Transform Your Python Projects with Robust Logging Techniques - Part I

Logging is a crucial skill for any Python developer, aiding in debugging, performance monitoring, and fault diagnosis. Here we will delve deep into Python logging, covering it from basic to advanced levels, and including practical examples to solidify your understanding.

🕒 Estimated reading time: 10 minutes

Logging is the practice of recording information about a program's execution. This can include details such as errors, informational messages, warnings, and debug information. Python provides a built-in logging module that developers can use to implement logging within their applications.

Why is Logging Important?

  • Debugging: Logging enables you to understand the flow of your application and helps you identify where things might be going wrong. It's much easier to trace issues when you have a record of what the application was doing at various points in time.

  • Monitoring: Logs can be used to monitor the health of an application in real time or by reviewing logs at a later time. They can provide insights into performance bottlenecks, resource usage, and other operational aspects.

  • Audit and Compliance: Many industries have regulatory requirements that necessitate keeping logs for compliance purposes. Logging is an essential part of maintaining an audit trail, which can be critical for security audits and compliance reviews.

  • User Support: Detailed logs can provide invaluable information for customer support teams when users report issues. Knowing what the system was doing when an error occurred can help rapidly pinpoint and resolve issues.

  • Persistence: Unlike print statements which are transient and only visible in the console, logs can be saved to files, databases, or other storage mediums for long-term analysis and inspection.

Now, let's dive into the world of Logging in Python with some practical examples that are also available on Google Colab here 👨‍🔬.

Setting Up Basic Logging

Python’s built-in logging library makes it easy to set up logging. Here’s how to get started:

import logging

# Configure the logging system
# Sets the threshold for the logger to the DEBUG level
# This means all the logging messages at this level and above will be shown
logging.basicConfig(level=logging.DEBUG)

# Below are different levels of logging messages in increasing order of severity.

# DEBUG: Detailed information, typically of interest only when diagnosing problems.
logging.debug("This is a debug message")

# INFO: Confirmation that things are working as expected.
logging.info("This is an info message")

# WARNING: An indication that something unexpected happened, or indicative of some problem in the near future
# (e.g., ‘disk space low’). The software is still working as expected.
logging.warning("This is a warning message")

# ERROR: Due to a more serious problem, the software has not been able to perform some function.
logging.error("This is an error message")

# CRITICAL: A very serious error, indicating that the program itself may be unable to continue running.
logging.critical("This is a critical message")

Practical Example: Simple Script Logging

Let's write a basic script that demonstrates logging:

import logging  # Import the logging module to enable logging of events, errors, and informational messages.

def divide(a, b):
    """Function to divide two numbers.

    Args:
    a (float): The numerator.
    b (float): The denominator.

    Returns:
    float: The result of the division if successful, otherwise None.
    """
    logging.info(f"Dividing {a} by {b}")  # Log an info message indicating the operation being performed.
    
    if b == 0:  # Check if the denominator is zero to avoid division by zero error.
        logging.error("Division by zero attempted")  # Log an error message if division by zero is attempted.
        return None  # Return None to indicate the operation failed.
    
    return a / b  # Perform the division and return the result.

if __name__ == "__main__":
    # Configure the logging to display messages of level DEBUG and above
    logging.basicConfig(level=logging.DEBUG)
    
    # Test the divide function with valid input
    result = divide(10, 2)
    print(f"Result: {result}")  # Output the result of the division

    # Test the divide function with division by zero
    result = divide(10, 0)
    print(f"Result: {result}")  # Output the result, which should be None because of division by zero

Configuring Loggers, Handlers, and Formatters

Python logging has several levels (DEBUG, INFO, WARNING, ERROR, CRITICAL). By default, logging captures WARNING and above levels unless configured otherwise.

  • A logger is an entry point for logging;

  • Handlers send log messages to configured destinations like files or consoles;

  • Formatters define the layout of the log messages.

import logging

