10+ practical examples to use python logging() in detail

How to log messages in Python programming? What are the different python logging levels? Can I add some custom format to the log messages? How do I redirect the log output to a file?

A log is usually a system file that accumulates messages, often inserting useful information such as a timestamp or the name of the user who’s running the program. Often logs are rotated (renamed) daily and compressed; by doing so, they don’t fill up your disk and cause problems themselves. When something goes wrong with your program, you can look at the appropriate log file to see what happened. The contents of exceptions are especially useful in logs because they show you the actual line at which your program croaked, and why.

Logging is something which is one of the most crucial part of any code or script, this helps the developer debug any kind of failure. So, it is always recommended to add enough log messages in the code.

I have briefly noted down the steps involved in using python logging module. Are you in a hurry?, just looking for quick steps to have a basic logging configuration for your python script, jump to these internal hyperlinks:

If you are still here, I would recommend reading the entire article to get proper overview on Python Logging module. In python we have inbuilt logging module which can be used generate different level of logs. In this tutorial I will cover below topics:

  • Introduction to logging module
  • Different classes available in python logging module
  • Using Handlers
  • Using Formatter to format the output of the log messages
  • Python logging levels
  • Logging to log file, console and syslog
  • Configure logging using basicConfig, dictConfig, fileConfig

 

Overview on python logging module

Python has an in-built logging module which is extremely helpful, but it tends to be very difficult to use correctly. The result is often that people just disable logging completely and use print statements instead. This is insightful but a waste of the very extensive logging system in Python. The key benefit of having the logging API provided by a standard library module is that all Python modules can participate in logging, so your application log can include your own messages integrated with messages from third-party modules.

The most important objects of the logging module are the following:

  • Logger: the actual logging interface
  • Handler: This processes the log statements and outputs them
  • Formatter: This formats the input data into a string
  • Filter: This allows filtering of certain messages

 

Why to use logging when we have print() function?

  • It is definitely up to you what kind of behaviour you wish to have in your Python script.
  • But you have to understand print() has very limited benefits compared to logging
  • With print() you can mostly put messages on STDOUT with no additional information on the type of message

With logging you can:

  • set different levels to your message such as info(), debug(), error(), warning()
  • add different format of the message, i.e. put date timestamps, filename, process, path and many more LogRecord attributes
  • log to files, sockets, pretty much anything, all at the same time.

So you see we have much more control on the messages when we use logging() compared to print() function

 

Python Logging Levels

There are different pre-define levels which you can use based on the severity of messages or events you need to track in your Python program.

LevelNumeric ValueWhen to be used?
CRITICAL50A serious error, indicating that the program itself may be unable to continue running.
ERROR40Due to a more serious problem, the software has not been able to perform some function.
WARNING30An indication that something unexpected happened, or indicative of some problem in the near future (e.g. ‘disk space low’). The software is still working as expected.
INFO20Confirmation that things are working as expected.
DEBUG10Detailed information, typically of interest only when diagnosing problems.
NOTSET0When a logger is created, the level is set to NOTSET

  • You can also choose to create your own custom level
  • Also, when defining custom levels, you will have to overwrite existing levels if they have the same numeric value.
  • The numbers are the numeric values of these log levels. While you can generally ignore them, the order is obviously important while setting the minimum level
  • You are required to define the logging level in your script. The default level is WARNING, which means that only events of this level and above will be tracked, unless the logging package is configured to do otherwise.
  • You must be aware of the order which will be considered when you define the logging level. Assuming you define your logging level as logging.WARNING, in such case you will be allowed to define warning(), error() and critical() levels.

For example, in this python script I have just imported the logging module and have not defined any level

#!/usr/bin/env python3

import logging

logging.debug('debug')
logging.info('info')
logging.warning('warning')
logging.error('error')
logging.critical('critical')

When we execute this script, we get output only for warning(), error(), and critical(). This is because the default logging level is set to warning() and the script will only consider all levels having "equal to or higher numerical value" than warning()

# python3 /tmp/logging_ex.py
WARNING:root:warning
ERROR:root:error
CRITICAL:root:critical

