f4exb / sdrangel

SDR Rx/Tx software for Airspy, Airspy HF+, BladeRF, HackRF, LimeSDR, PlutoSDR, RTL-SDR, SDRplay and FunCube
GNU General Public License v3.0
2.91k stars 441 forks source link

Crash/hang when closing FileSink #1356

Closed srcejon closed 2 years ago

srcejon commented 2 years ago

It seems the FileSink can crash/hang when closing if acquisition is running

To recreate

CTRL-C (gdb) info stack

0 __futex_abstimed_wait_common64 (private=-10496, cancel=true, abstime=0x7fffffffd390, op=137, expected=0, futex_word=0x55555567db34) at futex-internal.c:57

1 __futex_abstimed_wait_common (cancel=true, private=-10496, abstime=0x7fffffffd390, clockid=32767, expected=0, futex_word=0x55555567db34) at futex-internal.c:87

2 __GI___futex_abstimed_wait_cancelable64

(futex_word=futex_word@entry=0x55555567db34, expected=expected@entry=0, clockid=clockid@entry=1, abstime=abstime@entry=0x7fffffffd390, private=private@entry=0) at futex-internal.c:139

3 0x00007ffff5b19d9e in __pthread_cond_wait_common (abstime=0x7fffffffd390, clockid=1, mutex=0x55555567dae0, cond=0x55555567db08) at pthread_cond_wait.c:504

4 ___pthread_cond_timedwait64 (cond=0x55555567db08, mutex=0x55555567dae0, abstime=0x7fffffffd390) at pthread_cond_wait.c:653

5 0x00007ffff5fb3a4c in QWaitCondition::wait(QMutex*, QDeadlineTimer) () at /lib/x86_64-linux-gnu/libQt5Core.so.5

6 0x00007ffff5fb3b4b in QWaitCondition::wait(QMutex*, unsigned long) () at /lib/x86_64-linux-gnu/libQt5Core.so.5

7 0x00007ffff73fe304 in SyncMessenger::sendWait(Message&, unsigned long) (this=0x55555565ee08, message=..., msPollTime=100)

at /opt/build/srcejon/sdrangel/sdrbase/util/syncmessenger.cpp:49

8 0x00007ffff7320a6d in DSPDeviceSourceEngine::removeSink(BasebandSampleSink*) (this=0x55555565edd0, sink=0x5555565d00f0)

at /opt/build/srcejon/sdrangel/sdrbase/dsp/dspdevicesourceengine.cpp:134

9 0x00007ffff738c14b in DeviceAPI::removeChannelSink(BasebandSampleSink*, int) (this=0x555556566a80, sink=0x5555565d00f0, streamIndex=0)

at /opt/build/srcejon/sdrangel/sdrbase/device/deviceapi.cpp:79

10 0x00007fff816f776a in FileSink::~FileSink() (this=0x5555565d00f0, this=) at /opt/build/srcejon/sdrangel/plugins/channelrx/filesink/filesink.cpp:96

11 0x00007fff816f783e in FileSink::~FileSink() (this=0x5555565d00f0, this=) at /opt/build/srcejon/sdrangel/plugins/channelrx/filesink/filesink.cpp:103

12 0x00007fff816f6eb8 in FileSink::destroy() (this=0x5555565d00f0) at /opt/build/srcejon/sdrangel/plugins/channelrx/filesink/filesink.h:86

13 0x00007ffff7e55b35 in DeviceUISet::handleDeleteChannel(ChannelAPI*) (this=0x555556389850, channelAPI=0x5555565d00f8) at /opt/build/srcejon/sdrangel/sdrgui/device/deviceuiset.cpp:747

14 0x00007ffff7e55834 in operator()() const (__closure=0x5555568696d0) at /opt/build/srcejon/sdrangel/sdrgui/device/deviceuiset.cpp:732

15 0x00007ffff7e592a6 in QtPrivate::FunctorCall<QtPrivate::IndexesList<>, QtPrivate::List<>, void, DeviceUISet::handleChannelGUIClosing(ChannelGUI*)::<lambda()> >::call(struct {...} &, void **) (f=..., arg=0x7fffffffd780) at /usr/include/x86_64-linux-gnu/qt5/QtCore/qobjectdefs_impl.h:146

16 0x00007ffff7e58c46 in QtPrivate::Functor<DeviceUISet::handleChannelGUIClosing(ChannelGUI)::<lambda()>, 0>::call<QtPrivate::List<>, void>(struct {...} &, void , void **)

