Python Logging Module

This tutorial will teach us about Python’s logging features and why you want to use them. Logging is essential in the development process because it enables your code to record events as the program executes them for later analysis. You can think of logging as sort of like an airplane’s black box. It’s always recording data about how things are functioning. And if something unexpected happens, you can use the log to help diagnose the issue in your program. It’s also not always possible or feasible to use a regular debugger to step through your program’s code to help analyze and solve problems in real-time. For example, the code might be running on a remote server, making it challenging to debug locally. In addition, some errors and issues only happen occasionally during the program’s lifetime. Logging makes it easy to categorize various events that occur while your program executes, which can help when you’re trying to track down the origin of a problem. Even if you don’t use logging for debugging, it can provide a valuable audit trail of the program’s execution for business analysis purposes. It’s also very straightforward to customize the output format of logging data. So you can record information as detailed or simple as you need. Logging is a little bit like exercising. Everyone knows they should do it, but not everyone does it as often as they should. By the end of this chapter, you’ll see how easy logging is, and you’ll never again wonder why you need to use it.

Logging Module

import logging

logging.debug('This is for debug logging')
logging.info('The info logging is informational')
logging.warning('Warnings are for when something is not right')
logging.error('An error indicates something is wrong')
logging.critical('This level is for critical errors')

You import the logging module into your app using Python’s logging features. To send information to the log output, there are individual functions for each kind or level of the message. There are five different methods to use for recording log messages. These are debug, info, warning, error, and critical. Each method corresponds to a particular message type, indicating different application statuses. Debug messages are typically used to provide helpful diagnostic information when trying to track down a problem. Info messages are usually used to indicate that a particularly interesting operation was able to complete normally. Warning messages indicate that something unexpected happened or a more severe problem might be approaching, such as running out of storage space or being unable to communicate with a remote server. Error messages indicate that a particular operation was unable to complete. And critical messages suggest that the program has suffered a severe error and might be unable to continue running.

import logging

# Use basicConfig to configure logging
logging.basicConfig(level=logging.DEBUG,
                    filemode="w",
                    filename="output.log")

# Trying out each of the log levels
logging.debug("This is a debug-level log message")
logging.info("This is an info-level log message")
logging.warning("This is a warning-level message")
logging.error("This is an error-level message")
logging.critical("This is a critical-level message")

# Output formatted string to the log
logging.info(f"Here's a {'string'} variable and an int: {10}")

output.log

DEBUG:root:This is a debug-level log message
INFO:root:This is an info-level log message
WARNING:root:This is a warning-level message
ERROR:root:This is an error-level message
CRITICAL:root:This is a critical-level message
INFO:root:Here's a string variable and an int: 10

You can configure logging output with the basicConfig function and set the level argument to the minimum logging level you need. In the code above, you can see the import of the logging module and that there is some simple code to try out some of the logging functions. When we run this code, the output is sent to a file named output.log. We can see that all messages are sent to the log output. It’s worth noting that the basicConfig function is only executed once before logging starts. Once you start logging, then successive calls to this function won’t have any effect.

Logging Modes

The example above sets the file mode for output.log to write. We’ll see the same output in the log file each time this example runs. You can leave that parameter if you would rather append the debug information. Let’s see the code run a few times with that slight adjustment.

import logging

# Use basicConfig to configure logging
logging.basicConfig(level=logging.DEBUG, filename="output.log")

# Trying out each of the log levels
logging.debug("This is a debug-level log message")
logging.info("This is an info-level log message")
logging.warning("This is a warning-level message")
logging.error("This is an error-level message")
logging.critical("This is a critical-level message")

# Output formatted string to the log
logging.info(f"Here's a {'string'} variable and an int: {10}")
DEBUG:root:This is a debug-level log message
INFO:root:This is an info-level log message
WARNING:root:This is a warning-level message
ERROR:root:This is an error-level message
CRITICAL:root:This is a critical-level message
INFO:root:Here's a string variable and an int: 10
DEBUG:root:This is a debug-level log message
INFO:root:This is an info-level log message
WARNING:root:This is a warning-level message
ERROR:root:This is an error-level message
CRITICAL:root:This is a critical-level message
INFO:root:Here's a string variable and an int: 10
DEBUG:root:This is a debug-level log message
INFO:root:This is an info-level log message
WARNING:root:This is a warning-level message
ERROR:root:This is an error-level message
CRITICAL:root:This is a critical-level message
INFO:root:Here's a string variable and an int: 10
DEBUG:root:This is a debug-level log message
INFO:root:This is an info-level log message
WARNING:root:This is a warning-level message
ERROR:root:This is an error-level message
CRITICAL:root:This is a critical-level message
INFO:root:Here's a string variable and an int: 10