The lowest level would be DEBUG and the highest level would be CRITICAL. So it is recommended that you always define the logging level with the minimal value i.e. DEBUG so that you can also use higher logging levels if required.

We will learn more on how to set logging level and more in coming chapters

 

Define logger name with logging.getLogger()

  • Did you observed we are getting "root" in the logging output in above example?
  • The root of the hierarchy of loggers is called the root logger.
  • That’s the logger used by the functions debug(), info(), warning(), error() and critical(), which just call the same-named method of the root logger.
  • The root logger’s name is printed as ‘root’ in the logged output.

The following function is used to retrieve or create new logging objects:

getLogger(logname)

For example:

#!/usr/bin/env python3

import logging

# Get the default logger object
print(logging.getLogger())

This will print the default logger name and level:

# python3 /tmp/logging_ex.py
<RootLogger root (WARNING)>

We can define our custom logger name using the same function, for example:

logger = logging.getLogger(__name__)

This will create a module-wide "logger" object with a name that matches the module name. The root logger has the name ""; that is, an empty string.

There are four common use cases for using logging.getLogger() to name our Loggers

  • Module names
  • Object instances
  • Class names
  • Function names

 

Configure logging using basicConfig()

  • A quick and easy start logging configuration is with basicConfig().
  • I recommend using this if you just need some quick logging for a script you're writing, but not for a full-blown application.
  • logging.basicConfig() does basic configuration for the logging system by creating a StreamHandler with a default Formatter and adding it to the root logger.
  • The functions debug(), info(), warning(), error() and critical() will call basicConfig() automatically if no handlers are defined for the root logger.
  • You check check official docs.python.org to get the list of keyword arguments supported with basicConfig()

 

Python Script Example with basicConfig()

In this example I will use logging.basicConfig() with below keywords:

  • filename: Specifies that a FileHandler be created, using the specified filename, rather than a StreamHandler.
  • format: Use the specified format string for the handler.
  • level: Set the root logger level to the specified level.
#!/usr/bin/env python3

import logging

log_format = (
    '[%(asctime)s] %(levelname)-8s %(name)-12s %(message)s')

logging.basicConfig(
    level=logging.DEBUG,
    format=log_format,
    filename=('debug.log'),
)

logging.debug('debug')
logging.info('info')
logging.warning('warning')
logging.error('error')
logging.critical('critical')

Execute the script

# python3 /tmp/logging_ex.py

Check the debug.log file after executing the script

# tail -f debug.log
[2020-06-24 09:19:58,490] DEBUG    root         debug
[2020-06-24 09:19:58,490] INFO     root         info
[2020-06-24 09:19:58,490] WARNING  root         warning
[2020-06-24 09:19:58,491] ERROR    root         error
[2020-06-24 09:19:58,491] CRITICAL root         critical

But again we see root logger's name, so we will define our own custom logger name.

#!/usr/bin/env python3

import logging

log_format = (
    '[%(asctime)s] %(levelname)-8s %(name)-12s %(message)s')

# Define basic configuration
logging.basicConfig(
    # Define logging level
    level=logging.DEBUG,
    # Define the format of log messages
    format=log_format,
    # Provide the filename to store the log messages
    filename=('debug.log'),
)
# Define your own logger name
logger = logging.getLogger("my_logger")

# Now we use our logger object instead of logging
logger.debug('debug')
logger.info('info')
logger.warning('warning')
logger.error('error')
logger.critical('critical')

Execute the script

# python3 /tmp/logging_ex.py

Check the debug.log file after executing the script, now we get our custom defined logger name

[2020-06-24 10:13:43,651] DEBUG    my_logger    debug
[2020-06-24 10:13:43,651] INFO     my_logger    info
[2020-06-24 10:13:43,651] WARNING  my_logger    warning
[2020-06-24 10:13:43,651] ERROR    my_logger    error
[2020-06-24 10:13:43,651] CRITICAL my_logger    critical

 

Python logging.handlers

  • Now we know the basics to setup python logging, let us learn about handlers now.
  • Handler objects are responsible for dispatching the appropriate log messages (based on the log messages’ severity) to the handler’s specified destination
  • The logging.handlers module offers a large number of handlers for routing, printing, or saving the sequence of logging messages.
  • There are various types of handlers part of logging.handlers, this tutorials uses mainly StreamHandler and FileHandler in its examples.

 

