Structured logging in Python

Structured logging means emitting machine-parseable events (one JSON object per line) instead of prose. "Payment failed for order 42 after 3 retries" needs a regex to analyze; {"event": "payment_failed", "order_id": 42, "retries": 3} is immediately queryable in any log backend (ELK Stack (Elasticsearch, Logstash, Kibana)). Log events with fields, not sentences with values baked in.

stdlib logging: where plain formatting falls short

The standard logging pipeline (logger → handler → formatter) formats records into strings. Two problems:

• logger.info("payment failed order=%s", order_id) — the field is interpolated away; the backend sees one opaque string.
• extra={"order_id": 42} attaches real fields, but the default formatter ignores them and nothing enforces consistency.

Minimal JSON with stdlib only (via python-json-logger):

import logging
from pythonjsonlogger.json import JsonFormatter

# stdout — the 12-factor way
handler = logging.StreamHandler()
handler.setFormatter(JsonFormatter("%(timestamp)s %(level)s %(name)s %(message)s",
                                   timestamp=True))
logging.basicConfig(handlers=[handler], level=logging.INFO)

logging.getLogger("billing").info("payment_failed", extra={"order_id": 42, "retries": 3})
# {"timestamp": "...", "level": "INFO", "name": "billing", "message": "payment_failed", "order_id": 42, "retries": 3}

Workable, but field discipline stays manual. That’s the gap structlog fills.

structlog — the standard answer

structlog builds each log entry as a dict flowing through a processor pipeline, with first-class context binding:

import structlog

structlog.configure(
    processors=[
        # pull in request-scoped context
        structlog.contextvars.merge_contextvars,
        structlog.processors.add_log_level,
        structlog.processors.TimeStamper(fmt="iso"),
        structlog.processors.dict_tracebacks,      # exceptions as structured data
        structlog.processors.JSONRenderer(),       # prod; ConsoleRenderer() for dev
    ],
)

log = structlog.get_logger()
log.info("payment_failed", order_id=42, retries=3, amount_cents=1999)

The two features that matter in services:

• bind() / contextvars — attach context once, every subsequent log line carries it:

# middleware, once per request
structlog.contextvars.bind_contextvars(request_id=req_id, user_id=user.id)
# any log call anywhere in the request now includes request_id and user_id

contextvars make this async-safe — each task sees its own context. The full request-ID propagation story (FastAPI middleware, httpx, Celery, Kafka) is Correlation IDs and Trace Context in Async Python.

• Dev/prod split — same call sites, ConsoleRenderer (pretty, colored) locally and JSONRenderer in prod. Point structlog at stdlib handlers (stdlib.BoundLogger + ProcessorFormatter) when you also need third-party libraries’ stdlib logs rendered through the same pipeline.

What goes in every event

Keep event constant and put variables in fields: log.info("payment_failed", reason=...), never log.info(f"payment failed: {reason}") — f-strings in log calls quietly destroy structure (and evaluate even when the level is off).

Never log: passwords, tokens, full card numbers, raw PII. Logs outlive databases in backups and have looser access control. Add a redaction processor for known-sensitive keys.

Canonical log lines

High-signal pattern: emit one wide event per request at completion, carrying everything — route, status, duration, user, DB time, retries. One line answers “what happened on this request” without joining ten fragments; per-request cost stays predictable. Middleware accumulates fields on the contextvars, logs once in the finally.

Async and performance notes

• Handlers write synchronously — a slow destination stalls the event loop. Logging to stdout is fast; if you must ship to a network sink from-process, isolate with QueueHandler/QueueListener. Preferred: don’t ship from the app at all — stdout + node-level collector (The twelve-factor app, ELK Stack (Elasticsearch, Logstash, Kibana)).
• Levels are a cost dial: INFO for events you’d query, DEBUG gated off in prod (or sampled), WARNING+ for things a human might act on. Log volume is billed per GB in every backend.
• Exceptions: log.exception("task_failed", task_id=...) inside except — with dict_tracebacks the stack becomes structured data, not a 40-line string blob.

Common pitfalls

• f-string interpolation at call sites — kills queryability, the single most common regression.
• Unbounded field names (dict keys from user data) — mapping explosion in Elasticsearch (ELK Stack (Elasticsearch, Logstash, Kibana)); values vary, names must not.
• Two logging worlds — your app logs JSON but uvicorn/gunicorn access logs stay plaintext; route them through the same formatter or disable and log requests yourself.
• Binding context but never clearing it (clear_contextvars per request) — leaked fields from the previous request on reused workers.