"""Request middleware: trace IDs, structured logging, and access metrics.""" from __future__ import annotations import logging import time import uuid from typing import Awaitable, Callable import structlog from starlette.middleware.base import BaseHTTPMiddleware from starlette.requests import Request from starlette.responses import Response def configure_logging(level: str = "INFO") -> None: """Initialize structlog + stdlib logging once on startup.""" logging.basicConfig( format="%(message)s", level=getattr(logging, level.upper(), logging.INFO), ) structlog.configure( processors=[ structlog.contextvars.merge_contextvars, structlog.processors.add_log_level, structlog.processors.TimeStamper(fmt="iso"), structlog.processors.StackInfoRenderer(), structlog.processors.format_exc_info, structlog.processors.JSONRenderer(), ], wrapper_class=structlog.make_filtering_bound_logger( getattr(logging, level.upper(), logging.INFO) ), cache_logger_on_first_use=True, ) class RequestContextMiddleware(BaseHTTPMiddleware): """Attach a trace_id to every request, log latency, and surface it as a header.""" async def dispatch( self, request: Request, call_next: Callable[[Request], Awaitable[Response]], ) -> Response: trace_id = request.headers.get("x-trace-id") or uuid.uuid4().hex[:16] request.state.trace_id = trace_id log = structlog.get_logger("nexus.http").bind( trace_id=trace_id, method=request.method, path=request.url.path, ) start = time.perf_counter() try: response = await call_next(request) except Exception as exc: duration_ms = (time.perf_counter() - start) * 1000 log.error("request.error", error=str(exc), duration_ms=round(duration_ms, 2)) raise duration_ms = (time.perf_counter() - start) * 1000 response.headers["X-Trace-Id"] = trace_id response.headers["X-Response-Time-ms"] = f"{duration_ms:.2f}" log.info( "request.complete", status=response.status_code, duration_ms=round(duration_ms, 2), ) return response