Reisacher-Forderung/app/http_logging.py

"""ASGI response logging outside authentication, without consuming request bodies."""

import logging
import time
from uuid import uuid4

from starlette.responses import PlainTextResponse

from .logging_setup import request_context

logger = logging.getLogger(__name__)


class RequestLoggingMiddleware:
    def __init__(self, app):
        self.app = app

    async def __call__(self, scope, receive, send):
        if scope["type"] != "http":
            return await self.app(scope, receive, send)
        request_id = uuid4().hex
        scope.setdefault("state", {})["request_id"] = request_id
        token = request_context.set({"request_id": request_id, "scope": scope})
        started = time.perf_counter()
        status, completed, failed = None, False, False

        def finish(outcome, level=None):
            nonlocal completed
            if completed:
                return
            completed = True
            level = level or (
                logging.ERROR
                if status and status >= 500
                else (
                    logging.WARNING
                    if status and status >= 400
                    else (
                        logging.DEBUG
                        if scope["path"] == "/health" or scope["path"].startswith("/static/")
                        else logging.INFO
                    )
                )
            )
            logger.log(
                level,
                "HTTP-Anfrage abgeschlossen",
                extra={
                    "event": "http_completed",
                    "status": status,
                    "duration_ms": round((time.perf_counter() - started) * 1000, 2),
                    "outcome": outcome,
                },
            )

        async def logged_send(message):
            nonlocal status
            if message["type"] == "http.response.start":
                message = dict(
                    message,
                    headers=[
                        (key, value) for key, value in message.get("headers", []) if key.lower() != b"x-request-id"
                    ]
                    + [(b"x-request-id", request_id.encode("ascii"))],
                )
            await send(message)
            if message["type"] == "http.response.start":
                status = message["status"]
            if message["type"] == "http.response.body" and not message.get("more_body", False):
                finish("completed")

        try:
            await self.app(scope, receive, logged_send)
        except Exception:
            failed = True
            streaming = status is not None
            logger.exception(
                "HTTP-Verarbeitung fehlgeschlagen",
                extra={"event": "response_stream_error" if streaming else "unhandled_exception"},
            )
            if status is None:
                status = 500
            if not completed:
                finish("stream_failed" if streaming else "failed", logging.ERROR)
            raise
        finally:
            if not completed and not failed:
                finish("aborted", logging.WARNING)
            request_context.reset(token)


async def unhandled_error_response(request, exc):
    request_id = getattr(request.state, "request_id", None)
    return PlainTextResponse(
        "Internal Server Error", status_code=500, headers={"X-Request-ID": request_id} if request_id else {}
    )


def install_request_logging(app):
    app.add_middleware(RequestLoggingMiddleware)
    app.add_exception_handler(Exception, unhandled_error_response)