Structured Logging with structlog (and When stdlib Is Enough)

Every production Python API eventually needs queryable logs — one JSON object per line, each carrying enough context to trace a single request end to end. The question is not whether to log JSON; it is whether to reach for structlog or stay on the standard library's logging module with a JSON formatter bolted on. This page makes the call with runnable code on both sides, then goes past the toy example into the production config, the redaction, and the cost math that decide it in practice. Part of the monitoring and logging Python APIs guide.

The short version: stdlib logging can produce JSON, but binding per-request context — a request_id that follows every log call without being passed around by hand — is awkward and easy to forget. structlog makes that binding the default path and turns your log format into an ordered pipeline of small functions you can edit without touching a single call site. Below is the comparison, the config, the concurrency model, and the criteria for choosing.

stdlib logging vs structlog, side by side

Both approaches end at the same place — structured JSON on stdout — but the developer experience of getting there differs sharply, and the difference is almost entirely about per-request context.

Here is the same "request completed" log line in stdlib logging, configured with dictConfig and a JSON formatter:

# stdlib_logging.py
import logging.config
import os

logging.config.dictConfig({
    "version": 1,
    "disable_existing_loggers": False,
    "formatters": {
        "json": {
            "()": "pythonjsonlogger.jsonlogger.JsonFormatter",
            "format": "%(asctime)s %(levelname)s %(name)s %(message)s",
        }
    },
    "handlers": {
        "stdout": {"class": "logging.StreamHandler", "formatter": "json"}
    },
    "root": {
        "handlers": ["stdout"],
        "level": os.getenv("LOG_LEVEL", "INFO"),
    },
})

log = logging.getLogger("builder-api")
# Context must be threaded through manually on each call:
log.info("request_completed", extra={"request_id": "abc", "status": 200})

That works, but extra={...} has to appear on every single call, and forgetting it on one log line silently drops the request_id you needed most — the one attached to the 500 you are trying to reproduce. A LoggerAdapter helps, but you still pass it down every function that logs. structlog moves context binding out of the call site entirely, which is the whole reason to adopt it.

structlog config bound to request context

The processor pipeline is the core idea: each log event flows through an ordered list of functions that enrich it, format it, and finally render it. merge_contextvars is the one that injects request-scoped fields automatically, so nothing in your route code has to know they exist.

# structlog_setup.py
import logging
import os
import structlog

def configure_logging() -> None:
    level = os.getenv("LOG_LEVEL", "INFO").upper()
    logging.basicConfig(format="%(message)s", level=level)
    structlog.configure(
        processors=[
            structlog.contextvars.merge_contextvars,   # inject request context
            structlog.processors.add_log_level,
            structlog.processors.TimeStamper(fmt="iso"),
            structlog.processors.StackInfoRenderer(),
            structlog.processors.format_exc_info,
            structlog.processors.JSONRenderer(),        # one JSON line out
        ],
        wrapper_class=structlog.make_filtering_bound_logger(
            logging.getLevelName(level)
        ),
        cache_logger_on_first_use=True,
    )

log = structlog.get_logger()

The pipeline order is not cosmetic. merge_contextvars runs first so request fields are present before anything else reads the event dict, and JSONRenderer runs last because nothing can render after the event has become a string. If you insert a redaction processor (below) it must sit before the renderer or it has nothing structured left to strip.

Wiring it into FastAPI

Bind context once in middleware, and every log call inside that request — in your route, in a service function, in a dependency, anywhere down the async call stack — inherits the request_id for free:

# app.py
import uuid
import structlog
from fastapi import FastAPI, Request
from structlog_setup import configure_logging

configure_logging()
log = structlog.get_logger()
app = FastAPI()

@app.middleware("http")
async def bind_request_context(request: Request, call_next):
    structlog.contextvars.bind_contextvars(
        request_id=request.headers.get("X-Request-ID", str(uuid.uuid4())),
        path=request.url.path,
    )
    try:
        return await call_next(request)
    finally:
        structlog.contextvars.clear_contextvars()

@app.get("/items/{item_id}")
async def get_item(item_id: int):
    log.info("item_lookup", item_id=item_id)  # request_id added automatically
    return {"item_id": item_id}

The clear_contextvars() in the finally block is mandatory, and the reason is the most common structlog bug in production. contextvars are not automatically request-scoped; they are task-scoped and the underlying worker task is reused. Skip the clear and one request's request_id leaks into whatever request the event loop schedules next on that task — so your logs blame customer A for an error customer B triggered. Always clear in finally so it runs even when the route raises.

Isolating context across concurrent requests

The reason structlog beats a global dict or a thread-local for this job is that contextvars are copied per async task. Two requests handled concurrently on the same worker each see only their own bound fields; there is no cross-talk even though they share one logger and one pipeline. That is what makes the shared pipeline safe.

There is one edge case worth knowing: asyncio.create_task() snapshots the current context, so a background task spawned mid-request inherits the request_id at spawn time — usually what you want. But if you hand work to a thread pool via run_in_executor, the copy does not follow automatically; bind again inside the worker or pass the id explicitly. The same caveat applies when you push work onto a queue for background jobs with Celery: the request context does not cross the process boundary, so propagate the request_id as a task argument and re-bind it in the worker.

Production configuration that pays off

The toy config renders ISO timestamps and levels. A commercial API needs three more things: level control from the environment, a redaction step so you never ship PII to your log store, and a faster serializer once volume climbs.

Redaction is a processor like any other. This one drops known-sensitive keys before the renderer sees them, so an authorization header or a raw email never lands in your log platform where it becomes a compliance liability:

