Spaces:
Running
Running
File size: 3,584 Bytes
f1fa34c | 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 100 101 102 103 104 | """
Request middleware: correlation IDs and structured access logging.
Replaces ad-hoc ``print()`` on the request path. Every line is JSON so a log
aggregator can index it, and every line carries the same ``request_id`` the
client received in its response header — which makes a user-reported error
traceable to a single request.
Deliberately never logs: request bodies, Authorization headers, or LLM API keys.
"""
from __future__ import annotations
import json
import logging
import sys
import time
from starlette.middleware.base import BaseHTTPMiddleware
from starlette.requests import Request
from api.errors import REQUEST_ID_HEADER, new_request_id, request_id_ctx
logger = logging.getLogger("researchrag.api")
# Never emit these, whatever happens.
_REDACTED_HEADERS = {"authorization", "cookie", "x-api-key"}
class JsonLogFormatter(logging.Formatter):
"""Minimal JSON formatter — no dependency on structlog."""
def format(self, record: logging.LogRecord) -> str:
payload = {
"ts": self.formatTime(record, "%Y-%m-%dT%H:%M:%S%z"),
"level": record.levelname,
"logger": record.name,
"message": record.getMessage(),
}
for key in ("request_id", "method", "path", "status", "duration_ms", "client"):
value = getattr(record, key, None)
if value is not None:
payload[key] = value
if record.exc_info:
payload["exception"] = self.formatException(record.exc_info)
return json.dumps(payload, ensure_ascii=False)
def configure_logging(level: str = "INFO", json_output: bool = True) -> None:
"""Install a single stdout handler. Safe to call once at startup."""
handler = logging.StreamHandler(sys.stdout)
handler.setFormatter(
JsonLogFormatter()
if json_output
else logging.Formatter("%(levelname)s %(name)s %(message)s")
)
root = logging.getLogger()
root.handlers = [handler]
root.setLevel(level.upper())
# uvicorn's own access log would duplicate ours.
logging.getLogger("uvicorn.access").disabled = True
class RequestContextMiddleware(BaseHTTPMiddleware):
"""Assign a request id, log the outcome, and echo the id to the client."""
async def dispatch(self, request: Request, call_next):
rid = request.headers.get(REQUEST_ID_HEADER) or new_request_id()
token = request_id_ctx.set(rid)
started = time.perf_counter()
try:
response = await call_next(request)
except Exception:
# The exception handler builds the response; just record timing.
logger.exception(
"request_failed",
extra={
"request_id": rid,
"method": request.method,
"path": request.url.path,
"duration_ms": round((time.perf_counter() - started) * 1000, 1),
},
)
request_id_ctx.reset(token)
raise
duration_ms = round((time.perf_counter() - started) * 1000, 1)
response.headers[REQUEST_ID_HEADER] = rid
logger.info(
"request",
extra={
"request_id": rid,
"method": request.method,
"path": request.url.path,
"status": response.status_code,
"duration_ms": duration_ms,
"client": request.client.host if request.client else None,
},
)
request_id_ctx.reset(token)
return response
|