Closed Bug 461936 Opened 12 years ago Closed 12 years ago

Deadlock shutting down a playing stream

Categories

(Core :: Audio/Video, defect)

x86
macOS
defect
Not set

Tracking

()

RESOLVED FIXED

People

(Reporter: roc, Assigned: roc)

Details

Attachments

(1 file, 2 obsolete files)

I got a deadlock on Mac with the following thread stacks:

Thread 19 (process 80487 thread 0xaa03):
#0  0x95ea54ee in semaphore_wait_signal_trap ()
#1  0x95eacfc5 in pthread_mutex_lock ()
#2  0x11bfa5b3 in audio_callback (arg=0x1e327690, action_flags=0xb055656c, time_stamp=0x1d1f3a30, bus_num=0, n_frames=512, data=0x1d1f3d80) at /Users/roc/mozilla-checkin/media/libsydneyaudio/src/sydney_audio_mac.c:430
#3  0x7000ea30 in dyld_stub_vImageTableLookUp_Planar8 ()
#4  0x7000e234 in dyld_stub_vImageTableLookUp_Planar8 ()
#5  0x7000d58b in dyld_stub_vImageTableLookUp_Planar8 ()
#6  0x94b3a1b1 in AudioConverterChain::CallInputProc ()
#7  0x94b39df4 in AudioConverterChain::FillBufferFromInputProc ()
#8  0x94b39d94 in BufferedAudioConverter::GetInputBytes ()
#9  0x94b39c1d in CBRConverter::RenderOutput ()
#10 0x94b3998c in BufferedAudioConverter::FillBuffer ()
#11 0x94b39b14 in AudioConverterChain::RenderOutput ()
#12 0x94b3998c in BufferedAudioConverter::FillBuffer ()
#13 0x94b4f323 in AudioConverterFillComplexBuffer ()
#14 0x7000d098 in dyld_stub_vImageTableLookUp_Planar8 ()
#15 0x700060a2 in dyld_stub_vImageTableLookUp_Planar8 ()
#16 0x70011d37 in AUGenericOutputEntry ()
#17 0x919e7fe3 in HP_IOProc::Call ()
#18 0x919e7cd4 in IOA_Device::CallIOProcs ()
#19 0x919e7bb0 in HP_IOThread::PerformIO ()
#20 0x919e5f8b in HP_IOThread::WorkLoop ()
#21 0x919e5aaf in HP_IOThread::ThreadEntry ()
#22 0x919d6304 in CAPThread::Entry ()
#23 0x95ed66f5 in _pthread_start ()
#24 0x95ed65b2 in thread_start ()

Thread 18 (process 80487 thread 0xa503):
#0  0x95ea54a6 in mach_msg_trap ()
#1  0x95eacc9c in mach_msg ()
#2  0x921fc0ce in CFRunLoopRunSpecific ()
#3  0x921fccf8 in CFRunLoopRunInMode ()
#4  0x919d6468 in HALRunLoop::OwnThread ()
#5  0x919d6304 in CAPThread::Entry ()
#6  0x95ed66f5 in _pthread_start ()
#7  0x95ed65b2 in thread_start ()

