Intermittent dom/media/tests/mochitest/test_peerConnection_webAudio.html | application timed out after 330 seconds with no output

RESOLVED DUPLICATE of bug 1304519

Status

()

Core
WebRTC
P3
normal
Rank:
35
RESOLVED DUPLICATE of bug 1304519
2 years ago
6 months ago

People

(Reporter: Treeherder Bug Filer, Unassigned)

Tracking

({intermittent-failure})

Firefox Tracking Flags

(Not tracked)

Details

It looks in the log like we got stuck in step 31: PC_REMOTE_SET_LOCAL_DESCRIPTION.
Rank: 35
Component: Audio/Video → WebRTC
Priority: -- → P3

Comment 2

2 years ago
Why is main doing a reflow I wonder...
Looks like the reflow got triggered by a VSync. But it is crashing while doing some font/graphics related stuff. Is this our bug at all?
Isn't the timeout happening first though? That's what the bug is about really.

I just assumed the gfx crash was due to shutting down. Suggested by the log:

>  14:37:54 WARNING - TEST-UNEXPECTED-TIMEOUT | dom/media/tests/mochitest/test_peerConnection_webAudio.html | application timed out after 330 seconds with no output
>  14:37:54 INFO - 2739 ERROR Force-terminating active process(es).
Here's a try with more info: https://treeherder.mozilla.org/#/jobs?repo=try&revision=557cd026f3bc&selectedJob=28042728

Log: https://archive.mozilla.org/pub/firefox/try-builds/pehrsons@gmail.com-557cd026f3bcaa336987ec76cbb2e3cd988dd391/try-win32/try_win7_vm_test-mochitest-media-e10s-bm140-tests1-windows-build1257.txt.gz

