Stage 9 · L40

Design structured events and request correlation

Core · original Session 9

Useful request logs answer what operation happened, how long it took and which observations belong together. RequestObservation generates a UUID and sets a ContextVar for the request. A pure ASGI wrapper sees response-start/body messages without relying on a decorator middleware's simplified completion timing.

ContextVar gives independent logical context across concurrent async requests and propagates into the worker context used by FastAPI. The wrapper resets its token in finally, even if logging itself fails. A global mutable current_request_id would let one request overwrite another. The concurrent fixture intentionally overlaps two requests and confirms separate body/header/log identifiers and cleanup.

SafeJSON emits a positive field allowlist: event, generated request ID, method, route template, status, duration, completion, error kind and scoped provider counters. It does not emit raw paths/query strings, bodies, headers, token values, passwords or arbitrary exception messages. Unknown event text becomes application_event rather than being copied into structured output.

The app configures a stdout handler explicitly and disables propagation to avoid relying on Uvicorn to configure an unrelated application logger. The independent Uvicorn error logger is a separate concern and is not certified by these application-formatter tests. Do not claim that one safe formatter sanitizes all process output.

Route templates such as /rentals/{rental_id} prevent a separate log dimension for every UUID. The generated response X-Request-ID matches the log context and is not accepted from untrusted incoming data. Provider logging records one logical lookup and its local attempt count using its own context token, avoiding inaccurate subtraction of concurrently changing global counters.

DEBUG is development detail; INFO records ordinary events; WARNING signals an unusual condition worth attention; ERROR records failed operations; CRITICAL concerns an inability to continue. This snapshot logs ordinary access atINFO and failed/stream-error events atERROR, with a structured level field. A4xx access result is not automatically a server error. Choose the level for the event's operational meaning, without logging secrets to explain it.

event='request'; level='INFO'; method='GET'
route='/rentals/{rental_id}'; status=200
request_id=<generated UUID>; response_complete=True

Omit query/body/headers/token/password/exception message.
Unknown event text → application_event.

Ordinary access isINFO; a failed operation/stream error isERROR. Use generated per-request context and a route template rather than UUID-specific raw URLs. A positive field allowlist excludes submitted/private data. A global mutable ID can be overwritten by a concurrent request. This focused answer does not configure metrics/traces or logging collectors.