Structured JSON Logging for APIs: Correlation IDs, Request Context and No More print()

The moment you run more than one instance of an API, human-readable text logs stop being an asset and become a liability. You cannot grep across twelve pods, and you cannot follow a single request through three services when every line is a free-form string.

The fix is not more logging. It is structured logging: every line a JSON object with the same machine-readable fields, a correlation ID that ties a request together across services, and enough request context bound automatically that you never have to remember to add it. This recipe wires structlog into a FastAPI 0.115 application on Python 3.12, with a middleware that assigns or propagates an X-Request-ID, records latency and status, and keeps secrets out of the output. Copy-paste config included.

Why print() and the stdlib defaults let you down

A line like User 4821 updated order 99 in 240ms is fine for one developer on one machine. In production it is a dead end. You cannot filter for all lines where latency_ms > 500, because latency is embedded in prose. You cannot join it to the same request in the payments service, because there is no shared identifier. And when a log aggregator ingests it, every line is an unstructured blob it has to re-parse with brittle regular expressions.

Structured logging inverts this. You emit {"event": "order updated", "user_id": 4821, "order_id": 99, "latency_ms": 240, "request_id": "..."}. Now the aggregator indexes fields, you filter on them, and a correlation ID lets you reconstruct one request’s journey across every service that handled it. That reconstruction is exactly what you need when you are measuring the operational metrics that matter, such as the DORA four and mean time to recovery — you cannot shorten an incident you cannot trace.

The structlog configuration

Configure structlog once, at startup. The processor chain does the work: merge_contextvars pulls in anything bound to the current context (this is how request context reaches every line without being passed around), then timestamps, log level and the exception formatter run, and JSONRenderer serialises the event to a single JSON line. Put merge_contextvars first so context is present for every downstream processor.

# logging_config.py — structlog 24.x, Python 3.12
import logging
import structlog


def configure_logging(json_logs: bool = True, level: str = "INFO") -> None:
    """Initialise structlog. Call once at application startup."""
    shared_processors = [
        structlog.contextvars.merge_contextvars,
        structlog.processors.add_log_level,
        structlog.processors.TimeStamper(fmt="iso", utc=True),
        structlog.processors.StackInfoRenderer(),
        structlog.processors.format_exc_info,
    ]

    # JSON in production; a colourised console renderer in development.
    renderer = (
        structlog.processors.JSONRenderer()
        if json_logs
        else structlog.dev.ConsoleRenderer()
    )

    structlog.configure(
        processors=shared_processors + [renderer],
        wrapper_class=structlog.make_filtering_bound_logger(
            logging.getLevelName(level)
        ),
        logger_factory=structlog.PrintLoggerFactory(),
        cache_logger_on_first_use=True,
    )

Two deliberate choices. make_filtering_bound_logger drops below-threshold calls before any processor runs, so a suppressed debug() costs almost nothing — that is what lets you sample noisy endpoints cheaply. And cache_logger_on_first_use=True means you must finish configuring before the first logger is bound, which is why this runs at import/startup, not lazily.

The request-ID middleware

The middleware is where correlation is born. On each request it reads an inbound X-Request-ID if an upstream proxy or caller supplied one, and generates a UUID if not. It clears any stale context, binds the request ID plus method and path, times the handler, and logs a single completion line with status and latency. The ID goes back out on the response header so the caller — and your load balancer’s access log — can line up with it.

# middleware.py — FastAPI 0.115
import time
import uuid

import structlog
from starlette.middleware.base import BaseHTTPMiddleware
from starlette.requests import Request

log = structlog.get_logger()


class RequestContextMiddleware(BaseHTTPMiddleware):
    async def dispatch(self, request: Request, call_next):
        # Clear context left over from a recycled worker, then bind.
        structlog.contextvars.clear_contextvars()
        request_id = request.headers.get("X-Request-ID") or str(uuid.uuid4())
        structlog.contextvars.bind_contextvars(
            request_id=request_id,
            method=request.method,
            path=request.url.path,
        )

        start = time.perf_counter()
        try:
            response = await call_next(request)
        except Exception:
            log.exception("request failed")
            raise
        elapsed_ms = round((time.perf_counter() - start) * 1000, 2)

        log.info(
            "request completed",
            status_code=response.status_code,
            latency_ms=elapsed_ms,
        )
        response.headers["X-Request-ID"] = request_id
        return response

Register it, and from that point every log call inside the request — in your route, your service layer, your database code — carries request_id, method and path automatically, because merge_contextvars reads them from the context.

# main.py
from fastapi import FastAPI

from logging_config import configure_logging
from middleware import RequestContextMiddleware

configure_logging(json_logs=True, level="INFO")

app = FastAPI()
app.add_middleware(RequestContextMiddleware)


@app.get("/orders/{order_id}")
async def get_order(order_id: int):
    log = structlog.get_logger()
    # request_id, method and path are already bound — no need to pass them.
    log.info("order fetched", order_id=order_id)
    return {"order_id": order_id}

If you also bind an authenticated user or tenant early in the request — after your auth dependency resolves — do it with another bind_contextvars(user_id=...) and it flows onto every subsequent line for that request too.

Keeping secrets out, and noise down

Structured logging makes leaks worse, not better, because a bound field is trivially indexed and searchable. Never bind a raw Authorization header, an API key, a card number or a password. The same discipline that applies when you store API keys as hashes with a visible prefix applies here: log the non-sensitive prefix or a hash, never the secret. Enforce it with a small redaction processor rather than trusting every developer to remember.

# Redaction processor — insert before the renderer in shared_processors.
_REDACT = {"password", "authorization", "api_key", "token", "card_number"}


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

For volume, lean on the filtering bound logger for levels, and sample deliberately for chatty endpoints — health checks, readiness probes — by short-circuiting them in the middleware before you log the completion line, or by dropping their info lines to debug. Keep errors and slow requests at full fidelity; those are the ones you will actually read.

Shipping it

Because the output is already one JSON object per line on stdout, you do not need a clever shipper. In a container, stdout is captured by the runtime and a collector — Fluent Bit, Vector, the cloud provider’s agent — forwards it to a JSON-aware backend that indexes the fields for free. Do not write to files and rotate them yourself; emit to stdout and let the platform own transport. The one rule that makes the whole chain work: one event, one line, always valid JSON. The day you concatenate a stack trace across three lines is the day your backend stops parsing.

Correlation IDs pay off most when a request crosses services — propagate the same X-Request-ID on every outbound call, and pair it with request-safety patterns like idempotency keys for retryable POSTs so a retried request is both traceable and safe. Get that right and an incident review stops being archaeology and becomes a single query.