Python Script Example: Print message only on console

  • In this example we will use logging.StreamHandler.
  • The StreamHandler is used to write to the console, if stream is specified, the instance will use it for logging output; otherwise, sys.stderr will be used.
  • We can use logging.StreamHandler(sys.stdout) or just logging.StreamHandler() to use sys.stderr. In both cases the messages will be printed on console
#!/usr/bin/env python3

import logging
import sys

# Define the log format
log_format = (
    '[%(asctime)s] %(levelname)-8s %(name)-12s %(message)s')

# Define basic configuration
logging.basicConfig(
    # Define logging level
    level=logging.DEBUG,
    # Declare the object we created to format the log messages
    format=log_format,
    # Declare handlers
    handlers=[
        logging.StreamHandler()
    ]
)

# Define your own logger name
logger = logging.getLogger("my_logger")

# Now we use our logger object instead of logging
logger.debug('debug')
logger.info('info')
logger.warning('warning')
logger.error('error')
logger.critical('critical')

Next execute the script, this will print the messages on the console:

# python3 /tmp/logging_ex.py
[2020-06-24 14:28:06,614] DEBUG    my_logger    debug
[2020-06-24 14:28:06,614] INFO     my_logger    info
[2020-06-24 14:28:06,614] WARNING  my_logger    warning
[2020-06-24 14:28:06,614] ERROR    my_logger    error
[2020-06-24 14:28:06,614] CRITICAL my_logger    critical

 

Python Script Example: Write messages to log file only

  • For long-running programs, logging to the screen is not a very viable option. After running the code for hours, the oldest logged messages will be lost, and even if they were still available, it wouldn't be very easy to read all the logs or search through them.
  • Saving logs to a file allows for unlimited length (as far as our disk allows it) and enables the usage of tools, such as grep, to search through them.
  • The FileHandler class, located in the core logging package, sends logging output to a disk file.
  • It inherits the output functionality from StreamHandler.

In this script we will write our messages to /tmp/debug.log which is defined as "logfile" object

#!/usr/bin/env python3

import logging

# Log file location
logfile = '/tmp/debug.log'
# Define the log format
log_format = (
    '[%(asctime)s] %(levelname)-8s %(name)-12s %(message)s')

# Define basic configuration
logging.basicConfig(
    # Define logging level
    level=logging.DEBUG,
    # Declare the object we created to format the log messages
    format=log_format,
    # Declare handlers
    handlers=[
        logging.FileHandler(logfile)
    ]
)

# Define your own logger name
logger = logging.getLogger("my_logger")

# Write messages with all different types of levels
logger.debug('debug')
logger.info('info')
logger.warning('warning')
logger.error('error')
logger.critical('critical')

Execute this script

# python3 /tmp/logging_ex.py

This should create a new log file (if not present already) and append the logger messages

# tail -f /tmp/debug.log
[2020-06-24 16:16:17,414] DEBUG    my_logger    debug
[2020-06-24 16:16:17,415] INFO     my_logger    info
[2020-06-24 16:16:17,415] WARNING  my_logger    warning
[2020-06-24 16:16:17,415] ERROR    my_logger    error
[2020-06-24 16:16:17,415] CRITICAL my_logger    critical

 

Python Script Example: Write messages to console and log file both

We learned about two different logging.handlers() separately. We can combine both of them in a single script to be able to write messages on console terminal as well in a log file.
In this script we will use both FileHandler and Streamhandler inside basicConfig()

#!/usr/bin/env python3

import logging
import sys

# Log file location
logfile = '/tmp/debug.log'
# Define the log format
log_format = (
    '[%(asctime)s] %(levelname)-8s %(name)-12s %(message)s')

# Define basic configuration
logging.basicConfig(
    # Define logging level
    level=logging.DEBUG,
    # Declare the object we created to format the log messages
    format=log_format,
    # Declare handlers
    handlers=[
        logging.FileHandler(logfile),
        logging.StreamHandler(sys.stdout),
    ]
)

