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 <noreply@anthropic.com>
This commit is contained in:
co-authored by
Claude Sonnet 4.6
parent
aad7635623
commit
a37a91071c
+8
-1
@@ -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 ──────────────────────────────────────────────────────────────────
|
||||
|
||||
Reference in New Issue
Block a user