Skip to Content
Course content

152: Log Handlers, Formatters, and Levels

Click on the "Edit" button in the top corner of the screen to edit your slide content.

I've seen this exact scenario play out in countless code reviews. A developer wants to log general information to the console but keep a detailed "paper trail" of debug data in a file. They try to use logging.basicConfig() twice, and then they spend an hour wondering why their log file is empty and their console is ignoring debug messages.

import logging

# I want general info in the console
logging.basicConfig(level=logging.INFO)
logging.info("Application started successfully")

# Now I want detailed debug info to go to a file
logging.basicConfig(filename='debug.log', level=logging.DEBUG)
logging.debug("Connecting to database at 192.168.1.5...")

print("Done!")

If you run this, you'll see "Application started successfully" in your terminal, but you won't see the debug message anywhere—not in the terminal, and not in a file. The debug.log file won't even be created.

The basicConfig Single-Shot Limitation

Here is the kicker: logging.basicConfig() only works the first time it is called in a session. If the root logger already has handlers configured, basicConfig simply does nothing. It doesn't update the settings; it just exits silently.

In the code above, the first call set the level to INFO and attached a default StreamHandler (the console). When the second call attempted to switch to a file and DEBUG level, Python essentially said, "I'm already configured, I'll pass," and ignored the request entirely. Because the root level remained at INFO, the logging.debug() call was filtered out before it ever had a chance to be processed.

Routing Traffic with Handlers

To actually send logs to multiple places with different rules, we need to stop relying on the "magic" of basicConfig and start using Handlers. Think of a Logger as the manager and Handlers as the delivery drivers. The manager decides if a message is important enough to be sent, and the drivers decide where it goes.

import logging

# Create a custom logger
logger = logging.getLogger('app_logger')
logger.setLevel(logging.DEBUG) # Set the lowest level we care about globally

# Create a console handler for general info
console_handler = logging.StreamHandler()
console_handler.setLevel(logging.INFO)

# Create a file handler for deep debugging
file_handler = logging.FileHandler('app_debug.log')
file_handler.setLevel(logging.DEBUG)

# Add the handlers to the logger
logger.addHandler(console_handler)
logger.addHandler(file_handler)

logger.info("Application started") # Goes to both
logger.debug("Detailed DB connection string: admin:password123@localhost") # Only goes to file

Now we have a hierarchy. The logger itself is set to DEBUG, so it allows everything through. Then, the console_handler filters out anything below INFO, while the file_handler lets everything in. This is how you keep your terminal clean without losing the data you need for post-mortem debugging.

Adding Professionalism with Formatters

By default, logs are just raw strings. That's useless when you're looking at a file with 10,000 lines and trying to figure out when an error happened or which module triggered it. This is where Formatters come in.

I usually recommend different formats for different destinations. Your console logs should be concise; your file logs should be exhaustive.

# Create formatters
console_fmt = logging.Formatter('%(levelname)s: %(message)s')
file_fmt = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')

# Attach formatters to handlers
console_handler.setFormatter(console_fmt)
file_handler.setFormatter(file_fmt)


Now, your console will simply show INFO: Application started, but your file will contain a timestamped, traceable entry: 2023-10-27 14:05:01,123 - app_logger - INFO - Application started. This makes a world of difference when you're trying to correlate a crash with a specific server timestamp.

The Hierarchy of Log Levels

Just as a refresher on the levels we've used: DEBUG < INFO < WARNING < ERROR < CRITICAL. If you set a handler to WARNING, it will capture WARNING, ERROR, and CRITICAL, but it will ignore INFO and DEBUG. Always set your main logger to the lowest level you might possibly need; you can always tighten the restrictions at the handler level, but you can't "recover" a log message that the main logger already discarded.




📋 Practical Task

Exercise: The Dual-Channel System Monitor

You are building a system monitor that tracks server health. You need to implement a logging system that meets the following strict requirements:

  • Console Output: Should only display messages of level WARNING and above. The format should be: [ALERT] message.
  • File Output (system_health.log): Should capture everything from DEBUG level and above. The format should include the timestamp, the log level, and the message.
  • The Scenario: Your code must trigger one DEBUG message (e.g., "Checking CPU temperature..."), one INFO message (e.g., "CPU temperature is 45C"), and one WARNING message (e.g., "CPU temperature exceeding 80C!").

Goal: Write the script such that when executed, the console shows only the warning, but the system_health.log file contains all three messages with their respective timestamps.

Rating
0 0

There are no comments for now.

to be the first to leave a comment.