gps-denied-onboard/tests/unit/test_az267_fdr_log_bridge.py

"""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,
        },
    )