Python Logging Configuration That Doesn't Hurt

Introduction¶

Python's logging has a reputation for being confusing. It isn't, once you know the three-object model and one rule: applications configure logging; libraries only emit.

The model¶

• Logger — what you call (logger.info(...)). Named hierarchically by dotted path (myapp.db.pool). You get one with logging.getLogger(__name__).
• Handler — where records go (stderr, a file, syslog, a network endpoint). A logger can have several.
• Formatter — how a record is rendered to text.
• Level — on both loggers and handlers. A record must pass the logger's level and the handler's level.

Records propagate up the logger hierarchy to the root by default. Usually you attach handlers only to the root and let everything flow there.

Library code¶

import logging

logger = logging.getLogger(__name__)     # e.g. "mypackage.client"

def do_thing():
    logger.debug("starting", extra={"target": target})
    ...
    logger.warning("retrying after %s", err)

That's the entire library side. No basicConfig, no handlers, no setLevel on the root. A logging.NullHandler() on your top package logger (logging.getLogger("mypackage").addHandler(logging.NullHandler())) suppresses "No handlers could be found" if the app never configures logging.

Application configuration — dictConfig¶

Do this once, early, at the entry point:

import logging.config

logging.config.dictConfig({
    "version": 1,
    "disable_existing_loggers": False,     # keep loggers created at import time
    "formatters": {
        "plain": {"format": "%(asctime)s %(levelname)-8s %(name)s: %(message)s"},
        "json": {"()": "pythonjsonlogger.jsonlogger.JsonFormatter",
                 "format": "%(asctime)s %(levelname)s %(name)s %(message)s"},
    },
    "handlers": {
        "console": {"class": "logging.StreamHandler", "formatter": "plain",
                    "stream": "ext://sys.stderr"},
    },
    "root": {"handlers": ["console"], "level": "INFO"},
    "loggers": {
        "mypackage.db": {"level": "DEBUG"},      # noisier for one subsystem
        "urllib3": {"level": "WARNING"},         # quieter for a dependency
    },
})

dictConfig is declarative, testable, and easy to load from a file (YAML/JSON) per environment.

Structured logging¶

For anything that ships to a log aggregator, emit JSON:

logger.info("request complete", extra={
    "method": request.method,
    "path": request.path,
    "status": response.status_code,
    "duration_ms": round(elapsed * 1000, 1),
})

With a JSON formatter each extra key becomes a top-level field you can filter on. structlog is the popular library if you want richer context binding (request IDs threaded through automatically).

What NOT to do¶

• logging.basicConfig() in a library — it configures the root and fights the app.
• print() for diagnostics — no levels, no routing, no timestamps.
• logger.info(f"user {user_id} did {action}") — f-string is always evaluated even when the level is off; use logger.info("user %s did %s", user_id, action) so formatting is lazy.
• Logging secrets / full request bodies / PII — filter or redact.
• A handler per logger — leads to duplicate lines via propagation.

Verification and troubleshooting¶

# See the tree
import logging
logging.getLogger().manager.loggerDict.keys()
logging.getLogger("mypackage.db").getEffectiveLevel()

• Duplicate log lines — handlers on both a child logger and the root, plus propagation. Attach handlers only to root, or set propagate = False on the child (and give it its own handler).
• No output at all — no handler configured (records go nowhere), or the level is above your message. logging.basicConfig(level=logging.DEBUG) as a one-liner to confirm the code path, then do it properly.
• DEBUG messages not showing despite level: DEBUG on the logger — the handler is still at INFO. Both must allow it.
• disable_existing_loggers ate my loggers — it defaults to True in dictConfig (a legacy wart). Set it False.
• Third-party library floods logs — set its logger to WARNING in the loggers section ("boto3": {"level": "WARNING"}).
• Logs missing in a subprocess / worker — each process configures its own logging; call dictConfig in the worker init, not just the parent.
• Timestamps in the wrong zone — logging uses local time; set logging.Formatter.converter = time.gmtime for UTC, or use a formatter that emits ISO-8601 with offset.

Related tools and reading¶

• On-site: JSON formatter, Timestamp converter.
• Related posts: asyncio for I/O-bound scripts, journalctl recipes.