# Define your own logger name
logger = logging.getLogger("my_logger")

# Write messages with all different types of levels
logger.debug('debug')
logger.info('info')
logger.warning('warning')
logger.error('error')
logger.critical('critical')

Execute the script, and it should write messages on the console:

# python3 /tmp/logging_ex.py
[2020-06-24 16:30:14,163] DEBUG    my_logger    debug
[2020-06-24 16:30:14,163] INFO     my_logger    info
[2020-06-24 16:30:14,163] WARNING  my_logger    warning
[2020-06-24 16:30:14,164] ERROR    my_logger    error
[2020-06-24 16:30:14,164] CRITICAL my_logger    critical

Also the same content would be appended to our log file /tmp/debug.log

[2020-06-24 16:30:14,163] DEBUG    my_logger    debug
[2020-06-24 16:30:14,163] INFO     my_logger    info
[2020-06-24 16:30:14,163] WARNING  my_logger    warning
[2020-06-24 16:30:14,164] ERROR    my_logger    error
[2020-06-24 16:30:14,164] CRITICAL my_logger    critical

 

Python Script Example: Write messages to syslog (or rsyslog)

  • The SysLogHandler class, located in the logging.handlers module, supports sending logging messages to a remote or local Unix syslog.
  • So to be able to send log messages to syslog you must also import logging.handlers module
  • Note that if your server is not listening on UDP port 514, SysLogHandler may appear not to work.
  • In that case, check what address you should be using for a domain socket - it’s system dependent. For example, on Linux it’s usually ‘/dev/log’ but on OS/X it’s ‘/var/run/syslog
  • Since I am using Linux environment, I will use "/dev/log"
#!/usr/bin/env python3

import logging
import logging.handlers

# Log file location
logfile = '/tmp/debug.log'
# Define the log format
log_format = (
    '[%(asctime)s] %(levelname)-8s %(name)-12s %(message)s')

# Define basic configuration
logging.basicConfig(
    # Define logging level
    level=logging.DEBUG,
    # Declare the object we created to format the log messages
    format=log_format,
    # Declare handlers
    handlers=[
        logging.handlers.SysLogHandler(address="/dev/log"),
    ]
)

# Define your own logger name
logger = logging.getLogger("my_logger")

# Write messages with all different types of levels
logger.debug('debug')
logger.info('info')
logger.warning('warning')
logger.error('error')
logger.critical('critical')

Next execute the script

# python3 /tmp/logging_ex.py

and observe your syslog (I am using journalctl -f to view the latest messages)

Jun 24 16:46:25 client.example.com python3[2467]: [2020-06-24 16:46:25,644] DEBUG    my_logger    debug
Jun 24 16:46:25 client.example.com python3[2467]: [2020-06-24 16:46:25,644] INFO     my_logger    info
Jun 24 16:46:25 client.example.com python3[2467]: [2020-06-24 16:46:25,644] WARNING  my_logger    warning
Jun 24 16:46:25 client.example.com python3[2467]: [2020-06-24 16:46:25,644] ERROR    my_logger    error
Jun 24 16:46:25 client.example.com python3[2467]: [2020-06-24 16:46:25,645] CRITICAL my_logger    critical
NOTE:

You can again combine FileHandler(), StreamHandler() and SysLogHandler() to have all three kinds of messages i.e. write to a file, write on the console and write to the syslog respectively.

 

Create multiple handlers with different log levels

  • We used handlers within our basicConfig() function in all the above python scripts. Now let us use it outside the basicConfig() function.
  • We can assign different log files, log levels, formats and assign to individual handlers and use them as per your requirement.
  • Assuming you wish the format of the message to write on console is different compared to the messages which you write in log file so we can create difference format and assign to individual handlers.
  • Similarly you can assign different log levels such as only ERROR and higher level of logs would be printed on the console while DEBUG and higher level of log would be written to the log file.

 

Python script example: Assign different log level and format to handlers

In this example we create

console_handler:

  • write messages on the console
  • Use it's own formatter defined by print_format object
  • Set to CRITICAL log level so only messages with CRITICAL level will be printed on the console

 

