diff --git a/src/adn_server/infrastructure/proxy/obp_fanin.py b/src/adn_server/infrastructure/proxy/obp_fanin.py index 2c3de3e..ca71e95 100644 --- a/src/adn_server/infrastructure/proxy/obp_fanin.py +++ b/src/adn_server/infrastructure/proxy/obp_fanin.py @@ -181,7 +181,6 @@ class ObpFanInDemux: self._registry = registry self.debug = debug self._log = logger or _logger - self._last_stream: dict[str, bytes] = {} def deliver( self, @@ -210,29 +209,17 @@ class ObpFanInDemux: entry = self._registry.bridges.get(system_name) if entry is None: return - if self.debug: - opcode = data[:4] - if opcode in (DMRD, DMRE) and len(data) >= 20: - stream_id = data[16:20] - if self._last_stream.get(system_name) != stream_id: - self._last_stream[system_name] = stream_id - self._log.debug( - "(OBP_PROXY) RX %s from %s:%s stream=%s -> %s", - opcode, - host, - port, - stream_id.hex(), - system_name, - ) - else: - self._log.debug( - "(OBP_PROXY) RX %s from %s:%s len=%d -> %s", - opcode, - host, - port, - len(data), - system_name, - ) + if self.debug and data[:4] not in (DMRD, DMRE): + # DMRD/DMRE demux by NETWORK_ID, never ambiguous; *CALL START*/*CALL END* + # (routing_use_cases.py) already give once-per-call visibility for those. + self._log.debug( + "(OBP_PROXY) RX %s from %s:%s len=%d -> %s", + data[:4], + host, + port, + len(data), + system_name, + ) entry.reply_transport.note_ingress(transport) entry.sink.inject(data, addr) diff --git a/tests/infrastructure/test_obp_proxy.py b/tests/infrastructure/test_obp_proxy.py index f750be9..4a804b1 100644 --- a/tests/infrastructure/test_obp_proxy.py +++ b/tests/infrastructure/test_obp_proxy.py @@ -22,6 +22,8 @@ from __future__ import annotations +import logging + import pytest from tests.conftest import minimal_valid_config @@ -570,11 +572,12 @@ def test_control_frame_prefers_configured_peer_over_relaxed_target() -> None: assert not protocols["OBP-FR"].packets -def test_debug_rx_log_once_per_stream(caplog) -> None: - """A call sends many DMRD/DMRE packets; the RX debug line must fire once per - stream_id, not once per packet, or an active call floods the log.""" - import logging as _logging - +def test_debug_does_not_log_voice_packets(caplog) -> None: + """DMRD/DMRE demux by NETWORK_ID, never ambiguous, and *CALL START*/*CALL END* + (routing_use_cases.py) already give once-per-call visibility. Concurrent calls + on the same bridge (BOTH_SLOTS, several TGs) interleave stream_ids packet by + packet, so any per-stream tracking here would still log almost every packet — + so voice frames are not logged at all, only control frames are.""" receiver = _RecordingObp() transport = _RecordingTransport() registry = ObpBridgeRegistry() @@ -588,13 +591,12 @@ def test_debug_rx_log_once_per_stream(caplog) -> None: ) ) demux = ObpFanInDemux(registry, debug=True) - caplog.set_level(_logging.DEBUG) + caplog.set_level(logging.DEBUG) - wire_a = build_dmrd_v1(_sample_dmr_voice(stream_id=0x11111111), _NETWORK, _PASS) - for _ in range(5): - demux.deliver(wire_a, _ADDR, local_port=62032, transport=transport) - assert sum("RX" in r.getMessage() for r in caplog.records) == 1 + for stream in (0x11111111, 0x22222222, 0x11111111, 0x22222222): + wire = build_dmrd_v1(_sample_dmr_voice(stream_id=stream), _NETWORK, _PASS) + demux.deliver(wire, _ADDR, local_port=62032, transport=transport) + assert not any("RX" in r.getMessage() for r in caplog.records) - wire_b = build_dmrd_v1(_sample_dmr_voice(stream_id=0x22222222), _NETWORK, _PASS) - demux.deliver(wire_b, _ADDR, local_port=62032, transport=transport) - assert sum("RX" in r.getMessage() for r in caplog.records) == 2 + demux.deliver(build_bcka(_PASS), _ADDR, local_port=62032, transport=transport) + assert sum("RX" in r.getMessage() for r in caplog.records) == 1