Configuring Python Logging with Timestamps, Severity, and Context

Why Logging is Better Than Printing

When an automation script runs, it's helpful to know what it's doing. You could use print() statements, but this has several drawbacks:

• No Severity: A print() statement doesn't distinguish between a routine status update ("Starting process...") and a critical failure ("Database connection failed!").
• No Context: A printed message is just text. It doesn't automatically include when the event happened or where in the code it originated.
• All or Nothing: You can't easily turn off certain types of messages (like detailed debugging info) in a production environment without commenting out code.
• No Standard Destination: Messages are just sent to the console, which is lost as soon as the window is closed.

The logging module solves all of these problems by providing a flexible framework for emitting and capturing event messages.

The Five Levels of Logging

The logging module categorizes messages into five standard levels of severity. Understanding these levels is key to creating meaningful logs.

By default, Python's logging is configured to only show messages of WARNING level and above. This is why, in a fresh script, logging.info() will produce no output, but logging.warning() will.

Basic Configuration for Simple Scripts

For many automation scripts, a simple, global logging configuration is all you need. This is done with a single function call: logging.basicConfig(). Crucially, you can only call this once, and it must be done before any logging functions are called.

basicConfig() allows you to set up the most common logging options, such as the minimum severity level to record, the output file, and the message format.

The following tutorial from Real Python provides excellent, practical examples of how to get started.

Let's combine these concepts into a single example. Imagine a script that processes a file. We want to log its progress to a file named automation.log.

import logging
from pathlib import Path

# --- Configuration (do this once at the start of your script) ---
LOG_FILE = Path("automation.log")
logging.basicConfig(
    level=logging.INFO, # Record INFO and higher level messages
    filename=LOG_FILE,
    filemode="w", # Overwrite the log file each time
    encoding="utf-8",
    format="%(asctime)s - %(levelname)s - %(message)s",
    datefmt="%Y-%m-%d %H:%M:%S"
)

# --- Script Logic ---
logging.info("Automation script started.")
logging.debug("This is a debug message and will NOT be logged because our level is INFO.")

input_file = Path("data.csv")
logging.info(f"Processing input file: {input_file}")

# ... script does some work ...

logging.warning("Encountered a minor issue: A data row was skipped.")

logging.info("Processing complete.")
logging.info("Automation script finished.")

If you run this code, it won't print anything to the console. Instead, it will create (or overwrite) a file named automation.log with the following content:

2023-10-27 10:30:00 - INFO - Automation script started.
2023-10-27 10:30:00 - INFO - Processing input file: data.csv
2023-10-27 10:30:00 - WARNING - Encountered a minor issue: A data row was skipped.
2023-10-27 10:30:00 - INFO - Processing complete.
2023-10-27 10:30:00 - INFO - Automation script finished.

Notice how each message is neatly formatted with a timestamp and severity level, providing a clear audit trail.

Recording Essential Diagnostic Context

The true power of logging shines when things go wrong. In the last lesson, you learned to catch exceptions. Now, let's log them properly to capture the full context of the error.

You can include the full exception traceback in your log message in two ways:

1. Call a logging function (like logging.error) with the argument exc_info=True.
2. Use the special function logging.exception(), which can only be called from within an except block. It automatically logs the message at the ERROR level and includes the exception info.

Let's refactor the read_workflow_state function from our previous lesson. Instead of printing warnings to the console, we'll log them.

import json
import logging
from pathlib import Path
from datetime import datetime

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

STATE_FILE = Path("workflow_state.json")

def read_workflow_state(state_path: Path) -> datetime | None:
    """Safely reads the last run time from the state file, logging any issues."""
    try:
        state_text = state_path.read_text(encoding="utf-8")
        state_data = json.loads(state_text)
        last_run_str = state_data["last_successful_run"]
        last_run_time = datetime.fromisoformat(last_run_str)
    
    except FileNotFoundError:
        # This is expected on the first run, so it's just an INFO message.
        logging.info("State file not found. Assuming this is the first run.")
        return None
        
    except (json.JSONDecodeError, KeyError) as e:
        # This is a recoverable problem, but we should log it as a warning
        # with the full exception details for debugging.
        logging.warning(
            f"Could not read state file due to a data error. Starting fresh.",
            exc_info=True
        )
        # Using logging.exception() would achieve the same result here:
        # logging.exception("Could not read state file...")
        return None
        
    else:
        logging.info(f"Successfully loaded state. Last run was at: {last_run_time}")
        return last_run_time

# --- Main script logic ---
last_run = read_workflow_state(STATE_FILE)

if last_run:
    logging.info(f"Performing tasks since {last_run}.")
else:
    logging.info("Performing a full run.")

Try running this script after creating a workflow_state.json file with invalid content (e.g., {"key": "value} without the required last_successful_run key). You'll see a detailed traceback in your log, pinpointing the exact cause of the error, without crashing the script.

A More Flexible Approach: Custom Loggers

basicConfig is great for simple, single-file scripts. However, as your projects grow, you'll want more control. For example, you might want to:

• Log INFO messages to the console but only WARNING and above to a file.
• Have different log formats for different destinations.
• Organize logs by the part of the application they come from.

This is achieved using a more modular system of Loggers, Handlers, and Formatters.

• Logger: The object your application code interacts with (logger.info(...)). You can create multiple loggers (e.g., one per module).
• Handler: Determines where the log messages are sent (e.g., to the console, a file, over the network). A logger can have multiple handlers.
• Formatter: Defines the layout of the log message (%(asctime)s - %(message)s). A handler has one formatter.

This video from Tech With Tim provides a great visual walkthrough of setting up this more advanced configuration.

Here is a code example demonstrating this professional pattern. This setup achieves the same result as our first basicConfig example but is far more extensible.

import logging
from pathlib import Path

# 1. Create a custom logger
# Using __name__ is a convention that names the logger after the module.
logger = logging.getLogger(__name__)
logger.setLevel(logging.INFO) # Set the lowest level this logger will handle.

# 2. Create a handler
# This handler will write messages to a file.
LOG_FILE = Path("automation_custom.log")
file_handler = logging.FileHandler(LOG_FILE, mode="w", encoding="utf-8")

# 3. Create a formatter
# Define the format of the log messages.
formatter = logging.Formatter(
    fmt="%(asctime)s - %(name)s - %(levelname)s - %(message)s",
    datefmt="%Y-%m-%d %H:%M:%S"
)

# 4. Connect the pieces
file_handler.setFormatter(formatter) # Apply the formatter to the handler.
logger.addHandler(file_handler)     # Add the configured handler to the logger.

# --- Now, use the logger in your application code ---
logger.info("This log comes from our custom logger.")
logger.warning("This is a custom warning.")

This might seem like more work, but it gives you complete control over your application's logging behavior, a crucial feature for complex automation projects.

Conclusion

In this lesson, you've learned how to transform your script's output from simple print statements into a structured, informative, and persistent log.

Here are the key takeaways:

• Logging provides essential context (timestamps, severity) and control (levels, destinations) that print() lacks.
• There are five standard logging levels: DEBUG, INFO, WARNING, ERROR, and CRITICAL.
• For simple scripts, logging.basicConfig() is a quick way to configure logging to a file with a specific format and level.
• You can capture full exception details by using logging.exception() or exc_info=True inside an except block.
• For professional applications, the Logger, Handler, and Formatter model provides a flexible and powerful way to manage complex logging requirements.

We've configured our logging directly in the script, but what if you want to change the log level from INFO to DEBUG for troubleshooting, without editing your Python code? In the next lesson, we will explore how to load non-secret settings from a configuration file, making your automations even more flexible and easier to manage.