Thread 17 (process 80487 thread 0x7f07):
#0  0x95ea54ee in semaphore_wait_signal_trap ()
#1  0x95eacfc5 in pthread_mutex_lock ()
#2  0x919ba4eb in CAMutex::Lock ()
#3  0x919e1ca7 in IOA_Device::StartCommandExecution ()
#4  0x919e1b6d in HP_Device::ExecuteCommand ()
#5  0x919e8ede in HP_HardwarePlugIn_DeviceStop ()
#6  0x919e8e28 in HALPlugIn::DeviceStopIOProc ()
#7  0x919e8df2 in HALDevice::StopIOProc ()
#8  0x919e8d87 in AudioDeviceStop ()
#9  0x70010f89 in AUGenericOutputEntry ()
#10 0x70012106 in AUGenericOutputEntry ()
#11 0x7003e1ee in DefaultOutputAUEntry ()
#12 0x9448cded in CallComponentDispatch ()
#13 0x9631b9d5 in AudioOutputUnitStop ()
#14 0x11bfa29b in sa_stream_destroy (s=0x1e327690) at /Users/roc/mozilla-checkin/media/libsydneyaudio/src/sydney_audio_mac.c:270
#15 0x11bdc57b in nsAudioStream::Shutdown (this=0x1d1e0330) at /Users/roc/mozilla-checkin/content/media/video/src/nsAudioStream.cpp:112
#16 0x11be1963 in nsOggDecodeStateMachine::CloseAudioStream (this=0x1d1ac2d0) at /Users/roc/mozilla-checkin/content/media/video/src/nsOggDecoder.cpp:674
#17 0x11be19a3 in nsOggDecodeStateMachine::StopAudio (this=0x1d1ac2d0) at /Users/roc/mozilla-checkin/content/media/video/src/nsOggDecoder.cpp:691
#18 0x11be19b7 in nsOggDecodeStateMachine::StopPlayback (this=0x1d1ac2d0) at /Users/roc/mozilla-checkin/content/media/video/src/nsOggDecoder.cpp:715
#19 0x11be35b8 in nsOggDecodeStateMachine::PlayFrame (this=0x1d1ac2d0) at /Users/roc/mozilla-checkin/content/media/video/src/nsOggDecoder.cpp:615
#20 0x11be3b78 in nsOggDecodeStateMachine::Run (this=0x1d1ac2d0) at /Users/roc/mozilla-checkin/content/media/video/src/nsOggDecoder.cpp:868
#21 0x00484296 in nsThread::ProcessNextEvent (this=0x1d1ac140, mayWait=1, result=0xb0452ecc) at /Users/roc/mozilla-checkin/xpcom/threads/nsThread.cpp:510
#22 0x0040e09c in NS_ProcessNextEvent_P (thread=0x1d1ac140, mayWait=1) at nsThreadUtils.cpp:227
#23 0x004844a5 in nsThread::ThreadFunc (arg=0x1d1ac140) at /Users/roc/mozilla-checkin/xpcom/threads/nsThread.cpp:254
#24 0x0064f3ab in _pt_root (arg=0x1d1ac3a0) at /Users/roc/mozilla-checkin/nsprpub/pr/src/pthreads/ptthread.c:221
#25 0x95ed66f5 in _pthread_start ()
#26 0x95ed65b2 in thread_start ()

