"""AZ-267 — FDR log bridge (WARN + ERROR forwarding). Verifies all five ACs: 1. WARN reaches FDR with kind=log + correct component back-reference. 2. ERROR + ``logger.exception`` carries traceback in ``exc``. 3. INFO + DEBUG never reach FDR. 4. Saturated queue does not block the caller. 5. Re-wiring is idempotent — exactly one bridge handler per logger. """ from __future__ import annotations import logging import time from collections.abc import Iterator import pytest from gps_denied_onboard.fdr_client.fakes import FakeFdrSink from gps_denied_onboard.logging import get_logger from gps_denied_onboard.logging.fdr_bridge import ( FdrLogBridgeHandler, wire_log_bridge, ) @pytest.fixture def isolated_logger_state() -> Iterator[None]: """Snapshot + restore the root logger to keep tests independent.""" root = logging.getLogger() saved_handlers = list(root.handlers) saved_level = root.level yield root.handlers = saved_handlers root.setLevel(saved_level) def _resolver_for(sink: FakeFdrSink): # type: ignore[no-untyped-def] def _resolve(_component: str) -> FakeFdrSink: return sink return _resolve # --------------------------------------------------------------------------- # AC-1: WARN records reach FDR. def test_ac1_warn_reaches_fdr(isolated_logger_state: None) -> None: # Arrange sink = FakeFdrSink(producer_id="c2_vpr") wire_log_bridge(_resolver_for(sink), target_loggers=("c2_vpr",)) logger = get_logger("c2_vpr") # Act logger.warning("covariance jumped 5x", extra={"component": "c2_vpr", "kind": "vpr.cov_spike"}) # Assert assert len(sink.records) == 1 record = sink.records[0] assert record.kind == "log" assert record.producer_id == "c2_vpr" assert record.payload["level"] == "WARN" assert record.payload["component"] == "c2_vpr" assert record.payload["msg"] == "covariance jumped 5x" # --------------------------------------------------------------------------- # AC-2: ERROR + logger.exception carries traceback in exc. def test_ac2_logger_exception_carries_traceback(isolated_logger_state: None) -> None: # Arrange sink = FakeFdrSink(producer_id="c11_tilemanager") wire_log_bridge(_resolver_for(sink), target_loggers=("c11_tilemanager",)) logger = get_logger("c11_tilemanager") # Act try: raise RuntimeError("HTTP 503") except RuntimeError: logger.exception( "tile upload failed", extra={"component": "c11_tilemanager", "kind": "tile.upload_fail"}, ) # Assert assert len(sink.records) == 1 record = sink.records[0] assert record.payload["level"] == "ERROR" assert record.payload["exc"] is not None assert "RuntimeError" in record.payload["exc"] assert "HTTP 503" in record.payload["exc"] # --------------------------------------------------------------------------- # AC-3: INFO + DEBUG never reach FDR. def test_ac3_info_and_debug_never_reach_fdr(isolated_logger_state: None) -> None: # Arrange sink = FakeFdrSink(producer_id="c5_state") wire_log_bridge(_resolver_for(sink), target_loggers=("c5_state",)) logger = get_logger("c5_state") logger.setLevel(logging.DEBUG) # Act for _ in range(100): logger.info("startup") logger.debug("trace point") # Assert assert sink.records == [] assert sink.all_records_ever == [] # --------------------------------------------------------------------------- # AC-4: saturated queue does not block the caller. def test_ac4_saturated_queue_does_not_block(isolated_logger_state: None) -> None: # Arrange sink = FakeFdrSink(producer_id="c1_vio", capacity=4, with_default_overrun_policy=True) wire_log_bridge(_resolver_for(sink), target_loggers=("c1_vio",)) logger = get_logger("c1_vio") # Fill the sink. for i in range(4): logger.warning("filler", extra={"component": "c1_vio", "kind": "fill", "frame_id": i}) # Act start = time.perf_counter() logger.warning( "overrun trigger", extra={"component": "c1_vio", "kind": "trigger", "frame_id": 999}, ) elapsed = time.perf_counter() - start # Assert — must return well under 0.5 ms wall clock per NFR-perf. assert elapsed < 0.005, f"call blocked: {elapsed * 1e3:.2f} ms" # --------------------------------------------------------------------------- # AC-5: single attachment — re-wiring does not stack duplicate handlers. def test_ac5_single_attachment_is_idempotent(isolated_logger_state: None) -> None: # Arrange sink = FakeFdrSink(producer_id="c7_inference") wire_log_bridge(_resolver_for(sink), target_loggers=("c7_inference",)) # Act — re-wire three times. wire_log_bridge(_resolver_for(sink), target_loggers=("c7_inference",)) wire_log_bridge(_resolver_for(sink), target_loggers=("c7_inference",)) # Assert target_logger = logging.getLogger("c7_inference") bridge_handlers = [h for h in target_logger.handlers if isinstance(h, FdrLogBridgeHandler)] assert len(bridge_handlers) == 1 # --------------------------------------------------------------------------- # Bridge does not recurse on internal warnings. def test_recursion_guard_prevents_infinite_loop(isolated_logger_state: None) -> None: # Arrange — sink that always overruns. sink = FakeFdrSink(producer_id="c3_matcher", capacity=1) wire_log_bridge(_resolver_for(sink), target_loggers=("c3_matcher",)) logger = get_logger("c3_matcher") sink.enqueue(_dummy_record()) # Act — should not recurse infinitely. logger.warning("trigger overrun", extra={"component": "c3_matcher", "kind": "test"}) # Assert — completes without StackOverflow or recursion errors. def _dummy_record(): from gps_denied_onboard.fdr_client.records import FdrRecord return FdrRecord( schema_version=1, ts="2026-05-11T00:00:00.000000Z", producer_id="c3_matcher", kind="log", payload={ "level": "INFO", "component": "c3_matcher", "frame_id": None, "kind": "test", "msg": "filler", "kv": {}, "exc": None, }, )