chicken_babies_site/app/middleware/access_log.py

"""Structured access-log middleware.

Emits a single ``http_request`` INFO event per request, capturing the
HTTP verb, path, status code, wall-clock duration, client IP, and a
truncated user-agent. The goal is a compact but auditable trail of
production traffic without the noise of a traditional access log and
without ever writing secrets to disk.

Key design choices:

- **No bodies, no query strings.** We deliberately skip query strings
  entirely to avoid leaking tokens that might end up there in future
  (the magic-link consume route keeps its token in the path, so we
  redact that explicitly below).
- **Magic-link path redaction.** Requests to
  ``/admin/auth/consume/{token}`` have the token segment replaced with
  ``<redacted>`` before logging. ``CLAUDE.md`` forbids logging raw
  tokens anywhere.
- **Skip ``/healthz``.** Compose / Docker health probes hit this every
  few seconds. Logging each one drowns out real traffic.
- **Exceptions still get logged.** If the downstream handler raises,
  we record a ``status_code=500`` entry before re-raising so no failed
  request vanishes silently.
"""

from __future__ import annotations

import time

import structlog
from fastapi import Request
from fastapi.responses import Response
from starlette.middleware.base import BaseHTTPMiddleware


logger = structlog.get_logger(__name__)


# Prefix used to recognise magic-link consume URLs whose trailing token
# segment must be redacted before logging.
_CONSUME_PREFIX: str = "/admin/auth/consume/"

# Path we skip entirely to reduce health-probe log noise.
_SKIP_PATH: str = "/healthz"

# User-agent strings are unbounded; cap to 256 chars so a hostile client
# can't bloat log lines to arbitrary size.
_UA_MAX: int = 256


def _redact_path(path: str) -> str:
    """Return ``path`` with magic-link tokens replaced by ``<redacted>``.

    The consume URL is ``/admin/auth/consume/{token}``; everything after
    the prefix is swapped out. We preserve the prefix so log readers can
    still see which route was hit.
    """
    if path.startswith(_CONSUME_PREFIX):
        return _CONSUME_PREFIX + "<redacted>"
    return path


class AccessLogMiddleware(BaseHTTPMiddleware):
    """Log one ``http_request`` event per completed request.

    Installed outermost in :mod:`app.main` so the timing measurement
    covers the entire downstream middleware stack, including security
    headers and CSRF cookie work.
    """

    async def dispatch(self, request: Request, call_next):
        """Time the request, log a structured event, reraise on failure."""
        path: str = request.url.path

        # Early exit for health probes — don't even record timing.
        if path == _SKIP_PATH:
            return await call_next(request)

        method: str = request.method
        client_ip: str = request.client.host if request.client else ""
        user_agent: str = request.headers.get("user-agent", "")[:_UA_MAX]
        redacted_path: str = _redact_path(path)

        start: float = time.monotonic()
        try:
            response: Response = await call_next(request)
        except Exception:
            duration_ms = int((time.monotonic() - start) * 1000)
            # Record the failure before re-raising so unhandled exceptions
            # don't vanish from the log. Status is synthetic (500) because
            # the framework hasn't written a response yet at this point.
            logger.info(
                "http_request",
                method=method,
                path=redacted_path,
                status_code=500,
                duration_ms=duration_ms,
                client_ip=client_ip,
                user_agent=user_agent,
            )
            raise

        duration_ms = int((time.monotonic() - start) * 1000)
        logger.info(
            "http_request",
            method=method,
            path=redacted_path,
            status_code=response.status_code,
            duration_ms=duration_ms,
            client_ip=client_ip,
            user_agent=user_agent,
        )
        return response