(f=..., arg=0x7fffffffd780) at /usr/include/x86_64-linux-gnu/qt5/QtCore/qobjectdefs_impl.h:256

17 0x00007ffff7e587eb in QtPrivate::QFunctorSlotObject<DeviceUISet::handleChannelGUIClosing(ChannelGUI)::<lambda()>, 0, QtPrivate::List<>, void>::impl(int, QtPrivate::QSlotObjectBase , QObject *, void *, bool ) (which=1, this_=0x5555568696c0, r=0x555556389850, a=0x7fffffffd780, ret=0x0) at /usr/include/x86_64-linux-gnu/qt5/QtCore/qobjectdefs_impl.h:443

18 0x00007ffff61d1a53 in () at /lib/x86_64-linux-gnu/libQt5Core.so.5

19 0x00007ffff61cae23 in QObject::destroyed(QObject*) () at /lib/x86_64-linux-gnu/libQt5Core.so.5

20 0x00007ffff6cc6b13 in QWidget::~QWidget() () at /lib/x86_64-linux-gnu/libQt5Widgets.so.5

21 0x00007ffff7d24516 in ChannelGUI::~ChannelGUI() (this=0x555555c9f1c0, this=) at /opt/build/srcejon/sdrangel/sdrgui/channel/channelgui.cpp:212

22 0x00007fff8170bc7d in FileSinkGUI::~FileSinkGUI() (this=0x555555c9f1c0, this=) at /opt/build/srcejon/sdrangel/plugins/channelrx/filesink/filesinkgui.cpp:239

23 0x00007fff8170bcaa in FileSinkGUI::~FileSinkGUI() (this=0x555555c9f1c0, this=) at /opt/build/srcejon/sdrangel/plugins/channelrx/filesink/filesinkgui.cpp:239

Exception thrown: read access violation.

image

The above are with a Debug build. Windows doesn't seem to crash with a Release build. On Linux release build:

2022-07-21 11:33:33.521 (D) FileSink::stop 2022-07-21 11:33:33.524 (W) Qt has caught an exception thrown from an event handler. Throwing exceptions from an event handler is not supported in Qt. You must not let any exception whatsoever propagate through Qt code. If that is not possible, in Qt 5 you must at least reimplement QCoreApplication::notify() and catch all exceptions there.

terminate called after throwing an instance of 'std::bad_alloc' what(): std::bad_alloc Aborted (core dumped)

f4exb commented 2 years ago

It happens only when closing the FileSink with the "X" icon not when exiting with Ctl-Q or File>Exit.

f4exb commented 2 years ago

Strangely enough the DeviceUISet::handleChannelGUIClosing method is called twice for a FileSink:

2022-07-22 03:54:40.843 (D) ChannelGUI::closeEvent
2022-07-22 03:54:40.843 (D) FileSink::handleMessage: MsgConfigureFileSink
2022-07-22 03:54:40.843 (D) FileSink::applySettings: m_inputFrequencyOffset:  0 m_log2Decim:  0 m_fileRecordName:  "/opt/build/sdrangel/build/test.sdriq" force:  false
2022-07-22 03:54:40.843 (D) FileSinkBaseband::handleMessage: MsgConfigureFileSinkBaseband
2022-07-22 03:54:40.843 (D) FileSinkBaseband::applySettings: m_log2Decim: 0 m_inputFrequencyOffset: 0 m_fileRecordName:  "/opt/build/sdrangel/build/test.sdriq" m_centerFrequency:  435000000 force:  false
2022-07-22 03:54:40.844 (D) FileSinkSink::applySettings: m_fileRecordName:  "/opt/build/sdrangel/build/test.sdriq" force:  false
2022-07-22 03:54:40.844 (D) FileSink::handleMessage: MsgConfigureFileSink
2022-07-22 03:54:40.844 (D) FileSink::applySettings: m_inputFrequencyOffset:  0 m_log2Decim:  0 m_fileRecordName:  "/opt/build/sdrangel/build/test.sdriq" force:  false
2022-07-22 03:54:40.844 (D) FileSinkBaseband::handleMessage: MsgConfigureFileSinkBaseband
2022-07-22 03:54:40.844 (D) DeviceUISet::handleChannelGUIClosing: File Sink: 0
2022-07-22 03:54:40.844 (D) DeviceUISet::handleChannelGUIClosing: File Sink: 0
2022-07-22 03:54:40.844 (D) FileSinkBaseband::applySettings: m_log2Decim: 0 m_inputFrequencyOffset: 0 m_fileRecordName:  "/opt/build/sdrangel/build/test.sdriq" m_centerFrequency:  435000000 force:  false
2022-07-22 03:54:40.844 (D) FileSinkSink::applySettings: m_fileRecordName:  "/opt/build/sdrangel/build/test.sdriq" force:  false
2022-07-22 03:54:40.844 (D) ChannelGUI::~ChannelGUI
2022-07-22 03:54:40.844 (D) ChannelGUI::~ChannelGUI: end
2022-07-22 03:54:40.844 (D) DSPDeviceSourceEngine::removeSink:  FileSink
2022-07-22 03:54:40.844 (D) DSPDeviceSourceEngine::handleSynchronousMessages:  DSPRemoveBasebandSampleSink
2022-07-22 03:54:40.844 (D) FileSink::stop
2022-07-22 03:54:40.844 (D) FileRecord::stopRecording

