benevoles/backend/app/request_logging.py

"""Journal des requêtes HTTP — une ligne par requête, pour diagnostiquer
après coup une erreur rencontrée par un utilisateur (voir CLAUDE.md § 8,
RGPD : identifiants et codes seulement).

- Chaque requête reçoit un identifiant (`X-Request-ID`, repris s'il est
  fourni et bien formé, généré sinon), renvoyé dans l'en-tête de la réponse
  et préfixé à toutes les lignes de log émises pendant son traitement
  (`app/logging_config.py:request_id_var`).
- La ligne d'accès donne la route **modèle** (`/editions/{edition_id}/…`) et
  ses paramètres d'identifiants, jamais l'URL brute : la chaîne de requête
  peut porter un jeton (`access_token` du formulaire public), et les
  paramètres de chemin nommés `*token*` (inscription en attente) sont omis.
- Code d'erreur métier (`detail.code`) et compte connecté ajoutés quand ils
  existent ; détails d'une erreur de validation 422 (emplacement + type,
  jamais la valeur saisie).
- Une exception non gérée est journalisée avec sa trace et renvoie un 500
  JSON `{detail: {code: "error.internal", request_id}}` plutôt qu'un texte
  brut.
"""

import logging
import re
import time
import uuid

from fastapi import FastAPI, HTTPException, Request
from fastapi.exception_handlers import (
    http_exception_handler,
    request_validation_exception_handler,
)
from fastapi.exceptions import RequestValidationError
from fastapi.responses import JSONResponse
from starlette.exceptions import HTTPException as StarletteHTTPException

from app.logging_config import request_id_var

logger = logging.getLogger("app.request")

REQUEST_ID_HEADER = "X-Request-ID"
_INCOMING_ID = re.compile(r"^[A-Za-z0-9-]{8,64}$")
# Sondes de santé (Docker, Caddy) : pas une ligne INFO toutes les 10 s.
_QUIET_PATHS = {"/health"}


def _route_label(request: Request) -> str:
    route = request.scope.get("route")
    template = getattr(route, "path", None) or "<non routé>"
    params = {
        key: value
        for key, value in (request.scope.get("path_params") or {}).items()
        if "token" not in key
    }
    if not params:
        return template
    return f"{template} " + " ".join(f"{k}={v}" for k, v in params.items())


def install_request_logging(app: FastAPI) -> None:
    @app.middleware("http")
    async def log_requests(request: Request, call_next):
        incoming = request.headers.get(REQUEST_ID_HEADER, "")
        request_id = incoming if _INCOMING_ID.match(incoming) else uuid.uuid4().hex[:12]
        reset = request_id_var.set(request_id)
        started = time.monotonic()
        try:
            try:
                response = await call_next(request)
            except Exception:
                logger.exception(
                    "Exception non gérée sur %s %s", request.method, _route_label(request)
                )
                response = JSONResponse(
                    status_code=500,
                    content={"detail": {"code": "error.internal", "request_id": request_id}},
                )
            duration_ms = (time.monotonic() - started) * 1000
            response.headers[REQUEST_ID_HEADER] = request_id

            status_code = response.status_code
            if status_code >= 500:
                level = logging.ERROR
            elif status_code >= 400:
                level = logging.WARNING
            elif request.url.path in _QUIET_PATHS or request.method == "OPTIONS":
                level = logging.DEBUG
            else:
                level = logging.INFO
            extras = []
            error_code = getattr(request.state, "error_code", None)
            if error_code:
                extras.append(f"code={error_code}")
            account_id = getattr(request.state, "account_id", None)
            if account_id:
                extras.append(f"compte={account_id}")
            logger.log(
                level,
                "%s %s → %d (%d ms)%s",
                request.method,
                _route_label(request),
                status_code,
                duration_ms,
                (" " + " ".join(extras)) if extras else "",
            )
            return response
        finally:
            request_id_var.reset(reset)

    @app.exception_handler(StarletteHTTPException)
    async def log_http_exception(request: Request, exc: HTTPException):
        detail = exc.detail
        if isinstance(detail, dict) and detail.get("code"):
            request.state.error_code = detail["code"]
            violations = detail.get("violations")
            if violations:
                # Codes de violation seulement (`SHIFT_OVERLAP`…) : les
                # paramètres peuvent porter des horaires, pas utiles ici.
                request.state.error_code += " violations=" + ",".join(
                    sorted({str(v.get("code")) for v in violations if isinstance(v, dict)})
                )
        return await http_exception_handler(request, exc)

    @app.exception_handler(RequestValidationError)
    async def log_validation_error(request: Request, exc: RequestValidationError):
        # Emplacement + type d'erreur, jamais `input` (la valeur saisie, qui
        # peut être un nom, un email…).
        request.state.error_code = "validation " + "; ".join(
            f"{'.'.join(str(p) for p in err.get('loc', ()))}:{err.get('type')}"
            for err in exc.errors()[:10]
        )
        return await request_validation_exception_handler(request, exc)