Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Crash when transmitting in SSB over pulseaudio RTP #1661

Closed
sh123 opened this issue Apr 16, 2023 · 13 comments
Closed

Crash when transmitting in SSB over pulseaudio RTP #1661

sh123 opened this issue Apr 16, 2023 · 13 comments

Comments

@sh123
Copy link

sh123 commented Apr 16, 2023

RPI4 (bullseye distro), sdrangel master version, when using SSB transmit plugin to transmit from microphone through pulseaudio rtp module, after a while application is freezing and then crashes with corrupted double-linked list

2023-04-16 11:22:11.694 (D) CWKeyer::applySettings:   m_dashKey:  Qt::Key_Minus  m_dashKeyModifiers:  QFlags<Qt::KeyboardModifier>(NoModifier)  m_dotKey:  Qt::Key_Period  m_dotKeyModifiers:  QFlags<Qt::KeyboardModifier>(NoModifier)  m_keyboardIambic:  true  m_loop:  false  m_mode:  0  m_sampleRate:  48000  m_text:  ""  m_wpm:  13
2023-04-16 11:22:11.694 (D) CWKeyer::handleMessage: MsgConfigureCWKeyer
2023-04-16 11:22:11.694 (D) CWKeyer::applySettings:   m_dashKey:  Qt::Key_Minus  m_dashKeyModifiers:  QFlags<Qt::KeyboardModifier>(NoModifier)  m_dotKey:  Qt::Key_Period  m_dotKeyModifiers:  QFlags<Qt::KeyboardModifier>(NoModifier)  m_keyboardIambic:  true  m_loop:  false  m_mode:  0  m_sampleRate:  48000  m_text:  ""  m_wpm:  13
2023-04-16 11:22:14.829 (D) SSBMod::handleMessage: MsgConfigureSSBMod
2023-04-16 11:22:14.829 (D) SSBModBaseband::handleMessage: MsgConfigureSSBModBaseband
2023-04-16 11:22:14.829 (D) AudioDeviceManager::addAudioSource: 11: 0x5580cf8fe8
2023-04-16 11:22:15.357 (W) AudioInputDevice::start: using audio device #11: rtpfrompc.monitor
2023-04-16 11:22:15.357 (I) AudioInputDevice::start: audio format OK
corrupted double-linked list
Aborted (core dumped)

Happens in libqtmedia_pulse.so, so might be issue with qt and/or pulse?

(gdb) bt
#0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1  0x0000007f902ebaa0 in __GI_abort () at abort.c:79
#2  0x0000007f90338e80 in __libc_message (action=action@entry=do_abort, fmt=fmt@entry=0x7f903fc648 "%s\n")
    at ../sysdeps/posix/libc_fatal.c:155
#3  0x0000007f903403dc in malloc_printerr (str=str@entry=0x7f903f8200 "double free or corruption (!prev)") at malloc.c:5347
#4  0x0000007f90341830 in _int_free (av=0x7ed4000020, p=0x7ed4021e90, have_lock=<optimized out>) at malloc.c:4317
#5  0x0000007f90740280 in QRingBuffer::free(long long) () at /lib/aarch64-linux-gnu/libQt5Core.so.5
#6  0x0000007f90740458 in QRingBuffer::read(char*, long long) () at /lib/aarch64-linux-gnu/libQt5Core.so.5
#7  0x0000007f9081f498 in QIODevicePrivate::read(char*, long long, bool) () at /lib/aarch64-linux-gnu/libQt5Core.so.5
#8  0x0000007f880ac920 in  () at /usr/lib/aarch64-linux-gnu/qt5/plugins/audio/libqtmedia_pulse.so
#9  0x0000007f909324d4 in  () at /lib/aarch64-linux-gnu/libQt5Core.so.5
#10 0x0000007f90936cc0 in QTimer::timeout(QTimer::QPrivateSignal) () at /lib/aarch64-linux-gnu/libQt5Core.so.5
#11 0x0000007f909276e8 in QObject::event(QEvent*) () at /lib/aarch64-linux-gnu/libQt5Core.so.5
#12 0x0000007f913bea80 in QApplicationPrivate::notify_helper(QObject*, QEvent*) ()
    at /lib/aarch64-linux-gnu/libQt5Widgets.so.5