Thread 1 (process 80487 local thread 0x2f43):
#0  0x95ea54e2 in semaphore_wait_trap ()
#1  0x95eacfd2 in pthread_mutex_lock ()
#2  0x00647fab in PR_Lock (lock=0x1d1abe64) at /Users/roc/mozilla-checkin/nsprpub/pr/src/pthreads/ptsynch.c:206
#3  0x00648c84 in PR_EnterMonitor (mon=0x1d1abe60) at /Users/roc/mozilla-checkin/nsprpub/pr/src/pthreads/ptsynch.c:531
#4  0x0044ee16 in nsAutoMonitor::nsAutoMonitor (this=0xbfffd5ac, mon=0x1d1abe60) at nsAutoLock.h:304
#5  0x0044ee3e in nsAutoMonitor::nsAutoMonitor (this=0xbfffd5ac, mon=0x1d1abe60) at nsAutoLock.h:307
#6  0x11be1b4f in nsOggDecoder::ChangeState (this=0x1d1abdc0, aState=nsOggDecoder::PLAY_STATE_ENDED) at /Users/roc/mozilla-checkin/content/media/video/src/nsOggDecoder.cpp:1425
#7  0x11be2467 in nsOggDecoder::Stop (this=0x1d1abdc0) at /Users/roc/mozilla-checkin/content/media/video/src/nsOggDecoder.cpp:1210
#8  0x11be48f6 in nsOggDecoderShutdown::Run (this=0x169cd870) at /Users/roc/mozilla-checkin/content/media/video/src/nsOggDecoder.cpp:1108
#9  0x00484296 in nsThread::ProcessNextEvent (this=0x716820, mayWait=0, result=0xbfffd6c4) at /Users/roc/mozilla-checkin/xpcom/threads/nsThread.cpp:510
#10 0x0040e1fe in NS_ProcessPendingEvents_P (thread=0x716820, timeout=20) at nsThreadUtils.cpp:180
#11 0x1343b349 in nsBaseAppShell::NativeEventCallback (this=0x740b50) at /Users/roc/mozilla-checkin/widget/src/xpwidgets/nsBaseAppShell.cpp:121
#12 0x133f4a02 in nsAppShell::ProcessGeckoEvents (aInfo=0x740b50) at /Users/roc/mozilla-checkin/widget/src/cocoa/nsAppShell.mm:373
#13 0x921fc615 in CFRunLoopRunSpecific ()
#14 0x921fccf8 in CFRunLoopRunInMode ()
#15 0x9390c480 in RunCurrentEventLoopInMode ()
#16 0x9390c1d2 in ReceiveNextEventCommon ()
#17 0x9390c10d in BlockUntilNextEventMatchingListInMode ()
#18 0x94caf3ed in _DPSNextEvent ()
#19 0x94caeca0 in -[NSApplication nextEventMatchingMask:untilDate:inMode:dequeue:] ()
#20 0x94ca7cdb in -[NSApplication run] ()
#21 0x133f32c4 in nsAppShell::Run (this=0x740b50) at /Users/roc/mozilla-checkin/widget/src/cocoa/nsAppShell.mm:692
#22 0x13ee177e in nsAppStartup::Run (this=0x75b000) at /Users/roc/mozilla-checkin/toolkit/components/startup/src/nsAppStartup.cpp:182
#23 0x000f5071 in XRE_main (argc=3, argv=0xbfffed14, aAppData=0x70e690) at /Users/roc/mozilla-checkin/toolkit/xre/nsAppRunner.cpp:3263
#24 0x000026e3 in main (argc=3, argv=0xbfffed14) at /Users/roc/mozilla-checkin/browser/app/nsBrowserApp.cpp:156
I'm guessing thread 19 has grabbed some Core Audio lock and is now trying to grab libsydney's s->mutex. Meanwhile thread 17 has grabbed s->mutex and is now calling into Core Audio which is trying to grab its lock. (The main thread is stuck waiting for thread 17, but that's not the real issue.)
Added kinetik, as he's looked at the Mac libsydneyaudio code recently and might have a better understanding of the code.
Actually I've got a patch.
Attached patch fix (obsolete) — Splinter Review
I think this is correct, but I can't find the right documentation to be completely sure. But basically the comment says it all.

If it's right, this should of course go upstream; I guess either Matthew or Chris is the right person to handle that.
Assignee: nobody → roc
Attachment #345063 - Flags: review?
Attachment #345063 - Flags: review? → review?(kinetik)
Attached patch fix v2 (obsolete) — Splinter Review
The fix makes sense to me.  The best documentation I could find (http://lists.apple.com/archives/coreaudio-api/2005/Dec/msg00055.html) suggests that calling AudioOutputUnitStop from the non-IO thread does wait until callbacks have completed (and the HAL has shut down).

It looks like pause/resume have the same bug, they hold s->mutex while calling AudioOutputUnitStop/Start.  Interestingly, write has a comment near its call to AudioOutputUnitStart that suggests holding s->mutex is bad:

   * Once we have our first block of audio data, enable the audio callback
   * function. This doesn't need to be protected by the mutex, because
   * s->playing is not used in the audio callback thread, and it's probably
   * better not to be inside the lock when we enable the audio callback.

New patch addresses pause/resume bugs and tweaks the comments slightly, including a reference to the URL mentioned above.
Attachment #345063 - Attachment is obsolete: true
Attachment #345063 - Flags: review?(kinetik)
Attachment #345114 - Attachment is patch: true
Attachment #345114 - Attachment mime type: application/octet-stream → text/plain
Comment on attachment 345114 [details] [diff] [review]
fix v2

Let's land this and get it upstream.
Attachment #345114 - Flags: review+
If you land it before sending it upstream please change README_MOZILLA to document the change, and update.sh to apply a patch for the change for when I refresh from upstream in case upstream take a while to apply it.
As discussed with doublec, I've filed an upstream bug with the patch included: http://trac.annodex.net/ticket/432
It (and another patch we submitted to fix a leak on Win32: http://trac.annodex.net/ticket/426) have been committed upstream now, so we can update our in-tree version of sydneyaudio to r3755 and close this bug.
The latest libsydneyaudio containing the fixes provided by kinetik
Attachment #345114 - Attachment is obsolete: true
Status: NEW → RESOLVED
Closed: 12 years ago
Resolution: --- → FIXED
You need to log in before you can comment on or make changes to this bug.