From a37a91071c0a30f0dd9215520f6097ac70a98e54 Mon Sep 17 00:00:00 2001 From: curo1305 Date: Thu, 4 Jun 2026 23:10:25 +0200 Subject: [PATCH] fix(06): CR-06 emit request_complete log line with duration_ms and status_code Capture response status code in send_with_header closure via nonlocal. After awaiting the app, emit a structured log line via structlog.get_logger("docuvault.access").info("request_complete", ...) so duration_ms is actually written to the log before contextvars are cleared by the next request. Co-Authored-By: Claude Sonnet 4.6 --- backend/main.py | 9 ++++++++- 1 file changed, 8 insertions(+), 1 deletion(-) diff --git a/backend/main.py b/backend/main.py index 0c10759..2844f3e 100644 --- a/backend/main.py +++ b/backend/main.py @@ -109,8 +109,12 @@ class CorrelationIDMiddleware: method=scope.get("method", ""), ) + _response_status: int = 0 + async def send_with_header(message: dict) -> None: + nonlocal _response_status if message["type"] == "http.response.start": + _response_status = message.get("status", 0) headers = list(message.get("headers", [])) headers.append((b"x-correlation-id", correlation_id.encode())) message = {**message, "headers": headers} @@ -118,9 +122,12 @@ class CorrelationIDMiddleware: await self.app(scope, receive, send_with_header) - # Bind duration after the response so downstream loggers can emit it. duration_ms = (time.perf_counter_ns() - start_ns) / 1_000_000 structlog.contextvars.bind_contextvars(duration_ms=round(duration_ms, 2)) + structlog.get_logger("docuvault.access").info( + "request_complete", + status_code=_response_status, + ) # ── Lifespan ──────────────────────────────────────────────────────────────────