vs NFMDemod:

2022-07-22 04:02:03.983 (D) ChannelGUI::closeEvent
2022-07-22 04:02:03.984 (D) NFMDemodGUI::applySettings
2022-07-22 04:02:03.984 (D) NFMDemod::handleMessage: MsgConfigureNFMDemod
2022-07-22 04:02:03.984 (D) NFMDemod::applySettings:  m_inputFrequencyOffset:  0  m_rfBandwidth:  12500  m_afBandwidth:  3000  m_fmDeviation:  5000  m_volume:  1  m_squelchGate:  5  m_deltaSquelch:  false  m_squelch:  -30  m_ctcssIndex:  0  m_ctcssOn:  false  m_dcsOn:  false  m_dcsCode:  23  m_dcsPositive:  false  m_highPass:  true  m_audioMute:  false  m_audioDeviceName:  "System default device"  m_streamIndex:  0  m_useReverseAPI:  false  m_reverseAPIAddress:  "127.0.0.1"  m_reverseAPIPort:  8888  m_reverseAPIDeviceIndex:  0  m_reverseAPIChannelIndex:  0  force:  false
2022-07-22 04:02:03.984 (D) NFMDemodBaseband::handleMessage: MsgConfigureNFMDemodBaseband
2022-07-22 04:02:03.984 (D) DeviceUISet::handleChannelGUIClosing: NFM Demodulator: 1
2022-07-22 04:02:03.984 (D) NFMDemodSink::applySettings:  m_inputFrequencyOffset:  0  m_rfBandwidth:  12500  m_afBandwidth:  3000  m_fmDeviation:  5000  m_volume:  1  m_squelchGate:  5  m_deltaSquelch:  false  m_squelch:  -30  m_ctcssIndex:  0  m_ctcssOn:  false  m_dcsOn:  false  m_dcsCode:  19  m_dcsPositive:  false  m_highPass:  true  m_audioMute:  false  m_audioDeviceName:  "System default device"  force:  false
2022-07-22 04:02:03.984 (D) ChannelGUI::~ChannelGUI
2022-07-22 04:02:03.984 (D) ChannelGUI::~ChannelGUI: end
2022-07-22 04:02:03.984 (D) DSPDeviceSourceEngine::removeSink:  NFMDemod
2022-07-22 04:02:03.984 (D) DSPDeviceSourceEngine::handleSynchronousMessages:  DSPRemoveBasebandSampleSink
2022-07-22 04:02:03.984 (D) NFMDemod::stop
2022-07-22 04:02:03.985 (D) AudioDeviceManager::removeAudioSink: 0x55e66190e710
f4exb commented 2 years ago

Same thing with SigMFFileSink Also happens while recording or not

f4exb commented 2 years ago

I have narrowed down the problem to here: https://github.com/f4exb/sdrangel/blob/master/plugins/channelrx/filesink/filesink.cpp#L164

And also here: https://github.com/f4exb/sdrangel/blob/master/plugins/channelrx/filesink/filesink.cpp#L99

I think this happens since the order of deletion between the channel and its GUI has been reversed. The GUI has been deleted but FileSink was not told that it should not access the GUI message queue anymore. Thus in the destructor of the GUI the reference to the message queue in FileSink should be nullified.

It is probably worth having a look if this could not happen anywhere else. The case for SigMFFileSink which is constructed on the same model has already been identified.

Note that in this case the stop() method is not called from the destructor but from the DSP engine when removing the channel. This does not change the game as it happens in the same time frame.

f4exb commented 2 years ago

After double check only SigMFFileSink is in a similar case.