[CDAPI-118]: Reintroduce Filter to add corr id to every log

Author: nhsd-rebecca-flynn

pathology-api/lambda_handler.py

@@ -114,35 +114,31 @@ def status() -> Response[str]:
 def post_result() -> Response[str]:
     correlation_id = app.current_event.headers.get(_CORRELATION_ID_HEADER)
 
-    _logger.info("RFL app = %s", app)
-
     if not correlation_id:
         raise ValueError(f"Missing required header: {_CORRELATION_ID_HEADER}")
-    elif not app.current_event.raw_path.__contains__("_status"):
-        set_correlation_id(correlation_id)
-
-    _logger.debug("Post result endpoint called.")
+    with set_correlation_id(correlation_id):
+        _logger.debug("Post result endpoint called.")
 
-    try:
-        payload = app.current_event.json_body
-    except JSONDecodeError as e:
-        raise ValidationError("Invalid payload provided.") from e
+        try:
+            payload = app.current_event.json_body
+        except JSONDecodeError as e:
+            raise ValidationError("Invalid payload provided.") from e
 
-    _logger.debug("Payload received: %s", payload)
+        _logger.debug("Payload received: %s", payload)
 
-    if payload is None:
-        raise ValidationError(
-            "Resources must be provided as a bundle of type 'document'"
-        )
+        if payload is None:
+            raise ValidationError(
+                "Resources must be provided as a bundle of type 'document'"
+            )
 
-    bundle = Bundle.model_validate(payload, by_alias=True)
+        bundle = Bundle.model_validate(payload, by_alias=True)
 
-    response = handle_request(bundle)
+        response = handle_request(bundle)
 
-    return _with_default_headers(
-        status_code=200,
-        body=response,
-    )
+        return _with_default_headers(
+            status_code=200,
+            body=response,
+        )
 
 
 def handler(data: dict[str, Any], context: LambdaContext) -> dict[str, Any]:

pathology-api/src/pathology_api/logging.py

@@ -1,10 +1,19 @@
+import logging
 from typing import Any, Protocol
 
 from aws_lambda_powertools import Logger
 
 from pathology_api.request_context import get_correlation_id
 
 
+class _CorrelationIdFilter(logging.Filter):
+    """Injects the current correlation ID into every log record."""
+
+    def filter(self, record: logging.LogRecord) -> bool:
+        record.correlation_id = get_correlation_id()
+        return True
+
+
 class LogProvider(Protocol):
     """Protocol defining required contract for a logger."""
 
@@ -22,5 +31,5 @@ def exception(self, msg: str, *args: Any, **kwargs: Any) -> None: ...
 def get_logger(service: str) -> LogProvider:
     """Get a configured logger instance."""
     logger = Logger(service=service, level="DEBUG", serialize_stacktrace=True)
-    logger.set_correlation_id(get_correlation_id())
+    logger.addFilter(_CorrelationIdFilter())
     return logger

pathology-api/src/pathology_api/test_request_context.py

@@ -2,10 +2,6 @@
 
 
 class TestSetAndGetCorrelationId:
-    def test_set_and_get_correlation_id_within_context(self) -> None:
-        with set_correlation_id("round-trip-test-123"):
-            assert get_correlation_id() == "round-trip-test-123"
-
     def test_correlation_id_is_cleared_after_context_exit(self) -> None:
         with set_correlation_id("round-trip-test-123"):
             assert get_correlation_id() == "round-trip-test-123"

pathology-api/test_lambda_handler.py

@@ -67,10 +67,8 @@ def test_create_test_result_success(self) -> None:
         response = handler(event, context)
 
         assert response["statusCode"] == 200
-        assert response["headers"] == {
-            "Content-Type": "application/fhir+json",
-            "nhsd-correlation-id": "test-correlation-id",
-        }
+        assert response["headers"]["Content-Type"] == "application/fhir+json"
+        assert response["headers"]["nhsd-correlation-id"] == "test-correlation-id"
 
         response_body = response["body"]
         assert isinstance(response_body, str)
@@ -127,10 +125,8 @@ def test_create_test_result_no_payload(self) -> None:
         response = handler(event, context)
 
         assert response["statusCode"] == 400
