LESSON 42 · DEEPER PYTHON30 min

Replace Debug Prints with Python Logging

Record messages at appropriate levels and filter them into a deterministic in-memory report.

Before you start: Functions · Exceptions · Dictionaries

Example check: Worked and guided code samples are checked against CPython 3.13. Practice uses Pyodide 0.29.5 (Python 3.13) in your browser. How we check lessons

WATCH

Video lesson: Replace Debug Prints with Python Logging

The preview is stored on this site. YouTube loads only when you press Play. Watch on YouTube

Jump to a chapter

Read the video transcript

Select a timestamp to watch that moment on YouTube.

00:00
Printing is perfect when a program needs to show a result to its user. Diagnostic notes have a different job: they should tell us what happened while the program ran, often with enough detail to investigate a failure. Python's logging module gives those notes levels and destinations. A DEBUG message can help a developer trace a loop, an INFO message can record a normal milestone, and an ERROR message can record a failed operation. The logger decides which levels are eligible. A handler decides where eligible records go. A formatter decides how they look. That is three separate controls, and many beginner surprises come from changing one while forgetting another.
00:44
In this video we will deliberately lose an INFO message, inspect the level that filtered it, and then build a deterministic in-memory event report. We will avoid global logging configuration so our output is stable inside the browser console and the checked exercise. We will also run the function twice to catch accidental duplicate handlers. The companion PythonLessonLab lesson includes worked examples, the code console, a practical checker, common mistakes, and a quiz. Before writing the final function, remember that logging is not an exception-handling strategy by itself. Recording that a save failed does not repair the save or automatically tell the caller what to do next.
01:29
We still need clear program behavior. We called logger.info, but started did not appear. The method call ran; the logger simply discarded that record because INFO is below its configured WARNING threshold. The WARNING record met the threshold and reached the handler. That is why changing the handler's destination alone would not reveal the missing INFO record. The logger never passed it along. To see normal milestones as well as warnings, set the logger's threshold to INFO or lower. This filtering is valuable in real services because we can reduce diagnostic noise without deleting logging calls from source code.
02:11
During a focused debugging session we may allow DEBUG. In production we may keep INFO or WARNING, depending on what the operations team needs. Do not interpret the default output of a quick script as proof that all levels are enabled. Global configuration and parent loggers can affect what appears. Our lesson creates an isolated Logger object and an in-memory StringIO destination so another lesson or library cannot quietly change the result. Notice that `stream.getvalue()` reads text written by the handler, not by print. We print the captured text only so the demonstration has an observable, exact output.
02:52
The practical exercise uses the same idea and returns a list of captured lines. First, though, we need a formatter so readers can tell which severity produced each line. Now both records are eligible, and the formatter makes their purpose clear. `%(levelname)s` becomes INFO or ERROR. `%(message)s` becomes the finished message. Logging accepts the format string and its arguments separately, as in `logger.info('Loaded %s rows', 3)`. That lets the logging machinery perform interpolation only when it needs to emit the record. Avoid building expensive f-strings for debug-only messages if that work would happen even when DEBUG is filtered.
03:37
The StringIO buffer is an in-memory stand-in for a file or console stream. It gives the lesson a stable output with no timestamp that changes between runs. In a real application a timestamp and request identifier might be useful, but they would make this exact-output exercise noisy. Also avoid writing passwords, access tokens, or unnecessary personal details into log messages. Logs are often copied, stored, and viewed by more people than the live program output. A message such as authentication request failed can be useful without dumping the secret that was used.
04:17
We have separated the three pieces: logger level for eligibility, handler for destination, formatter for presentation. The next step is to wrap that setup in a function that processes events and cleans up its handler reliably. Every call creates its own StringIO buffer, Logger, and handler. The logger's threshold comes from the trusted minimum level name, and each event's level name is converted to logging's standard numeric level. The `logger.log` call emits the message as a string argument, and the formatter adds the visible level. DEBUG is below INFO, so it disappears. INFO and ERROR remain in the original input order.
04:59
The function returns a list of lines rather than printing diagnostics itself. That makes it easy to test and easy for another part of a program to display or save the report. Cleanup in `finally` removes and closes the handler even if logging an event raises an error. With a fresh standalone Logger, this is mainly disciplined ownership; with a shared named logger, failing to remove old handlers can cause the same event to appear multiple times on later calls. We intentionally assume that event levels are one of DEBUG, INFO, WARNING, or ERROR. If levels came from untrusted user input, validate them before using getattr.
05:41
An unknown name would otherwise raise AttributeError. The point here is not to write a production logging framework in a dozen lines. It is to understand what the module already provides and avoid a pile of debug prints mixed with the program's real output. The first assertion checks that WARNING filters out DEBUG and INFO while keeping the two more severe records in order. The second lowers the threshold to DEBUG and sees all four. Empty input returns an empty list. The last two calls prove that an earlier message does not leak into a later report and that a handler did not get duplicated. These are practical checks, not merely copies of the implementation: a function that always returns a fixed list would fail as soon as the event values or threshold change.
06:31
Open the matching lesson page and complete the loop in the starter code. The surrounding logger, handler, formatter, and cleanup are already prepared so you can focus on emitting each input event at its level. Run the task checker, then use the quiz to test whether you can explain the three roles without looking at the code. When a real log message is missing, trace the path in the same order we used: was the record created, was it eligible at the logger, did a handler receive it, and how did the formatter render it? If the program writes duplicate lines, inspect how often handlers are added and removed. That reasoning scales from a small browser exercise to a real Python service.
07:15
Keep logs helpful, specific, and free of secrets, and keep user-facing program results separate from diagnostic records.

