Fix #768: log validation exceptions (HTTP 422) (#780)

Author: leplatrem

jbi/app.py

@@ -8,7 +8,10 @@
 from typing import Any, Awaitable, Callable
 
 import sentry_sdk
-from fastapi import FastAPI, Request, Response
+from fastapi import FastAPI, Request, Response, status
+from fastapi.encoders import jsonable_encoder
+from fastapi.exceptions import RequestValidationError
+from fastapi.responses import JSONResponse
 from fastapi.staticfiles import StaticFiles
 
 from jbi.environment import get_settings, get_version
@@ -20,6 +23,8 @@
 settings = get_settings()
 version_info = get_version()
 
+logger = logging.getLogger(__name__)
+
 
 def traces_sampler(sampling_context: dict[str, Any]) -> float:
     """Function to dynamically set Sentry sampling rates"""
@@ -75,7 +80,29 @@ async def request_summary(
         return response
     except Exception as exc:
         log_fields = format_request_summary_fields(
-            request, request_time, status_code=500
+            request, request_time, status_code=status.HTTP_500_INTERNAL_SERVER_ERROR
         )
         summary_logger.info(exc, extra=log_fields)
         raise
+
+
+@app.exception_handler(RequestValidationError)
+async def validation_exception_handler(
+    request: Request, exc: RequestValidationError
+) -> Response:
+    """
+    Override the default exception handler for validation
+    errors in order to log some information about malformed
+    requests.
+    """
+    logger.error(
+        "invalid incoming request: %s",
+        exc,
+        extra={
+            "errors": exc.errors(),
+        },
+    )
+    return JSONResponse(
+        status_code=status.HTTP_422_UNPROCESSABLE_ENTITY,
+        content={"detail": jsonable_encoder(exc.errors())},
+    )

tests/unit/test_app.py

@@ -28,6 +28,21 @@ def test_request_summary_is_logged(caplog):
             assert summary.querystring == "{}"
 
 
+def test_422_errors_are_logged(webhook_create_example, caplog):
+    webhook_create_example.bug = None
+
+    with TestClient(app) as anon_client:
+        with caplog.at_level(logging.INFO):
+            anon_client.post("/bugzilla_webhook", data=webhook_create_example.json())
+
+    logged = [r for r in caplog.records if r.name == "jbi.app"][0]
+    assert logged.errors[0]["loc"] == ("body", "bug")
+    assert (
+        logged.errors[0]["msg"]
+        == "Input should be a valid dictionary or object to extract fields from"
+    )
+
+
 def test_request_summary_defaults_user_agent_to_empty_string(caplog):
     with caplog.at_level(logging.INFO):
         with TestClient(app) as anon_client: