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.api.responses.error import (
     ForbiddenResponse,
     InternalServerErrorResponse,
@@ -27,6 +29,31 @@
 logger = get_logger(__name__)
 
 
+def _record_authorization_metrics(
+    action: Action,
+    result: str,
+    start_time: float,
+) -> None:
+    """Record authorization metrics without affecting request authorization flow.
+
+    Args:
+        action: Protected action being authorized.
+        result: Authorization result label.
+        start_time: Monotonic timestamp captured before authorization began.
+    """
+    duration = time.monotonic() - start_time
+
+    try:
+        recording.record_authorization_check(action.value, result)
+    except Exception:  # pylint: disable=broad-exception-caught
+        logger.warning("Failed to record authorization check metric", exc_info=True)
+
+    try:
+        recording.record_authorization_duration(action.value, result, duration)
+    except Exception:  # pylint: disable=broad-exception-caught
+        logger.warning("Failed to record authorization duration metric", exc_info=True)
+
+
 @lru_cache(maxsize=1)
 def get_authorization_resolvers() -> tuple[RolesResolver, AccessResolver]:
     """Get authorization resolvers from configuration (cached).
@@ -124,39 +151,47 @@ 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())'"
-        )
-        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
+        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:
+        _record_authorization_metrics(action, result, start_time)
 
 
 def authorize(action: Action) -> Callable:

src/metrics/__init__.py

@@ -22,6 +22,21 @@
     float("inf"),
 )
 
+AUTHORIZATION_DURATION_BUCKETS: Final[tuple[float, ...]] = (
+    0.001,
+    0.005,
+    0.01,
+    0.025,
+    0.05,
+    0.1,
+    0.25,
+    0.5,
+    1.0,
+    2.5,
+    5.0,
+    float("inf"),
+)
+
 # Counter to track REST API calls
 # This will be used to count how many times each API endpoint is called
 # and the status code of the response
@@ -73,9 +88,25 @@
 )
 
 # Histogram to measure the latency of direct LLM inference backend calls.
-llm_inference_duration_seconds = Histogram(
+llm_inference_duration_seconds: Final[Histogram] = Histogram(
     "ls_llm_inference_duration_seconds",
     "LLM inference call duration",
     ["provider", "model", "endpoint", "result"],
     buckets=LLM_INFERENCE_DURATION_BUCKETS,
 )
+
+# Counter to track authorization checks by bounded protected action and result.
+# Actions are normalized against the Action enum; results are success, denied, or error.
+authorization_checks_total: Final[Counter] = Counter(
+    "ls_authorization_checks_total",
+    "Authorization checks",
+    ["action", "result"],
+)
+
+# Histogram to measure authorization check latency by bounded action and result.
+authorization_duration_seconds: Final[Histogram] = Histogram(
+    "ls_authorization_duration_seconds",
+    "Authorization check duration",
+    ["action", "result"],
+    buckets=AUTHORIZATION_DURATION_BUCKETS,
+)

src/metrics/recording.py

@@ -7,12 +7,58 @@
 
 from collections.abc import Iterator
 from contextlib import contextmanager
+from typing import Final
 
 import metrics
 from log import get_logger
+from models.config import Action
 
 logger = get_logger(__name__)
 
+AUTHORIZATION_ACTION_UNKNOWN: Final[str] = "unknown"
+AUTHORIZATION_RESULT_SUCCESS: Final[str] = "success"
+AUTHORIZATION_RESULT_DENIED: Final[str] = "denied"
+AUTHORIZATION_RESULT_ERROR: Final[str] = "error"
+
+ALLOWED_AUTHORIZATION_ACTIONS: Final[frozenset[str]] = frozenset(
+    action.value for action in Action
+)
+ALLOWED_AUTHORIZATION_RESULTS: Final[frozenset[str]] = frozenset(
+    {
+        AUTHORIZATION_RESULT_SUCCESS,
+        AUTHORIZATION_RESULT_DENIED,
+        AUTHORIZATION_RESULT_ERROR,
+    }
+)
+
+
+def normalize_authorization_action(action: str) -> str:
+    """Normalize authorization action labels to the bounded Action enum values.
+
+    Args:
+        action: Raw authorization action label.
+
+    Returns:
+        The action when it is a known protected action, otherwise ``unknown``.
+    """
+    if action in ALLOWED_AUTHORIZATION_ACTIONS:
+        return action
+    return AUTHORIZATION_ACTION_UNKNOWN
+
+
+def normalize_authorization_result(result: str) -> str:
+    """Normalize authorization result labels to the bounded result set.
+
+    Args:
+        result: Raw authorization result label.
+
+    Returns:
+        The result when it is allowed, otherwise ``error``.
+    """
+    if result in ALLOWED_AUTHORIZATION_RESULTS:
+        return result
+    return AUTHORIZATION_RESULT_ERROR
+
 
 @contextmanager
 def measure_response_duration(path: str) -> Iterator[None]:
@@ -129,3 +175,40 @@ def record_llm_inference_duration(
         ).observe(duration)
     except (AttributeError, TypeError, ValueError):
         logger.warning("Failed to update LLM inference duration metric", exc_info=True)
+
+
+def record_authorization_check(action: str, result: str) -> None:
+    """Record one authorization check.
+
+    Args:
+        action: Protected action name. Unknown values are recorded as ``unknown``.
+        result: Bounded result label. Unknown values are recorded as ``error``.
+    """
+    normalized_action = normalize_authorization_action(action)
+    normalized_result = normalize_authorization_result(result)
+
+    try:
+        metrics.authorization_checks_total.labels(
+            normalized_action, normalized_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. Unknown values are recorded as ``unknown``.
+        result: Bounded result label. Unknown values are recorded as ``error``.
+        duration: Authorization check duration in seconds.
+    """
+    normalized_action = normalize_authorization_action(action)
+    normalized_result = normalize_authorization_result(result)
+
+    try:
+        metrics.authorization_duration_seconds.labels(
+            normalized_action, normalized_result
+        ).observe(duration)
+    except (AttributeError, TypeError, ValueError):
+        logger.warning("Failed to update authorization duration metric", exc_info=True)

tests/unit/authorization/test_middleware.py

@@ -322,6 +322,37 @@ async def test_everyone_role_added(
             Action.QUERY, {"employee", "*"}
         )
 
+    @pytest.mark.asyncio
+    async def test_authorization_metric_errors_do_not_mask_success(
+        self,
+        mocker: MockerFixture,
+        dummy_auth_tuple: AuthTuple,
+        mock_resolvers: tuple[MockType, MockType],
+    ) -> None:
+        """Test metric recorder failures do not fail successful authorization."""
+        mocker.patch(
+            "authorization.middleware.get_authorization_resolvers",
+            return_value=mock_resolvers,
+        )
+        mock_check = mocker.patch(
+            "authorization.middleware.recording.record_authorization_check",
+            side_effect=RuntimeError("metric backend unavailable"),
+        )
+        mock_duration = mocker.patch(
+            "authorization.middleware.recording.record_authorization_duration"
+        )
+        mock_logger = mocker.patch("authorization.middleware.logger")
+
+        await _perform_authorization_check(Action.QUERY, (), {"auth": dummy_auth_tuple})
+
+        mock_check.assert_called_once_with(Action.QUERY.value, "success")
+        mock_duration.assert_called_once()
+        assert mock_duration.call_args.args[:2] == (Action.QUERY.value, "success")
+        assert mock_duration.call_args.args[2] >= 0
+        mock_logger.warning.assert_called_once_with(
+            "Failed to record authorization check metric", exc_info=True
+        )
+
 
 class TestAuthorizeDecorator:
     """Test cases for authorize decorator."""