#13 0x0000007f908f5460 in QCoreApplication::notifyInternal2(QObject*, QEvent*) () at /lib/aarch64-linux-gnu/libQt5Core.so.5
#14 0x0000007f90956408 in QTimerInfoList::activateTimers() () at /lib/aarch64-linux-gnu/libQt5Core.so.5
#15 0x0000007f90956dec in  () at /lib/aarch64-linux-gnu/libQt5Core.so.5
#16 0x0000007f8ecdabc8 in g_main_context_dispatch () at /lib/aarch64-linux-gnu/libglib-2.0.so.0
#17 0x0000007f8ecdae5c in  () at /lib/aarch64-linux-gnu/libglib-2.0.so.0
#18 0x0000007f8ecdaf24 in g_main_context_iteration () at /lib/aarch64-linux-gnu/libglib-2.0.so.0
#19 0x0000007f90957154 in QEventDispatcherGlib::processEvents(QFlags<QEventLoop::ProcessEventsFlag>) ()
    at /lib/aarch64-linux-gnu/libQt5Core.so.5
#20 0x0000007f908f38ac in QEventLoop::exec(QFlags<QEventLoop::ProcessEventsFlag>) ()
    at /lib/aarch64-linux-gnu/libQt5Core.so.5
#21 0x0000007f907089ec in QThread::exec() () at /lib/aarch64-linux-gnu/libQt5Core.so.5
#22 0x0000007f90709e6c in  () at /lib/aarch64-linux-gnu/libQt5Core.so.5
#23 0x0000007f8f6d8648 in start_thread (arg=0x7ee2bfb980) at pthread_create.c:477
#24 0x0000007f9039dc1c in thread_start () at ../sysdeps/unix/sysv/linux/aarch64/clone.S:78

Also, compared to older version (~1 year ago), app started consuming lot of CPU when idling, no processing is done sinks and sources are stopped.

image

Tried to run with soapy remote, but there is also crash in SoapyRPCPacker when soapy server drops connection:

2023-04-16 15:53:27.588 (D) SoapySDRInputThread::SoapySDRInputThread
2023-04-16 15:53:27.589 (D) SoapySDRInput::start: (re)sart buddy thread
2023-04-16 15:53:27.589 (D) SoapySDRInput::start: started
terminate called after throwing an instance of 'std::runtime_error'
2023-04-16 15:53:27.589 (D) DSPDeviceSourceEngine::gotoRunning: starting  SpectrumVis
  what():  SoapyRPCPacker::send() FAIL: send() [32: Broken pipe]
2023-04-16 15:53:27.589 (D) DSPDeviceSourceEngine::gotoRunning: starting  SSBDemod
Aborted

There is also crash when selecting output audio device

2023-04-19 18:26:34.707 (D) GLSpectrumGUI::handleInputMessages: message: GLSpectrumView::MsgReportSampleRate
2023-04-19 18:27:21.592 (D) AudioOutputDevice::stop
2023-04-19 18:27:21.592 (W) QObject::killTimer: Timers cannot be stopped from another thread
2023-04-19 18:27:21.594 (W) QObject::~QObject: Timers cannot be stopped from another thread
Bus error
@sh123 sh123 closed this as completed Apr 20, 2023
@f4exb
Copy link
Owner

f4exb commented Apr 21, 2023

Well I also have quantity of issues related to QRingBuffer::read mostly some kind of infinite loop but sometimes similar memory issues so there could be something fishy here. Very difficult to track since there is no SDRangel code directly involved similarly to the stack trace shown above. Possibly a Qt issue. This is random and in my case I have SSB demods (not mods) in my setup.

@sh123
Copy link
Author

sh123 commented Apr 21, 2023

@f4exb , I cannot reproduce this issue with RX, only when TX, it might be issue with QT/pulse corrupting memory, but under valgrind there is a number of invalid memory reads in other places, maybe it is consequence, but valgrind does not point to qt/pulse, for example

