multi_rx: TimeoutError from TimeoutLock kills the msgq pump thread; UI/terminal freezes silently while decode continues

[jtruland]

Describe the bug

On a busy P25 trunked system, TimeoutLock raises TimeoutError on talkgroups_mutex. The exception propagates out of run() in multi_rx.py and permanently kills the msgq pump thread.

Decode is unaffected — it lives in the C++ flowgraph — so tsbks keep climbing and audio keeps playing. But with the pump dead, every UI/terminal update stops: the HTTP terminal still listens and answers every poll with [], and nothing further is logged. A polling client just sits there showing its initial state.

Happened twice in 17 minutes on this system.

Traceback

Exception in thread Thread-4:
Traceback (most recent call last):
  File "/usr/lib/python3.11/threading.py", line 1038, in _bootstrap_inner
    self.run()
  File "./multi_rx.py", line 1019, in run
    self.callback(msg)
  File "./multi_rx.py", line 1084, in process_qmsg
    if msg is None or self.tb.process_qmsg(msg):
  File "./multi_rx.py", line 865, in process_qmsg
    ui_rsp.append(self.ui_freq_update())
  File "./multi_rx.py", line 954, in ui_freq_update
    params = json.loads(self.trunk_rx.get_chan_status())
  File "tk_p25.py", line 308, in get_chan_status
    d[str(rcvr)] = json.loads(self.receivers[rcvr]['rx_rcvr'].get_status())
  File "tk_p25.py", line 2721, in get_status
    with self.system.talkgroups_mutex:
  File "helper_funcs.py", line 211, in __enter__
    raise TimeoutError(f"Could not acquire lock within "
TimeoutError: Could not acquire lock within specified timeout of 1.0s

Identified code

• helper_funcs.py:211 — TimeoutLock.__enter__ raises TimeoutError when acquire(timeout=...) returns False.
• tk_p25.py:376 — self.talkgroups_mutex = TimeoutLock(timeout=1.0). Same 1.0s value at tk_p25.py:124, 382, 384 and tk_smartnet.py:85, 220, 222.
• tk_p25.py:2721 — get_status() enters that mutex on the UI update path.
• multi_rx.py:1019 — self.callback(msg) is unguarded; the enclosing try catches only KeyboardInterrupt, so any TimeoutError terminates the thread.

So any contention that exceeds the timeout once, anywhere on the UI path, takes out all UI/terminal output for the life of the process.

Suggested fix

Skip the message rather than terminate the pump:

                     if msg is not None:
-                        self.callback(msg)
+                        try:
+                            self.callback(msg)
+                        except TimeoutError as e:
+                            sys.stderr.write('%s msgq callback lock timeout, message skipped: %s\n' % (log_ts.get(), e))

Locally this plus raising the tk_p25.py timeouts to 5.0s has held. Reporting the unguarded callback as the substantive issue — the 1.0s value only changes how often it is hit.

System Information

• OS: Raspbian GNU/Linux 12 (bookworm), aarch64 kernel with armhf userland
• Hardware: Raspberry Pi 4 Model B Rev 1.1, 4 cores, 4 GB RAM (CPU underclocked to arm_freq=850)
• GNU Radio: 3.10.5.1
• Python: 3.11.2
• op25: 28f2c40 (master)
• Invocation: ./multi_rx.py -v 8 -c <config>.json 2> stderr.2

Possibly relevant: -v 8 on a slow SD card means heavy stderr writes, which plausibly widens the contention window. I have not proven that is the trigger, and the unguarded callback is a problem regardless.

Introduced by 9479cde (mutex protection, 2025-01-18) and 0bff66e (lock timeouts, 2025-11-09).

[boatbod]

While I do think there is clear merit in handling a timeout in a recoverable manner, the presence of a lock timeout strongly suggests something else very bad is going on. Firstly, I have a hard time figuring out why it would be a good idea to wait 5 seconds for tk_p25 to obtain a lock when the signaling is being received off the line in real time. Either your hardware is just too slow, or it is too busy doing other things to run op25 without stuttering and stalling all over the place. Secondly, trapping the timeout, discarding the message, and attempting to continue processing may leave data in an undefined state. Partially updated data structures, a hanging mutex? I don't know, but the idea concerns me enough that it would need much more thought before moving forward with the fix proposed.