file_handler

  • write messages to log file (/tmp/debug.log)
  • Use it's own formatter defined by log_format object
  • Set to DEBUG log level so all messages with DEBUG ad higher level will be written to the log file.
#!/usr/bin/env python3

import logging
import sys

# Log file location
logfile = '/tmp/debug.log'


# Define your own logger name
logger = logging.getLogger("my_logger")
# Set default logging level to DEBUG
logger.setLevel(logging.DEBUG)

# create a console handler
# and define a custom log format, set its log level to CRITICAL
print_format = logging.Formatter('%(levelname)-8s %(name)-12s %(message)s')
console_handler = logging.StreamHandler(sys.stdout)
console_handler.setLevel(logging.CRITICAL)
console_handler.setFormatter(print_format)

# create a log file handler
# and define a custom log format, set its log level to DEBUG
log_format = logging.Formatter('[%(asctime)s] %(levelname)-8s %(name)-12s %(message)s')
file_handler = logging.FileHandler(logfile)
file_handler.setLevel(logging.DEBUG)
file_handler.setFormatter(log_format)

#Add handlers to the logger
logger.addHandler(file_handler)
logger.addHandler(console_handler)

# Write messages with all different types of levels
logger.debug('debug')
logger.info('info')
logger.warning('warning')
logger.error('error')
logger.critical('critical')

Execute the script, the output on the console only contains CRITICAL messages

# python3 /tmp/logging_ex.py
CRITICAL my_logger    critical

while the log file /tmp/debug.log contains all message levels above DEBUG in the hierarchy using our defined log format

[2020-06-24 19:50:00,433] DEBUG    my_logger    debug
[2020-06-24 19:50:00,433] INFO     my_logger    info
[2020-06-24 19:50:00,434] WARNING  my_logger    warning
[2020-06-24 19:50:00,434] ERROR    my_logger    error
[2020-06-24 19:50:00,434] CRITICAL my_logger    critical

 

Configure logging using fileConfig()

  • There are several ways to configure the logging system, ranging from pure code to JSON files or even remote configuration.
  • In the above examples we use basicConfig() to configure logging using class and functions with handlers. But as you saw our last example was little too complicated for someone newbie to understand. Now imagine if we have more number of handlers then this may become more complex.
  • In this example we will re-write the above example script using fileConfig() with logging config file.
  • Here, we will have two handlers i.e. consoleHandler which will write logs to the console and fileHandler which will write messages to /tmp/debug.log file
  • The consoleHandler will only write if the log level is CRITICAL while fileHandler will write messages from all level having higher numerical value than DEBUG
  • We will assign separate formatters to both the handlers

 

Configuration file format

  • The file must contain sections called [loggers], [handlers] and [formatters] which identify by name the entities of each type which are defined in the file.
  • For each such entity, there is a separate section which identifies how that entity is configured.
  • Thus, for a logger named "my_logger" in the [loggers] section, the relevant configuration details are held in a section [logger_my_logger]
  • Similarly, a handler called consoleHandler in the [handlers] section will have its configuration held in a section called [handler_consoleHandler],
  • while a formatter called fileFormatter in the [formatters] section will have its configuration specified in a section called [formatter_fileFormatter]
NOTE:

It is important that you define all the sections, although the naming convention for the keys are not important. You can assign any name as per your environment.

Below is our logging.conf file. You can give any name to this configuration file.

[loggers]
keys=root,my_logger

[handlers]
keys=consoleHandler,fileHandler

[formatters]
keys=consoleFormatter,fileFormatter

[logger_root]
level=DEBUG
handlers=consoleHandler

[logger_my_logger]
level=DEBUG
handlers=consoleHandler,fileHandler
qualname=my_logger
propagate=0

[handler_consoleHandler]
class=StreamHandler
level=CRITICAL
formatter=consoleFormatter
args=(sys.stdout,)

[handler_fileHandler]
class=FileHandler
level=DEBUG
formatter=fileFormatter
args=('/tmp/debug.log', 'a')

[formatter_consoleFormatter]
format=%(levelname)-8s %(name)-12s %(message)s

[formatter_fileFormatter]
format=[%(asctime)s] %(levelname)-8s %(name)-12s %(message)s

