fix(obp-proxy): drop per-packet RX debug for voice, not once-per-stream

#82 logged the RX debug line once per stream_id per bridge, but a bridge
with BOTH_SLOTS/several concurrent talkgroups interleaves packets from
multiple calls, so the "last seen" stream flips almost every packet and
the line logs nearly as often as before the fix — confirmed against
production output (three interleaved streams on OBP-CL).

DMRD/DMRE demux by NETWORK_ID, which is never ambiguous, and
*CALL START*/*CALL END* (application/routing_use_cases.py,
application/routing/obp_forward.py) already log once per real call with
better detail (SUB, TGID, TS, duration). Drop the fan-in RX line for voice
frames entirely instead of trying to approximate "once per call" with no
session state; control frames (BCKA/BCSQ/BCST/BCVE) keep logging every
time, since they are rare and that visibility mattered for the #79 fix.
pull/83/head
Rodrigo Pérez 1 week ago
parent 3ac8540168
commit e8da064d63

@ -181,7 +181,6 @@ class ObpFanInDemux:
self._registry = registry self._registry = registry
self.debug = debug self.debug = debug
self._log = logger or _logger self._log = logger or _logger
self._last_stream: dict[str, bytes] = {}
def deliver( def deliver(
self, self,
@ -210,29 +209,17 @@ class ObpFanInDemux:
entry = self._registry.bridges.get(system_name) entry = self._registry.bridges.get(system_name)
if entry is None: if entry is None:
return return
if self.debug: if self.debug and data[:4] not in (DMRD, DMRE):
opcode = data[:4] # DMRD/DMRE demux by NETWORK_ID, never ambiguous; *CALL START*/*CALL END*
if opcode in (DMRD, DMRE) and len(data) >= 20: # (routing_use_cases.py) already give once-per-call visibility for those.
stream_id = data[16:20] self._log.debug(
if self._last_stream.get(system_name) != stream_id: "(OBP_PROXY) RX %s from %s:%s len=%d -> %s",
self._last_stream[system_name] = stream_id data[:4],
self._log.debug( host,
"(OBP_PROXY) RX %s from %s:%s stream=%s -> %s", port,
opcode, len(data),
host, system_name,
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,
)
entry.reply_transport.note_ingress(transport) entry.reply_transport.note_ingress(transport)
entry.sink.inject(data, addr) entry.sink.inject(data, addr)

@ -22,6 +22,8 @@
from __future__ import annotations from __future__ import annotations
import logging
import pytest import pytest
from tests.conftest import minimal_valid_config 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 assert not protocols["OBP-FR"].packets
def test_debug_rx_log_once_per_stream(caplog) -> None: def test_debug_does_not_log_voice_packets(caplog) -> None:
"""A call sends many DMRD/DMRE packets; the RX debug line must fire once per """DMRD/DMRE demux by NETWORK_ID, never ambiguous, and *CALL START*/*CALL END*
stream_id, not once per packet, or an active call floods the log.""" (routing_use_cases.py) already give once-per-call visibility. Concurrent calls
import logging as _logging 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() receiver = _RecordingObp()
transport = _RecordingTransport() transport = _RecordingTransport()
registry = ObpBridgeRegistry() registry = ObpBridgeRegistry()
@ -588,13 +591,12 @@ def test_debug_rx_log_once_per_stream(caplog) -> None:
) )
) )
demux = ObpFanInDemux(registry, debug=True) 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 stream in (0x11111111, 0x22222222, 0x11111111, 0x22222222):
for _ in range(5): wire = build_dmrd_v1(_sample_dmr_voice(stream_id=stream), _NETWORK, _PASS)
demux.deliver(wire_a, _ADDR, local_port=62032, transport=transport) demux.deliver(wire, _ADDR, local_port=62032, transport=transport)
assert sum("RX" in r.getMessage() for r in caplog.records) == 1 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(build_bcka(_PASS), _ADDR, local_port=62032, transport=transport)
demux.deliver(wire_b, _ADDR, local_port=62032, transport=transport) assert sum("RX" in r.getMessage() for r in caplog.records) == 1
assert sum("RX" in r.getMessage() for r in caplog.records) == 2

Loading…
Cancel
Save

Powered by TurnKey Linux.