-        assert response["headers"] == {
-            "Content-Type": "application/fhir+json",
-            "nhsd-correlation-id": "test-correlation-id",
-        }
+        assert response["headers"]["Content-Type"] == "application/fhir+json"
+        assert response["headers"]["nhsd-correlation-id"] == "test-correlation-id"
 
         returned_issue = self._parse_returned_issue(response["body"])
 
@@ -153,10 +149,8 @@ def test_create_test_result_empty_payload(self) -> None:
         response = handler(event, context)
 
         assert response["statusCode"] == 400
-        assert response["headers"] == {
-            "Content-Type": "application/fhir+json",
-            "nhsd-correlation-id": "test-correlation-id",
-        }
+        assert response["headers"]["Content-Type"] == "application/fhir+json"
+        assert response["headers"]["nhsd-correlation-id"] == "test-correlation-id"
 
         returned_issue = self._parse_returned_issue(response["body"])
 
@@ -179,10 +173,8 @@ def test_create_test_result_invalid_json(self) -> None:
         response = handler(event, context)
 
         assert response["statusCode"] == 400
-        assert response["headers"] == {
-            "Content-Type": "application/fhir+json",
-            "nhsd-correlation-id": "test-correlation-id",
-        }
+        assert response["headers"]["Content-Type"] == "application/fhir+json"
+        assert response["headers"]["nhsd-correlation-id"] == "test-correlation-id"
 
         returned_issue = self._parse_returned_issue(response["body"])
         assert returned_issue["severity"] == "error"
@@ -234,10 +226,8 @@ def test_create_test_result_processing_error(
             response = handler(event, context)
 
         assert response["statusCode"] == expected_status_code
-        assert response["headers"] == {
-            "Content-Type": "application/fhir+json",
-            "nhsd-correlation-id": "test-correlation-id",
-        }
+        assert response["headers"]["Content-Type"] == "application/fhir+json"
+        assert response["headers"]["nhsd-correlation-id"] == "test-correlation-id"
 
         returned_issue = self._parse_returned_issue(response["body"])
         assert returned_issue == expected_issue
@@ -279,10 +269,8 @@ def test_create_test_result_model_validate_error(
             response = handler(event, context)
 
             assert response["statusCode"] == 400
-            assert response["headers"] == {
-                "Content-Type": "application/fhir+json",
-                "nhsd-correlation-id": "test-correlation-id",
-            }
+            assert response["headers"]["Content-Type"] == "application/fhir+json"
+            assert response["headers"]["nhsd-correlation-id"] == "test-correlation-id"
 
             returned_issue = self._parse_returned_issue(response["body"])
             assert returned_issue["severity"] == "error"

pathology-api/tests/integration/test_endpoints.py

@@ -36,6 +36,7 @@ def test_bundle_returns_200(self, client: Client) -> None:
 
         assert response.status_code == 200
         assert response.headers["Content-Type"] == "application/fhir+json"
+        assert response.headers["X-Correlation-ID"] == "test-correlation-id-555666777"
         assert response.headers["nhsd-correlation-id"].startswith(
             ".test-correlation-id-555666777"
         )
@@ -263,19 +264,26 @@ def test_status_returns_200(self, client: Client) -> None:
         response = client.send_without_payload(
             request_method="GET",
             path="_status",
-            headers={"X-Correlation-ID": "test-correlation-id-555666777"},
+            headers={"X-Correlation-ID": "test-correlation-id-111222333"},
         )
         assert response.status_code == 200
         assert response.headers["Content-Type"] == "application/json"
         assert response.headers["nhsd-correlation-id"].startswith(
-            ".test-correlation-id-555666777"
+            ".test-correlation-id-111222333.rrt-"
+        )
+
+        import json
+        import logging
+
+        logger = logging.getLogger(__name__)
+        logger.warning(
+            "/_status response JSON: %s", json.dumps(response.json(), indent=2)
         )
 
         parsed = StatusResponse.model_validate(response.json())
 
         assert parsed.status == "pass"
         assert parsed.checks.healthcheck.responseCode == 200
-        assert parsed.checks.healthcheck.outcome == "OK"
 
 
 class StatusLinks(BaseModel):
@@ -286,7 +294,7 @@ class HealthCheck(BaseModel):
     status: Literal["pass", "fail"]
     timeout: Literal["true", "false"]
     responseCode: int
-    outcome: str
+    outcome: dict[Any, Any]
     links: StatusLinks