Logging in Python

Learn how to use Python's built-in logging module to log your Python applications, changing default format, level, and learning in a concrete example, as well as using logging handlers.
  · 10 min read · Updated oct 2020 · Python Standard Library


Logging allows programmers and software developers to track events that happen in their software, it can not only track the actual event, but when it occured and in which function and even in which line.

Logging generates a detailed set of events that occur within your application. For example, if there is an error somewhere in your application, you can easily find the cause of the problem when you have logging setup correctly in your code.

Useful logs doesn't only help us debug our errors, but it can provide us with a tremendous help when trying to understand what a particular code is actually doing. In this tutorial, you will learn how to use the built-in logging module in Python.

You may be wondering, why we shouldn't only use the known print() function ? Well, you should only use it on small Python scripts, but for larger complex programs, it will quickly get messy and you should definitely use logging.

Logging is a cleaner way to keep track of what your code is doing. Almost every production level application uses this technique to keep track of what phases their applications are going through.

Logging Module

Logging module is built-in with Python standard library and it's a powerful ready-to-use tool for Python programmers to get started quickly with logging. It is also a convenient way and it's used by most of the third party Python libraries.

Logging module comes with 5 standard logging levels indicating the severity of events, each has a corresponding method that can be used to log events at that level, the following table shows all the logging levels as well as their numeric values and when we use it:

 Level  Numeric Value  When it's used
 DEBUG  10  Detailed information, such as trying to find bugs in your program.
 INFO  20  Informational messages that confirms everything is working as intended.
 WARNING  30  Indicating that something unexpected happened, telling some potential problem or deprectation warning.
 ERROR  40  Designates the software hasn't been able to perform certain function, but still allow the application to continue running.
 CRITICAL  50  A serious error that will lead the program to stop running. 

The following code cell performs simple logging messages with all the levels to the console:

import logging

# make a debug message
logging.debug("This is a simple debug log")
# make an info message
logging.info("This is a simple info log")
# make a warning message
logging.warning("This is a simple warning log")
# make an error message
logging.error("This is a simple error log")
# make a critical message
logging.critical("This is a simple critical log")

Output:

WARNING:root:This is a simple warning log
ERROR:root:This is a simple error log
CRITICAL:root:This is a simple critical log

Awesome, so the default logging format is the level, the name of the logger (root as default) and the message. In later sections, we'll see how to change this format to add more useful information.

You may be wondering, why DEBUG and INFO messages didn't get logged ? Well, this is because the default logging level is WARNING:

# just mapping logging level integers into strings for convenience
logging_levels = {
    logging.DEBUG: "DEBUG", # 10
    logging.INFO: "INFO", # 20
    logging.WARNING: "WARNING", # 30
    logging.ERROR: "ERROR", # 40
    logging.CRITICAL: "CRITICAL", # 50
}

# get the current logging level
print("Current logging level:", logging_levels.get(logging.root.level))

Output:

Current logging level: WARNING

So using this level, the logging module logs the messages with a level of WARNING or above, the only messages that get through are WARNING, ERROR and CRITICAL. If you set it to INFO, then INFO, WARNING, ERROR and CRITICAL messages will get through, and so on.

The following line of code prints the default logging format:

# get the current logging format
print("Current logging format:", logging.BASIC_FORMAT)

Output:

Current logging format: %(levelname)s:%(name)s:%(message)s

Right, so the default format is the level name, the name of the logger and the actual message.

Basic Configurations

The logging module provides us with a useful basicConfig() method, which allows us to change a couple of parameters during our logging process, it accepts a bunch of useful parameters, here are the most used ones:

  • filename: Specifies the file name to log into, so it'll log into a file instead of the console.
  • filemode: Specifies the mode to open the file, defaults to 'a' that stands for append, 'w' to write, etc.
  • level: Set the root logger level to the specified level, which are logging.DEBUG, logging.INFO, logging.WARNING, logging.ERROR and logging.CRITICAL.
  • format: A specified format string for the logger.
  • datefmt: The format of the date/datetime.
  • handlers: If specified, this should be an iterable of logging handlers, which will be added to the root handler.

Changing Logging Level

You can easily change the severity level using basicConfig() method:

import logging

# make a basic logging configuration
# here we set the level of logging to DEBUG
logging.basicConfig(
    level=logging.DEBUG
)

# make a debug message
logging.debug("This is a simple debug log")
# make an info message
logging.info("This is a simple info log")
# make a warning message
logging.warning("This is a simple warning log")
# make an error message
logging.error("This is a simple error log")
# make a critical message
logging.critical("This is a simple critical log")

And indeed, now all the messages will get through:

DEBUG:root:This is a simple debug log
INFO:root:This is a simple info log        
WARNING:root:This is a simple warning log  
ERROR:root:This is a simple error log      
CRITICAL:root:This is a simple critical log

Changing Logging Format

We can change the logging format by setting the format parameter to basicConfig() method:

import logging

