Building a Simple and Consistent Log Structure for Python Programs with Log Rotation

Logging is an essential part of any robust Python application. It provides insights into how your program runs, tracks errors, and helps with debugging. In this post, we’ll cover how to create a simple and consistent log structure for your Python programs, ensuring that logs include relevant details like timestamps, filenames, and line numbers.

We’ll also configure a rotating log system so that your application logs are archived daily, keeping your log files manageable.

---

Step 1: Basic Logging Setup Using basicConfig

The foundation of any logging system is configuring the basic structure of your logs. Using Python’s logging module, we can set up a simple and consistent format for our logs, including details like the log level, filename, line number, and message.

Here’s the initial setup:

import logging
import os

# Ensure the ./log directory exists
if not os.path.exists('log'):
    os.makedirs('log')

# Basic configuration for logging
logging.basicConfig(
    level=logging.DEBUG,
    format='%(asctime)s - %(name)s - %(levelname)s - %(filename)s:%(lineno)d - %(message)s',
    handlers=[
        logging.StreamHandler()  # Also log to console
    ]
)

Breakdown:

• Log Format:
  • %(asctime)s: Adds a timestamp.
  • %(name)s: Logger name (typically the module name).
  • %(levelname)s: Log level (e.g., DEBUG, INFO).
  • %(filename)s:%(lineno)d: Includes the filename and line number where the log was generated.
  • %(message)s: The actual log message.

This setup ensures that all log messages follow a consistent format, which makes them easier to read and debug.

---

Step 2: Using Module-Specific Loggers

In larger applications, it’s helpful to use module-specific loggers to distinguish logs from different parts of your program. This is achieved by creating a logger in each module using logging.getLogger(__name__).

Here’s an example of how to configure a logger inside a module:

import logging

# Create a logger specific to this module
logger = logging.getLogger(__name__)

def some_function():
    logger.debug("This is a debug message")
    logger.info("This is an info message")
    logger.warning("This is a warning message")
    logger.error("This is an error message")
    logger.critical("This is a critical message")

By using __name__ as the logger name, the log messages will reflect the specific module they come from, providing better insight into where your application is logging from.

---

Step 3: Adding Log Rotation with TimedRotatingFileHandler

To prevent your log file from growing too large, we’ll add a rotating log system. This setup ensures that logs are rotated every day at midnight, with old logs archived with a date-based suffix. The most common way to implement this is through Python’s TimedRotatingFileHandler.

Complete Example:

import logging
import os
from logging.handlers import TimedRotatingFileHandler

# Ensure the ./log directory exists
if not os.path.exists('log'):
    os.makedirs('log')

# Set up a TimedRotatingFileHandler to rotate logs at midnight
file_handler = TimedRotatingFileHandler(
    "log/application.log", when="midnight", interval=1, backupCount=0
)
file_handler.suffix = "%Y-%m-%d"  # Add a date suffix to the log files
file_handler.setLevel(logging.DEBUG)

# Set up the logging format
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(filename)s:%(lineno)d - %(message)s')
file_handler.setFormatter(formatter)

# Configure the logging system
logging.basicConfig(
    level=logging.DEBUG,
    format='%(asctime)s - %(name)s - %(levelname)s - %(filename)s:%(lineno)d - %(message)s',
    handlers=[
        file_handler,  # Log to rotating file
        logging.StreamHandler()  # Also log to console
    ]
)

# Example logger for the main module
logger = logging.getLogger(__name__)

def main():
    logger.info("Starting the application")
    
    try:
        # Simulate a function call that does some processing
        logger.debug("Running some_function()")
        some_function()
    except Exception as e:
        logger.error(f"An error occurred: {e}")

def some_function():
    logger.info("This function is processing data...")
    # Simulate an error
    raise ValueError("An example error in some_function")

if __name__ == "__main__":
    main()

Breakdown:

• TimedRotatingFileHandler:
  • when="midnight": This rotates the log file every day at midnight.
  • interval=1: Rotates the log file every 1 day.
  • backupCount=0: Never removed old logfiles. If you don’t want to save all old logfiles, use backupCount=7 which keeps the last 7 log files. Older logs are automatically deleted.
  • suffix="%Y-%m-%d": Adds a date suffix to the rotated log files, so you can easily identify which day a log file corresponds to.

By combining TimedRotatingFileHandler with logging.basicConfig(), this approach logs to both the console and a daily rotating log file. Logs will be neatly archived in the ./log directory, with older logs automatically cleaned up.

---

Step 4: Understanding Log Output

The resulting logs will look something like this:

2024-10-04 10:45:15,123 - __main__ - INFO - example.py:26 - Starting the application
2024-10-04 10:45:15,124 - __main__ - DEBUG - example.py:30 - Running some_function()
2024-10-04 10:45:15,125 - __main__ - INFO - example.py:37 - This function is processing data...
2024-10-04 10:45:15,126 - __main__ - ERROR - example.py:34 - An error occurred: An example error in some_function

Conclusion

With this approach, you now have a simple and consistent log structure for your Python programs, with detailed log entries that include timestamps, filenames, and line numbers. By incorporating TimedRotatingFileHandler, your logs will rotate daily at midnight, ensuring they stay manageable and don’t take up too much disk space.

This structure is highly scalable, making it suitable for both small and large Python projects. It ensures logs are neatly organized and easy to analyze, whether for debugging or production monitoring.