Thread still waiting for critical section at shutdown:
03:25:07     INFO -  Thread 49
03:25:07     INFO -   0  ntdll.dll!KiFastSystemCallRet + 0x0
03:25:07     INFO -      eip = 0x779370b4   esp = 0x0712c8a0   ebp = 0x0712c904   ebx = 0x00000000
03:25:07     INFO -      esi = 0x01400044   edi = 0x00000000   eax = 0x00000000   ecx = 0x00000008
03:25:07     INFO -      edx = 0x00000000   efl = 0x00000213
03:25:07     INFO -      Found by: given as instruction pointer in context
03:25:07     INFO -   1  ntdll.dll!NtWaitForSingleObject + 0xc
03:25:07     INFO -      eip = 0x77936a24   esp = 0x0712c8a4   ebp = 0x0712c904
03:25:07     INFO -      Found by: call frame info
03:25:07     INFO -   2  ntdll.dll!RtlpWaitOnCriticalSection + 0xc4
03:25:07     INFO -      eip = 0x77922264   esp = 0x0712c8a8   ebp = 0x0712c904
03:25:07     INFO -      Found by: call frame info
03:25:07     INFO -   3  ntdll.dll!EtwEventEnabled + 0xd9
03:25:07     INFO -      eip = 0x77922148   esp = 0x0712c90c   ebp = 0x0712c92c   ebx = 0x01400148
03:25:07     INFO -      Found by: call frame info
03:25:07     INFO -   4  mozglue.dll!arena_malloc_small [jemalloc.c:557cd026f3bc : 4234 + 0xd]
03:25:07     INFO -      eip = 0x719e42fb   esp = 0x0712c934   ebp = 0x0712c948   ebx = 0x00000001
03:25:07     INFO -      Found by: call frame info
03:25:07     INFO -   5  mozglue.dll!arena_malloc [jemalloc.c:557cd026f3bc : 4311 + 0xe]
03:25:07     INFO -      eip = 0x719e4200   esp = 0x0712c950   ebp = 0x0712c95c
03:25:07     INFO -      Found by: call frame info
03:25:07     INFO -   6  mozglue.dll!imalloc [jemalloc.c:557cd026f3bc : 4323 + 0x12]
03:25:07     INFO -      eip = 0x719e6eae   esp = 0x0712c964   ebp = 0x0712c970
03:25:07     INFO -      Found by: call frame info
03:25:07     INFO -   7  mozglue.dll!je_malloc [jemalloc.c:557cd026f3bc : 6190 + 0x6]
03:25:07     INFO -      eip = 0x719e7416   esp = 0x0712c978   ebp = 0x0712c980
03:25:07     INFO -      Found by: call frame info
03:25:07     INFO -   8  mozglue.dll!moz_xmalloc [mozalloc.cpp:557cd026f3bc : 83 + 0x8]
03:25:07     INFO -      eip = 0x719e2aa2   esp = 0x0712c988   ebp = 0x0712c98c
03:25:07     INFO -      Found by: call frame info
03:25:07     INFO -   9  xul.dll!std::_Allocate(unsigned int,unsigned int,bool) [xmemory0:557cd026f3bc : 83 + 0x7]
03:25:07     INFO -      eip = 0x5c57e03d   esp = 0x0712c994   ebp = 0x0712c998
03:25:07     INFO -      Found by: call frame info
03:25:07     INFO -  10  xul.dll!std::_List_alloc<std::_List_base_types<webrtc::ForwardErrorCorrection::RecoveredPacket *,std::allocator<webrtc::ForwardErrorCorrection::RecoveredPacket *> > >::_Buynode0(std::_List_node<webrtc::ForwardErrorCorrection::RecoveredPacket *,void *> *,std::_List_node<webrtc::ForwardErrorCorrection::RecoveredPacket *,void *> *) [list:557cd026f3bc : 730 + 0xb]
03:25:07     INFO -      eip = 0x5d8e1f3e   esp = 0x0712c9a0   ebp = 0x0712c9ac
03:25:07     INFO -      Found by: call frame info
03:25:07     INFO -  11  xul.dll!webrtc::AudioConferenceMixerImpl::Process() [audio_conference_mixer_impl.cc:557cd026f3bc : 220 + 0xf]
03:25:07     INFO -      eip = 0x5d92a8c0   esp = 0x0712c9b4   ebp = 0x0712ca00
03:25:07     INFO -      Found by: call frame info
03:25:07     INFO -  12  xul.dll!webrtc::VoEExternalMediaImpl::ExternalPlayoutGetData(short * const,int,int,int &) [voe_external_media_impl.cc:557cd026f3bc : 394 + 0x1b]
03:25:07     INFO -      eip = 0x5d8d2cca   esp = 0x0712ca08   ebp = 0x0712e864
03:25:07     INFO -      Found by: call frame info
03:25:07     INFO -  13  xul.dll!mozilla::WebrtcAudioConduit::GetAudioFrame(short * const,int,int,int &) [AudioConduit.cpp:557cd026f3bc : 653 + 0x15]
03:25:07     INFO -      eip = 0x5ca8fc3b   esp = 0x0712e86c   ebp = 0x0712e8b4
03:25:07     INFO -      Found by: call frame info
03:25:07     INFO -  14  xul.dll!mozilla::MediaPipelineReceiveAudio::PipelineListener::NotifyPull(mozilla::MediaStreamGraph *,__int64) [MediaPipeline.cpp:557cd026f3bc : 2019 + 0x1d]
03:25:07     INFO -      eip = 0x5ca9977f   esp = 0x0712e8bc   ebp = 0x0712fb44
03:25:07     INFO -      Found by: call frame info
03:25:07     INFO -  15  xul.dll!mozilla::MediaStreamGraphImpl::ExtractPendingInput(mozilla::SourceMediaStream *,__int64,bool *) [MediaStreamGraph.cpp:557cd026f3bc : 195 + 0xc]
03:25:07     INFO -      eip = 0x5d2be9a6   esp = 0x0712fb4c   ebp = 0x0712fb80
03:25:07     INFO -      Found by: call frame info
03:25:07     INFO -  16  xul.dll!mozilla::MediaStreamGraphImpl::UpdateGraph(__int64) [MediaStreamGraph.cpp:557cd026f3bc : 1265 + 0x10]
03:25:07     INFO -      eip = 0x5d2d2993   esp = 0x0712fb88   ebp = 0x0712fbcc
03:25:07     INFO -      Found by: call frame info
03:25:07     INFO -  17  xul.dll!mozilla::MediaStreamGraphImpl::OneIteration(__int64) [MediaStreamGraph.cpp:557cd026f3bc : 1409 + 0x11]
03:25:07     INFO -      eip = 0x5d2c82ce   esp = 0x0712fbd4   ebp = 0x0712fbf0
03:25:07     INFO -      Found by: call frame info
03:25:07     INFO -  18  xul.dll!mozilla::AudioCallbackDriver::DataCallback(float const *,float *,long) [GraphDriver.cpp:557cd026f3bc : 951 + 0xe]
03:25:07     INFO -      eip = 0x5d2971c0   esp = 0x0712fbf8   ebp = 0x0712fc44
03:25:07     INFO -      Found by: call frame info
Hmm, comment 5 might be unrelated.

It seems like the child process crashed on main thread. With TelemetryHistogram in the stack:

