Stop Reaching for print(): A Practical Deep Dive into Python's logging Module

Learn how Python's logging module really works — loggers, handlers, formatters, levels, and propagation — plus dictConfig setup, structured JSON logs, rotating files, and the pitfalls that trip up almost everyone.

Stop Reaching for print(): A Practical Deep Dive into Python's logging Module

Every project starts the same way: you sprinkle a few print() calls to see what's happening, ship it, and move on. Then something breaks in production at 2 a.m., and you have no idea what your code was doing when it failed. print() can't tell you when something happened, where it came from, how severe it was, or send it anywhere other than standard output. Python's logging module solves all of this — but it has a reputation for being confusing. This guide unpacks how it actually works and how to configure it without the guesswork.

The mental model: four moving parts

Almost every misunderstanding about logging disappears once you internalize its four core objects and how a message flows through them:

  • Logger — the object you call (logger.info(...)). Loggers are named and arranged in a hierarchy.
  • Handler — decides where a record goes: the console, a file, the network, etc.
  • Formatter — decides what the text looks like.
  • Filter — optional fine-grained control over which records pass.

A log call creates a record, the logger checks its level, then passes the record to its handlers (and, by default, up to its parent loggers). Each handler checks its own level and formats the record. Two level checks, not one — remember that and half the mysteries vanish.

Don't configure the root logger by accident

The single most common beginner mistake is calling logging.info(...) directly (or relying on basicConfig) everywhere. Those go through the root logger, which makes it impossible to control verbosity per component. Instead, create a named logger per module using __name__:

import logging

logger = logging.getLogger(__name__)

def create_order(order_id, total):
    logger.info("order %s created for $%.2f", order_id, total)
    return {"id": order_id, "total": total}

Because __name__ is something like shop.orders, your loggers automatically form a hierarchy (shopshop.orders). You can then dial the whole shop subtree up to DEBUG while leaving noisy third-party libraries at WARNING.

Levels and the two-check rule

The five standard levels, in ascending severity, are DEBUG, INFO, WARNING, ERROR, and CRITICAL. A record only appears if it clears both the logger's level and the handler's level:

import logging, sys

logger = logging.getLogger("shop.orders")
logger.setLevel(logging.DEBUG)          # logger allows everything

handler = logging.StreamHandler(sys.stdout)
handler.setLevel(logging.INFO)          # but this handler drops DEBUG
handler.setFormatter(logging.Formatter(
    "%(asctime)s %(name)s %(levelname)s %(message)s",
    datefmt="%H:%M:%S",
))
logger.addHandler(handler)

logger.debug("this is filtered out by the handler")
logger.info("order %s created for $%.2f", 1234, 19.5)
# 03:08:55 shop.orders INFO order 1234 created for $19.50

Use lazy %-formatting, not f-strings

It's tempting to write logger.info(f"processing {expensive()}"), but that always evaluates the f-string, even when the message will be discarded. Pass arguments separately and let logging do the interpolation only if the record is actually emitted:

# Good: interpolation only happens if INFO is enabled
logger.info("processing user %s with %d items", user_id, count)

# Wasteful: f-string is built even when DEBUG is off
logger.debug(f"payload = {build_huge_debug_dump()}")

Logging exceptions the right way

Inside an except block, use logger.exception() — it logs at ERROR level and attaches the full traceback automatically. Outside an except block, pass exc_info=True to any level:

def process(order_id):
    try:
        1 / 0
    except ZeroDivisionError:
        logger.exception("failed to process order %s", order_id)
        # logs the message plus the complete traceback

Configure once with dictConfig

Wiring handlers and formatters by hand is fine for a script, but for a real application you want one declarative block, ideally near your entry point. logging.config.dictConfig is the idiomatic choice — it maps cleanly to a YAML or JSON config file:

import logging.config

