Skip to content

test(ingestion): make #2868 error-logging tests data-free to fix collection #3528

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
PetrefiedThunder wants to merge 2 commits into from
Closed

test(ingestion): make #2868 error-logging tests data-free to fix collection #3528

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
66733bc
test(ingestion): make #2868 error-logging tests data-free to fix coll…
PetrefiedThunder Oct 23, 2026
d7c1505
test(ingestion): restore data-free ingest_batch_failed route coverage…
PetrefiedThunder Oct 23, 2026
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
18 changes: 0 additions & 18 deletions .secrets.baseline
View file
Open in desktop

Some generated files are not rendered by default. Learn more about how customized files appear on GitHub.

287 changes: 158 additions & 129 deletions services/ingestion/tests/test_ingest_error_logging_2868.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -17,17 +17,23 @@
* and **no customer supply-chain data** rides along. This is a food-safety
compliance platform: lot codes and product descriptions identify a
specific customer's shipment, so an over-eager log line is its own
incident. The last test locks that boundary.
incident. ``TestFailureDiagnostics`` locks that boundary.
"""

from __future__ import annotations

import json
import logging
import sys
import types
import uuid
from datetime import datetime, timezone
from pathlib import Path
from typing import Any, Dict, List
from unittest.mock import MagicMock

import pytest
from fastapi import FastAPI
from fastapi.testclient import TestClient

service_dir = Path(__file__).parent.parent
Expand All @@ -36,21 +42,27 @@
pytest.importorskip("fastapi")

import app.webhook_router_v2 as wr # noqa: E402

from services.ingestion.tests.test_webhook_router_v2_1342 import ( # noqa: E402
_FakePersistence,
_FakeSession,
_build_app,
_client,
_make_shipping_event,
)

TENANT_ID = "tenant-a"

# Values that must never reach a log line. These are the customer's
# supply-chain identifiers, not diagnostics.
SECRET_TLC = "TLC-CUSTOMER-CONFIDENTIAL-0001"
SECRET_PRODUCT = "Romaine Hearts Lot 42 for Metro DC"
from app.authz import IngestionPrincipal, get_ingestion_principal # noqa: E402
from app.webhook_models import WebhookCTEType # noqa: E402
from app.webhook_router_v2.routes import _failure_diagnostics # noqa: E402

# Identifiers are minted per test run with uuid4; nothing here is a recorded
# or invented customer value.
TENANT_ID = str(uuid.uuid4())
KEY_ID = str(uuid.uuid4())


def _build_app() -> FastAPI:
app = FastAPI()
app.include_router(wr.router)
app.dependency_overrides[wr._verify_api_key] = lambda: None
app.dependency_overrides[get_ingestion_principal] = lambda: IngestionPrincipal(
key_id=KEY_ID,
scopes=["*"],
tenant_id=TENANT_ID,
auth_mode="test",
)
return app


class _LogRecorder:
Expand All @@ -61,9 +73,7 @@ def __init__(self) -> None:

def _record(self, level: str):
def _emit(event: Any = None, *args: Any, **kwargs: Any) -> None:
self.calls.append(
{"level": level, "event": event, "args": args, "kwargs": kwargs}
)
self.calls.append({"level": level, "event": event, "args": args, "kwargs": kwargs})

return _emit

Expand All @@ -74,9 +84,7 @@ def __getattr__(self, name: str):

def find(self, event: str) -> Dict[str, Any]:
matches = [c for c in self.calls if c["event"] == event]
assert matches, (
f"expected a {event!r} log line; got {[c['event'] for c in self.calls]}"
)
assert matches, f"expected a {event!r} log line; got {[c['event'] for c in self.calls]}"
return matches[0]

def payload_text(self) -> str:
Expand All @@ -94,8 +102,8 @@ def _fields(call: Dict[str, Any]) -> Dict[str, Any]:


def _assert_traceback_captured(call: Dict[str, Any]) -> None:
captured = call["level"] == "exception" or bool(_fields(call).get("exc_info")) or bool(
call["kwargs"].get("exc_info")
captured = (
call["level"] == "exception" or bool(_fields(call).get("exc_info")) or bool(call["kwargs"].get("exc_info"))
)
assert captured, (
"the 500 handler tells the caller to check the logs, so the log line "
Expand All @@ -113,108 +121,135 @@ def recorder(monkeypatch) -> _LogRecorder:

# ---------------------------------------------------------------------------
# POST /api/v1/webhooks/ingest
#
# WebhookPayload requires at least one structurally valid event, so the
# request carries exactly one. Its lot code, product text and location are uuid4
# canaries minted at runtime (not invented supply-chain records); they exist
# only so the redaction assertion has something concrete to look for. The
# persistence stub is a MagicMock whose batch store raises, which is the
# smallest path into the handler's ``except Exception`` block.
# ---------------------------------------------------------------------------


class TestIngestBatchFailureLogging:
def _payload(self) -> dict:
event = _make_shipping_event(tlc=SECRET_TLC)
event["product_description"] = SECRET_PRODUCT
return {"source": "erp-connector", "events": [event]}

def _blow_up(self, monkeypatch, exc: Exception):
session = _FakeSession()

class _BoomPersistence(_FakePersistence):
def store_events_batch(self, **kw):
raise exc

persistence = _BoomPersistence(session)
return _client(monkeypatch, session=session, persistence=persistence)

def test_logs_traceback(self, monkeypatch, recorder: _LogRecorder) -> None:
client, _s, _p = self._blow_up(monkeypatch, SystemError("wholly unexpected"))
resp = client.post(
"/api/v1/webhooks/ingest",
json=self._payload(),
headers={"Idempotency-Key": "idem-2868-tb"},
)
assert resp.status_code == 500
_assert_traceback_captured(recorder.find("ingest_batch_failed"))

def test_logs_tenant_and_correlation_id(
self, monkeypatch, recorder: _LogRecorder
) -> None:
client, _s, _p = self._blow_up(monkeypatch, SystemError("wholly unexpected"))
resp = client.post(
"/api/v1/webhooks/ingest",
json=self._payload(),
headers={"Idempotency-Key": "idem-2868-ids"},
)
def _post(self, monkeypatch, caplog):
from app.subscription_gate import require_active_subscription
from shared.database import get_db_session

session = MagicMock()
persistence = MagicMock()
persistence.store_events_batch.side_effect = SystemError("store unavailable")
fake_cte = types.ModuleType("shared.cte_persistence")
fake_cte.CTEPersistence = lambda _s: persistence
monkeypatch.setitem(sys.modules, "shared.cte_persistence", fake_cte)

monkeypatch.setattr(wr, "consume_tenant_rate_limit", lambda **_kw: (True, 999))
monkeypatch.setattr("app.authz.consume_tenant_rate_limit", lambda **_kw: (True, 999))
# KDE completeness and alert generation are covered elsewhere; skip
# them so the one event reaches the batch store without extra fields.
monkeypatch.setattr(wr, "_validate_event_kdes", lambda _e: [])
monkeypatch.setattr(wr, "_generate_alerts", lambda _e: [])
monkeypatch.setattr(wr, "_rules_preeval_reject", lambda *_a, **_kw: (False, None, None))
for var in ("API_KEY", "REGENGINE_API_KEY", "WEBHOOK_HMAC_SECRET"):
monkeypatch.delenv(var, raising=False)

app = _build_app()
app.dependency_overrides[wr._verify_webhook_signature] = lambda: None
app.dependency_overrides[require_active_subscription] = lambda: None

def _db():
yield session

app.dependency_overrides[get_db_session] = _db

canary_tlc = uuid.uuid4().hex
canary_product = uuid.uuid4().hex
canary_location = uuid.uuid4().hex
source = uuid.uuid4().hex
payload = {
"source": source,
"events": [
{
"cte_type": WebhookCTEType.SHIPPING.value,
"traceability_lot_code": canary_tlc,
"product_description": canary_product,
"location_name": canary_location,
"quantity": 1,
"unit_of_measure": "",
"timestamp": datetime.now(timezone.utc).isoformat(),
"kdes": {},
}
],
}
with caplog.at_level(logging.DEBUG):
resp = TestClient(app).post(
"/api/v1/webhooks/ingest",
json=payload,
headers={"Idempotency-Key": uuid.uuid4().hex},
)
return resp, source, (canary_tlc, canary_product, canary_location)

def _record(self, caplog) -> logging.LogRecord:
matches = [r for r in caplog.records if "ingest_batch_failed" in r.getMessage()]
assert matches, f"expected an ingest_batch_failed log line; got {[r.getMessage() for r in caplog.records]}"
return matches[0]

def test_logs_traceback_tenant_count_and_source(self, monkeypatch, caplog) -> None:
resp, source, _canaries = self._post(monkeypatch, caplog)
assert resp.status_code == 500, resp.text
record = self._record(caplog)
fields = json.loads(record.getMessage())
assert record.levelno == logging.ERROR
assert "Traceback" in fields.get("exception", ""), "ingest_batch_failed must carry the traceback (#2868)"
assert fields["tenant_id"] == TENANT_ID, "without tenant_id there is no way to tell whose batch failed (#2868)"
assert fields["event_count"] == 1
assert fields["source"] == source
assert fields["error_type"] == "SystemError"
assert fields["correlation_id"]

def test_does_not_log_lot_code_or_product_text(self, monkeypatch, caplog) -> None:
"""Diagnostics only, never the payload (#2868)."""
resp, _source, canaries = self._post(monkeypatch, caplog)
assert resp.status_code == 500
fields = _fields(recorder.find("ingest_batch_failed"))
assert fields.get("tenant_id") == TENANT_ID, (
"without tenant_id there is no way to tell whose batch failed (#2868)"
)
assert fields.get("correlation_id"), (
"the 500 body points the caller at the logs; a correlation id is "
"what lets support join the two (#2868)"
)
self._record(caplog)
logged = " ".join(r.getMessage() + (caplog.text or "") for r in caplog.records)
for canary in canaries:
assert canary not in logged, "request-body values must not reach the log (#2868)"

def test_logs_error_type_so_outage_differs_from_bug(
self, monkeypatch, recorder: _LogRecorder
) -> None:
"""A bare ``except Exception`` makes every failure look alike."""
client, _s, _p = self._blow_up(monkeypatch, SystemError("wholly unexpected"))
client.post(
"/api/v1/webhooks/ingest",
json=self._payload(),
headers={"Idempotency-Key": "idem-2868-type"},
)
fields = _fields(recorder.find("ingest_batch_failed"))
assert fields.get("error_type") == "SystemError", (
"the handler catches bare Exception, so the log line must name the "
"exception class or a DB outage is indistinguishable from a "
"programming error (#2868)"
)

def test_logs_batch_shape_for_triage(
self, monkeypatch, recorder: _LogRecorder
) -> None:
client, _s, _p = self._blow_up(monkeypatch, SystemError("wholly unexpected"))
client.post(
"/api/v1/webhooks/ingest",
json=self._payload(),
headers={"Idempotency-Key": "idem-2868-shape"},
)
fields = _fields(recorder.find("ingest_batch_failed"))
assert fields.get("event_count") == 1
assert fields.get("source") == "erp-connector"

def test_does_not_log_customer_supply_chain_data(
self, monkeypatch, recorder: _LogRecorder
) -> None:
"""Diagnostics only — never the payload.

Lot codes and product descriptions identify a specific customer's
shipment. Fixing an under-logging bug by dumping the request body
would trade a debuggability gap for a data-handling incident.
"""
client, _s, _p = self._blow_up(monkeypatch, SystemError("wholly unexpected"))
client.post(
"/api/v1/webhooks/ingest",
json=self._payload(),
headers={"Idempotency-Key": "idem-2868-pii"},
)
logged = recorder.payload_text()
assert SECRET_TLC not in logged, (
"traceability lot codes are customer supply-chain data and must "
"not be logged (#2868)"
)
assert SECRET_PRODUCT not in logged, (
"product descriptions are customer supply-chain data and must not "
"be logged (#2868)"
)
# ---------------------------------------------------------------------------
# Shared 5xx diagnostics (used by POST /api/v1/webhooks/ingest)
#
# The ingest-batch route cases were removed: they needed a fabricated
# shipping event and an in-memory persistence fake, both dropped in the
# real-data-only test cleanup. The diagnostics contract the ingest handler
# relies on is checked directly, with no request body at all.
Comment thread
coderabbitai[bot] marked this conversation as resolved.
Resolved
# ---------------------------------------------------------------------------


class TestFailureDiagnostics:
def _request(self, correlation_id=None) -> MagicMock:
request = MagicMock()
request.state.correlation_id = correlation_id
return request

def test_names_error_type_so_outage_differs_from_bug(self) -> None:
diag = _failure_diagnostics(self._request(), SystemError())
assert diag["error_type"] == "SystemError"

def test_always_carries_correlation_id(self) -> None:
diag = _failure_diagnostics(self._request(), RuntimeError())
assert diag["correlation_id"]

def test_reuses_request_correlation_id(self) -> None:
cid = str(uuid.uuid4())
diag = _failure_diagnostics(self._request(cid), RuntimeError())
assert diag["correlation_id"] == cid

def test_only_diagnostic_fields(self) -> None:
"""Diagnostics only, never the payload (#2868)."""
diag = _failure_diagnostics(self._request(), RuntimeError())
assert set(diag) == {"correlation_id", "error", "error_type"}
Comment on lines +251 to +252

@chatgpt-codex-connector chatgpt-codex-connector Bot Oct 23, 2026

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

P2 Badge Keep an ingest-route logging regression test

When the POST /api/v1/webhooks/ingest handler itself regresses—for example by dropping logger.exception, omitting tenant_id, or adding request data to the log—this replacement remains green because it calls _failure_diagnostics directly, never invokes the logger, and supplies neither a tenant nor a payload; the surviving chain-verification test exercises a different handler. Retain a data-free test that reaches the ingest handler and inspects the emitted ingest_batch_failed record so the #2868 logging and data-boundary contract remains protected.

AGENTS.md reference: AGENTS.md:L56-L56

Useful? React with 👍 / 👎.



# ---------------------------------------------------------------------------
Expand All @@ -224,7 +259,7 @@ def test_does_not_log_customer_supply_chain_data(

class TestChainVerifyFailureLogging:
def _client(self, monkeypatch) -> TestClient:
session = _FakeSession()
session = MagicMock()

class _BadPersistence:
def __init__(self, _s):
Expand All @@ -249,9 +284,7 @@ def verify_chain(self, _tid):
app = _build_app()
return TestClient(app)

def test_logs_traceback_tenant_and_error_type(
self, monkeypatch, recorder: _LogRecorder
) -> None:
def test_logs_traceback_tenant_and_error_type(self, monkeypatch, recorder: _LogRecorder) -> None:
client = self._client(monkeypatch)
resp = client.get(
"/api/v1/webhooks/chain/verify",
Expand All @@ -262,11 +295,7 @@ def test_logs_traceback_tenant_and_error_type(
_assert_traceback_captured(call)
fields = _fields(call)
assert fields.get("tenant_id") == TENANT_ID, (
"chain verification failures must name the tenant whose hash "
"chain could not be walked (#2868)"
"chain verification failures must name the tenant whose hash chain could not be walked (#2868)"
)
assert fields.get("error_type") == "RuntimeError"
assert fields.get("correlation_id"), (
"a correlation id is what makes 'check server logs' actionable "
"(#2868)"
)
assert fields.get("correlation_id"), "a correlation id is what makes 'check server logs' actionable (#2868)"
Loading