> 03:25:06  WARNING -  PROCESS-CRASH | dom/media/tests/mochitest/test_peerConnection_webAudio.html | application crashed [@ jemalloc_crash]
> 03:25:06     INFO -  Crash dump filename: c:\users\cltbld\appdata\local\temp\tmprdvghe.mozrunner\minidumps\714eb595-2837-4603-8617-7d76020744e3.dmp
> 03:25:06     INFO -  Operating system: Windows NT
> 03:25:06     INFO -                    6.1.7601 Service Pack 1
> 03:25:06     INFO -  CPU: x86
> 03:25:06     INFO -       GenuineIntel family 6 model 62 stepping 4
> 03:25:06     INFO -       8 CPUs
> 03:25:06     INFO -  Crash reason:  EXCEPTION_BREAKPOINT
> 03:25:06     INFO -  Crash address: 0x719e753b
> 03:25:06     INFO -  Assertion: Unknown assertion type 0x00000000
> 03:25:06     INFO -  Process uptime: 497 seconds
> 03:25:06     INFO -  Thread 0 (crashed)
> 03:25:06     INFO -   0  mozglue.dll!jemalloc_crash [jemalloc.c:557cd026f3bc : 1631 + 0x0]
> 03:25:06     INFO -      eip = 0x719e753b   esp = 0x0028df70   ebp = 0x0028df80   ebx = 0x0cc91000
> 03:25:06     INFO -      esi = 0x00000000   edi = 0x01000000   eax = 0x01000000   ecx = 0x00000018
> 03:25:06     INFO -      edx = 0x00000018   efl = 0x00200206
> 03:25:06     INFO -      Found by: given as instruction pointer in context
> 03:25:06     INFO -   1  mozglue.dll!arena_run_reg_dalloc [jemalloc.c:557cd026f3bc : 3434 + 0x5]
> 03:25:06     INFO -      eip = 0x719e4dee   esp = 0x0028df74   ebp = 0x0028df80
> 03:25:06     INFO -      Found by: call frame info
> 03:25:06     INFO -   2  mozglue.dll!arena_dalloc_small [jemalloc.c:557cd026f3bc : 4618 + 0xb]
> 03:25:06     INFO -      eip = 0x719e40d6   esp = 0x0028df88   ebp = 0x0028dfb4
> 03:25:06     INFO -      Found by: call frame info
> 03:25:06     INFO -   3  mozglue.dll!arena_dalloc [jemalloc.c:557cd026f3bc : 4745 + 0xd]
> 03:25:06     INFO -      eip = 0x719e400b   esp = 0x0028dfbc   ebp = 0x0028dfd8
> 03:25:06     INFO -      Found by: call frame info
> 03:25:06     INFO -   4  mozglue.dll!arena_ralloc [jemalloc.c:557cd026f3bc : 4929 + 0xe]
> 03:25:06     INFO -      eip = 0x719e4805   esp = 0x0028dfe0   ebp = 0x0028dff4
> 03:25:06     INFO -      Found by: call frame info
> 03:25:06     INFO -   5  mozglue.dll!je_realloc [jemalloc.c:557cd026f3bc : 6430 + 0x17]
> 03:25:06     INFO -      eip = 0x719e74fc   esp = 0x0028dffc   ebp = 0x0028e010
> 03:25:06     INFO -      Found by: call frame info
> 03:25:06     INFO -   6  mozglue.dll!moz_xrealloc [mozalloc.cpp:557cd026f3bc : 105 + 0xb]
> 03:25:06     INFO -      eip = 0x719e2ac5   esp = 0x0028e018   ebp = 0x0028e020
> 03:25:06     INFO -      Found by: call frame info
> 03:25:06     INFO -   7  xul.dll!nsTArray_base<nsTArrayInfallibleAllocator,nsTArray_CopyWithMemutils>::EnsureCapacity<nsTArrayInfallibleAllocator>(unsigned int,unsigned int) [nsTArray-inl.h:557cd026f3bc : 183 + 0x8]
> 03:25:06     INFO -      eip = 0x5c54ed1e   esp = 0x0028e028   ebp = 0x0028e03c
> 03:25:06     INFO -      Found by: call frame info
> 03:25:06     INFO -   8  xul.dll!nsTArray_Impl<nsPermissionManager::ApplicationCounter,nsTArrayInfallibleAllocator>::AppendElement<nsPermissionManager::ApplicationCounter &,nsTArrayInfallibleAllocator>(nsPermissionManager::ApplicationCounter &) [nsTArray.h:557cd026f3bc : 2073 + 0x11]
> 03:25:06     INFO -      eip = 0x5ca5a7fc   esp = 0x0028e044   ebp = 0x0028e05c
> 03:25:06     INFO -      Found by: call frame info
> 03:25:06     INFO -   9  xul.dll!`anonymous namespace'::internal_RemoteAccumulate [TelemetryHistogram.cpp:557cd026f3bc : 1328 + 0x15]
> 03:25:06     INFO -      eip = 0x5daf56ae   esp = 0x0028e064   ebp = 0x0028e078
> 03:25:06     INFO -      Found by: call frame info
> 03:25:06     INFO -  10  xul.dll!`anonymous namespace'::internal_Accumulate [TelemetryHistogram.cpp:557cd026f3bc : 1396 + 0xb]
> 03:25:06     INFO -      eip = 0x5daf3b2b   esp = 0x0028e080   ebp = 0x0028e08c
> 03:25:06     INFO -      Found by: call frame info
> 03:25:06     INFO -  11  xul.dll!`anonymous namespace'::internal_JSHistogram_Add [TelemetryHistogram.cpp:557cd026f3bc : 1531 + 0xc]
> 03:25:06     INFO -      eip = 0x5daf4910   esp = 0x0028e094   ebp = 0x0028e1a8
> 03:25:06     INFO -      Found by: call frame info
> 03:25:06     INFO -  12  xul.dll!js::InternalCallOrConstruct(JSContext *,JS::CallArgs const &,js::MaybeConstruct) [Interpreter.cpp:557cd026f3bc : 458 + 0x68]
> 03:25:06     INFO -      eip = 0x5e0ef607   esp = 0x0028e1b0   ebp = 0x0028e1f8
> 03:25:06     INFO -      Found by: call frame info
> 03:25:06     INFO -  13  xul.dll!InternalCall [Interpreter.cpp:557cd026f3bc : 503 + 0xb]
> 03:25:06     INFO -      eip = 0x5e0ef454   esp = 0x0028e200   ebp = 0x0028e218
> 03:25:06     INFO -      Found by: call frame info
> 03:25:06     INFO -  14  xul.dll!Interpret [Interpreter.cpp:557cd026f3bc : 2922 + 0x10]
> 03:25:06     INFO -      eip = 0x5e0f4a56   esp = 0x0028e220   ebp = 0x0028ec10
> 03:25:06     INFO -      Found by: call frame info
> 03:25:06     INFO -  15  xul.dll!mozilla::Vector<js::LiveSavedFrameCache::Entry,0,js::SystemAllocPolicy>::growStorageBy(unsigned int) [Vector.h:557cd026f3bc : 958 + 0x7]
> 03:25:06     INFO -      eip = 0x5dff24a9   esp = 0x0028e250   ebp = 0x0028ed98
> 03:25:06     INFO -      Found by: stack scanning
> 03:25:06     INFO -  16  xul.dll!js::LiveSavedFrameCache::insert(JSContext *,mozilla::Variant<js::AbstractFramePtr,js::jit::CommonFrameLayout *> &,unsigned char *,JS::Handle<js::SavedFrame *>) [SavedStacks.cpp:557cd026f3bc : 88 + 0x14]
> 03:25:06     INFO -      eip = 0x5dff3617   esp = 0x0028e278   ebp = 0x0028ee10
> 03:25:06     INFO -      Found by: call frame info with scanning
> 03:25:06     INFO -  17  xul.dll!js::SavedStacks::insertFrames(JSContext *,js::FrameIter &,JS::MutableHandle<js::SavedFrame *>,mozilla::Variant<JS::AllFrames,JS::MaxFrames,JS::FirstSubsumedFrame> &&) [SavedStacks.cpp:557cd026f3bc : 1349 + 0xa]
> 03:25:06     INFO -      eip = 0x5dff3fe4   esp = 0x0028e2a8   ebp = 0x0028e3a8
> 03:25:06     INFO -      Found by: call frame info with scanning
> 03:25:06     INFO -  18  xul.dll + 0x1b95e50
> 03:25:06     INFO -      eip = 0x5dff5e50   esp = 0x0028e2f4   ebp = 0x0028e3a8
> 03:25:06     INFO -      Found by: stack scanning
> 03:25:06     INFO -  19  0x1400040
> 03:25:06     INFO -      eip = 0x01400040   esp = 0x0028e3b0   ebp = 0x0028ec4a
> 03:25:06     INFO -      Found by: previous frame's frame pointer
> 03:25:06     INFO -  20  0x50000028
> 03:25:06     INFO -      eip = 0x50000028   esp = 0x0028ec52   ebp = 0xecd008a7
> 03:25:06     INFO -      Found by: previous frame's frame pointer
This very much looks like bug 1304519. I.e., caused by bug 1218576.
Blocks: 1218576
Status: NEW → RESOLVED
Last Resolved: a year ago
Resolution: --- → DUPLICATE
Duplicate of bug: 1304519

Comment 8

6 months ago
1 failures in 939 pushes (0.001 failures/push) were associated with this bug in the last 7 days.   

Repository breakdown:
* mozilla-central: 1

Platform breakdown:
* android-7-1-armv8-api16: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1282196&startday=2017-08-28&endday=2017-09-03&tree=all
You need to log in before you can comment on or make changes to this bug.