"""Structured (JSON) logging + per-request context (P9 CP-A). Three pieces: - `JsonFormatter` — emits one JSON object per record with a stable schema. - `RequestContextFilter` — pulls `request_id` + `slot_id` from contextvars and attaches them as record attributes. - `RequestIdMiddleware` — mints a request_id per request (or reuses an incoming `X-Request-ID`), sets the contextvar, echoes it on the response. Production sets `BRIDGE_LOG_FORMAT=json`; dev defaults to plaintext. P8 CP-B's `RedactFilter` is applied independently; both filters coexist on the root logger. CLI parity: stdlib only. """ from __future__ import annotations import contextvars import json import logging import os import sys import uuid from datetime import datetime, timezone from starlette.middleware.base import BaseHTTPMiddleware from starlette.requests import Request # ----- per-request context vars ------------------------------------------- request_id_ctx: contextvars.ContextVar[str | None] = contextvars.ContextVar( "bridge_request_id", default=None ) slot_id_ctx: contextvars.ContextVar[str | None] = contextvars.ContextVar( "bridge_slot_id", default=None ) # ----- formatter ---------------------------------------------------------- class JsonFormatter(logging.Formatter): """One JSON object per record with a stable field order.""" def format(self, record: logging.LogRecord) -> str: payload: dict[str, object] = { "ts": datetime.now(timezone.utc).strftime("%Y-%m-%dT%H:%M:%S.%fZ"), "level": record.levelname, "logger": record.name, } # Context attached by RequestContextFilter (if running under request scope) rid = getattr(record, "request_id", None) sid = getattr(record, "slot_id", None) if rid: payload["request_id"] = rid if sid: payload["slot_id"] = sid try: payload["msg"] = record.getMessage() except Exception as exc: payload["msg"] = f"" # Exception info (if any) if record.exc_info: payload["exc"] = self.formatException(record.exc_info) return json.dumps(payload, separators=(",", ":"), ensure_ascii=False) # ----- filter ------------------------------------------------------------- class RequestContextFilter(logging.Filter): """Attaches the current request_id + slot_id contextvars to every record.""" def filter(self, record: logging.LogRecord) -> bool: record.request_id = request_id_ctx.get() record.slot_id = slot_id_ctx.get() return True # ----- middleware --------------------------------------------------------- _REQUEST_ID_HEADER = "X-Request-ID" class RequestIdMiddleware(BaseHTTPMiddleware): """Mints a request_id per request (or reuses incoming), sets contextvars, echoes the header on the response.""" async def dispatch(self, request: Request, call_next): incoming = request.headers.get(_REQUEST_ID_HEADER) rid = incoming or uuid.uuid4().hex[:12] token_rid = request_id_ctx.set(rid) # slot_id is set by the JWT middleware later (or stays None for public routes) try: response = await call_next(request) finally: request_id_ctx.reset(token_rid) # Echo on response, regardless of inbound source response.headers[_REQUEST_ID_HEADER] = rid return response # ----- install hook ------------------------------------------------------- _INSTALLED = False def install_structured_logging() -> None: """Apply JsonFormatter + RequestContextFilter to the root logger. Honors `BRIDGE_LOG_FORMAT` env: `json` (production) installs; any other value (default `text`) is a no-op so dev keeps human-readable logs. Idempotent. Safe to call multiple times. """ global _INSTALLED if _INSTALLED: return if os.environ.get("BRIDGE_LOG_FORMAT", "text").lower() != "json": return root = logging.getLogger() # If no handler yet, attach a stderr handler (uvicorn usually installs its # own, but be defensive). if not root.handlers: root.addHandler(logging.StreamHandler(stream=sys.stderr)) fmt = JsonFormatter() for h in root.handlers: h.setFormatter(fmt) # Attach the context filter idempotently (don't duplicate) if not any(isinstance(f, RequestContextFilter) for f in root.filters): root.addFilter(RequestContextFilter()) _INSTALLED = True def reset_for_tests() -> None: """Test helper — drop the context filter + reset formatters; clear sentinel.""" global _INSTALLED root = logging.getLogger() root.filters = [f for f in root.filters if not isinstance(f, RequestContextFilter)] _INSTALLED = False