feat: add authorization monitoring metrics

Signed-off-by: Major Hayden <major@redhat.com>

Author: major

src/authorization/middleware.py

@@ -1,5 +1,6 @@
 """Authorization middleware and decorators."""
 
+import time
 from collections.abc import Callable
 from functools import lru_cache, wraps
 from typing import Any, Optional
@@ -18,6 +19,7 @@
 )
 from configuration import configuration
 from log import get_logger
+from metrics import recording
 from models.config import Action
 from models.responses import (
     ForbiddenResponse,
@@ -124,39 +126,50 @@ async def _perform_authorization_check(
         HTTPException: with 403 Forbidden if the resolved roles are not
                        permitted to perform `action`.
     """
-    role_resolver, access_resolver = get_authorization_resolvers()
+    start_time = time.monotonic()
+    result = "error"
 
     try:
-        auth = kwargs["auth"]
-    except KeyError as exc:
-        logger.error(
-            "Authorization only allowed on endpoints that accept "
-            "'auth: Any = Depends(get_auth_dependency())'"
+        role_resolver, access_resolver = get_authorization_resolvers()
+
+        try:
+            auth = kwargs["auth"]
+        except KeyError as exc:
+            logger.error(
+                "Authorization only allowed on endpoints that accept "
+                "'auth: Any = Depends(get_auth_dependency())'"
+            )
+            response = InternalServerErrorResponse.generic()
+            raise HTTPException(**response.model_dump()) from exc
+
+        # Everyone gets the everyone (aka *) role
+        everyone_roles = {"*"}
+
+        user_roles = await role_resolver.resolve_roles(auth) | everyone_roles
+
+        if not access_resolver.check_access(action, user_roles):
+            response = ForbiddenResponse.endpoint(user_id=auth[0])
+            result = "denied"
+            raise HTTPException(**response.model_dump())
+
+        authorized_actions = access_resolver.get_actions(user_roles)
+
+        req: Optional[Request] = None
+        if "request" in kwargs and isinstance(kwargs["request"], Request):
+            req = kwargs["request"]
+        else:
+            for arg in args:
+                if isinstance(arg, Request):
+                    req = arg
+                    break
+        if req is not None:
+            req.state.authorized_actions = authorized_actions
+        result = "success"
+    finally:
+        recording.record_authorization_check(action.value, result)
+        recording.record_authorization_duration(
+            action.value, result, time.monotonic() - start_time
         )
-        response = InternalServerErrorResponse.generic()
-        raise HTTPException(**response.model_dump()) from exc
-
-    # Everyone gets the everyone (aka *) role
-    everyone_roles = {"*"}
-
-    user_roles = await role_resolver.resolve_roles(auth) | everyone_roles
-
-    if not access_resolver.check_access(action, user_roles):
-        response = ForbiddenResponse.endpoint(user_id=auth[0])
-        raise HTTPException(**response.model_dump())
-
-    authorized_actions = access_resolver.get_actions(user_roles)
-
-    req: Optional[Request] = None
-    if "request" in kwargs and isinstance(kwargs["request"], Request):
-        req = kwargs["request"]
-    else:
-        for arg in args:
-            if isinstance(arg, Request):
-                req = arg
-                break
-    if req is not None:
-        req.state.authorized_actions = authorized_actions
 
 
 def authorize(action: Action) -> Callable:

src/metrics/__init__.py

@@ -55,3 +55,17 @@
     "LLM tokens received",
     ["provider", "model", "endpoint"],
 )
+
+# Counter to track authorization checks by protected action.
+authorization_checks_total = Counter(
+    "ls_authorization_checks_total",
+    "Authorization checks",
+    ["action", "result"],
+)
+
+# Histogram to measure authorization check latency by protected action.
+authorization_duration_seconds = Histogram(
+    "ls_authorization_duration_seconds",
+    "Authorization check duration",
+    ["action", "result"],
+)

src/metrics/recording.py

@@ -109,3 +109,30 @@ def record_llm_token_usage(
         )
     except (AttributeError, TypeError, ValueError):
         logger.warning("Failed to update token metrics", exc_info=True)
+
+
+def record_authorization_check(action: str, result: str) -> None:
+    """Record one authorization check.
+
+    Args:
+        action: Protected action name.
+        result: Bounded result label, such as ``success`` or ``denied``.
+    """
+    try:
+        metrics.authorization_checks_total.labels(action, result).inc()
+    except (AttributeError, TypeError, ValueError):
+        logger.warning("Failed to update authorization metric", exc_info=True)
+
+
+def record_authorization_duration(action: str, result: str, duration: float) -> None:
+    """Record authorization check duration.
+
+    Args:
+        action: Protected action name.
+        result: Bounded result label, such as ``success`` or ``denied``.
+        duration: Authorization check duration in seconds.
+    """
+    try:
+        metrics.authorization_duration_seconds.labels(action, result).observe(duration)
+    except (AttributeError, TypeError, ValueError):
+        logger.warning("Failed to update authorization duration metric", exc_info=True)

tests/unit/metrics/test_recording.py

@@ -1,10 +1,38 @@
 """Unit tests for Prometheus metric recording helpers."""
 
+from collections.abc import Callable
+from dataclasses import dataclass
+from typing import Any
+
+import pytest
 from pytest_mock import MockerFixture
 
 from metrics import recording
 
 
+@dataclass(frozen=True)
+class CounterRecorderCase:
+    """Expected behavior for a counter-style metric recorder."""
+
+    metric_path: str
+    recorder: Callable[..., None]
+    args: tuple[object, ...]
+    labels: tuple[object, ...]
+    warning_message: str
+
+
+@dataclass(frozen=True)
+class HistogramRecorderCase:
+    """Expected behavior for a histogram-style metric recorder."""
+
+    metric_path: str
+    recorder: Callable[..., None]
+    args: tuple[object, ...]
+    labels: tuple[object, ...]
+    duration: float
+    warning_message: str
+
+
 def test_measure_response_duration_records_timer(mocker: MockerFixture) -> None:
     """Test that response duration measurement uses the path label timer."""
     mock_timer = mocker.MagicMock()
@@ -159,3 +187,78 @@ def test_record_llm_token_usage_logs_metric_errors(mocker: MockerFixture) -> Non
     mock_logger.warning.assert_called_once_with(
         "Failed to update token metrics", exc_info=True
     )
+
+
+@pytest.fixture(name="recording_logger")
+def recording_logger_fixture(mocker: MockerFixture) -> Any:
+    """Patch the metric recording logger for failure assertions."""
+    return mocker.patch("metrics.recording.logger")
+
+
+@pytest.mark.parametrize(
+    "case",
+    [
+        CounterRecorderCase(
+            metric_path="metrics.recording.metrics.authorization_checks_total",
+            recorder=recording.record_authorization_check,
+            args=("responses", "success"),
+            labels=("responses", "success"),
+            warning_message="Failed to update authorization metric",
+        ),
+    ],
+)
+def test_counter_recorders_update_metrics_and_log_errors(
+    mocker: MockerFixture,
+    recording_logger: Any,
+    case: CounterRecorderCase,
+) -> None:
+    """Test new single-counter helpers with shared success and failure coverage."""
+    mock_metric = mocker.patch(case.metric_path)
+
+    case.recorder(*case.args)
+
+    mock_metric.labels.assert_called_once_with(*case.labels)
+    mock_metric.labels.return_value.inc.assert_called_once()
+
+    mock_metric.reset_mock()
+    mock_metric.labels.return_value.inc.side_effect = AttributeError("missing")
+    case.recorder(*case.args)
+
+    recording_logger.warning.assert_called_once_with(
+        case.warning_message, exc_info=True
+    )
+
+
+@pytest.mark.parametrize(
+    "case",
+    [
+        HistogramRecorderCase(
+            metric_path="metrics.recording.metrics.authorization_duration_seconds",
+            recorder=recording.record_authorization_duration,
+            args=("responses", "success", 0.25),
+            labels=("responses", "success"),
+            duration=0.25,
+            warning_message="Failed to update authorization duration metric",
+        ),
+    ],
+)
+def test_histogram_recorders_observe_metrics_and_log_errors(
+    mocker: MockerFixture,
+    recording_logger: Any,
+    case: HistogramRecorderCase,
+) -> None:
+    """Test new histogram helpers with shared success and failure coverage."""
+    mock_metric = mocker.patch(case.metric_path)
+
+    case.recorder(*case.args)
+
+    mock_metric.labels.assert_called_once_with(*case.labels)
+    mock_metric.labels.return_value.observe.assert_called_once_with(case.duration)
+
+    mock_metric.reset_mock()
+    mock_metric.labels.return_value.observe.side_effect = TypeError("bad")
+    case.recorder(*case.args)
+
+    recording_logger.warning.assert_called_once_with(
+        case.warning_message, exc_info=True
+    )