Now for each time the program is run, the log output is appended onto the most recent content of the file, so it continues to grow. If you don’t specify this argument, the file is open in append mode by default. It will depend on the particular application if you want to use write or append mode for the log file.

Custom Python Logging

The Python logging module is very flexible and makes it easy to customize the message output depending on your needs. This way, you are not stuck with a single message format. The basicConfig function takes two additional arguments, format and datefmt. The format argument specifies a string that controls the precise formatting of the output message sent to the log. The date format argument is used in conjunction with the format argument. If the format argument contains a date specifier, then the date format argument is used to format the date string using the same kind of date formatting strings that you would pass to the strftime function. You can review all the logging options in the official documentation. The example code below shows a more customized logging setup, and the resulting log data looks a little more like what you might find in a real-world application.

extra_data = {'user': 'admin'}


def custom_debug():
    logging.debug("This is a debug-level log message", extra=extra_data)


fmtStr = "%(asctime)s: %(levelname)s: %(funcName)s Line:%(lineno)d User:%(user)s %(message)s"

dateStr = "%m/%d/%Y %I:%M:%S %p"

logging.basicConfig(filename="output.log", level=logging.DEBUG, format=fmtStr, datefmt=dateStr)

logging.info("This is an info-level log message", extra=extra_data)

logging.warning("This is a warning-level message", extra=extra_data)

custom_debug()
10/25/2022 01:23:34 PM: INFO: <module> Line:16 User:admin This is an info-level log message
10/25/2022 01:23:34 PM: WARNING: <module> Line:18 User:admin This is a warning-level message
10/25/2022 01:23:34 PM: DEBUG: custom_debug Line:7 User:admin This is a debug-level log message
10/25/2022 01:23:51 PM: INFO: <module> Line:16 User:admin This is an info-level log message
10/25/2022 01:23:51 PM: WARNING: <module> Line:18 User:admin This is a warning-level message
10/25/2022 01:23:51 PM: DEBUG: custom_debug Line:7 User:admin This is a debug-level log message

More Logging Examples

This example of logging in Python uses a technique of sending program output to a log file rather than using a print function to print the results to the screen. In learning Python, we all use the print() function extensively. It helps to swap out the print() function for logging statements when getting a handle on how to use the logging module in Python.

import logging

logging.basicConfig(filename='output.log', level=logging.DEBUG,
                    format='%(asctime)s:%(levelname)s:%(message)s',
                    datefmt='%m/%d/%Y %I:%M:%S %p')


def addition(x, y):
    """Add Function"""
    return x + y


def subtraction(x, y):
    """Subtract Function"""
    return x - y


def multiplication(x, y):
    """Multiply Function"""
    return x * y


def division(x, y):
    """Divide Function"""
    return x / y


num_1 = 50
num_2 = 20

add_result = addition(num_1, num_2)
logging.debug('Add: {} + {} = {}'.format(num_1, num_2, add_result))

sub_result = subtraction(num_1, num_2)
logging.debug('Sub: {} - {} = {}'.format(num_1, num_2, sub_result))

mul_result = multiplication(num_1, num_2)
logging.debug('Mul: {} * {} = {}'.format(num_1, num_2, mul_result))

div_result = division(num_1, num_2)
logging.debug('Div: {} / {} = {}'.format(num_1, num_2, div_result))
10/25/2022 01:42:59 PM:DEBUG:Add: 50 + 20 = 70
10/25/2022 01:42:59 PM:DEBUG:Sub: 50 - 20 = 30
10/25/2022 01:42:59 PM:DEBUG:Mul: 50 * 20 = 1000
10/25/2022 01:42:59 PM:DEBUG:Div: 50 / 20 = 2.5