# Create a logger object with the name 'example_logger'
logger = logging.getLogger('example_logger')
# Set the logging level to DEBUG. This means that all messages with the level DEBUG and above will be logged
logger.setLevel(logging.DEBUG)

# Create a handler that will print log messages to the console (standard output)
console_handler = logging.StreamHandler()
# Create a handler that will write log messages to a file named 'example.log'
file_handler = logging.FileHandler('example.log')

# Define a formatter that specifies the format of the log messages
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
# Set the formatter for the console handler
console_handler.setFormatter(formatter)
# Set the formatter for the file handler
file_handler.setFormatter(formatter)

# Add the console handler to the logger. This means that log messages will be output to the console
logger.addHandler(console_handler)
# Add the file handler to the logger. This means that log messages will be written to the 'example.log' file
logger.addHandler(file_handler)

# Log an informational message with the logger
logger.info('This is an informational message')

Running the above script will produce the following logs, both in the console and in the file example.log.

2024-06-06 08:12:05,389 - example_logger.log - INFO - This is an informational message

⚠️ On Google Colab, if you want to check out the file contents, select the folder icon named 'Files' on the left sidebar.

Rotating Log Files

Rotating log files is essential for maintaining an efficient and manageable logging system in any application. As an application runs, its log files can grow indefinitely, leading to increased disk usage and potentially causing performance issues or running out of disk space.

By rotating log files, you limit the size and number of log files retained, ensuring that you only keep the most recent and relevant logs for troubleshooting and monitoring purposes. Log rotation also improves the readability of logs by preventing any single log file from becoming excessively large and unwieldy. Additionally, it enhances security by ensuring sensitive information doesn't remain accessible indefinitely.

import logging  # Import the logging module to handle logging
from logging.handlers import RotatingFileHandler  # Import the RotatingFileHandler to create a rotating log system

# Create a logger object named 'rotating_logger'
logger = logging.getLogger('rotating_logger')
# Set the logging level to DEBUG so that all levels (DEBUG, INFO, WARNING, ERROR, and CRITICAL) will be logged
logger.setLevel(logging.DEBUG)

# Create a rotating file handler that will write to 'rotating_log.log'
# maxBytes=2000 means each log file can contain up to 2000 bytes
# backupCount=5 means the handler will keep up to 5 backup log files before overwriting the oldest one
rotating_handler = RotatingFileHandler('rotating_log.log', maxBytes=2000, backupCount=5)

# Define a format for the log messages
# The format includes the timestamp, logger's name, log level, and message
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
# Apply the formatter to the rotating handler
rotating_handler.setFormatter(formatter)

# Add the rotating handler to the logger so it knows how to handle the logging
logger.addHandler(rotating_handler)

# Generate 100 debug log messages
for i in range(100):
    # Each debug message will contain the loop index
    logger.debug(f"Debug message {i}")

Project in Action: From Theory to Practice

To consolidate your understanding, let’s create a project where we combine the concepts. Let’s suppose we are building a simple web scraper that extracts data from a website. We want to log various events such as starting the scraper, errors encountered, and successful data extraction. Here's a step-by-step example:

Step 1: Setting Up Logging Configuration

import logging

# Create a logger object with the name 'web_scraper_logger'
web_scraper_logger = logging.getLogger('web_scraper')

# Set the logging level to DEBUG. This means that all messages with the level DEBUG and above will be logged
web_scraper_logger.setLevel(logging.DEBUG)

# Create handlers that will print log messages to the console (standard output) write log messages to a file named 'web_scraper.log'
console_handler = logging.StreamHandler()
file_handler = logging.FileHandler('web_scraper.log')

# Define a formatter that specifies the format of the log messages
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')

# Set the formatter for the console handler and for the file handler
console_handler.setFormatter(formatter)
file_handler.setFormatter(formatter)

# Add the console handler to the logger. This means that log messages will be output to the console
web_scraper_logger.addHandler(console_handler)
# Add the file handler to the logger. This means that log messages will be written to the 'example.log' file
web_scraper_logger.addHandler(file_handler)

Step 2: Creating a Web Scraping Function

