Nature40 / pyradiotracking

Detect signals of wildlife tracking systems with RTL SDR devices.
GNU General Public License v3.0
14 stars 1 forks source link

[Bug] Dead loggers do not lead to program termination when exceptions occur in the python callback #14

Closed jonashoechst closed 3 years ago

jonashoechst commented 3 years ago

There seems to be a rare case, in which a dead logger leads to a process failing instead of restarting / terminating the program.

Mar 19 11:13:40 jonas-rpi-00001 python3[970]: INFO:radiotracking.analyze:SDR 0 recv 131072, clock drift: -0.021 s, filtered 0 / 0 signals, block len: 43.7 ms, compute: 20.8 ms
Mar 19 11:13:40 jonas-rpi-00001 python3[970]: INFO:radiotracking.analyze:SDR 2 recv 131072, clock drift: -0.026 s, filtered 0 / 0 signals, block len: 43.7 ms, compute: 18.0 ms
Mar 19 11:13:40 jonas-rpi-00001 python3[970]: INFO:radiotracking.analyze:SDR 1 recv 131072, clock drift: -0.024 s, filtered 0 / 0 signals, block len: 43.7 ms, compute: 21.5 ms
Mar 19 11:13:40 jonas-rpi-00001 python3[970]: INFO:radiotracking.analyze:SDR 3 recv 131072, clock drift: -0.052 s, filtered 0 / 0 signals, block len: 43.7 ms, compute: 18.9 ms
Mar 19 11:13:40 jonas-rpi-00001 python3[970]: /usr/lib/python3/dist-packages/numpy/ctypeslib.py:527: RuntimeWarning: A builtin ctypes object gave a PEP3118 format string that does not match its itemsize, so a best-guess will be made of the data type. Newer versions of python may behave correctly.
Mar 19 11:13:40 jonas-rpi-00001 python3[970]:   return array(obj, copy=False)
Mar 19 11:13:40 jonas-rpi-00001 python3[970]: WARNING:radiotracking.analyze:SDR 3 total clock drift (0.14707 s) is larger than two blocks, signal detection is degraded. Resyncing...
Mar 19 11:13:40 jonas-rpi-00001 python3[970]: /usr/lib/python3/dist-packages/scipy/signal/spectral.py:1773: UserWarning: nperseg = 256 is greater than input length  = 0, using nperseg = 0
Mar 19 11:13:40 jonas-rpi-00001 python3[970]:   .format(nperseg, input_length))
Mar 19 11:13:40 jonas-rpi-00001 python3[970]: Traceback (most recent call last):
Mar 19 11:13:40 jonas-rpi-00001 python3[970]:   File "_ctypes/callbacks.c", line 232, in 'calling callback function'
Mar 19 11:13:40 jonas-rpi-00001 python3[970]:   File "/usr/local/lib/python3.7/dist-packages/rtlsdr/rtlsdr.py", line 612, in _bytes_converter_callback
Mar 19 11:13:40 jonas-rpi-00001 python3[970]:     self._callback_bytes(values, context)
Mar 19 11:13:40 jonas-rpi-00001 python3[970]:   File "/usr/local/lib/python3.7/dist-packages/rtlsdr/rtlsdr.py", line 659, in _samples_converter_callback
Mar 19 11:13:40 jonas-rpi-00001 python3[970]:     self._callback_samples(iq, context)
Mar 19 11:13:40 jonas-rpi-00001 python3[970]:   File "/home/pi/pyradiotracking/radiotracking/analyze.py", line 154, in process_samples
Mar 19 11:13:40 jonas-rpi-00001 python3[970]:     signals = self.extract_signals(freqs, times, spectrogram, ts_start)
Mar 19 11:13:40 jonas-rpi-00001 python3[970]:   File "/home/pi/pyradiotracking/radiotracking/analyze.py", line 227, in extract_signals
Mar 19 11:13:40 jonas-rpi-00001 python3[970]:     signal_min_duration_num = self.signal_min_duration / (times[1] - times[0])
Mar 19 11:13:40 jonas-rpi-00001 python3[970]: IndexError: index 1 is out of bounds for axis 0 with size 0
Mar 19 11:13:40 jonas-rpi-00001 python3[970]: WARNING:radiotracking.analyze:SDR 3 total clock drift (0.020442 s) is larger than two blocks, signal detection is degraded. Resyncing...
Mar 19 11:13:40 jonas-rpi-00001 python3[970]: Traceback (most recent call last):
Mar 19 11:13:40 jonas-rpi-00001 python3[970]:   File "_ctypes/callbacks.c", line 232, in 'calling callback function'
Mar 19 11:13:40 jonas-rpi-00001 python3[970]:   File "/usr/local/lib/python3.7/dist-packages/rtlsdr/rtlsdr.py", line 612, in _bytes_converter_callback
Mar 19 11:13:40 jonas-rpi-00001 python3[970]:     self._callback_bytes(values, context)
Mar 19 11:13:40 jonas-rpi-00001 python3[970]:   File "/usr/local/lib/python3.7/dist-packages/rtlsdr/rtlsdr.py", line 659, in _samples_converter_callback
Mar 19 11:13:40 jonas-rpi-00001 python3[970]:     self._callback_samples(iq, context)
Mar 19 11:13:40 jonas-rpi-00001 python3[970]:   File "/home/pi/pyradiotracking/radiotracking/analyze.py", line 154, in process_samples
Mar 19 11:13:40 jonas-rpi-00001 python3[970]:     signals = self.extract_signals(freqs, times, spectrogram, ts_start)
Mar 19 11:13:40 jonas-rpi-00001 python3[970]:   File "/home/pi/pyradiotracking/radiotracking/analyze.py", line 227, in extract_signals
Mar 19 11:13:40 jonas-rpi-00001 python3[970]:     signal_min_duration_num = self.signal_min_duration / (times[1] - times[0])
Mar 19 11:13:40 jonas-rpi-00001 python3[970]: IndexError: index 1 is out of bounds for axis 0 with size 0
Mar 19 11:13:40 jonas-rpi-00001 python3[970]: WARNING:radiotracking.analyze:SDR 3 total clock drift (0.008299 s) is larger than two blocks, signal detection is degraded. Resyncing...
jonashoechst commented 3 years ago

As far as I understood the bug, rtlsdr does return zero bytes here, which leads the further processing to fail and raise an exception.

The main loop checks its SDRs periodically to handle such errors: https://github.com/Nature40/pyradiotracking/blob/7fa51520230e2b48067d7190d369faf3344e4a17/radiotracking/__main__.py#L123-L124

However, this raised exception does somehow not lead to the process being stopped.

jonashoechst commented 3 years ago

The underlying exception can easily be fixed by checking for the times array. However, if other Exceptions arise from corrupt data, the underlying bug will still be problematic.

jonashoechst commented 3 years ago

A redundant watchdog system was introduced in fb44944 which should fix this error and other potential errors related to incorrect analyzer process termination.