# redaction.py
import os

_REDACT = set(
    os.getenv("LOG_REDACT_KEYS", "authorization,password,token,email").split(",")
)

def redact_pii(logger, method_name, event_dict):
    for key in list(event_dict):
        if key.lower() in _REDACT:
            event_dict[key] = "***"
    return event_dict

Insert redact_pii into the processors list just before JSONRenderer. For throughput, swap the default renderer for structlog.processors.JSONRenderer(serializer=orjson.dumps) — orjson serializes two to three times faster than the stdlib json module, which matters only once you are emitting millions of lines a day but costs nothing to adopt early. Keep LOG_LEVEL at INFO in production and reserve DEBUG for a temporary environment override; make_filtering_bound_logger discards below-threshold events before they touch the pipeline, so a filtered DEBUG call is close to free.

On cost: JSON serialization of a typical event dict runs in single-digit microseconds. An API serving 1M requests a month that emits five log lines per request produces 5M lines. At roughly 400–600 bytes per line that is about 2.5 GB of log volume a month — small enough that CPU spent logging is lost next to a single database round-trip, but large enough that your log ingestion bill is the real number to watch. This is why you sample: keep INFO for request-completed lines and one WARNING/ERROR per failure, but do not log every cache hit at INFO. Whether a log line earns its ingestion cost is the same margin question you face when calculating cost per API request.

When to choose structlog

Reach for structlog when you run an async API and need a request_id (or user_id, tenant) on every log line without threading it through every function — the contextvars binding is the decisive feature and nothing in stdlib matches it cleanly. Reach for it too when you want key-value ergonomics over f-strings, or you expect your log schema to evolve, since adding or redacting a field is a one-line processor change. That evolvability is what keeps your logs useful as you build out usage tracking and analytics or start logging usage events to Postgres for billing.

Stay on stdlib logging when your service is a small script, cron job, or single-purpose worker where one JsonFormatter and the occasional extra={...} cover every case; when you have no per-request context to propagate, which erases structlog's main advantage; or when you want zero added dependencies and your team already knows dictConfig. Either way, log to stdout as one JSON object per line and let your platform ship it — that advice from the parent guide is library-agnostic and non-negotiable in a containerized deploy.

Migration note: moving from stdlib to structlog

You do not have to rewrite everything at once, and you should not try to. structlog can sit on top of the stdlib logging system, so logs from third-party libraries — every one of which uses stdlib logging — and your new structlog calls render through the same JSON pipeline. Point stdlib's root logger at a structlog.stdlib.ProcessorFormatter, then migrate your own call sites from logger.info("x", extra={...}) to log.info("x", **kwargs) module by module. Existing logging.getLogger(__name__) calls keep working the whole time, so the transition is mechanical and reversible per file rather than a big-bang rewrite you have to land in one deploy. Verify the migrated modules with a quick assertion in your pytest suite using structlog.testing.capture_logs, which records emitted events as plain dicts you can assert against.

Builder verdict

If you are running a commercial async API on FastAPI, use structlog. The contextvars-bound request_id alone justifies it: it is the difference between grepping one id to trace a customer's failed request and reconstructing the call from scattered timestamps at 2 a.m. The processor pipeline keeps PII redaction and schema changes to one-line edits, the stdlib bridge means you adopt it without losing library logs, and the per-call overhead is measured in microseconds you will never feel behind a database round-trip. Reserve plain stdlib logging for scripts and workers with no request context to carry — there, structlog is dependency weight for a feature you will not use. The one discipline it demands is the clear_contextvars() in finally; get that right and everything else is upside.

FAQ

How much does structured logging cost to run at 1M requests a month? The CPU is negligible — JSON serialization is single-digit microseconds per line, lost next to any I/O. The real cost is log ingestion: at five lines per request and roughly 500 bytes each you produce about 2.5 GB a month, so your bill is set by your log platform's per-GB rate, not by structlog. Sample aggressively at INFO and the number stays small.

Is structlog slower than stdlib logging? No meaningfully. Per-call overhead is comparable and dominated by JSON serialization, which both approaches pay. cache_logger_on_first_use=True and make_filtering_bound_logger discard below-threshold calls before the pipeline runs, so filtered DEBUG logs cost almost nothing. Swap in orjson as the serializer and structlog is typically faster than a stdlib JsonFormatter.

Can I keep using logging.getLogger() with structlog? Yes. structlog bridges to the stdlib logging system, so existing logging.getLogger(__name__) calls and third-party library logs continue to work and can render through the same JSON pipeline. That bridge is exactly what makes an incremental, per-module migration safe.

How does contextvars handle concurrent async requests without leaking data?contextvars are isolated per async task, so two requests handled concurrently each see only their own bound request_id — no cross-talk. The one rule is to clear_contextvars() in a finally block when the request finishes, so values never leak into the next request scheduled on that reused task.

Do I still need Prometheus if I have structured logs? Yes — they solve different problems. Structured logs give per-request detail for debugging one incident; Prometheus gives aggregate metrics, percentiles, and alerting across all of them. The parent monitoring guide wires up both, because logs alone give you no dashboards and no way to page yourself when p99 latency doubles.

Related

Same track:

• Monitoring and Logging Python APIs — the parent guide that wires structlog together with Prometheus metrics.
• Running Background Jobs with Celery — where you must re-bind request context because it does not cross the process boundary.
• Testing Python APIs with pytest — assert on emitted log events with capture_logs.

Other tracks:

• Logging API Usage Events to Postgres — structured events feeding a billing and analytics store.
• Calculating Cost per API Request — put a number on what each log line costs to ingest.