Move rejection logging helpers out of the exception handlers

Author: thomas-samoht

app/errors/handlers.py

@@ -9,6 +9,7 @@
 
 from app.errors.fhir import FHIRError
 from app.errors.mapping import DEFAULT_SPEC, EXCEPTION_MAP, UNEXPECTED_ERROR_MESSAGE, spec_for
+from app.logging.rejections import log_rejection, summarize_reason
 from app.models.fhir.resources.operation_outcome.resource import (
     OperationOutcome,
     OperationOutcomeDetail,
@@ -17,34 +18,11 @@
 
 logger = logging.getLogger(__name__)
 
-_DENIAL_STATUSES = frozenset({401, 403})
-
-
-def _summarize_reason(exc: Exception) -> str:
-    if isinstance(exc, RequestValidationError):
-        reasons = [
-            f"{'.'.join(str(loc) for loc in err.get('loc', ()))}: {err.get('msg', '')}".strip(" :")
-            for err in exc.errors()
-        ]
-        return "; ".join(r for r in reasons if r) or "validation error"
-    return str(exc)
-
-
-def log_rejection(status_code: int, exc: Exception) -> None:
-    level = logging.WARNING if status_code in _DENIAL_STATUSES else logging.INFO
-    logger.log(
-        level,
-        "Request rejected with %s (%s): %s",
-        status_code,
-        type(exc).__name__,
-        _summarize_reason(exc),
-    )
-
 
 def handle_mapped_exception(request: Request, exc: Exception) -> JSONResponse:
     spec = spec_for(exc)
     status_code = spec.http_status
-    log_rejection(status_code, exc)
+    log_rejection(status_code, exc, summarize_reason(exc))
 
     if "fhir" in request.url.path:
         fhir_error = FHIRError(severity=spec.severity, code=spec.fhir_code, msg=str(exc))
@@ -60,7 +38,7 @@ def handle_mapped_exception(request: Request, exc: Exception) -> JSONResponse:
 def handle_request_validation_exception(req: Request, exc: RequestValidationError) -> JSONResponse:
     path = req.url.path
     status_code = 422
-    log_rejection(status_code, exc)
+    log_rejection(status_code, exc, summarize_reason(exc))
     if "fhir" in path:
         issues = []
 

app/logging/rejections.py

@@ -0,0 +1,23 @@
+import logging
+
+from fastapi.exceptions import RequestValidationError
+from pydantic import ValidationError
+
+logger = logging.getLogger(__name__)
+
+_DENIAL_STATUSES = frozenset({401, 403})
+
+
+def summarize_reason(exc: Exception) -> str:
+    if isinstance(exc, (RequestValidationError, ValidationError)):
+        reasons = [
+            f"{'.'.join(str(loc) for loc in err.get('loc', ()))}: {err.get('msg', '')}".strip(" :")
+            for err in exc.errors()
+        ]
+        return "; ".join(r for r in reasons if r) or "validation error"
+    return str(exc)
+
+
+def log_rejection(status_code: int, exc: Exception, reason: str) -> None:
+    level = logging.WARNING if status_code in _DENIAL_STATUSES else logging.INFO
+    logger.log(level, "Request rejected with %s (%s): %s", status_code, type(exc).__name__, reason)

app/services/fhir/bundle.py

@@ -6,9 +6,9 @@
 import gfmodules.logging as gflog
 from pydantic import ValidationError
 
-from app.errors.handlers import log_rejection
 from app.errors.mapping import DEFAULT_SPEC, UNEXPECTED_ERROR_MESSAGE, spec_for
 from app.logging.events import Log
+from app.logging.rejections import log_rejection, summarize_reason
 from app.models.auth.context import AuthContext
 from app.models.auth.data import AuthorizationScope
 from app.models.fhir.bundle import Bundle, BundleEntry, EntryRequest, EntryRequestDto, EntryResponse
@@ -143,7 +143,7 @@ def _entry_result(self, index: int, action: Callable[[], BundleEntry[Any]]) -> B
             if unexpected:
                 logger.exception("Bundle entry action failed")
             else:
-                log_rejection(spec.http_status, exc)
+                log_rejection(spec.http_status, exc, summarize_reason(exc))
 
             return BundleEntry(
                 response=EntryResponse.make_error_response(

tests/logging/test_rejections.py

@@ -0,0 +1,24 @@
+import pytest
+from pydantic import BaseModel, ValidationError
+
+from app.logging.rejections import summarize_reason
+
+
+class _Model(BaseModel):
+    values: list[int]
+
+
+def _validation_error(values: list[str]) -> ValidationError:
+    with pytest.raises(ValidationError) as caught:
+        _Model.model_validate({"values": values})
+    return caught.value
+
+
+def test_summarizes_a_validation_error_without_its_input() -> None:
+    reason = summarize_reason(_validation_error(["secret-input"]))
+
+    assert reason == "values.0: Input should be a valid integer, unable to parse string as an integer"
+
+
+def test_summarizes_a_plain_exception_by_its_message() -> None:
+    assert summarize_reason(RuntimeError("boom")) == "boom"