Audio Glitches and Segfault in the PlaybackDemo app with 4osc synth

audioishi · January 23, 2020, 8:22am

I’m getting a strange bug and EXC_BAD_ACCESS crash in Mac OS 10.14.6 (Mojave) in the tracktion_engine PlaybackDemo app. The crash seems to be correlated with audio dropout artifacts that occur when switching the active application in (using the command+tab hot key) or when scrolling quickly in a a GUI app such as Chrome while simultaneously playing an edit that contains the 4osc synth in the PlaybackDemo app.

I’ve also observed this bug in my own project in Debug and Release builds. The end result is that the user should expect audio dropouts and and eventual segfault when running a tracktion engine app and 4osc while multitasking.

To reproduce:

Open the PlaybackDemo XCode project
Move the attached demo.tracktionedit.txt (14.4 KB) file into the xcode build’s Debug folder where the PlaybackDemo application is. (Rename the file to .tracktionedit, removing the .txt) The bug does not occur with the integrated edit.
Edit the XCode Scheme (Command+<), adding ./demo.tracktionedit as a command line argument.
Screen Shot 2020-01-23 at 2.41.17 AM2206×1098 248 KB
Run the application via the XCode Debug scheme.
Skip past the assertion error for an invalid Project ID when loading the edit.
The 4osc synth should start playing.
On the same machine, open Chrome to a web page. Its easier to use a long web page, becase it can scroll faster (https://forum.juce.com works well)
While the audio is use a two finger scroll gesture to quickly scroll up and down the web page. The audio dropouts should start right away, and be very noticeable. These dropouts are more subtle when using command+tab to switch applications.
Continue Scrolling. A variable amount of time later, I get the crash shown in the stack trace below. This might be as soon as a few seconds, but is often over a minute, and can be longer than 5 minutes. I believe it happens sooner when the computer is working harder on other tasks. For example, the crash occurred immediately when I tried to use quicktime to record a video of these steps.

It is possible that audio glitches and the crash are separate issues, however I believe that the segfault tends to happen much sooner iff I open a web page in google chrome, and quickly scroll up and down the page with two finger gesture.

Here’s the console output leading up to the crash, followed by the thread backtrace from lldb. In the example below, the EXC_BAD_ACCESS crash occurred on the “Built-In Output” thread, but I have also observed it on one of the mixer threads.

JUCE v5.4.5
Finding MIDI I/O
MIDI output: IAC Driver Bus 1 (enabled)
opening MIDI out device:IAC Driver Bus 1
MIDI output: IAC Driver IAC MTC
MIDI output: Tracktion MIDI Device
MIDI input: IAC Driver Bus 1 (enabled)
opening MIDI in device: IAC Driver Bus 1
MIDI input: IAC Driver IAC MTC
2020-01-23 02:17:42.418819-0500 PlaybackDemo[68781:3206726]   saved enable noise cancellation setting is the same as the default (=1)
Audio block size: 512  Rate: 44100
Rebuilding Wave Device List...
Wave In: Input 1 (enabled): 0 (L)
Wave In: Input 2 (enabled): 1 (L)
Wave Out: Output 1 + 2 (enabled): 0 (L), 1 (R)
Default Wave Out: Output 1 + 2
Default MIDI Out: IAC Driver Bus 1
Default Wave In: Input 1
Default MIDI In: IAC Driver Bus 1
Creating Default Controllers...
JUCE Assertion failure in tracktion_Edit.cpp:492
Edit loaded in: 12 ms
Generating waves: 838ms
2020-01-23 02:17:51.459423-0500 PlaybackDemo[68781:3206764] SecTaskLoadEntitlements failed error=22 cs_flags=20, pid=68781
2020-01-23 02:17:51.459531-0500 PlaybackDemo[68781:3206764] SecTaskCopyDebugDescription: PlaybackDemo[68781]/0#-1 LF=0
2020-01-23 02:17:51.976794-0500 PlaybackDemo[68781:3207060] [BoringSSL] nw_protocol_boringssl_get_output_frames(1301) [C1.1:2][0x103429de0] get output frames failed, state 8196
2020-01-23 02:17:51.976912-0500 PlaybackDemo[68781:3207060] [BoringSSL] nw_protocol_boringssl_get_output_frames(1301) [C1.1:2][0x103429de0] get output frames failed, state 8196
2020-01-23 02:17:51.977243-0500 PlaybackDemo[68781:3207060] TIC Read Status [1:0x0]: 1:57
2020-01-23 02:17:51.977263-0500 PlaybackDemo[68781:3207060] TIC Read Status [1:0x0]: 1:57
2020-01-23 02:17:51.986039-0500 PlaybackDemo[68781:3206726] SecTaskLoadEntitlements failed error=22 cs_flags=20, pid=68781
2020-01-23 02:17:51.986177-0500 PlaybackDemo[68781:3206726] SecTaskCopyDebugDescription: PlaybackDemo[68781]/0#-1 LF=0
(lldb) bt
* thread #20, name = 'Built-in Output', stop reason = EXC_BAD_ACCESS (code=1, address=0x10100df80ad)
    frame #0: 0x0000010100df80ad
  * frame #1: 0x0000000100de9e50 PlaybackDemo`tracktion_engine::Plugin::initialiseWithoutStopping(tracktion_engine::PlaybackInitialisationInfo const&) at tracktion_Plugin.h:101
    frame #2: 0x0000000100df80ad PlaybackDemo`tracktion_engine::PluginAudioNode::prepareForNextBlock(this=0x00006000017fafc0, rc=0x000070000d6fbf80) at tracktion_Plugin.cpp:207
    frame #3: 0x0000000100ca417e PlaybackDemo`tracktion_engine::SingleInputAudioNode::prepareForNextBlock(this=0x0000600002129130, rc=0x000070000d6fbf80) at tracktion_AudioNode.cpp:136
    frame #4: 0x0000000100cae623 PlaybackDemo`tracktion_engine::MixerAudioNode::prepareForNextBlock(this=0x0000000103515e30, rc=0x000070000d6fbf80) at tracktion_MixerAudioNode.cpp:443
    frame #5: 0x0000000100df80ad PlaybackDemo`tracktion_engine::PluginAudioNode::prepareForNextBlock(this=0x00006000017ec580, rc=0x000070000d6fbf80) at tracktion_Plugin.cpp:207
    frame #6: 0x0000000100cae623 PlaybackDemo`tracktion_engine::MixerAudioNode::prepareForNextBlock(this=0x0000000103612b40, rc=0x000070000d6fbf80) at tracktion_MixerAudioNode.cpp:443
    frame #7: 0x0000000100c8f067 PlaybackDemo`tracktion_engine::WaveOutputDeviceInstance::fillNextAudioBlock(this=0x0000000103513950, playhead=0x0000000103513410, streamTime=(start = 23.289614512470848, end = 23.301224489795111), allChannels=0x0000600001754800, numSamples=512) at tracktion_WaveOutputDevice.cpp:146
    frame #8: 0x0000000100c8659a PlaybackDemo`tracktion_engine::EditPlaybackContext::fillNextAudioBlock(this=0x0000000103513400, streamTime=(start = 23.289614512470848, end = 23.301224489795111), allChannels=0x0000600001754800, numSamples=512) at tracktion_EditPlaybackContext.cpp:696
    frame #9: 0x0000000100c85250 PlaybackDemo`tracktion_engine::DeviceManager::audioDeviceIOCallback(this=0x000000010503b400, inputChannelData=0x0000600001754840, numInputChannels=2, outputChannelData=0x0000600001754800, totalNumOutputChannels=2, numSamples=512) at tracktion_DeviceManager.cpp:1104
    frame #10: 0x0000000100087686 PlaybackDemo`juce::AudioDeviceManager::audioDeviceIOCallbackInt(this=0x000000010503b458, inputChannelData=0x0000600001754840, numInputChannels=2, outputChannelData=0x0000600001754800, numOutputChannels=2, numSamples=512) at juce_AudioDeviceManager.cpp:812
    frame #11: 0x000000010009572f PlaybackDemo`juce::AudioDeviceManager::CallbackHandler::audioDeviceIOCallback(this=0x0000600000c53480, ins=0x0000600001754840, numIns=2, outs=0x0000600001754800, numOuts=2, numSamples=512) at juce_AudioDeviceManager.cpp:54
    frame #12: 0x00000001000a38bf PlaybackDemo`juce::CoreAudioClasses::AudioIODeviceCombiner::run(this=0x000000010504f600) at juce_mac_CoreAudio.cpp:1610
    frame #13: 0x0000000100333686 PlaybackDemo`juce::Thread::threadEntryPoint(this=0x000000010504f600) at juce_Thread.cpp:96
    frame #14: 0x0000000100333b45 PlaybackDemo`juce::juce_threadEntryPoint(userData=0x000000010504f600) at juce_Thread.cpp:118
    frame #15: 0x0000000100361896 PlaybackDemo`juce::threadEntryProc(userData=0x000000010504f600) at juce_posix_SharedCode.h:834
    frame #16: 0x0000000103200dc3 libsystem_pthread.dylib`_pthread_body + 126
    frame #17: 0x0000000103203e8d libsystem_pthread.dylib`_pthread_start + 66
    frame #18: 0x00000001031ffe11 libsystem_pthread.dylib`thread_start + 13
(lldb)

I’ve been using this tracktionedit file for testing, but I’ve had similar results with other edits.
demo.tracktionedit.txt (14.4 KB)

The computer I’m running this on is a 2015 Macbook Pro with 3.1 GHz Intel Core i7 and 16GB RAM.

I’m using tracktion_engine develop branch at commit 5d4fc9e40546840ecc4baf1b9f52c2fd678d5209 from January 14th.

I cannot reproduce the bug with the same .tracktionedit file in Waveform 64-bit version: 10.1.5 (Built: 29 April 2019)

dave96 · January 23, 2020, 1:49pm

That’s weird, does it not get caught in the debugger? Letting you know exactly what is corrupted?

What type of plugin is this that’s crashing?

I’m a bit tied up at the moment but should be able to take a look at this over the next few days.

g-mon · January 23, 2020, 4:05pm

4OSC is painfully slow in a debug build. I’m running a 3.7 GHz Quad-Core Xeon E5 and it hits over 50% CPU. It’s more like 4% in a release build. I’ve added a CPU meter to the PlaybackDemo so you can see how long your render block is taking. If you are using a lot of CPU in another app, it’s most likely 4OSC is running out of time to render the block and glitching.

I can’t reproduce your crash. Your call stack doesn’t make a lot of sense, PluginAudioNode::prepareForNextBlock doesn’t call Plugin::initialiseWithoutStopping. You must be getting some sort of heap or stack corruption. I haven’t been able to reproduce it yet, but I’ll keep looking.

dave96 · January 23, 2020, 4:12pm

If this is the case, running with Tsan (and Asan) can be extremely helpful.

audioishi · January 23, 2020, 7:40pm

Thanks for all the tips!

When I run a release build its much harder to get the audio dropout/crackles, so it seems that issue is dependent on processor speed.

However, I still get the segfault on release – So my intuition that the issues are related may be incorrect, but it’s hard to know for sure.

Here’s a stack trace from a release build.

Finding MIDI I/O
MIDI output: IAC Driver Bus 1 (enabled)
opening MIDI out device:IAC Driver Bus 1
MIDI output: IAC Driver IAC MTC
MIDI output: MPK Mini Mk II
MIDI input: IAC Driver Bus 1 (enabled)
opening MIDI in device: IAC Driver Bus 1
MIDI input: IAC Driver IAC MTC
MIDI input: MPK Mini Mk II
2020-01-23 14:19:04.519226-0500 PlaybackDemo[72145:3383255]   saved enable noise cancellation setting is the same as the default (=1)
Audio block size: 512  Rate: 44100
Rebuilding Wave Device List...
Wave In: Input 1 (enabled): 0 (L)
Wave In: Input 2 (enabled): 1 (L)
Wave Out: Output 1 + 2 (enabled): 0 (L), 1 (R)
Default Wave Out: Output 1 + 2
Default MIDI Out: IAC Driver Bus 1
Default Wave In: Input 1
Default MIDI In: IAC Driver Bus 1
Creating Default Controllers...
2020-01-23 14:19:05.237269-0500 PlaybackDemo[72145:3383301] SecTaskLoadEntitlements failed error=22 cs_flags=20, pid=72145
2020-01-23 14:19:05.237381-0500 PlaybackDemo[72145:3383301] SecTaskCopyDebugDescription: PlaybackDemo[72145]/0#-1 LF=0
2020-01-23 14:19:05.464423-0500 PlaybackDemo[72145:3383411] [BoringSSL] nw_protocol_boringssl_get_output_frames(1301) [C1.1:2][0x10123e3c0] get output frames failed, state 8196
2020-01-23 14:19:05.464493-0500 PlaybackDemo[72145:3383411] [BoringSSL] nw_protocol_boringssl_get_output_frames(1301) [C1.1:2][0x10123e3c0] get output frames failed, state 8196
2020-01-23 14:19:05.465299-0500 PlaybackDemo[72145:3383411] TIC Read Status [1:0x0]: 1:57
2020-01-23 14:19:05.465339-0500 PlaybackDemo[72145:3383411] TIC Read Status [1:0x0]: 1:57
2020-01-23 14:19:05.475533-0500 PlaybackDemo[72145:3383255] SecTaskLoadEntitlements failed error=22 cs_flags=20, pid=72145
2020-01-23 14:19:05.475648-0500 PlaybackDemo[72145:3383255] SecTaskCopyDebugDescription: PlaybackDemo[72145]/0#-1 LF=0
(lldb) bt
* thread #23, name = 'mixer', stop reason = EXC_BAD_ACCESS (code=1, address=0x0)
  * frame #0: 0x0000000000000000
    frame #1: 0x0000010100000100
    frame #2: 0x0000000100486fc4 PlaybackDemo`tracktion_engine::Plugin::applyToBufferWithAutomation(tracktion_engine::AudioRenderContext const&) + 292
    frame #3: 0x00000001004b005b PlaybackDemo`tracktion_engine::PluginAudioNode::renderPlugin(tracktion_engine::AudioRenderContext const&) + 107
    frame #4: 0x00000001004158fe PlaybackDemo`tracktion_engine::MultiCPU::ParallelMixOperation::processNode(tracktion_engine::AudioNode&, juce::AudioBuffer<float>&) + 446
    frame #5: 0x0000000100454879 PlaybackDemo`tracktion_engine::MultiCPU::MixerThreadPool::MixerThread::run() + 233
    frame #6: 0x00000001001076bc PlaybackDemo`juce::threadEntryProc(void*) + 300
    frame #7: 0x0000000100f01dc3 libsystem_pthread.dylib`_pthread_body + 126
    frame #8: 0x0000000100f04e8d libsystem_pthread.dylib`_pthread_start + 66
    frame #9: 0x0000000100f00e11 libsystem_pthread.dylib`thread_start + 13

Like @G-Mon mentioned - I’ve never seen the call stack jump to an arbitrary function like that before. I have to focus on some more immediate deadlines, but I’ll return to debugging this (hopefully next week), and will look into thread sanitation and address sanitation. I really appreciate all the input so far. Thank you!

Site navigation

JUCE

Audio Glitches and Segfault in the PlaybackDemo app with 4osc synth

Further Information