App beachballs for a few seconds every time I change the volume on this video

RESOLVED WORKSFORME

Status

()

Core
Audio/Video
RESOLVED WORKSFORME
8 years ago
7 years ago

People

(Reporter: bz, Assigned: cpearce)

Tracking

Trunk
x86
Mac OS X
Points:
---

Firefox Tracking Flags

(blocking2.0 betaN+)

Details

(URL)

I was watching http://videos.mozilla.org/serv/air_mozilla/firefox4.ogg today (reasonably current nightly, but I see the bug in a current tip self-build too), and every time I changed the volume Firefox would beachball for 3-5 seconds.

I tried breaking in gdb during the beachball, and the main thread was consistently trying to enter the monitor in nsBuiltinDecoderStateMachine::SetVolume (called from nsBuiltinDecoder::SetVolume, called from nsHTMLMediaElement::SetMuted or SetVolume, called from nsHTMLVideoElement::SetMuted or SetVolume, called from JS).  I poked around at the other threads, and there seem to be two other maybe-relevant ones: the thread AudioLoop is on and the thread DecodeLoop is on.  The latter is in a PR_Wait; the former is in nanosleep (set to sleep for 1ms, but see below).

Stacks coming up, but we seem to be holding the audio monitor in AudioLoop around the call to Write() and said call is busy-waiting in the loop at http://hg.mozilla.org/mozilla-central/file/36b3e529f9db/media/libsydneyaudio/src/sydney_audio_mac.c#l373 on a free buffer or something.

Stacks:
thread 1:
#0  0x90a362ae in semaphore_wait_signal_trap ()
#1  0x90a3dd85 in pthread_mutex_lock ()
#2  0x001713bc in PR_Lock (lock=0x13c138c4) at /Users/bzbarsky/mozilla/css-frameconst/mozilla/nsprpub/pr/src/pthreads/ptsynch.c:206
#3  0x00172158 in PR_EnterMonitor (mon=0x13c138c0) at /Users/bzbarsky/mozilla/css-frameconst/mozilla/nsprpub/pr/src/pthreads/ptsynch.c:561
#4  0x006c1432 in mozilla::Monitor::Enter (this=0x13c13794) at BlockingResourceBase.cpp:315
#5  0x00d81ebd in mozilla::MonitorAutoEnter::MonitorAutoEnter (this=0xbfffb22c, aMonitor=@0x13c13794) at Monitor.h:216
#6  0x120153da in nsBuiltinDecoderStateMachine::SetVolume (this=0x13c13780, volume=0) at /Users/bzbarsky/mozilla/css-frameconst/mozilla/content/media/nsBuiltinDecoderStateMachine.cpp:518
#7  0x1200f996 in nsBuiltinDecoder::SetVolume (this=0x13c12b50, volume=0) at /Users/bzbarsky/mozilla/css-frameconst/mozilla/content/media/nsBuiltinDecoder.cpp:78
#8  0x11d16f61 in nsHTMLMediaElement::SetMuted (this=0x13c0ac10, aMuted=1) at /Users/bzbarsky/mozilla/css-frameconst/mozilla/content/html/content/src/nsHTMLMediaElement.cpp:937
#9  0x11d1c00e in nsHTMLVideoElement::SetMuted (this=0x13c0ac10, aMuted=1) at nsHTMLVideoElement.h:64
#10 0x0075bb97 in NS_InvokeByIndex_P (that=0x13c0ac8c, methodIndex=80, paramCount=1, params=0xbfffb438) at /Users/bzbarsky/mozilla/css-frameconst/mozilla/xpcom/reflect/xptcall/src/md/unix/xptcinvoke_unixish_x86.cpp:179

(gdb) thread 17
[Switching to thread 17 (process 86889 thread 0x8707)]
0x90a3d44e in __semwait_signal ()
(gdb) bt
#0  0x90a3d44e in __semwait_signal ()
#1  0x90a3d2cf in nanosleep$UNIX2003 ()
#2  0x12057b74 in sa_stream_write (s=0x13c89aa0, data=0x1575ba0, nbytes=96) at /Users/bzbarsky/mozilla/css-frameconst/mozilla/media/libsydneyaudio/src/sydney_audio_mac.c:376
#3  0x1201b5ab in nsAudioStream::Write (this=0x13c8d6b0, aBuf=0x1582400, aCount=512, aBlocking=1) at /Users/bzbarsky/mozilla/css-frameconst/mozilla/content/media/nsAudioStream.cpp:187
#4  0x120183cb in nsBuiltinDecoderStateMachine::AudioLoop (this=0x13c13780) at /Users/bzbarsky/mozilla/css-frameconst/mozilla/content/media/nsBuiltinDecoderStateMachine.cpp:381
#5  0x12018f27 in nsRunnableMethodImpl<void (nsBuiltinDecoderStateMachine::*)(), true>::Run (this=0x1f3c8bc0) at nsThreadUtils.h:347
#6  0x0073b544 in nsThread::ProcessNextEvent (this=0x1f3c3540, mayWait=1, result=0xb0862ecc) at /Users/bzbarsky/mozilla/css-frameconst/mozilla/xpcom/threads/nsThread.cpp:527
(gdb) frame 2
#2  0x12057b74 in sa_stream_write (s=0x13c89aa0, data=0x1575ba0, nbytes=96) at /Users/bzbarsky/mozilla/css-frameconst/mozilla/media/libsydneyaudio/src/sydney_audio_mac.c:376
376               nanosleep(&ts, NULL);
Current language:  auto; currently c
(gdb) p ts
$1 = {
  tv_sec = 0, 
  tv_nsec = 1000000
}