THE IDEA

Understand the concept

print is useful for a quick result, but diagnostic messages need a level and a destination. The logging module gives standard levels such as DEBUG, INFO, WARNING, ERROR, and CRITICAL. A logger decides which records are eligible; a handler sends records to a stream, file, or another destination. A formatter decides how each record looks. A printed result belongs to the program's user; a log record explains what the program did or why it failed.

The default logging configuration can surprise learners because WARNING and above are typically visible while INFO may be filtered. Set the level deliberately. For a reproducible browser exercise, create an isolated Logger and attach a StreamHandler to a StringIO buffer instead of relying on global basicConfig or stderr. A formatter using %(levelname)s and %(message)s makes expected output stable across runs.

Logging methods can defer formatting: logger.info('Loaded %s rows', count) lets logging interpolate the argument only if it emits the record. Avoid putting passwords, tokens, or personal data into logs. Do not catch an exception merely to log and silently continue when the caller needs to know that an operation failed. Logging describes an error; it does not resolve it.

The checked task receives pairs of level and text and returns formatted lines at or above a chosen minimum level. Use a fresh in-memory stream and Logger for every call, so independent calls do not accumulate duplicate handlers or old messages. The example has DEBUG, INFO, and ERROR events and filters out DEBUG. Tests check filtering, ordering, empty input, and repeated calls.

Logging levels control eligibility
Handlers choose where records go
Formatters choose record text
A fresh isolated logger avoids duplicate handlers in repeated tests

WORKED EXAMPLES

See it step by step

Read the code, predict the output, then compare it with the result.

01. Filter a message by level

PYTHON

import logging
from io import StringIO

stream = StringIO()
logger = logging.Logger("demo")
logger.setLevel(logging.WARNING)
logger.addHandler(logging.StreamHandler(stream))
logger.info("not shown")
logger.warning("check disk")
print(stream.getvalue().strip())

EXPECTED OUTPUT

check disk

The logger rejects INFO below its WARNING threshold before the handler writes anything.

02. Format level and message explicitly

PYTHON

import logging
from io import StringIO

