diff --git a/docs/framework/middleware.md b/docs/framework/middleware.md index 151db48f..8e69ca78 100644 --- a/docs/framework/middleware.md +++ b/docs/framework/middleware.md @@ -50,7 +50,37 @@ The response flows back up in the reverse of this order. ### `CorrelationIdMiddleware` -Reads the `X-Request-ID` header (or generates a UUID4), puts it on `request.state.correlation_id`, and adds it to every log line via `contextvars`. Included in the response as `X-Request-ID` so clients can cross-reference logs. +Reads the `X-Correlation-ID` header (or generates a UUID4 hex) and makes the value available three ways: + +- `request.state.correlation_id` — for handlers that already hold the `Request`. +- The `simple_module_hosting.logging.correlation_id` `ContextVar` — for code (services, background tasks spawned from a request) that doesn't. +- An `X-Correlation-ID` response header — so clients can cross-reference their request with server-side logs. + +Every record emitted via the stdlib `logging` setup configured by `setup_logging()` already carries the ID under the `correlation_id` field, thanks to `_CorrelationIdFilter` reading the contextvar. For **structlog**, add a tiny processor that copies the framework's `ContextVar` into structlog's event dict: + +```python +# anywhere during app startup (e.g. main.py) +import structlog +from simple_module_hosting.logging import correlation_id + +def add_correlation_id(_, __, event_dict): + cid = correlation_id.get("") + if cid: + event_dict.setdefault("correlation_id", cid) + return event_dict + +structlog.configure( + processors=[ + add_correlation_id, + structlog.processors.add_log_level, + structlog.processors.JSONRenderer(), + ], +) +``` + +No per-handler `bind()` and no middleware of your own — the framework's middleware calls `correlation_id.set(...)` for the duration of every request, and the processor above lifts that value into every log event. + +> `structlog.contextvars.merge_contextvars` is **not** a substitute here: it only merges `ContextVar`s whose names start with `structlog_` (set via `structlog.contextvars.bind_contextvars`), and the framework's `correlation_id` is a plain stdlib `ContextVar` outside that namespace. ### `RequestLoggingMiddleware` diff --git a/framework/hosting/simple_module_hosting/_observability.py b/framework/hosting/simple_module_hosting/_observability.py index c6a7353d..57100133 100644 --- a/framework/hosting/simple_module_hosting/_observability.py +++ b/framework/hosting/simple_module_hosting/_observability.py @@ -26,10 +26,16 @@ class CorrelationIdMiddleware: """Generate or propagate a correlation ID for every request. - Reads the incoming ``X-Correlation-ID`` header (or generates a UUID4) and - stores it in a :class:`~contextvars.ContextVar` so that every log record - emitted during the request automatically includes the ID. The same value - is echoed back in the response header. + Reads the incoming ``X-Correlation-ID`` header (or generates a UUID4) and: + + * stores it in the ``simple_module_hosting.logging.correlation_id`` + ContextVar so the stdlib logging filter (or a user-supplied structlog + processor — see ``docs/framework/middleware.md``) picks it up with no + per-handler plumbing; + * exposes it on ``request.state.correlation_id`` for handlers that + prefer the request object over the contextvar; + * echoes the value back as the ``X-Correlation-ID`` response header so + clients can cross-reference their request with server-side logs. """ HEADER = "X-Correlation-ID" @@ -43,6 +49,8 @@ async def __call__(self, scope: Scope, receive: Receive, send: Send) -> None: return cid = Headers(scope=scope).get(self.HEADER) or uuid.uuid4().hex + # Skip allocating a Request wrapper — downstream Request(scope).state reads this same dict. + scope.setdefault("state", {})["correlation_id"] = cid async def send_with_header(message: Message) -> None: if message["type"] == _MSG_RESPONSE_START: diff --git a/framework/hosting/tests/test_logging.py b/framework/hosting/tests/test_logging.py index 496b1ed9..3046fe2e 100644 --- a/framework/hosting/tests/test_logging.py +++ b/framework/hosting/tests/test_logging.py @@ -4,6 +4,7 @@ import json import logging +from typing import TYPE_CHECKING import httpx from simple_module_hosting.logging import ( @@ -12,6 +13,13 @@ correlation_id, setup_logging, ) +from simple_module_hosting.middleware import CorrelationIdMiddleware +from starlette.applications import Starlette +from starlette.responses import JSONResponse +from starlette.routing import Route + +if TYPE_CHECKING: + from starlette.requests import Request # ── JsonFormatter ────────────────────────────────────────────────────── @@ -174,6 +182,29 @@ async def test_different_requests_get_different_ids(self, client: httpx.AsyncCli r2 = await client.get("/health") assert r1.headers["x-correlation-id"] != r2.headers["x-correlation-id"] + async def test_state_contextvar_and_header_agree(self): + # Background tasks read the ContextVar; handlers read request.state; + # clients read the response header — all three must agree per request. + async def echo(request: Request) -> JSONResponse: + return JSONResponse( + { + "state": request.state.correlation_id, + "contextvar": correlation_id.get(""), + } + ) + + app = Starlette(routes=[Route("/echo", echo)]) + app.add_middleware(CorrelationIdMiddleware) + + transport = httpx.ASGITransport(app=app) + async with httpx.AsyncClient(transport=transport, base_url="http://testserver") as c: + resp = await c.get("/echo", headers={CorrelationIdMiddleware.HEADER: "trace-xyz"}) + + assert resp.headers[CorrelationIdMiddleware.HEADER] == "trace-xyz" + body = resp.json() + assert body["state"] == "trace-xyz" + assert body["contextvar"] == "trace-xyz" + # ── Request logging middleware (integration) ────────────────────────────