🐛 Process canonical endpoint in fastapi case when collecting prometheus metrics

packages/service-library/src/servicelib/aiohttp/monitoring.py

@@ -2,8 +2,8 @@
 
 import asyncio
 import logging
-import time
 from collections.abc import Awaitable, Callable
+from time import perf_counter
 from typing import Final
 
 from aiohttp import web
@@ -67,7 +67,7 @@ async def middleware_handler(request: web.Request, handler: Handler):
         canonical_endpoint = request.path
         if request.match_info.route.resource:
             canonical_endpoint = request.match_info.route.resource.canonical
-        start_time = time.time()
+        start_time = perf_counter()
         try:
             if enter_middleware_cb:
                 with log_catch(logger=log, reraise=False):
@@ -111,14 +111,15 @@ async def middleware_handler(request: web.Request, handler: Handler):
             raise resp from exc
 
         finally:
-            resp_time_secs: float = time.time() - start_time
+            response_latency_seconds = perf_counter() - start_time
 
             record_response_metrics(
                 metrics=metrics,
                 method=request.method,
                 endpoint=canonical_endpoint,
                 user_agent=user_agent,
                 http_status=resp.status,
+                response_latency_seconds=response_latency_seconds,
             )
 
             if exit_middleware_cb:
@@ -133,7 +134,7 @@ async def middleware_handler(request: web.Request, handler: Handler):
                     request.remote,
                     request.method,
                     request.path,
-                    resp_time_secs,
+                    response_latency_seconds,
                     resp.status,
                     exc_info=log_exception,
                     stack_info=True,

packages/service-library/src/servicelib/fastapi/monitoring.py

@@ -3,6 +3,7 @@
 import asyncio
 import logging
 from collections.abc import AsyncIterator
+from time import perf_counter
 from typing import Final
 
 from fastapi import FastAPI, Request, Response, status
@@ -39,10 +40,12 @@ async def dispatch(
         self, request: Request, call_next: RequestResponseEndpoint
     ) -> Response:
         canonical_endpoint = request.url.path
+
         user_agent = request.headers.get(
             X_SIMCORE_USER_AGENT, UNDEFINED_DEFAULT_SIMCORE_USER_AGENT_VALUE
         )
 
+        start_time = perf_counter()
         try:
             with record_request_metrics(
                 metrics=self.metrics,
@@ -52,18 +55,26 @@ async def dispatch(
             ):
                 response = await call_next(request)
                 status_code = response.status_code
+
+                # path_params are not available before calling call_next
+                # https://github.com/encode/starlette/issues/685#issuecomment-550240999
+                for k, v in request.path_params.items():
+                    key = "{" + k + "}"
+                    canonical_endpoint = canonical_endpoint.replace(f"/{v}", f"/{key}")
         except Exception:  # pylint: disable=broad-except
             # NOTE: The prometheus metrics middleware should be "outside" exception handling
             # middleware. See https://fastapi.tiangolo.com/advanced/middleware/#adding-asgi-middlewares
             status_code = status.HTTP_500_INTERNAL_SERVER_ERROR
             raise
         finally:
+            reponse_latency_seconds = perf_counter() - start_time
             record_response_metrics(
                 metrics=self.metrics,
                 method=request.method,
                 endpoint=canonical_endpoint,
                 user_agent=user_agent,
                 http_status=status_code,
+                response_latency_seconds=reponse_latency_seconds,
             )
 
         return response

packages/service-library/src/servicelib/prometheus_metrics.py

@@ -1,7 +1,6 @@
 from collections.abc import Iterator
 from contextlib import contextmanager
 from dataclasses import dataclass
-from time import perf_counter
 
 from opentelemetry import trace
 from prometheus_client import (
@@ -132,20 +131,8 @@ def record_request_metrics(
     with metrics.in_flight_requests.labels(
         method, endpoint, user_agent
     ).track_inprogress():
-
-        start = perf_counter()
-
         yield
 
-        amount = perf_counter() - start
-        exemplar = _get_exemplar()
-        metrics.response_latency_with_labels.labels(
-            method, endpoint, user_agent
-        ).observe(amount=amount, exemplar=exemplar)
-        metrics.response_latency_detailed_buckets.observe(
-            amount=amount, exemplar=exemplar
-        )
-
 
 def record_response_metrics(
     *,
@@ -154,8 +141,15 @@ def record_response_metrics(
     endpoint: str,
     user_agent: str,
     http_status: int,
+    response_latency_seconds: float,
 ) -> None:
     exemplar = _get_exemplar()
     metrics.request_count.labels(method, endpoint, http_status, user_agent).inc(
         exemplar=exemplar
     )
+    metrics.response_latency_with_labels.labels(method, endpoint, user_agent).observe(
+        amount=response_latency_seconds, exemplar=exemplar
+    )
+    metrics.response_latency_detailed_buckets.observe(
+        amount=response_latency_seconds, exemplar=exemplar
+    )