From cceeaf31d52ecde225004ff69adf61f6039ee6fc Mon Sep 17 00:00:00 2001
From: Siddhant Rath <sid@tamu.edu>
Date: Thu, 18 Jun 2026 09:37:10 -0500
Subject: [PATCH] fix(logging): make access-log http.route resolution
 framework-robust
MIME-Version: 1.0
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: 8bit

AccessLogMiddleware._route_template read the matched route's `.path`, which newer
Starlette (1.x — what the service container actually resolves at build time)
renamed to `.path_format` (`.path` is None) — so EVERY request logged
http.route="__unmatched__", silently defeating per-route observability. The unit
test missed it: its toy app uses a small middleware stack and directly-added
routes where `.path` is still set.

Prefer scope["route"] (the router records it) and read path_format-or-path, with
a fallback that maps scope["endpoint"] back to its route. Verified resolving real
templates (/auth/providers, /authz/resolve, /admin/activity; 404 -> __unmatched__)
on BOTH starlette 0.52 and 1.3. Adds a regression test pinning path_format/path.

Why now: the shipped image installs latest-within-pyproject (the Dockerfile
resolves from pyproject, not the frozen lock), so 0.13.0's container already runs
starlette 1.x — the prod access-log is broken until this lands.

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
---
 service/src/middleware/access_log.py | 31 +++++++++++++++-------
 service/tests/test_access_log_mw.py  | 39 +++++++++++++++++++++++++++-
 2 files changed, 59 insertions(+), 11 deletions(-)

diff --git a/service/src/middleware/access_log.py b/service/src/middleware/access_log.py
index 7cde389..a54fba0 100644
--- a/service/src/middleware/access_log.py
+++ b/service/src/middleware/access_log.py
@@ -29,17 +29,28 @@
 def _route_template(scope) -> str:
     """Low-cardinality route template (e.g. /echo/{name}).
 
-    Uses the endpoint Starlette recorded on the scope during routing and maps it
-    back to its route template — O(routes) identity checks, no regex re-match
-    (the router already did the matching). Unmatched requests resolve to a
-    constant placeholder rather than leaking the raw path.
+    Reads the route the router recorded on the scope during routing (no regex
+    re-match) and returns its template. Version-robust across the framework's
+    routing reworks: prefers ``scope["route"]`` (newer Starlette sets it) and
+    reads ``path_format`` (newer) or ``path`` (older); falls back to mapping the
+    recorded ``scope["endpoint"]`` back to its route. Unmatched requests (404 /
+    OPTIONS preflight) resolve to a constant placeholder rather than leaking the
+    raw path (which can carry PII and explode http.route cardinality).
     """
-    endpoint = scope.get("endpoint")
-    if endpoint is None:
-        return _UNMATCHED  # 404 / 405 / OPTIONS preflight — never log the raw path
-    for route in getattr(scope.get("app"), "routes", []):
-        if getattr(route, "endpoint", None) is endpoint:
-            return getattr(route, "path", None) or _UNMATCHED
+    route = scope.get("route")
+    if route is None:
+        endpoint = scope.get("endpoint")
+        if endpoint is not None:
+            for r in getattr(scope.get("app"), "routes", []):
+                if getattr(r, "endpoint", None) is endpoint:
+                    route = r
+                    break
+    if route is not None:
+        return (
+            getattr(route, "path_format", None)
+            or getattr(route, "path", None)
+            or _UNMATCHED
+        )
     return _UNMATCHED
 
 
diff --git a/service/tests/test_access_log_mw.py b/service/tests/test_access_log_mw.py
index c1987b0..5609eae 100644
--- a/service/tests/test_access_log_mw.py
+++ b/service/tests/test_access_log_mw.py
@@ -2,7 +2,44 @@
 from fastapi.testclient import TestClient
 from structlog.testing import capture_logs
 
-from src.middleware.access_log import AccessLogMiddleware
+from src.middleware.access_log import AccessLogMiddleware, _route_template
+
+
+class _FakeRoute:
+    def __init__(self, *, endpoint=None, path=None, path_format=None):
+        self.endpoint = endpoint
+        if path is not None:
+            self.path = path
+        if path_format is not None:
+            self.path_format = path_format
+
+
+def test_route_template_reads_path_format_then_path():
+    # Newer Starlette sets scope["route"] and exposes the template as path_format
+    # (route.path is None); older exposes it as path. Be robust to both — the
+    # regression that logged "__unmatched__" for every request came from reading
+    # only .path against a newer Starlette where it is None.
+    newer = _FakeRoute(path_format="/users/{id}")  # 1.x: path absent/None
+    assert _route_template({"route": newer}) == "/users/{id}"
+    older = _FakeRoute(path="/users/{id}")  # 0.x: only path
+    assert _route_template({"route": older}) == "/users/{id}"
+
+
+def test_route_template_falls_back_to_endpoint_mapping():
+    def ep():
+        pass
+
+    route = _FakeRoute(endpoint=ep, path_format="/echo/{name}")
+
+    class _App:
+        routes = [route]
+
+    # No scope["route"], but scope["endpoint"] + app.routes lets us recover it.
+    assert _route_template({"endpoint": ep, "app": _App()}) == "/echo/{name}"
+
+
+def test_route_template_unmatched_when_nothing_recorded():
+    assert _route_template({}) == "__unmatched__"  # 404 / OPTIONS preflight
 
 
 def _app():