88 lines
2.9 KiB
Python
88 lines
2.9 KiB
Python
|
"""Request scoped middleware: correlation ids and structured access logs."""
|
||
|
|
|
||
|
|
from __future__ import annotations
|
||
|
|
|
||
|
|
import logging
|
||
|
|
import time
|
||
|
|
import uuid
|
||
|
|
from collections.abc import Callable
|
||
|
|
|
||
|
|
from django.http import HttpRequest, HttpResponse
|
||
|
|
|
||
|
|
from apps.core.logging import set_request_id
|
||
|
|
|
||
|
|
logger = logging.getLogger("apps.access")
|
||
|
|
|
||
|
|
REQUEST_ID_HEADER = "HTTP_X_REQUEST_ID"
|
||
|
|
RESPONSE_HEADER = "X-Request-ID"
|
||
|
|
_MAX_REQUEST_ID_LEN = 64
|
||
|
|
|
||
|
|
|
||
|
|
class RequestIDMiddleware:
|
||
|
|
"""
|
||
|
|
Reads ``X-Request-ID`` from the incoming request or generates one.
|
||
|
|
|
||
|
|
The value is echoed back on the response and injected into every log record
|
||
|
|
produced while handling the request, so a browser network tab entry can be
|
||
|
|
pasted straight into Kibana.
|
||
|
|
"""
|
||
|
|
|
||
|
|
def __init__(self, get_response: Callable[[HttpRequest], HttpResponse]) -> None:
|
||
|
|
self.get_response = get_response
|
||
|
|
|
||
|
|
def __call__(self, request: HttpRequest) -> HttpResponse:
|
||
|
|
incoming = request.META.get(REQUEST_ID_HEADER, "")
|
||
|
|
# Never trust client input verbatim: keep it short and alphanumeric.
|
||
|
|
request_id = (
|
||
|
|
incoming[:_MAX_REQUEST_ID_LEN]
|
||
|
|
if incoming and incoming.replace("-", "").replace("_", "").isalnum()
|
||
|
|
else uuid.uuid4().hex
|
||
|
|
)
|
||
|
|
request.request_id = request_id # type: ignore[attr-defined]
|
||
|
|
set_request_id(request_id)
|
||
|
|
|
||
|
|
response = self.get_response(request)
|
||
|
|
response[RESPONSE_HEADER] = request_id
|
||
|
|
return response
|
||
|
|
|
||
|
|
|
||
|
|
class AccessLogMiddleware:
|
||
|
|
"""Emits one structured log line per request with timing and identity."""
|
||
|
|
|
||
|
|
def __init__(self, get_response: Callable[[HttpRequest], HttpResponse]) -> None:
|
||
|
|
self.get_response = get_response
|
||
|
|
|
||
|
|
def __call__(self, request: HttpRequest) -> HttpResponse:
|
||
|
|
started = time.perf_counter()
|
||
|
|
response = self.get_response(request)
|
||
|
|
duration_ms = round((time.perf_counter() - started) * 1000, 2)
|
||
|
|
|
||
|
|
user = getattr(request, "user", None)
|
||
|
|
logger.info(
|
||
|
|
"http_request",
|
||
|
|
extra={
|
||
|
|
"event": "http_request",
|
||
|
|
"http_method": request.method,
|
||
|
|
"http_path": request.path,
|
||
|
|
"http_status": response.status_code,
|
||
|
|
"duration_ms": duration_ms,
|
||
|
|
"client_ip": _client_ip(request),
|
||
|
|
"user_agent": request.META.get("HTTP_USER_AGENT", "")[:200],
|
||
|
|
"user_id": getattr(user, "id", None) if user and user.is_authenticated else None,
|
||
|
|
},
|
||
|
|
)
|
||
|
|
return response
|
||
|
|
|
||
|
|
|
||
|
|
def _client_ip(request: HttpRequest) -> str:
|
||
|
|
"""
|
||
|
|
Resolve the client IP.
|
||
|
|
|
||
|
|
``X-Forwarded-For`` is only consulted because the API always sits behind a
|
||
|
|
reverse proxy we control; the left-most entry is the original client.
|
||
|
|
"""
|
||
|
|
forwarded = request.META.get("HTTP_X_FORWARDED_FOR")
|
||
|
|
if forwarded:
|
||
|
|
return forwarded.split(",")[0].strip()[:45]
|
||
|
|
return request.META.get("REMOTE_ADDR", "")[:45]
|