Python Logging: Deep Dive!

Logging is essential for understanding program flow and for diagnosing issues.

Rather than relying on print() statements, Python logging provides a flexible and standardized way to output messages, track events, debug issues, and collect runtime data. Python has a built-in logging module that offers a robust framework for implementing logging in your applications.

In this guide, we’ll explore the features of Python’s logging module, including setting up logging, configuring log levels, formatting log messages, writing logs to files, and so on.

Why Use Logging Over print()?

For sure, print() can be used for simple debugging, but logging has several advantages:

• Log Levels: Control the severity of messages (e.g., DEBUG, INFO, ERROR).
• Formatting: Easily customize how log messages appear (e.g., add timestamps or log level indicators).
• Persistence: Store logs in files, databases, or remote systems for future reference.
• Selective Output: Filter logs by severity, so you can output detailed information during development and limit output in production.

Basic Setup for Logging

To use logging, you must first import the logging module. You can then use the basicConfig() function to configure the default behavior, including the log level and format.

Basic Logging Setup Example:

import logging

# Configure the basic settings for logging
logging.basicConfig(level=logging.INFO)

# Log messages with different severity levels
logging.debug("This is a debug message.")
logging.info("This is an info message.")
logging.warning("This is a warning.")
logging.error("This is an error message.")
logging.critical("This is a critical error.")

Output:

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

In the example above…

• logging.basicConfig() sets the default configuration for the logging system.
• Messages are logged using different log levels (e.g., DEBUG, INFO, WARNING, ERROR, CRITICAL).

Since the log level is set to INFO, only messages at that level or higher (INFO, WARNING, ERROR, CRITICAL) are printed. The DEBUG message is ignored because it is lower than INFO.

Understanding Log Levels

Python’s logging module defines several log levels, with each level representing the severity of the event being logged. The available log levels (in increasing order of severity) are:

Example of Setting Different Log Levels:

logging.basicConfig(level=logging.DEBUG)

logging.debug("Debug message")
logging.info("Info message")
logging.warning("Warning message")
logging.error("Error message")
logging.critical("Critical message")

Here, because the log level is set to DEBUG, all messages (DEBUG and higher) are logged. If the log level were set to WARNING, only messages at the WARNING level and above (ERROR and CRITICAL) would be displayed.

Logging to a File

You can log output directly to a file by specifying a filename in basicConfig().

Example of Logging to a File:

logging.basicConfig(filename='app.log', level=logging.INFO)

logging.info("This message will be written to the log file.")
logging.error("This error message will also be logged.")

In this example, log messages are written to app.log instead of the console. If the file does not exist, Python will create it. Subsequent log entries will be appended to the file.

Sample Content of app.log:

INFO:root:This message will be written to the log file.
ERROR:root:This error message will also be logged.

Customizing Log Message Format

You can customize the format of log messages using the format argument in basicConfig(). This is useful when you want to include additional details like timestamps, log levels, or function names in your log entries.

Example of Custom Log Format:

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 with a custom format.")

Output:

2024-09-17 10:30:00 - INFO - This is an info message with a custom format.

Here, the format string includes:

• %(asctime)s: The current time in the format specified by datefmt.
• %(levelname)s: The log level (INFO, WARNING, etc.).
• %(message)s: The actual log message.

Common Format Specifiers:

• %(asctime)s: Timestamp when the log entry is created.
• %(levelname)s: The severity level of the log.
• %(message)s: The log message itself.
• %(name)s: The name of the logger.
• %(filename)s: The name of the file where the logging call was made.
• %(funcName)s: The name of the function where the log message was generated.

Creating and Using Loggers

By default, logging uses a root logger, but you can create custom loggers for more fine-grained control. This is especially useful in larger applications where different components need separate logging behavior.

Creating a Custom Logger:

# Create a custom logger
logger = logging.getLogger("my_logger")

# Set the log level for this logger
logger.setLevel(logging.DEBUG)

# Log messages using the custom logger
logger.debug("This is a debug message from my_logger.")
logger.info("This is an info message from my_logger.")

Using Multiple Loggers:

In complex applications, you can create multiple loggers, each with different configurations (e.g., different log levels, formats, or output destinations).

Logging Exceptions

The logging module provides a way to log exceptions along with traceback information using the exc_info=True argument. This is useful for logging errors when exceptions are raised.

Example of Logging Exceptions:

try:
    1 / 0
except ZeroDivisionError:
    logging.error("An error occurred", exc_info=True)

Output:

ERROR:root:An error occurred
Traceback (most recent call last):
  File "script.py", line 2, in <module>
    1 / 0
