"""Tests for :class:`app.middleware.AccessLogMiddleware`. structlog in this project is wired through ``PrintLoggerFactory`` (see :mod:`app.logging_config`), which emits rendered log lines to stdout. We therefore capture via pytest's ``capsys`` fixture — the same pattern :mod:`tests.test_email_service` uses for its dev-fallback assertion. Coverage: - Every request produces an ``http_request`` log line including the method, the path, and a status code. - ``/healthz`` is skipped (reduces compose healthcheck noise). - Magic-link consume paths have their token segment redacted to ```` before the line is emitted. """ from __future__ import annotations import re import pytest from fastapi.testclient import TestClient from app.logging_config import configure_logging from app.main import app # ConsoleRenderer wraps keys / values in ANSI colour escapes; strip them # so substring assertions can pattern-match on the semantic payload # rather than the rendering. _ANSI_RE = re.compile(r"\x1b\[[0-9;]*m") def _strip_ansi(text: str) -> str: """Return ``text`` with ANSI terminal escapes removed.""" return _ANSI_RE.sub("", text) @pytest.fixture def client(capsys: pytest.CaptureFixture[str]) -> TestClient: """Return a TestClient with structlog reconfigured for capture. The test harness may be left in any state by a previously run test; re-calling :func:`configure_logging` guarantees the ConsoleRenderer pipeline is active so ``capsys`` actually sees the log lines. ``capsys.readouterr()`` is called on entry so existing startup output (``app_started``, etc.) doesn't leak into the per-test assertions. """ configure_logging("development") capsys.readouterr() # drain any buffered prior output return TestClient(app) def test_request_emits_http_request_event( client: TestClient, capsys: pytest.CaptureFixture[str] ) -> None: """A single GET to / produces an ``http_request`` log line.""" response = client.get("/") assert response.status_code == 200 out = _strip_ansi(capsys.readouterr().out) assert "http_request" in out # The structured keys must also be present in the rendered line. assert "method=GET" in out assert "path=/" in out assert "status_code=200" in out def test_healthz_is_skipped( client: TestClient, capsys: pytest.CaptureFixture[str] ) -> None: """``/healthz`` requests do NOT produce an ``http_request`` event. Compose / Docker health probes hit this path every 30s; logging every probe would drown out real traffic. """ response = client.get("/healthz") assert response.status_code == 200 out = _strip_ansi(capsys.readouterr().out) assert "http_request" not in out, ( "AccessLogMiddleware should skip /healthz, but emitted: " f"{out!r}" ) def test_consume_path_is_redacted( client: TestClient, capsys: pytest.CaptureFixture[str] ) -> None: """Magic-link consume tokens must never appear in the access log. We hit the consume route with a synthetic token; the downstream handler will return 4xx (token doesn't match any DB row), but the middleware still runs — and its log line must carry the redacted path, not the raw token. """ fake_token = "super-secret-token-value-that-must-not-leak-1234567890" response = client.get(f"/admin/auth/consume/{fake_token}") # We don't care what status the router returns — only that the log # entry for this request redacts the token. assert response.status_code in (302, 303, 400, 401, 403, 404), ( f"unexpected status {response.status_code}" ) out = _strip_ansi(capsys.readouterr().out) assert "http_request" in out assert "/admin/auth/consume/" in out assert fake_token not in out, ( "raw magic-link token appeared in access log output" )