(gdb) thread 16
[Switching to thread 16 (process 86889 thread 0x850b)]
0x90a3d44e in __semwait_signal ()
(gdb) bt
#0  0x90a3d44e in __semwait_signal ()
#1  0x90a683e6 in _pthread_cond_wait ()
#2  0x90a67dcd in pthread_cond_wait$UNIX2003 ()
#3  0x00171c41 in PR_WaitCondVar (cvar=0x13c12c00, timeout=4294967295) at /Users/bzbarsky/mozilla/css-frameconst/mozilla/nsprpub/pr/src/pthreads/ptsynch.c:417
#4  0x00172407 in PR_Wait (mon=0x13c12c30, timeout=4294967295) at /Users/bzbarsky/mozilla/css-frameconst/mozilla/nsprpub/pr/src/pthreads/ptsynch.c:614
#5  0x006c0701 in mozilla::Monitor::Wait (this=0x13c12be0, interval=4294967295) at BlockingResourceBase.cpp:346
#6  0x12018ff0 in mozilla::MonitorAutoEnter::Wait (this=0xb07e0d54, interval=4294967295) at Monitor.h:226
#7  0x12014bab in nsBuiltinDecoderStateMachine::DecodeLoop (this=0x13c13780) at /Users/bzbarsky/mozilla/css-frameconst/mozilla/content/media/nsBuiltinDecoderStateMachine.cpp:287
#8  0x12018f27 in nsRunnableMethodImpl<void (nsBuiltinDecoderStateMachine::*)(), true>::Run (this=0x1f3c8ba0) at nsThreadUtils.h:347
#9  0x0073b544 in nsThread::ProcessNextEvent (this=0x1f3c3400, mayWait=1, result=0xb07e0ecc) at /Users/bzbarsky/mozilla/css-frameconst/mozilla/xpcom/threads/nsThread.cpp:527
I thought we'd already fixed things to not hold the lock while we do a blocking audio write...
In nsBuiltinDecoderStateMachine::AudioLoop we have:

368     {
369       MonitorAutoEnter audioMon(mAudioMonitor);
370       if (mAudioStream) {
371         // The state machine could have paused since we've released the decoder
372         // monitor and acquired the audio monitor. Rather than acquire both
373         // monitors, the audio stream also maintains whether its paused or not.
374         // This prevents us from doing a blocking write while holding the audio
375         // monitor while paused; we would block, and the state machine won't be 
376         // able to acquire the audio monitor in order to resume or destroy the
377         // audio stream.
378         if (!mAudioStream->IsPaused()) {
379           mAudioStream->Write(sound->mAudioData,
380                               sound->AudioDataLength(),
381                               PR_TRUE);
382           mAudioEndTime = sound->mTime + sound->mDuration;
383           mDecoder->UpdatePlaybackOffset(sound->mOffset);
384         } else {
385           mReader->mAudioQueue.PushFront(sound);
386           sound.forget();
387         }
388       }
389     }

In this case, presumably, IsPaused() is false.  Which makes sense, since I didn't pause anything.
(Assignee)

Comment 3

8 years ago
Ah, oops. We have to hold the audio monitor while writing, otherwise the state machine thread could destory it while we're in the midst of writing to it, and we also take the audio monitor when we set the volume for the same reason. If we're in a blocking audio write while holding the audio monitor, nsBuiltinDecoderStateMachine::SetVolume() will wait until the lock is released, causing these pauses. Maybe we should poll the volume inside the audio loop and update it in the nsAudioStream when it changes.
(In reply to comment #3)
> Ah, oops. We have to hold the audio monitor while writing, otherwise the state
> machine thread could destory it while we're in the midst of writing to it,

How about some kind of refcount instead? Hold the monitor while we add or release the refcount. If the refcount reaches zero, destroy the monitor and the audio stream resources. Add one to the refcount before we call Write and subtract one afterwards.
(In reply to comment #3)
> Ah, oops. We have to hold the audio monitor while writing, otherwise the state
> machine thread could destory it while we're in the midst of writing to it

The opposite can happen in the current code: https://bugzilla.mozilla.org/show_bug.cgi?id=560784#c19
(Assignee)

Updated

8 years ago
Assignee: nobody → chris
Status: NEW → ASSIGNED
(Assignee)

Comment 6

8 years ago
Boris, can you still reproduce this on trunk?
No, seems to work for me on trunk.
Status: ASSIGNED → RESOLVED
Last Resolved: 8 years ago
Resolution: --- → WORKSFORME
blocking2.0: ? → betaN+
You need to log in before you can comment on or make changes to this bug.