logging.basicConfig(
    level=logging.INFO,
    format="%(asctime)s - %(levelname)s - %(message)s",
)

logging.info("This is an info message!")

Output:

2020-10-10 19:26:19,908 - INFO - This is an info message!

Awesome! Now we have the datetime in our logging message. Notice we used %(asctime)s attribute to get the datetime, %(levelname)s to get the level name and %(message)s to get the actual log message.

There are a lot of other attributes, here are some of the most important ones:

  • %(funcName)s: Name of the function containing the logging call.
  • %(lineno)d: Source line number where the logging call was issued (if available).
  • %(module)s: Module name.
  • %(name)s: Name of the actual logger used to log the call.
  • %(process)d: Process ID (if available).

Please check this link to get all the available LogRecord attributes.

If you want to change the date format, then you should change datefmt parameter as well:

import logging

logging.basicConfig(
    level=logging.INFO,
    format="%(asctime)s - %(levelname)s - %(message)s",
    datefmt="[%Y-%m-%d] %H:%M:%S",
)

logging.info("This is an info message!")

The format codes are the same for time.strftime() and time.strptime() methods, get the list here.

Output:

[2020-10-10] 19:33:23 - INFO - This is an info message!

Amazing, now let's get our hands dirty with an example!

Example

The below recipe is a good example of using logging module in Python:

import logging
import math

logging.basicConfig(level=logging.DEBUG,
                    handlers=[logging.FileHandler('logs.log', 'a', 'utf-8')],
                    format="%(asctime)s %(levelname)-6s - %(funcName)-8s - %(filename)s - %(lineno)-3d - %(message)s",
                    datefmt="[%Y-%m-%d] %H:%M:%S - ",
                    )

logging.info("This is an info log")

def square_root(x):
    logging.debug(f"Getting the square root of {x}") 
    try:
        result = math.sqrt(x)
    except ValueError:
        logging.exception("Cannot get square root of a negative number")
        # or
        # logging.error("Cannot get square root of a negative number", exc_info=True)
        return None
    logging.info(f"The square root of {x} is {result:.5f}")
    return result

square_root(5)
square_root(-5)

In this example, we used handlers parameter to pass a list of logging handlers, we specified FileHandler that logs to logs.log file with append mode and UTF-8 encoding.

After running the above code, here is the resulting logs.log file:

[2020-10-10] 19:44:49 -  INFO   - <module> - logger_file.py - 10  - This is an info log
[2020-10-10] 19:44:49 -  DEBUG  - square_root - logger_file.py - 13  - Getting the square root of 5
[2020-10-10] 19:44:49 -  INFO   - square_root - logger_file.py - 21  - The square root of 5 is 2.23607
[2020-10-10] 19:44:49 -  DEBUG  - square_root - logger_file.py - 13  - Getting the square root of -5
[2020-10-10] 19:44:49 -  ERROR  - square_root - logger_file.py - 17  - Cannot get square root of a negative number
Traceback (most recent call last):
  File "c:/pythoncode-tutorials/python-standard-library/logging/logger_file.py", line 15, in square_root
    result = math.sqrt(x)
ValueError: math domain error

Awesome, we specified the function name as well as the line number of the event, notice when the logging isn't in a function, the <module> token will be an indicator that it's in module level (not in any function).

The toy square_root() function we used is catching a ValueError that is raised whenever we pass a negative value, we used logging.exception() function to include the error traceback in the log file, it is the same as using logging.error() function with exc_info set to True.

Using Handlers

So far, we've been using module-level logging, but what if we want to use multiple loggers for different purposes ? Here's where handlers comes into play.

We use logging handlers when we want to configure our own loggers and send the logs into multiple places. We can use handlers to send the log messages to the standard output, a file, or even over HTTP.

The following example retrieves a logger object using logging.getLogger() method and appends a handler to it:

import logging

# return a logger with the specified name & creating it if necessary
logger = logging.getLogger(__name__)

# create a logger handler, in this case: file handler
file_handler = logging.FileHandler("file.log")
# set the level of logging to INFO
file_handler.setLevel(logging.INFO)

# create a logger formatter
logging_format = logging.Formatter("%(asctime)s - %(levelname)s - %(message)s")

# add the format to the logger handler
file_handler.setFormatter(logging_format)

# add the handler to the logger
logger.addHandler(file_handler)

# use the logger as previously
logger.critical("This is a critical message!")

We also set a formatter to the file handler using setFormatter() method, here is the output of the file.log file:

2020-10-10 20:00:16,019 - CRITICAL - This is a critical message!

Conclusion

Awesome, now hopefully you start using logging in your Python programs instead of the regular print() function, I highly encourage you to check the tutorial from Python documentation for more in-depth information.

As an exercise, I invite you to check the below tutorials code, and add logging statements in the places where you think is useful:

Learn also: How to Use Regular Expressions in Python.

Happy Coding ♥

View Full Code
Sharing is caring!



Read Also





Comment panel