stream = StringIO()
logger = logging.Logger("report")
logger.setLevel(logging.INFO)
handler = logging.StreamHandler(stream)
handler.setFormatter(logging.Formatter("%(levelname)s: %(message)s"))
logger.addHandler(handler)
logger.info("Loaded %s rows", 3)
print(stream.getvalue().strip())

EXPECTED OUTPUT

INFO: Loaded 3 rows

The formatter chooses the visible fields, and logging interpolates the row count.

03. Keep separate calls independent

PYTHON

import logging
from io import StringIO

def one_record(text):
    stream = StringIO()
    logger = logging.Logger("fresh")
    logger.setLevel(logging.INFO)
    logger.addHandler(logging.StreamHandler(stream))
    logger.info("%s", text)
    return stream.getvalue().strip()

print(one_record("first"))
print(one_record("second"))

EXPECTED OUTPUT

first
second

Each call creates a distinct logger and stream, so old handlers do not duplicate later records.

GO DEEPER

A closer look

Follow the reasoning, inspect each result, then try the suggested changes in the console below.

01 / 03

See where an INFO record went

A missing log message often means it was filtered, not that the logging call failed. A logger has a minimum level. If it is WARNING, INFO records are below the threshold and never reach its handlers. The example attaches a handler to an in-memory stream so the output is visible and deterministic. It deliberately emits one filtered INFO record and one WARNING record.

This behavior is useful in a real application: a deployed service can keep warnings and errors visible while suppressing routine debug traffic. During local diagnosis you might lower the threshold. Set it deliberately rather than relying on whichever global logging configuration happened to run first. The lesson's checked task passes a minimum level and expects you to preserve the chosen filter.

PYTHON

import logging
from io import StringIO

stream = StringIO()
logger = logging.Logger("levels-demo")
logger.setLevel(logging.WARNING)
logger.addHandler(logging.StreamHandler(stream))
logger.info("started")
logger.warning("disk almost full")
print(stream.getvalue().strip())

EXPECTED OUTPUT

disk almost full

Follow the reasoning

INFO is below the WARNING threshold and is dropped.
WARNING meets the threshold and reaches StreamHandler.
The stream keeps the demonstration separate from the console's stderr.

02 / 03

Give each record a stable readable format

A handler chooses the destination; a formatter chooses the text. Logging records contain fields such as levelname and message. This example asks for `LEVEL: message`, making the output predictable and easy to compare in a test. The call `logger.info('Loaded %s rows', 3)` passes the format string and argument separately; logging combines them when the record is emitted.

In a larger program you might add a timestamp, module, or request ID. Do not add fields that make a beginner's exercise nondeterministic or expose secrets. A timestamp would change every run and would be a poor value for an exact-output check. The checked task uses a fresh StringIO and a fresh Logger on every call so old handlers cannot double the next line.

PYTHON

import logging
from io import StringIO

stream = StringIO()
logger = logging.Logger("formatted-demo")
logger.setLevel(logging.INFO)
handler = logging.StreamHandler(stream)
handler.setFormatter(logging.Formatter("%(levelname)s: %(message)s"))
logger.addHandler(handler)
logger.info("Loaded %s rows", 3)
logger.error("Could not save %s", "report.csv")
print(stream.getvalue().strip())

EXPECTED OUTPUT

INFO: Loaded 3 rows
ERROR: Could not save report.csv

Follow the reasoning

Logger eligibility is INFO and above.
The formatter includes the level and final interpolated message.
StringIO captures both records without depending on global configuration.

03 / 03

Filter an event report and clean up the handler

An event report takes an input sequence of level-message pairs. The logging module already knows the numerical order of standard levels. `getattr(logging, level)` turns a trusted uppercase level name such as WARNING into the corresponding level value. The exercise's input contract limits names to the listed standard levels. For untrusted data, validate the name before getattr so an unknown label produces a controlled error.

