AlexandreRouma
Dead lock, when switching one VFO sink from "New audio" to "Null" in a multi-VFO configuration
Setup:
- running self-compiled SDR++ commit 8deb018 on MacBook Air (13-inch, 2017) macOS 11.6 (Big Sur)
- source is RTL-SDR
- multi-VFO with 3 radios "Radio 1", "Radio 2" and "Radio 3" (all not muted)
- each radio has the "New Audio" sink set
- SDR++ is playing
Now try to change the VFO sink of "Radio 2" from "New Audio" to "Null". SDR++ immediately hangs for ever (spinning beach ball).
Here are the related stack traces:
(lldb) thread list
Process 32032 stopped
* thread #1: tid = 0x27b9a7, 0x00007fff2041c4ca libsystem_kernel.dylib`__psynch_mutexwait + 10, queue = 'com.apple.main-thread', stop reason = signal SIGSTOP
thread #2: tid = 0x27b9c4, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #5: tid = 0x27b9da, 0x00007fff2041a2ba libsystem_kernel.dylib`mach_msg_trap + 10, name = 'com.apple.NSEventThread'
thread #13: tid = 0x27b9eb, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #14: tid = 0x27b9ef, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #15: tid = 0x27b9f1, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #16: tid = 0x27b9f4, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #17: tid = 0x27b9f6, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #18: tid = 0x27b9f8, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #19: tid = 0x27b9fa, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #20: tid = 0x27b9fd, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #21: tid = 0x27ba01, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #22: tid = 0x27ba04, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #23: tid = 0x27ba06, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #24: tid = 0x27ba08, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #25: tid = 0x27ba0b, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #26: tid = 0x27ba0d, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #27: tid = 0x27ba10, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #28: tid = 0x27ba14, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #29: tid = 0x27ba17, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #30: tid = 0x27ba1c, 0x00007fff2041a2ba libsystem_kernel.dylib`mach_msg_trap + 10, name = 'org.libusb.device-hotplug'
thread #31: tid = 0x27ba1d, 0x00007fff2041a2f6 libsystem_kernel.dylib`semaphore_wait_trap + 10, name = 'AMCP Logging Spool'
thread #37: tid = 0x27ba2d, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #38: tid = 0x27ba2e, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #39: tid = 0x27ba2f, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #40: tid = 0x27ba31, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #41: tid = 0x27ba33, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #42: tid = 0x27ba36, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10, name = 'com.apple.audio.IOThread.client'
thread #43: tid = 0x27ba4a, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #44: tid = 0x27ba4b, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #45: tid = 0x27ba4c, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #46: tid = 0x27ba4e, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #47: tid = 0x27ba4f, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #48: tid = 0x27ba50, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #49: tid = 0x27ba5e, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #50: tid = 0x27ba5f, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #51: tid = 0x27ba60, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #52: tid = 0x27ba62, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #53: tid = 0x27ba63, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #54: tid = 0x27ba64, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #55: tid = 0x27ba68, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #56: tid = 0x27ba69, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #57: tid = 0x27ba6d, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #58: tid = 0x27ba77, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #59: tid = 0x27ba78, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #60: tid = 0x27ba7a, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #61: tid = 0x27ba7b, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #62: tid = 0x27ba7c, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #63: tid = 0x27ba7d, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #64: tid = 0x27ba7e, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #65: tid = 0x27ba7f, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #66: tid = 0x27ba80, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #67: tid = 0x27ba85, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #68: tid = 0x27ba86, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #69: tid = 0x27ba8e, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #73: tid = 0x27bb18, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #74: tid = 0x27bb19, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #75: tid = 0x27bb1a, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #76: tid = 0x27bb1b, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #77: tid = 0x27bb1c, 0x00007fff204209b2 libsystem_kernel.dylib`__accept + 10
thread #78: tid = 0x27bbc3, 0x00007fff204209ca libsystem_kernel.dylib`poll + 10
thread #79: tid = 0x27bdd7, 0x00007fff2041b95e libsystem_kernel.dylib`__workq_kernreturn + 10
thread #80: tid = 0x27c263, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
thread #81: tid = 0x27c264, 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
(lldb) thread select 42
* thread #42, name = 'com.apple.audio.IOThread.client'
frame #0: 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
libsystem_kernel.dylib`__psynch_cvwait:
-> 0x7fff2041ccde <+10>: jae 0x7fff2041cce8 ; <+20>
0x7fff2041cce0 <+12>: movq %rax, %rdi
0x7fff2041cce3 <+15>: jmp 0x7fff2041aad9 ; cerror_nocancel
0x7fff2041cce8 <+20>: retq
(lldb) bt
error: need to add support for DW_TAG_base_type 'auto' encoded with DW_ATE = 0x0, bit_size = 0
* thread #42, name = 'com.apple.audio.IOThread.client'
* frame #0: 0x00007fff2041ccde libsystem_kernel.dylib`__psynch_cvwait + 10
frame #1: 0x00007fff2044fe49 libsystem_pthread.dylib`_pthread_cond_wait + 1298
frame #2: 0x00007fff203b8d72 libc++.1.dylib`std::__1::condition_variable::wait(std::__1::unique_lock<std::__1::mutex>&) + 18
frame #3: 0x000000012f392644 new_portaudio_sink.dylib`AudioSink::_stereo_cb(void const*, void*, unsigned long, PaStreamCallbackTimeInfo const*, unsigned long, void*) [inlined] void std::__1::condition_variable::wait<dsp::stream<dsp::stereo_t>::read()::'lambda'()>(this=0x0000000108808a68, __lk=0x00007000093068e8, __pred=(anonymous class) @ scalar) at __mutex_base:409:9 [opt]
frame #4: 0x000000012f392615 new_portaudio_sink.dylib`AudioSink::_stereo_cb(void const*, void*, unsigned long, PaStreamCallbackTimeInfo const*, unsigned long, void*) [inlined] dsp::stream<dsp::stereo_t>::read(this=0x0000000108808998) at stream.h:64 [opt]
frame #5: 0x000000012f3925fe new_portaudio_sink.dylib`AudioSink::_stereo_cb(input=<unavailable>, output=0x000000010204b800, frameCount=800, timeInfo=<unavailable>, statusFlags=<unavailable>, userData=0x0000000108808800) at main.cpp:360 [opt]
frame #6: 0x000000012f3efa18 libportaudio.2.dylib`AdaptingOutputOnlyProcess + 183
frame #7: 0x000000012f3eee22 libportaudio.2.dylib`PaUtil_EndBufferProcessing + 601
frame #8: 0x000000012f3f3d2d libportaudio.2.dylib`AudioIOProc + 1323
frame #9: 0x000000016498fa7e CoreAudio`___lldb_unnamed_symbol88$$CoreAudio + 954
frame #10: 0x00000001649b5994 CoreAudio`___lldb_unnamed_symbol711$$CoreAudio + 1472
frame #11: 0x0000000164992c87 CoreAudio`___lldb_unnamed_symbol177$$CoreAudio + 1941
frame #12: 0x00007fff21dca61c CoreAudio`invocation function for block in HALC_ProxyIOContext::HALC_ProxyIOContext(unsigned int, unsigned int) + 5398
frame #13: 0x00007fff21f65b04 CoreAudio`HALB_IOThread::Entry(void*) + 72
frame #14: 0x00007fff2044f8fc libsystem_pthread.dylib`_pthread_start + 224
frame #15: 0x00007fff2044b443 libsystem_pthread.dylib`thread_start + 15
(lldb) frame select 4
new_portaudio_sink.dylib was compiled with optimization - stepping may behave oddly; variables may not be available.
frame #4: 0x000000012f392615 new_portaudio_sink.dylib`AudioSink::_stereo_cb(void const*, void*, unsigned long, PaStreamCallbackTimeInfo const*, unsigned long, void*) [inlined] dsp::stream<dsp::stereo_t>::read(this=0x0000000108808998) at stream.h:64 [opt]
61 int read() {
62 // Wait for data to be ready or to be stopped
63 std::unique_lock<std::mutex> lck(rdyMtx);
-> 64 rdyCV.wait(lck, [this]{ return (dataReady || readerStop); });
65
66 return (readerStop ? -1 : dataSize);
67 }
(lldb) p dataReady
(bool) $0 = false
(lldb) p readerStop
(bool) $1 = false
(lldb) thread select 1
* thread #1, queue = 'com.apple.main-thread'
frame #0: 0x00007fff2041c4ca libsystem_kernel.dylib`__psynch_mutexwait + 10
libsystem_kernel.dylib`__psynch_mutexwait:
-> 0x7fff2041c4ca <+10>: jae 0x7fff2041c4d4 ; <+20>
0x7fff2041c4cc <+12>: movq %rax, %rdi
0x7fff2041c4cf <+15>: jmp 0x7fff2041aad9 ; cerror_nocancel
0x7fff2041c4d4 <+20>: retq
(lldb) bt
* thread #1, queue = 'com.apple.main-thread'
* frame #0: 0x00007fff2041c4ca libsystem_kernel.dylib`__psynch_mutexwait + 10
frame #1: 0x00007fff2044d2ab libsystem_pthread.dylib`_pthread_mutex_firstfit_lock_wait + 76
frame #2: 0x00007fff2044b192 libsystem_pthread.dylib`_pthread_mutex_firstfit_lock_slow + 204
frame #3: 0x00007fff22190fc2 CoreAudio`HALB_Mutex::Lock() + 92
frame #4: 0x00007fff21dcc902 CoreAudio`HALC_ProxyIOContext::StopIOProc(int (*)(unsigned int, AudioTimeStamp const*, AudioBufferList const*, AudioTimeStamp const*, AudioBufferList*, AudioTimeStamp const*, void*)) + 46
frame #5: 0x00007fff21d98927 CoreAudio`HAL_HardwarePlugIn_DeviceDestroyIOProcID(AudioHardwarePlugInInterface**, unsigned int, int (*)(unsigned int, AudioTimeStamp const*, AudioBufferList const*, AudioTimeStamp const*, AudioBufferList*, AudioTimeStamp const*, void*)) + 390
frame #6: 0x00007fff221899c8 CoreAudio`HALDevice::DestroyIOProcID(int (*)(unsigned int, AudioTimeStamp const*, AudioBufferList const*, AudioTimeStamp const*, AudioBufferList*, AudioTimeStamp const*, void*)) + 116
frame #7: 0x00007fff21e75c7b CoreAudio`AudioDeviceDestroyIOProcID + 278
frame #8: 0x0000000164986ea1 CoreAudio`___lldb_unnamed_symbol18$$CoreAudio + 2663
frame #9: 0x00000001649943ad CoreAudio`___lldb_unnamed_symbol209$$CoreAudio + 201
frame #10: 0x0000000164a91bd2 CoreAudio`___lldb_unnamed_symbol3344$$CoreAudio + 30
frame #11: 0x00007fff21897460 AudioToolboxCore`APComponentInstance::disposeInstance() + 40
frame #12: 0x00007fff2199cd33 AudioToolboxCore`AudioComponentInstanceDispose + 40
frame #13: 0x000000012f3f2492 libportaudio.2.dylib`CloseStream + 234
frame #14: 0x000000012f3436ae new_portaudio_sink.dylib`AudioSink::stop(this=0x0000000109103200) at main.cpp:134:9 [opt]
frame #15: 0x00000001002c19a7 libsdrpp_core.dylib`SinkManager::setStreamSink(this=0x00000001006f5c48, name="Radio 2", providerName="None") at sink.cpp:230:23 [opt]
frame #16: 0x00000001002c405a libsdrpp_core.dylib`SinkManager::showMenu(this=<unavailable>) at sink.cpp:360:13 [opt]
frame #17: 0x000000010020482d libsdrpp_core.dylib`Menu::draw(this=0x00000001006f27b8, updateStates=false) at menu.cpp:118:13 [opt]
frame #18: 0x00000001001dbf2a libsdrpp_core.dylib`MainWindow::draw(this=0x0000000100321810) at main_window.cpp:486:23 [opt]
frame #19: 0x00000001001969ad libsdrpp_core.dylib`sdrpp_main(argc=<unavailable>, argv=<unavailable>) at core.cpp:486:29 [opt]
frame #20: 0x00007fff2046af3d libdyld.dylib`start + 1
(lldb)
The problem is harder to reproduce with new port audio sink. With rtaudio sink it is 100% reproducible with similar stack traces.
The reason, why the UI blocks is that thread 1 hangs on a mutex deep in the CoreAudio system of macOS. That mutex is currently held by thread 42, which is in the callback function of a new port audio sink. That callback function waits on a conditional variable in dsp:stream:read() @ stream.h:64. Both conditions (dataReady and readerStop) are false forever. So, thread 1 and thread 42 are in a deadlock situation. Normally in a single-VFO configuration the readerStop variable would prevent from such a deadlock, because it would be set to true for that VFO. But in a multi-VFO configuration there are multiple streams each having its own readerStop. Only one of them is set to true (that one whose sink is being changed). The other VFOs still wait for data, but obviously dataReady is stuck on false.
I think the problem is caused by an improper design of the port audio stream callback function. Here is an excerpt from the port audio documentation:
Before we begin, it's important to realize that the callback is a delicate place. This is because some systems perform the callback in a special thread, or interrupt handler, and it is rarely treated the same as the rest of your code. For most modern systems, you won't be able to cause crashes by making disallowed calls in the callback, but if you want your code to produce glitch-free audio, you will have to make sure you avoid function calls that may take an unbounded amount of time to execute. Exactly what these are depend on your platform but almost certainly include the following: memory allocation/deallocation, I/O (including file I/O as well as console I/O, such as printf()), context switching (such as exec() or yield()), mutex operations, or anything else that might rely on the OS. If you think short critical sections are safe please go read about priority inversion. Windows amd Mac OS schedulers have no real-time safe priority inversion prevention. Other platforms require special mutex flags. In addition, it is not safe to call any PortAudio API functions in the callback except as explicitly permitted in the documentation.
I think the same statement is true for the RTAudio system.
The current implementation calls dsp::stream::read(), which blocks on a mutex surrounding a conditional wait variable. According to the port audio documentation this is not allowed. Instead the callback function must NEVER block. If not enough data is available for fulfilling the callbacks' request, then some dummy data (usually just silence) must be generated. Similarly if the stream produces too much data than requested by the callback, then the superfluous data must be dropped. As far I understand the SDR++ design the data flow is driven by the source (e.g. RTL-SDR), which produces raw data at a specific rate (e.g. 2.4 Msamples/s). That data is processed and its rate is reduced according to the attached sink (e.g. audio sink @ 48000 samples/s). However, the 48000 samples/s requested by the audio system are measured in the time domain of the audio hardware. In contrast to that the source data rate is measured in the time domain of the RTL-SDR hardware in this example. Since the hardware clocks are never perfect a jitter buffer is needed somewhere in the system, preferably at a place, where inserting or dropping some samples has the least effect on the overall data processing. IMHO that place must be the audio sink module, because it only affects the heard sound, but not a parallel network sink, which forwards data to anther processing software. So, a non-blocking jitter buffer in the audio sink would solve both the data rate matching problem and the deadlock situation.
The current implementation calls dsp::stream::read(), which blocks on a mutex surrounding a conditional wait variable. According to the port audio documentation this is not allowed. Instead the callback function must NEVER block.
The streams are designed to have a mechanism to disable all blocking on command for either readers or writers (dsp::stream::stopReader() and dsp::stream::stopWriter()). They work by activating a flag that'll stop the condition variable instantly. These command are called before the callback has to be terminated so this should not be an issue.
If not enough data is available for fulfilling the callbacks' request, then some dummy data (usually just silence) must be generated
This is the role of PortAudio and it's done by zero stuffing the output when the callback doesn't return in time.
Similarly if the stream produces too much data than requested by the callback, then the superfluous data must be dropped. As far I understand the SDR++ design the data flow is driven by the source (e.g. RTL-SDR)
That is not the case, it is a dual throttled system with either the source or sink throtteling the data depending on which is slower. If the source is slower, portaudio and rtaudio will zero stuff the output and you'll get an underrun warning. If the source is too fast, a buffer after the source will try to buffer as much as it can and dump the rest (See the debug tab showing how much is being buffered).
a non-blocking jitter buffer in the audio sink would solve both the data rate matching problem and the deadlock situation.
Tried several time but never got it to work properly. It just resulted in worse audio on all platforms so since blocking works properly on windows, linux and BSD, I kept that methode. The non-blocking requirement in portaudio is quite antiquated, it dates back from when the callback occured inside an actual IRQ. Nowadays the callbacks run in a realtime priority thread that'll simply yield if no data is available. Portaudio and RtAudio already have their own jitter buffer that deals with this blocking but CoreAudio seems unhappy about it
TL;DR: Best solution would be to figure out exactly why the condition variable in the callback doesn't see that it's been instructed to stop blocking. Alternate solution that can only be accepted if it doesn't degrade audio quality for other platform is a jitter buffer but it's never worked properly in my experience.
First I suggest reading the port audio wiki for this topic.
The streams are designed to have a mechanism to disable all blocking on command for either readers or writers (dsp::stream::stopReader() and dsp::stream::stopWriter()). They work by activating a flag that'll stop the condition variable instantly. These command are called before the callback has to be terminated so this should not be an issue.
I'm talking about two different streams (multi-VFO!) - one stream, which is being stopped and another stream, which is still playing audio. The second one is blocked on the conditional variable, not the first one! So, calling dsp::stream:stopReader() on the first stream does not affect the conditional variable of the second stream.
If not enough data is available for fulfilling the callbacks' request, then some dummy data (usually just silence) must be generated
This is the role of PortAudio and it's done by zero stuffing the output when the callback doesn't return in time.
That works for the synchronous API of port audio but not for the asynchronous API as you are using. As stated in the wiki above port audio assumes that the callback function consumes all the CPU (i.e. is not blocking on any I/O or other OS call) in order to get its internal buffer management work properly. That contract is clearly violated in the port audio sink module.
The non-blocking requirement in portaudio is quite antiquated, it dates back from when the callback occured inside an actual IRQ. Nowadays the callbacks run in a realtime priority thread that'll simply yield if no data is available. Portaudio and RtAudio already have their own jitter buffer that deals with this blocking but CoreAudio seems unhappy about it
I don't think that the requirement is antiquated. It is still very popular. Here are some interesting links regarding this topic:
http://www.rossbencina.com/code/real-time-audio-programming-101-time-waits-for-nothing https://w2.mat.ucsb.edu/240/A/2017/05/17/realtime.html
TL;DR: Best solution would be to figure out exactly why the condition variable in the callback doesn't see that it's been instructed to stop blocking.
Yes, of course that issue with the condition variable must be solved nevertheless. When manipulating the audio sink of one VFO the other VFOs must not be affected.
Alternate solution that can only be accepted if it doesn't degrade audio quality for other platform is a jitter buffer but it's never worked properly in my experience.
Implementing a good jitter buffer is tricky. It is not enough to just drop samples on overrun or generate dummy samples on underrun. A jitter buffer must be be pre-filled and try to maintain a certain buffer fill level. It needs some margins to play with before dropping or generating sample. Of course, a jitter buffer introduces latency, but we are talking about 50ms or so. That should not be an issue for a SDR application. The music software developers have much more restrictive requirements.