For the sake of simplicity, let's create a basic web scraper that uses requests and BeautifulSoup to fetch the title of a webpage.

import requests # Import the requests library to make HTTP requests
from bs4 import BeautifulSoup # Import the BeautifulSoup class from the bs4 library to parse HTML content 

def fetch_title(url):
    """
    Function to fetch the title of a webpage given its URL.
    
    Args:
        url (str): The URL of the webpage to scrape.

    Returns:
        str or None: The title of the webpage, or None if an error occurs.
    """
    
    # Log the start of the web scraping process
    web_scraper_logger.info(f"Starting to scrape the URL: {url}")
    
    try:
        # Send a GET request to the specified URL
        response = requests.get(url)
        
        # Raise an HTTPError exception for response codes 4xx or 5xx
        response.raise_for_status()
    except requests.RequestException as e:
        # Log the error if the HTTP request fails
        web_scraper_logger.error(f"HTTP Request failed: {e}")
        return None

    try:
        # Parse the HTML content of the response using BeautifulSoup
        soup = BeautifulSoup(response.content, 'html.parser')
        
        # Extract the content of the <title> tag
        title = soup.title.string
        
        # Log a message indicating successful extraction of the title
        web_scraper_logger.info(f"Successfully fetched the title: {title}")
        return title
    except Exception as e:
        # Log any errors that occur during HTML parsing or title extraction
        web_scraper_logger.error(f"Failed to parse HTML or extract title: {e}")
        return None

Step 3: Using Logging Within the Function

Now let's test our web scraper and see the logging in action.

if __name__ == '__main__':
    urls = [
        'https://www.python.org',
        'https://www.example.com',
        'https://nonexistent.url'  # A URL that will cause a failed request
    ]

    for url in urls:
        title = fetch_title(url)
        if title:
            web_scraper_logger.debug(f"Scraped title for {url}: {title}")
        else:
            web_scraper_logger.warning(f"No title found for {url}")

Running the above script will produce the following logs, both in the console and in the file web_scraper.log.

2024-06-06 08:56:18,084 - web_scraper - INFO - Starting to scrape the URL: https://www.python.org
2024-06-06 08:56:18,341 - web_scraper - INFO - Successfully fetched the title: Welcome to Python.org
2024-06-06 08:56:18,349 - web_scraper - DEBUG - Scraped title for https://www.python.org: Welcome to Python.org
2024-06-06 08:56:18,357 - web_scraper - INFO - Starting to scrape the URL: https://www.example.com
2024-06-06 08:56:18,506 - web_scraper - INFO - Successfully fetched the title: Example Domain
2024-06-06 08:56:18,515 - web_scraper - DEBUG - Scraped title for https://www.example.com: Example Domain
2024-06-06 08:56:18,521 - web_scraper - INFO - Starting to scrape the URL: https://nonexistent.url
2024-06-06 08:56:18,584 - web_scraper - ERROR - HTTP Request failed: HTTPSConnectionPool(host='nonexistent.url', port=443): Max retries exceeded with url: / (Caused by NameResolutionError("<urllib3.connection.HTTPSConnection object at 0x7b5c7a73ab30>: Failed to resolve 'nonexistent.url' ([Errno -2] Name or service not known)"))
2024-06-06 08:56:18,588 - web_scraper - WARNING - No title found for https://nonexistent.url

Conclusion

We've covered the spectrum of Python logging — from the basics of setting up logging to more advanced concepts like rotating log files. With practical examples and a comprehensive project, you now have everything you need to incorporate effective logging into your Python applications, ensuring your code is maintainable, debuggable, and production-ready.

Feel free to reply to this newsletter with any questions or topics you'd like us to cover in the future.

If you liked this newsletter, don't forget to subscribe to receive regular updates. Share with your friends and colleagues interested in Python and let's grow together in our community of programmers!

Remember, the key to mastery is practice and persistence. Happy coding! Until the next edition, keep programming! 👨‍💻

InfinitePy Newsletter - Your source for Python learning and inspiration.