diff --git a/src/ol_analytics_api/core/observability/sentry.py b/src/ol_analytics_api/core/observability/sentry.py index b3ef005..76cc70c 100644 --- a/src/ol_analytics_api/core/observability/sentry.py +++ b/src/ol_analytics_api/core/observability/sentry.py @@ -6,6 +6,8 @@ from __future__ import annotations import logging +import re +from typing import Any, cast import sentry_sdk from sentry_sdk.integrations.fastapi import FastApiIntegration @@ -20,12 +22,65 @@ _SHUTDOWN_ERRORS = (SystemExit,) +# Postgres appends a DETAIL line to constraint violations that echoes the whole +# offending row verbatim. psycopg puts it in str(exc), so it ships inside the +# exception value, where no SDK privacy setting reaches it: send_default_pii +# governs user/cookie/header capture and max_request_body_size governs request +# bodies, and neither touches exception text. +# +# The newline is matched both raw and as a literal backslash-n: the SDK repr()s +# frame locals and non-string logging params during serialization, so there the +# DETAIL line arrives as "...constraint\\nDETAIL: ..." inside a repr string. +_PG_DETAIL_RE = re.compile(r"(\n|\\n)DETAIL:.*", re.DOTALL) + + +def _scrub_pg_detail(text: str) -> str: + """Truncate a Postgres error string at its DETAIL line. + + Keeps the primary message, which is what identifies the failure, and drops + the row echo plus any HINT/CONTEXT Postgres appends after it. + """ + return _PG_DETAIL_RE.sub(lambda match: match.group(1) + "DETAIL: [scrubbed]", text, count=1) + + +def _scrub_pg_details(event: Event) -> Event: + """Truncate Postgres DETAIL lines everywhere in a Sentry event. + + The row echo reaches Sentry through more fields than the exception value: + LoggingIntegration puts the log message in a breadcrumb + (BreadcrumbHandler._breadcrumb_from_record), logger.error("...: %s", exc) + puts it in logentry.params (EventHandler._emit), and captured stack-frame + locals carry it in frame vars because include_local_variables defaults to + True (serialize_frame). Walking the whole event covers those without + enumerating them, and does not go stale when the SDK adds another. + + Safe to walk naively because Client._prepare_event serializes the event + before calling before_send, so every leaf here is already a JSON + primitive -- no live exception objects to coerce. + """ + return cast("Event", _scrub_node(event)) + + +def _scrub_node(node: Any) -> Any: # noqa: ANN401 -- walks arbitrary JSON + """Recurse through the serialized event, rewriting strings in place.""" + if isinstance(node, str): + return _scrub_pg_detail(node) + if isinstance(node, dict): + for key, value in node.items(): + node[key] = _scrub_node(value) + return node + if isinstance(node, list): + node[:] = [_scrub_node(item) for item in node] + return node + return node + + def _before_send(event: Event, hint: Hint) -> Event | None: if "exc_info" in hint: _, exc_value, _ = hint["exc_info"] if isinstance(exc_value, _SHUTDOWN_ERRORS): return None - return event + return _scrub_pg_details(event) def init_sentry( # noqa: PLR0913 -- matches the org's established init_sentry() shape @@ -50,6 +105,16 @@ def init_sentry( # noqa: PLR0913 -- matches the org's established init_sentry() environment=environment, release=version, before_send=_before_send, + # Request bodies are NOT gated on send_default_pii: the Starlette and + # FastAPI integrations set request.data unconditionally + # (StarletteRequestExtractor.extract_request_info) and this is the only + # control (request_body_within_bounds). extract_request_info attaches + # no body when the content-length header is absent, and applies the + # bound to the declared value otherwise. Left unset it defaults to + # "medium", i.e. 10,000-byte bodies. Set explicitly so the choice is + # findable here rather than in a dependency's defaults. Every route + # this service registers is a GET. + max_request_body_size="small", # This service serves aggregated-only analytics (no individual # learner PII) — default to not sending request/user PII to Sentry. send_default_pii=False, diff --git a/tests/test_sentry.py b/tests/test_sentry.py new file mode 100644 index 0000000..2e16e1c --- /dev/null +++ b/tests/test_sentry.py @@ -0,0 +1,190 @@ +"""Tests for Sentry event scrubbing.""" + +import json +import logging + +import pytest +import sentry_sdk +from sentry_sdk.integrations.logging import LoggingIntegration +from sentry_sdk.transport import Transport + +from ol_analytics_api.core.observability.sentry import ( + _before_send, + _scrub_pg_detail, + _scrub_pg_details, +) + +# A real MITXONLINE-6PK exception value, with the learner identifiers replaced. +PG_INTEGRITY_ERROR = ( + 'null value in column "name" of relation "users_user" violates not-null ' + "constraint\n" + "DETAIL: Failing row contains (1863408, , 2026-08-07 18:38:14.503726+00, f, " + "learner@example.invalid, learner@example.invalid, null, f, t, " + "12d7dfc5-6f84-46db-9383-2d7079434173, 1863408, learner@example.invalid, f)." +) +PG_PRIMARY_MESSAGE = ( + 'null value in column "name" of relation "users_user" violates not-null constraint' +) + + +class FakeTransport(Transport): + """Collect outgoing events instead of sending them.""" + + def __init__(self): + super().__init__() + self.events = [] + + def capture_envelope(self, envelope): + self.events.extend(item.payload.json for item in envelope.items if item.type == "event") + + +@pytest.fixture +def sentry_transport(): + """Initialize the real SDK with _before_send, and detach it afterwards.""" + transport = FakeTransport() + sentry_sdk.init( + dsn="https://k@o0.ingest.sentry.io/0", + transport=transport, + before_send=_before_send, + default_integrations=False, + integrations=[LoggingIntegration(level=logging.INFO, event_level=logging.ERROR)], + ) + yield transport + sentry_sdk.get_global_scope().set_client(None) + + +def test_detail_line_is_truncated(): + """The row echo goes; the primary error that names the failure stays.""" + scrubbed = _scrub_pg_detail(PG_INTEGRITY_ERROR) + assert scrubbed.startswith(PG_PRIMARY_MESSAGE) + assert "learner@example.invalid" not in scrubbed + assert "12d7dfc5-6f84-46db-9383-2d7079434173" not in scrubbed + + +def test_escaped_detail_line_is_truncated(): + """repr() turns the newline into a literal backslash-n; that form goes too.""" + scrubbed = _scrub_pg_detail(repr(Exception(PG_INTEGRITY_ERROR))) + assert PG_PRIMARY_MESSAGE in scrubbed + assert "learner@example.invalid" not in scrubbed + + +def test_message_without_detail_is_unchanged(): + """A message with no DETAIL line passes through untouched.""" + message = "connection to server failed" + assert _scrub_pg_detail(message) == message + + +def test_hint_and_context_after_detail_are_dropped(): + """HINT and CONTEXT follow DETAIL and can quote row data too.""" + text = "boom\nDETAIL: row data\nHINT: try again\nCONTEXT: SQL statement" + scrubbed = _scrub_pg_detail(text) + assert "row data" not in scrubbed + assert "try again" not in scrubbed + assert "SQL statement" not in scrubbed + + +def test_scrubs_exception_values_logentry_and_message(): + """Every place the SDK can put an error string is covered.""" + event = { + "exception": {"values": [{"value": PG_INTEGRITY_ERROR}]}, + "logentry": { + "message": PG_INTEGRITY_ERROR, + "formatted": PG_INTEGRITY_ERROR, + }, + "message": PG_INTEGRITY_ERROR, + } + _scrub_pg_details(event) + assert "learner@example.invalid" not in repr(event) + + +def test_before_send_scrubs_the_event(): + """The scrub is wired into the before_send hook, not just callable.""" + event = {"exception": {"values": [{"value": PG_INTEGRITY_ERROR}]}} + assert "learner@example.invalid" not in repr(_before_send(event, {})) + + +def test_scrubs_breadcrumb_messages(): + """LoggingIntegration records the log message as a breadcrumb.""" + event = { + "breadcrumbs": { + "values": [ + {"type": "log", "category": "django_scim.views", "message": PG_INTEGRITY_ERROR} + ] + } + } + _scrub_pg_details(event) + assert "learner@example.invalid" not in repr(event) + + +def test_scrubs_logentry_params(): + """logger.error("...: %s", exc) puts the repr'd exception in logentry.params.""" + event = { + "logentry": { + "message": "Unable to complete SCIM call: %s", + "formatted": "Unable to complete SCIM call: " + PG_INTEGRITY_ERROR, + "params": [repr(Exception(PG_INTEGRITY_ERROR))], + } + } + _scrub_pg_details(event) + assert "learner@example.invalid" not in repr(event) + + +def test_scrubs_captured_frame_locals(): + """include_local_variables defaults to True, so repr'd frame vars carry it.""" + event = { + "exception": { + "values": [ + { + "value": "boom", + "stacktrace": { + "frames": [ + { + "function": "save", + "vars": { + "exc": repr(Exception(PG_INTEGRITY_ERROR)), + "retries": 3, + }, + } + ] + }, + } + ] + } + } + _scrub_pg_details(event) + assert "learner@example.invalid" not in repr(event) + frame = event["exception"]["values"][0]["stacktrace"]["frames"][0] + assert frame["vars"]["retries"] == 3 + + +def test_walk_preserves_non_string_leaves(): + """The walk must not coerce timestamps, ints or None into strings.""" + event = { + "timestamp": 1757345533.179, + "level": "error", + "extra": {"count": 42, "missing": None, "flag": True}, + "message": PG_INTEGRITY_ERROR, + } + _scrub_pg_details(event) + assert event["timestamp"] == 1757345533.179 + assert event["extra"] == {"count": 42, "missing": None, "flag": True} + assert "learner@example.invalid" not in event["message"] + + +def test_real_sdk_scrubs_params_and_local_variables(sentry_transport): + """Go through the real SDK, which repr()s params and locals before before_send.""" + + def save(): + exc = Exception(PG_INTEGRITY_ERROR) + raise exc + + try: + save() + except Exception as e: # noqa: BLE001 + logging.getLogger("x").error("Unable to save: %s", e) # noqa: TRY400 + sentry_sdk.capture_exception(e) + sentry_sdk.flush() + + assert len(sentry_transport.events) == 2 + for event in sentry_transport.events: + assert "learner@example.invalid" not in json.dumps(event)