Closed Bug 1209318 Opened 10 years ago Closed 6 years ago

Intermittent test_fragment_play.html | application timed out after 330 seconds with no output

Categories

(Core :: Audio/Video: Playback, defect, P5)

Product:
Core
Component:
Audio/Video: Playback
Type:
defect

Tracking

()

Status:
RESOLVED INCOMPLETE

People

(Reporter: KWierso, Unassigned)

Details

(Keywords: intermittent-failure)

(In reply to Treeherder Robot from comment #1) looks like a dead lock: 13:48:45 INFO - Thread 0 13:48:45 INFO - 0 ntdll.dll!KiFastSystemCallRet + 0x0 13:48:45 INFO - eip = 0x7c90e4f4 esp = 0x0012f6c4 ebp = 0x0012f728 ebx = 0x0f1c92a0 13:48:45 INFO - esi = 0x0000070c edi = 0x00000000 eax = 0x0012f606 ecx = 0x0278be48 13:48:45 INFO - edx = 0x00000000 efl = 0x00000246 13:48:45 INFO - Found by: given as instruction pointer in context 13:48:45 INFO - 1 ntdll.dll!ZwWaitForSingleObject + 0xc 13:48:45 INFO - eip = 0x7c90df3c esp = 0x0012f6c8 ebp = 0x0012f728 13:48:45 INFO - Found by: call frame info 13:48:45 INFO - 2 kernel32.dll!WaitForSingleObjectEx + 0x8b 13:48:45 INFO - eip = 0x7c8025db esp = 0x0012f6cc ebp = 0x0012f728 13:48:45 INFO - Found by: call frame info 13:48:45 INFO - 3 kernel32.dll!WaitForSingleObject + 0x12 13:48:45 INFO - eip = 0x7c802542 esp = 0x0012f730 ebp = 0x0012f73c 13:48:45 INFO - Found by: call frame info 13:48:45 INFO - 4 nss3.dll!_PR_MD_WAIT_CV [w95cv.c:51cc57918bf5 : 248 + 0xf] 13:48:45 INFO - eip = 0x0074fedd esp = 0x0012f744 ebp = 0x0012f758 13:48:45 INFO - Found by: call frame info 13:48:45 INFO - 5 nss3.dll!_PR_WaitCondVar [prucv.c:51cc57918bf5 : 172 + 0x1d] 13:48:45 INFO - eip = 0x0076097e esp = 0x0012f760 ebp = 0x0012f774 13:48:45 INFO - Found by: call frame info 13:48:45 INFO - 6 nss3.dll!PR_WaitCondVar [prucv.c:51cc57918bf5 : 525 + 0xb] 13:48:45 INFO - eip = 0x00760485 esp = 0x0012f77c ebp = 0x0012f794 13:48:45 INFO - Found by: call frame info 13:48:45 INFO - 7 nss3.dll!PR_EnterMonitor [prmon.c:51cc57918bf5 : 136 + 0x8] 13:48:45 INFO - eip = 0x0076394a esp = 0x0012f79c ebp = 0x0012f7b0 13:48:45 INFO - Found by: call frame info 13:48:45 INFO - 8 xul.dll!mozilla::ReentrantMonitor::Enter() [BlockingResourceBase.cpp:51cc57918bf5 : 434 + 0x9] 13:48:45 INFO - eip = 0x03273af3 esp = 0x0012f7b8 ebp = 0x0012f7c8 13:48:45 INFO - Found by: call frame info 13:48:45 INFO - 9 xul.dll!mozilla::ReentrantMonitorAutoEnter::ReentrantMonitorAutoEnter(mozilla::ReentrantMonitor &) [ReentrantMonitor.h:51cc57918bf5 : 180 + 0x7] 13:48:45 INFO - eip = 0x03232fdf esp = 0x0012f7c4 ebp = 0x0012f7c8 13:48:45 INFO - Found by: call frame info 13:48:45 INFO - 10 xul.dll!mozilla::MediaDecoder::ComputePlaybackRate() [MediaDecoder.cpp:51cc57918bf5 : 871 + 0x10] 13:48:45 INFO - eip = 0x04773fa1 esp = 0x0012f7d0 ebp = 0x0012f800 13:48:45 INFO - Found by: call frame info 13:48:46 INFO - Thread 69 13:48:46 INFO - 0 ntdll.dll!KiFastSystemCallRet + 0x0 13:48:46 INFO - eip = 0x7c90e4f4 esp = 0x12a7fabc ebp = 0x12a7fb20 ebx = 0x7c80981e 13:48:46 INFO - esi = 0x00000ab0 edi = 0x00000000 eax = 0x69171675 ecx = 0x02ffa58c 13:48:46 INFO - edx = 0x0e00a418 efl = 0x00000246 13:48:46 INFO - Found by: given as instruction pointer in context 13:48:46 INFO - 1 ntdll.dll!ZwWaitForSingleObject + 0xc 13:48:46 INFO - eip = 0x7c90df3c esp = 0x12a7fac0 ebp = 0x12a7fb20 13:48:46 INFO - Found by: call frame info 13:48:46 INFO - 2 kernel32.dll!WaitForSingleObjectEx + 0x8b 13:48:46 INFO - eip = 0x7c8025db esp = 0x12a7fac4 ebp = 0x12a7fb20 13:48:46 INFO - Found by: call frame info 13:48:46 INFO - 3 kernel32.dll!WaitForSingleObject + 0x12 13:48:46 INFO - eip = 0x7c802542 esp = 0x12a7fb28 ebp = 0x12a7fb34 13:48:46 INFO - Found by: call frame info 13:48:46 INFO - 4 wdmaud.drv!wdmaudDestroyCompletionThread + 0x6a 13:48:46 INFO - eip = 0x72d24081 esp = 0x12a7fb3c ebp = 0x12a7fb50 13:48:46 INFO - Found by: call frame info 13:48:46 INFO - 5 wdmaud.drv!wdmaudSetDeviceState + 0x10f 13:48:46 INFO - eip = 0x72d21669 esp = 0x12a7fb58 ebp = 0x12a7fb68 13:48:46 INFO - Found by: call frame info 13:48:46 INFO - 6 wdmaud.drv!wodMessage + 0x17c 13:48:46 INFO - eip = 0x72d21b97 esp = 0x12a7fb70 ebp = 0x12a7fb84 ebx = 0x0ec216a8 13:48:46 INFO - Found by: call frame info 13:48:46 INFO - 7 winmm.dll!waveMessage + 0x50 13:48:46 INFO - eip = 0x76b455b2 esp = 0x12a7fb8c ebp = 0x12a7fba8 ebx = 0x0ec216a8 13:48:46 INFO - Found by: call frame info 13:48:46 INFO - 8 winmm.dll!waveOutReset + 0x35 13:48:46 INFO - eip = 0x76b5bc28 esp = 0x12a7fbb0 ebp = 0x12a7fbc4 13:48:46 INFO - Found by: previous frame's frame pointer 13:48:46 INFO - 9 msacm32.drv!wodMessage + 0xe7 13:48:46 INFO - eip = 0x72d11311 esp = 0x12a7fbcc ebp = 0x12a7fbd8 13:48:46 INFO - Found by: call frame info 13:48:46 INFO - 10 winmm.dll!waveMessage + 0x50 13:48:46 INFO - eip = 0x76b455b2 esp = 0x12a7fbe0 ebp = 0x12a7fbfc 13:48:46 INFO - Found by: previous frame's frame pointer 13:48:46 INFO - 11 winmm.dll!waveOutReset + 0x35 13:48:46 INFO - eip = 0x76b5bc28 esp = 0x12a7fc04 ebp = 0x12a7fc18 13:48:46 INFO - Found by: previous frame's frame pointer 13:48:46 INFO - 12 xul.dll!winmm_stream_destroy [cubeb_winmm.c:51cc57918bf5 : 498 + 0x16] 13:48:46 INFO - eip = 0x055222b7 esp = 0x12a7fc20 ebp = 0x12a7fc30 13:48:46 INFO - Found by: call frame info 13:48:46 INFO - 13 xul.dll!cubeb_stream_destroy [cubeb.c:51cc57918bf5 : 244 + 0x8] 13:48:46 INFO - eip = 0x05521e4e esp = 0x12a7fc38 ebp = 0x12a7fc3c 13:48:46 INFO - Found by: call frame info 13:48:46 INFO - 14 xul.dll!mozilla::AudioStream::Shutdown() [AudioStream.cpp:51cc57918bf5 : 588 + 0xa] 13:48:46 INFO - eip = 0x0473d378 esp = 0x12a7fc44 ebp = 0x12a7fc74 13:48:46 INFO - Found by: call frame info 13:48:46 INFO - 15 xul.dll!mozilla::media::DecodedAudioDataSink::Shutdown() [DecodedAudioDataSink.cpp:51cc57918bf5 : 183 + 0xe] 13:48:46 INFO - eip = 0x047f6aff esp = 0x12a7fc54 ebp = 0x12a7fc74 13:48:46 INFO - Found by: call frame info 13:48:46 INFO - 16 xul.dll!mozilla::media::AudioSinkWrapper::Stop() [AudioSinkWrapper.cpp:51cc57918bf5 : 212 + 0xe] 13:48:46 INFO - eip = 0x047f6e80 esp = 0x12a7fc7c ebp = 0x12a7fcb4 13:48:46 INFO - Found by: call frame info 13:48:46 INFO - 17 xul.dll!mozilla::MediaDecoderStateMachine::StopMediaSink() [MediaDecoderStateMachine.cpp:51cc57918bf5 : 1540 + 0xe] 13:48:46 INFO - eip = 0x047a707f esp = 0x12a7fc8c ebp = 0x12a7fcb4 13:48:46 INFO - Found by: call frame info MediaDecoder is waiting for the monitor held by MediaDecoderStateMachine which is waiting for winmm_stream_destroy() to finish. Hi kinetik, Have you seen this stack before?
Flags: needinfo?(kinetik)
I'm not really sure what's going on here... There's a third thread that may be involved here -- thread 60 is blocked in winmm_refill_stream waiting for the stream lock that's held over the waveOutReset call made from winmm_stream_destroy. I think that is normal/expected as it'll have a chance to run after waveOutReset returns and we reach the WaitForSingleObject loop. It looks like waveOutReset is waiting for an internal thread to stop running, but I don't understand what's causing it to wait. The callback passed to waveOutOpen is intended to be non-blocking and use only functions documented as safe to call from the callback, and the real work is performed by our own winmm_buffer_thread. My first reaction was to speculate that dropping the stream lock around the waveOutReset call may help, but after refreshing my memory of how this code is structured (wrt to the separation of the non-blocking callback and blocking-thread), it shouldn't make a difference.
Flags: needinfo?(kinetik)
Component: Audio/Video → Audio/Video: Playback

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.