logging.config.dictConfig({
    "version": 1,
    "disable_existing_loggers": False,
    "formatters": {
        "simple": {"format": "%(levelname)s:%(name)s:%(message)s"},
        "detailed": {
            "format": "%(asctime)s %(name)s %(levelname)s "
                      "[%(filename)s:%(lineno)d] %(message)s",
        },
    },
    "handlers": {
        "console": {
            "class": "logging.StreamHandler",
            "formatter": "simple",
            "level": "INFO",
        },
        "file": {
            "class": "logging.handlers.RotatingFileHandler",
            "formatter": "detailed",
            "filename": "app.log",
            "maxBytes": 1_000_000,
            "backupCount": 3,
            "level": "DEBUG",
        },
    },
    "root": {"handlers": ["console", "file"], "level": "DEBUG"},
    "loggers": {
        # quiet a chatty dependency without touching your own logs
        "urllib3": {"level": "WARNING"},
    },
})

logging.getLogger("myapp").info("configured via dictConfig")

Set disable_existing_loggers to False — the default of True silently mutes any logger created before the config runs, which is a classic "why did my logs disappear?" trap.

Rotating files so logs don't eat your disk

RotatingFileHandler caps each file at maxBytes and keeps backupCount old copies (app.log.1, app.log.2, …). For time-based rotation — say, a fresh file every midnight — use TimedRotatingFileHandler instead:

from logging.handlers import TimedRotatingFileHandler

handler = TimedRotatingFileHandler(
    "app.log", when="midnight", backupCount=7  # keep a week of daily logs
)

Structured logging: emit JSON

Grepping plain text is fine locally, but log aggregators (Elasticsearch, Loki, CloudWatch) love structured data. You can emit JSON with a small custom formatter — no third-party dependency required:

import json, logging

class JsonFormatter(logging.Formatter):
    def format(self, record):
        payload = {
            "time": self.formatTime(record, "%Y-%m-%dT%H:%M:%S"),
            "level": record.levelname,
            "logger": record.name,
            "msg": record.getMessage(),
        }
        if record.exc_info:
            payload["exc"] = self.formatException(record.exc_info)
        return json.dumps(payload)

handler = logging.StreamHandler()
handler.setFormatter(JsonFormatter())
logging.getLogger("json.demo").addHandler(handler)
# {"time": "2026-08-11T03:08:55", "level": "INFO", ...}

Adding context with extra and filters

You often want per-request context — a request ID, a user ID — attached to every line. Pass an extra dict, and reference those keys in the format string:

logger.info("request handled", extra={"user_id": 42})
# formatter: "%(levelname)s %(message)s user_id=%(user_id)s"

The catch: if a record is missing a key the formatter expects, formatting raises KeyError. A Filter is the clean way to guarantee the field always exists:

class RequestContextFilter(logging.Filter):
    def filter(self, record):
        # supply a default so the formatter never blows up
        if not hasattr(record, "request_id"):
            record.request_id = "-"
        return True  # True means "keep this record"

handler.addFilter(RequestContextFilter())

Propagation and the library author's rule

By default a child logger passes records up to its ancestors, so a single handler on the root can capture everything — which is exactly what you want in an application. But if you're writing a library, never configure handlers or call basicConfig; that steals control from whoever imports you. Instead, attach a NullHandler and let the application decide:

# In a library's top-level package __init__.py
import logging
logging.getLogger(__name__).addHandler(logging.NullHandler())

Common pitfalls

  • Duplicate log lines. Usually caused by calling addHandler more than once (e.g., re-running setup in a notebook) or by both a child logger and the root having handlers. Configure handlers in exactly one place.
  • Nothing prints. With no handler configured, the root logger's default only shows WARNING and above. Add a handler, or lower the level.
  • Logs vanish after config. The disable_existing_loggers default bites again — set it to False.
  • Using the root logger everywhere. Prefer logging.getLogger(__name__) so you can tune components independently.

Wrap-up and next steps

Once the logger → handler → formatter flow and the two-level check click into place, logging stops being mysterious and becomes one of the most useful tools in the standard library. Start small: replace your print() calls with a module-level logging.getLogger(__name__), add a single dictConfig block at your entry point, and switch to lazy % arguments. From there, layer on JSON formatting when you adopt a log aggregator, add rotation so files stay bounded, and use filters to inject request context. To go deeper, explore QueueHandler/QueueListener for non-blocking logging in high-throughput services, and read the official Logging Cookbook in the Python docs for battle-tested recipes.