ZeroDivisionError: division by zero

In this example, the exc_info=True argument adds the full traceback to the log message.

Rotating Log Files

In production environments, log files can grow large over time. Python provides the RotatingFileHandler to automatically rotate log files when they reach a certain size, creating new files and optionally keeping a limited number of old log files.

Example Using RotatingFileHandler:

import logging
from logging.handlers import RotatingFileHandler

# Create a rotating file handler that rotates log files after they reach 1 MB
handler = RotatingFileHandler('app.log', maxBytes=1024*1024, backupCount=3)
logging.basicConfig(handlers=[handler], level=logging.INFO)

for i in range(10000):
    logging.info(f"Log message {i}")

Key Parameters:

• maxBytes: The maximum size of the log file before it gets rotated.
• backupCount: The number of backup log files to keep.

When the log file exceeds maxBytes, it is renamed, and a new log file is created. Up to backupCount log files are retained.

Advanced Logging Configuration with logging.config

You can configure logging more precisely using the logging.config module, which allows for detailed configuration of loggers, handlers, formatters, and filters. This can be done programmatically or using a configuration file (such as INI or YAML format).

Example Using logging.config (Programmatic Configuration):

import logging.config

LOGGING_CONFIG = {
    'version': 1,
    'formatters': {
        'default': {
            'format': '%(asctime)s - %(name)s - %(levelname)s - %(message)s'
        }
    },
    'handlers': {
        'file': {
            'class': 'logging.FileHandler',
            'filename': 'app.log',
            'formatter': 'default',
            'level': 'DEBUG'
        }
    },
    'root': {
        'handlers': ['file'],
        'level': 'DEBUG'
    }
}

logging.config.dictConfig(LOGGING_CONFIG)

logging.debug("This is a debug message.")
logging.info("This is an info message.")

Logging Best Practices

1. Use Appropriate Log Levels: Choose the right log level for your messages. Use DEBUG for detailed information during development, INFO for general application flow, and ERROR for issues that need immediate attention.
2. Avoid Overlogging: Log only relevant information. Too much logging can slow down the application and make logs harder to read.
3. Use Loggers for Different Modules: In larger applications, use multiple loggers with different configurations for different parts of the application.
4. Rotate Log Files: Use log rotation to prevent log files from growing too large.
5. Log Exceptions: Always log exceptions with exc_info=True to capture full traceback information.

Key Concepts Recap

• The logging module provides a flexible way to log messages at different levels (DEBUG, INFO, WARNING, ERROR, CRITICAL).
• Use basicConfig() to configure logging behavior, such as setting log levels and formatting log messages.
• Log output can be directed to the console, files, or even rotated files to manage log size.
• Use custom loggers for different components of an application.
• Log exceptions with exc_info=True to capture traceback details.
• Rotating log files is essential for production environments to prevent log files from becoming too large.

Exercise:

1. Basic Logging: Write a Python script that logs messages at all levels (DEBUG, INFO, WARNING, ERROR, CRITICAL) and directs the output to both the console and a file.
2. Rotating Logs: Modify the script to use rotating file handlers that limit the log file size to 1MB and keep up to 5 backups of the log files.
3. Exception Logging: Write a script that catches a division-by-zero error and logs the exception with the full traceback using logging.error() and exc_info=True.

You can learn more about Python logging in the official Python documentation.

Check out our free Learn Python Programming Masterclass to hone your skills or learn from scratch.

The course covers everything from first principles to Graphical User Interfaces and Machine Learning

FAQ

Q1: Why should I use logging instead of print() for debugging?

A1: logging provides more flexibility than print() by allowing you to:

• Set different log levels (e.g., DEBUG, INFO, ERROR) to control the verbosity.
• Format log messages with additional details like timestamps and log levels.
• Direct output to files, consoles, or external systems, which is useful for long-term monitoring or production.
• Filter or rotate logs for better management in large or distributed systems.

Q2: What are log levels, and how should I use them?

A2: Log levels categorize the importance of log messages:

• DEBUG: For detailed diagnostic information, useful during development.
• INFO: For general application flow or important events.
• WARNING: For potential issues that need attention but don’t stop the program.
• ERROR: For serious problems that may prevent part of the program from working.
• CRITICAL: For severe errors that may stop the entire application.

Choose log levels based on the severity of the event.

Q3: How can I log messages to a file instead of the console?

A3: You can log messages to a file using the filename argument in basicConfig():

logging.basicConfig(filename='app.log', level=logging.INFO)
logging.info("This message will be written to the log file.")

This creates or appends messages to app.log instead of printing them to the console.