After logging, remove and close the handler. That cleanup matters more with a shared logger; here it also models good resource ownership. The stream's text can then be split into lines for a tidy return value. Try running the function twice with different events. You should get only the current call's lines, not a duplicate from an earlier handler. Keep the input order; logging does not sort events for you.

PYTHON

import logging
from io import StringIO

def format_events(events, minimum):
    stream = StringIO()
    logger = logging.Logger("one-report")
    logger.setLevel(getattr(logging, minimum))
    handler = logging.StreamHandler(stream)
    handler.setFormatter(logging.Formatter("%(levelname)s: %(message)s"))
    logger.addHandler(handler)
    try:
        for level, message in events:
            logger.log(getattr(logging, level), "%s", message)
    finally:
        logger.removeHandler(handler)
        handler.close()
    return stream.getvalue().splitlines()

print(format_events([("INFO", "start"), ("ERROR", "failed")], "WARNING"))
print(format_events([("INFO", "retry")], "INFO"))

EXPECTED OUTPUT

['ERROR: failed']
['INFO: retry']

Follow the reasoning

The logger's minimum filters out start in the first call.
The formatted ERROR remains in the captured stream.
A fresh second call yields only its own INFO line.

HANDS-ON

Try it in Python

Edit the example and run it. Python starts in your browser the first time you click Run.

Python console

Ready to run

import logging
from io import StringIO

def format_events(events, minimum):
    stream = StringIO()
    logger = logging.Logger("pythonlessonlab.exercise")
    logger.setLevel(getattr(logging, minimum))
    handler = logging.StreamHandler(stream)
    handler.setFormatter(logging.Formatter("%(levelname)s: %(message)s"))
    logger.addHandler(handler)
    try:
        # Log each (level, message) pair with logger.log(...).
        pass
    finally:
        logger.removeHandler(handler)
        handler.close()
    return stream.getvalue().splitlines()

events = [("DEBUG", "cache hit"), ("INFO", "started"), ("ERROR", "save failed")]
print(format_events(events, "INFO"))

Need input()? Add one value per line

Input lines

Ctrl / ⌘ + Enter to run

OUTPUT

Your output appears here.

Your turnComplete format_events(events, minimum). Each event is a (level, message) pair and each level is DEBUG, INFO, WARNING, or ERROR. Use logger.log(getattr(logging, level), '%s', message) for each pair. Return only lines at or above the chosen minimum, formatted as 'LEVEL: message', in input order. Keep the existing isolated logger and cleanup. The prepared example should print ['INFO: started', 'ERROR: save failed'].

Need a hint?

Replace pass with `for level, message in events:` and an indented `logger.log(getattr(logging, level), '%s', message)`. The logger and formatter already handle filtering and line formatting.

Complete the task and select Check task to verify your code.

DEBUG BETTER

Typical mistakes

Everyone meets these errors. See what causes them and how to fix them.

Expecting INFO to appear under a WARNING threshold

COMMON MISTAKE

logger.setLevel(logging.WARNING)
logger.info('started')

FIX

logger.setLevel(logging.INFO)
logger.info('started')

What happens: The INFO record is filtered out before it reaches a handler.
Choose a threshold at or below the messages you need.

Adding a new handler to a shared logger on every call

COMMON MISTAKE

logger = logging.getLogger('app')
logger.addHandler(logging.StreamHandler(stream))

FIX

logger = logging.Logger('one-call')
logger.addHandler(logging.StreamHandler(stream))

What happens: Repeated setup can make the same event appear multiple times.
Use a fresh logger for a self-contained task or manage and remove shared handlers explicitly.

Logging secrets while debugging

COMMON MISTAKE

logger.info('token=%s', api_token)

FIX

logger.info('Authentication request started')

What happens: The token may be written to logs and retained outside the program.
Log the event and context needed for diagnosis without credentials or personal details.

Browse this lesson’s problem fixes

VERIFY THE STORY

Sources and further reading