Learn the basics of Python Logging [In-Depth Tutorial]

Important things to know before you start with Python Logging

To use the built-in logging module in Python, you typically need to import the module and then call the basicConfig() function to configure the logging. Some of the parameters which you will have to configure include:

• level: The logging level. This can be one of the predefined levels such as DEBUG, INFO, WARNING, ERROR, or CRITICAL, or a custom level.
• filename: The file to log to. If not specified, the logs will be printed to the console.
• filemode: The mode to open the file in. By default, the file is opened in 'a' (append) mode.
• format: The format of the log messages. This can include placeholders for various fields such as the timestamp, the logging level, and the log message.
• datefmt: The format of the timestamp.
• stream: The stream to log to. By default, the logs are printed to sys.stderr.

For more fine-grained control, you can use

• logging.basicConfig() function to configure the logging,
• logging.getLogger() function to get a logger instance and then use it to log messages.
• logging.FileHandler() and logging.StreamHandler() classes to log to a file or to the console respectively.
• logging.Formatter() class to customize the format of the log messages,
• logging.Filter() class to filter log messages based on certain criteria.

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

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

It is definitely up to you what kind of behavior 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

Different Logging Levels available in Python

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.

• 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.

Here is a simple program which utilizes logging module and helps you log messages with different log levels

import logging
logging.basicConfig(level=logging.DEBUG)
logging.debug('This is a debug message')
logging.info('This is an info message')
logging.warning('This is a warning message')
logging.error('This is an error message')
logging.critical('This is a critical message')

Output:

DEBUG:root:This is a debug message
INFO:root:This is an info message
WARNING:root:This is a warning message
ERROR:root:This is an error message
CRITICAL:root:This is a critical message

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 sections

Step-by-Step process to configure Python Logging

The process of configuring logging feature in Python using the logging module typically involves the following steps:

Step-1: Import logging module

The first steps is to import the logging module

import loggig

Step-2: Create logger instance using 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:

<RootLogger root (WARNING)>

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

logger = logging.getLogger('my_logger')

In this example, my_logger is the name of the logger. The name of the logger is used to identify it when configuring the logging or when retrieving log records.

You can also create a logger with a specific name by calling logging.getLogger("name"). By default, if no name is specified, the root logger is returned.

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

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

Step-3: Configure basicConfig() - [Define log level, filename and format]

Configure the logger using the basicConfig() function or the basicConfig() method on the logger object. This step is optional, but it is usually recommended to configure the logging level, the format of the log messages, and the destination for the log messages (e.g., a file or the console).

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()

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')

# 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 and 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 Examples

• 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.

Example-1: 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

Example-2: 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

Example-3: 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

Example-4: 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

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.

Example-1: 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]

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

The propagate entry is set to 0 to indicate that messages are not propagated to handlers up the hierarchy. If you wish to propagate to handlers higher up the logger hierarchy from this logger, then use 1 to indicate that messages.

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