Q4: Can I log to both a file and the console at the same time?

A4: Yes, you can log to both a file and the console by using multiple handlers. For example, you can use a FileHandler for file logging and a StreamHandler for console output:

import logging

# Create handlers
file_handler = logging.FileHandler('app.log')
console_handler = logging.StreamHandler()

# Set log level
file_handler.setLevel(logging.INFO)
console_handler.setLevel(logging.INFO)

# Create logger and add handlers
logger = logging.getLogger('my_logger')
logger.addHandler(file_handler)
logger.addHandler(console_handler)

logger.info("This will log to both the file and console.")

Q5: What is the exc_info=True argument used for in logging?

A5: The exc_info=True argument is used to log exceptions with their full traceback. This is especially useful for debugging errors that raise exceptions.

Example:

try:
    1 / 0
except ZeroDivisionError:
    logging.error("An error occurred", exc_info=True)

This will log the full traceback of the exception, helping you understand where the error occurred.

Q6: How do I format log messages to include timestamps and log levels?

A6: You can customize the format of log messages using the format parameter in basicConfig().

Example:

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

This adds a timestamp, log level, and the actual message to each log entry.

Q7: What is log file rotation, and why should I use it?

A7: Log file rotation automatically creates new log files when the current file reaches a certain size. This prevents log files from growing indefinitely, which is important in production environments.

You can use RotatingFileHandler to handle log file rotation:

from logging.handlers import RotatingFileHandler
handler = RotatingFileHandler('app.log', maxBytes=1024*1024, backupCount=3)

This rotates the log file when it reaches 1MB and keeps up to 3 backup log files.

Q8: How can I log messages from different parts of my application using multiple loggers?

A8: You can create multiple loggers to handle logging separately for different parts of your application. Each logger can have its own level, handlers, and formatting.

Example:

logger1 = logging.getLogger('module1')
logger2 = logging.getLogger('module2')

logger1.info("Logging from module 1")
logger2.warning("Logging from module 2")

Q9: What happens if I try to log a message with a level lower than the configured level?

A9: If a log message’s level is lower than the configured log level, it will be ignored. For example, if the log level is set to INFO, all DEBUG messages will be skipped.

Q10: How can I change the logging level dynamically?

A10: You can change the logging level at any point in your script by using setLevel() on the logger or handler.

Example:

logger = logging.getLogger()
logger.setLevel(logging.DEBUG)  # Change the log level to DEBUG at runtime

This allows you to switch between different logging levels (e.g., for debugging and production).

Q11: Can I disable logging messages below a certain severity level?

A11: Yes, you can control the log level using setLevel() to filter out messages below a certain severity. For example, to disable all logging messages below WARNING, set the level to WARNING:

logging.getLogger().setLevel(logging.WARNING)

This ensures that only WARNING, ERROR, and CRITICAL messages are logged.

Q12: How can I include the module name in log messages?

A12: You can include the module name in log messages by adding %(module)s to the format string:

logging.basicConfig(format='%(asctime)s - %(module)s - %(levelname)s - %(message)s')

This will add the name of the module from which the log message originated.

Q13: What is the root logger, and when should I use custom loggers?

A13: The root logger is the default logger created when you use logging.basicConfig(). It is suitable for simple scripts. However, in larger applications, it’s better to create custom loggers for different parts of the application for more granular control over logging behavior.

Q14: Can I log to different files depending on the log level?

A14: Yes, you can log messages to different files based on their severity by setting up different handlers for each level.

Example:

error_handler = logging.FileHandler('error.log')
error_handler.setLevel(logging.ERROR)

info_handler = logging.FileHandler('info.log')
info_handler.setLevel(logging.INFO)

logger = logging.getLogger('my_logger')
logger.addHandler(error_handler)
logger.addHandler(info_handler)

This logs INFO messages to info.log and ERROR messages to error.log.

Q15: How do I programmatically configure logging using a configuration dictionary?

A15: You can use logging.config.dictConfig() to configure logging with a dictionary, allowing for more advanced setups like multiple loggers, handlers, and formatters.

Example:

import logging.config

LOGGING_CONFIG = {
    'version': 1,
    'handlers': {
        'file': {
            'class': 'logging.FileHandler',
            'filename': 'app.log',
            'level': 'DEBUG',
            'formatter': 'default'
        }
    },
    'formatters': {
        'default': {
            'format': '%(asctime)s - %(name)s - %(levelname)s - %(message)s'
        }
    },
    'root': {
        'handlers': ['file'],
        'level': 'DEBUG'
    }
}

logging.config.dictConfig(LOGGING_CONFIG)