023-04-21 12:01:13.334 (D) GLShaderSpectrogram::initGrid: requested:  256  actual:  256
2023-04-21 12:01:15.765 (W) SampleSourceFifo::write: underrun (write too slow) using 9600 old samples
==19650== Thread 21 QThread:
==19650== Invalid read of size 8
==19650==    at 0x4851268: __GI_memmove (vg_replace_strmem.c:1271)
==19650==    by 0x49BCEA37: UnknownInlinedFun (stl_algobase.h:426)
==19650==    by 0x49BCEA37: UnknownInlinedFun (stl_algobase.h:472)
==19650==    by 0x49BCEA37: UnknownInlinedFun (stl_algobase.h:506)
==19650==    by 0x49BCEA37: UnknownInlinedFun (stl_algobase.h:513)
==19650==    by 0x49BCEA37: UnknownInlinedFun (stl_algobase.h:569)
==19650==    by 0x49BCEA37: SSBModSource::pullAudio(unsigned int) (ssbmodsource.cpp:156)
==19650==    by 0x49BC9B33: SSBModBaseband::processFifo(std::vector<Sample, std::allocator<Sample> >&, unsigned int, unsigned int) (ssbmodbaseband.cpp:128)
==19650==    by 0x49BC9C2F: SSBModBaseband::handleData() (ssbmodbaseband.cpp:116)
==19650==    by 0x653E7D3: QObject::event(QEvent*) (in /usr/lib/aarch64-linux-gnu/libQt5Core.so.5.15.2)
==19650==    by 0x568DA7F: QApplicationPrivate::notify_helper(QObject*, QEvent*) (in /usr/lib/aarch64-linux-gnu/libQt5Widgets.so.5.15.2)
19650==  Address 0x1a7f6360 is 0 bytes after a block of size 96,000 alloc'd
==19650==    at 0x484A484: operator new(unsigned long) (vg_replace_malloc.c:342)
==19650==    by 0x49BCE1F3: std::vector<AudioSample, std::allocator<AudioSample> >::_M_default_append(unsigned long) (new_allocator.h:115)
==19650==    by 0x49BD1BB3: UnknownInlinedFun (stl_vector.h:940)
==19650==    by 0x49BD1BB3: SSBModSource::SSBModSource() (ssbmodsource.cpp:54)
==19650==    by 0x49BCD3FF: SSBModBaseband::SSBModBaseband() (ssbmodbaseband.cpp:29)
==19650==    by 0x49BCD803: SSBMod::SSBMod(DeviceAPI*) (ssbmod.cpp:67)
==19650==    by 0x49BD457B: non-virtual thunk to SSBModPlugin::createTxChannel(DeviceAPI*, BasebandSampleSource**, ChannelAPI**) const (ssbmodplugin.cpp:61)
==19650==    by 0x49DF193: DeviceUISet::loadTxChannelSettings(Preset const*, PluginAPI*, QList<Workspace*>*, Workspace*) (deviceuiset.cpp:434)
==19650==    by 0x4907CD3: MainWindow::loadConfiguration(Configuration const*, bool) (mainwindow.cpp:1484)

It does not happen with hardware audio input, only with pulse RTP when TX with SSB module, maybe underrun/overrun causes it, because if I add qDebug() log lines into SSBModSource::pullAudio and SSBModSource::handleAudio it does not seem to crash for minutes as it introduces some delay?

@f4exb
Copy link
Owner

f4exb commented Apr 21, 2023

Indeed in this instruction (ssbmodsource.cpp:156):

std::copy(&m_audioReadBuffer[0], &m_audioReadBuffer[nbSamplesAudio], &m_audioBuffer[0]);

There is no guarantee that nbSamplesAudio will not exceed the size of m_audioReadBuffer. As far as I can see it is dimensioned at 24000 samples so 0.5s in most cases. However at certain times maybe a delay exceeding 0.5s could be accumulated and thus too many samples requested. I vaguely remember some similar issue encountered before.

@sh123
Copy link
Author

sh123 commented Apr 22, 2023

@f4exb , unfortunately this change did not fix issue for me as it is only for RX, but it also broke RX as receive stops working after clicking on STOP->START for the selected SDR receiver, it starts producing next lines, only app restart helps.

2023-04-22 22:46:53.880 (D) SSBDemodSink::processOneSample: 0/16384 samples written
2023-04-22 22:46:54.239 (C) AudioFifo::write: () overflow 16384 samples
2023-04-22 22:46:54.239 (D) SSBDemodSink::processOneSample: 0/16384 samples written
2023-04-22 22:46:54.565 (C) AudioFifo::write: () overflow 16384 samples
2023-04-22 22:46:54.565 (D) SSBDemodSink::processOneSample: 0/16384 samples written
2023-04-22 22:46:54.917 (C) AudioFifo::write: () overflow 16384 samples
2023-04-22 22:46:54.917 (D) SSBDemodSink::processOneSample: 0/16384 samples written
2023-04-22 22:46:55.245 (C) AudioFifo::write: () overflow 16384 samples
2023-04-22 22:46:55.245 (D) SSBDemodSink::processOneSample: 0/16384 samples written