Next we will use this logging configuration file in our python script

#!/usr/bin/env python3

import logging
import logging.config

# Define the logging.conf filePath
logging.config.fileConfig('/root/logging.conf', disable_existing_loggers=False)

# Define your own logger name
logger = logging.getLogger("my_logger")

# Write messages with all different types of levels
logger.debug('debug')
logger.info('info')
logger.warning('warning')
logger.error('error')
logger.critical('critical')

The fileConfig() function takes a default parameter, disable_existing_loggers, which defaults to True for reasons of backward compatibility. This may or may not be what you want, since it will cause any non-root loggers existing before the fileConfig() call to be disabled unless they are explicitly named in the configuration

Next execute this script and observe the output, we only get CRITICAL message on the console

# python3 /tmp/logging_ex.py
CRITICAL my_logger    critical

While our log file contains all messages from DEBUG level to higher ones

# tail -f /tmp/debug.log
[2020-06-24 22:44:18,480] DEBUG    my_logger    debug
[2020-06-24 22:44:18,480] INFO     my_logger    info
[2020-06-24 22:44:18,480] WARNING  my_logger    warning
[2020-06-24 22:44:18,480] ERROR    my_logger    error
[2020-06-24 22:44:18,480] CRITICAL my_logger    critical

 

Configure logging using dictConfig()

  • We can also Create a dictionary of configuration information and pass it to the dictConfig() function to configure logging
  • The contents of this dictionary are described in Configuration dictionary schema.
  • If an error is encountered during configuration, this function will raise a ValueError, TypeError, AttributeError or ImportError with a suitably descriptive message.

We will re-use our last python script example configuration with two handlers with separate formatters and log level

#!/usr/bin/env python3

import logging
import logging.config

# Declare handlers, formatters and all functions using dictionary 'key' : 'value' pair
logging.config.dictConfig({
    'version': 1,
    'disable_existing_loggers': False,
    'formatters': {
        'consoleFormatter': {
            'format': '%(levelname)-8s %(name)-12s %(message)s',
        },
        'fileFormatter': {
            'format': '[%(asctime)s] %(levelname)-8s %(name)-12s %(message)s',
            },
        },
        'handlers': {
            'file': {
                'filename': '/tmp/debug.log',
                'level': 'DEBUG',
                'class': 'logging.FileHandler',
                'formatter': 'fileFormatter',
            },
            'console': {
                'level': 'CRITICAL',
                'class': 'logging.StreamHandler',
                'formatter': 'consoleFormatter',
            },
        },
        'loggers': {
            '': {
                'handlers': ['file', 'console'],
                'level': 'DEBUG',
            },
        },
    })

# Define your own logger name
logger = logging.getLogger("my_logger")

# Write messages with all different types of levels
logger.debug('debug')
logger.info('info')
logger.warning('warning')
logger.error('error')
logger.critical('critical')

The output from this script shows only CRITICAL level message as expected

# python3 /tmp/logging_ex.py
CRITICAL my_logger    critical

while all DEBUG and higher level message are logged into /tmp/debug.log using FileHandler()

[2020-06-24 23:06:21,195] DEBUG    my_logger    debug
[2020-06-24 23:06:21,195] INFO     my_logger    info
[2020-06-24 23:06:21,195] WARNING  my_logger    warning
[2020-06-24 23:06:21,196] ERROR    my_logger    error
[2020-06-24 23:06:21,196] CRITICAL my_logger    critical

 

Conclusion

In this tutorial we learned about different types of methods to configure Python Logging using logging module. I showed you various examples to log messages to console, log file or syslog using different handlers, class and functions. Now you must have an idea on when you should be using the print() function and in which scenarios you should give precedence to logging function.
Lastly I hope this tutorial on Python logging was helpful. So, let me know your suggestions and feedback using the comment section.

 

References

I have used below external references for this tutorial guide
docs.python.org: Logging Configuration File
docs.python.org: Configure Logging
docs.python.org: Basic Python Logging Tutorial
Mastering Python

Leave a Comment

Please use shortcodes <pre class=comments>your code</pre> for syntax highlighting when adding code.