@f4exb
Copy link
Owner

f4exb commented Apr 24, 2023

I don't think this is related to the change. If you look at the code what it does is just a sanity check:

        if (m_audioBufferFill >= m_audioBuffer.size())
        {
            if (m_audioBufferFill > m_audioBuffer.size()) {
                qDebug("SSBDemodSink::processOneSample: dropping %d samples", (int) m_audioBufferFill - (int) m_audioBuffer.size());
            }

Normally m_audioBufferFill should never exceed m_audioBuffer.size() but since the precaution was made to do a >= comparison instead of == it remains a half-baked solution if you don't check for > later. This is just what this change does.

Then in the rest of the code you are left with the m_audioBufferFill == m_audioBuffer.size() condition so values are interchangeable.

@sh123
Copy link
Author

sh123 commented Apr 24, 2023

Yes, sorry, there must be something wrong with pulse/qt5 in RPIs bullsye distro , restarted RPI and stop->play SDR is able to start audio again.

But with TX app just completely freezes now after about 10 seconds of transmission.

This setup worked for me in the past with previous RPI distro and older SDRAngel version (about 1 year old). Must be some regression in pulseaudio... will re-try when they will release updates.

@srcejon
Copy link
Collaborator

srcejon commented Apr 25, 2023

edit: Deleted - PC problem, not SDRangel

@sh123
Copy link
Author

sh123 commented Apr 25, 2023

Interesting, that this initial SSB transmit issue does not happen when there is only one way pulseaudio RTP stream from PC to RPI running SDRAngel (only tx-ing through ssb, not rx-ing anything). When there are two pulseaudio streams from PC to RPI and from RPI to PC (it is enough just to have null sink without actual stream attached) then this issue happens. Maybe as a workaround it is possible to transmit through pulse audio and receive through built-in RTP...

@f4exb
Copy link
Owner

f4exb commented Apr 25, 2023

I am sorry that this part (at least) is so badly written that this simple change causes issues. I will fallback but this does not encourages me to continue with development of this software.

f4exb added a commit that referenced this issue Apr 25, 2023
@srcejon
Copy link
Collaborator

srcejon commented Apr 25, 2023

In case you missed it, I already deleted my earlier comments, as this change doesn't appear to have been the problem for me. Sorry about that. It just happened that my sound card stopped working properly at the same time as I pulled this update, and I was seeing the same buffer messages as above, so hasitly assumed it was the same thing. But seems fine after a reboot.

@sh123
Copy link
Author

sh123 commented Apr 25, 2023

@f4exb, we all like this software, code is readable, no problems, made a number of QSOs over QO-100 by using it and remote outdoors station... just something got broken in qt/pulse after taking dish with RPI from garage and upgrade :/

@f4exb
Copy link
Owner

f4exb commented Apr 25, 2023

OK glad to hear that. I hate it when it goes brittle for no apparent reason.

@sh123
Copy link
Author

sh123 commented Apr 27, 2023

Maybe somebody will find it helpful, this workaround does not trigger crash:

  • Use RTP stream from PC (mic) to RPI
pactl load-module module-native-protocol-tcp auth-ip-acl='127.0.0.1;192.168.0.0/16' auth-anonymous=1
pactl load-module module-rtp-send source=<source mic device> destination_ip=<rpi ip> rate=8000 channels=1
  • Use TCP tunnel sink from RPI to PC (speaker), it avoids creating second null sink on RPI side
pactl load-module module-tunnel-sink-new server=<pc ip> sink=<pc playback device> rate=8000 channels=1
pactl load-module module-null-sink sink_name=rtpfrompc sink_properties="device.description='RPI<-PC'"
pactl load-module module-rtp-recv sink=rtpfrompc sap_address=0.0.0.0 latency_msec=100

Also other qt5 based software, e.g. wsjtx does not have this issue when operating over pulseaudio RTP.

@sh123 sh123 changed the title Crash when transmitting in SSB Crash when transmitting in SSB over pulseaudio RTP Apr 27, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants