Closed Bug 1039884 Opened 10 years ago Closed 9 years ago

Intermittent test_dataChannel_basicAudio.html | Main app process exited normally | application crashed [@ mozilla::MediaStreamGraphImpl::AppendMessage(mozilla::ControlMessage*)] with Assertion failure: mCanRunMessagesSynchronously, at MediaStreamGraph.cpp

Categories

(Core :: WebRTC, defect)

x86
Linux
defect
Not set
normal

Tracking

()

RESOLVED FIXED
mozilla37
Tracking Status
firefox32 --- wontfix
firefox33 --- wontfix
firefox34 --- wontfix
firefox35 --- wontfix
firefox36 --- fixed
firefox37 --- fixed
firefox-esr24 --- unaffected
firefox-esr31 --- unaffected
b2g-v1.4 --- unaffected
b2g-v2.0 --- wontfix
b2g-v2.0M --- wontfix
b2g-v2.1 --- fixed
b2g-v2.1S --- fixed
b2g-v2.2 --- fixed

People

(Reporter: KWierso, Assigned: pehrsons)

References

Details

(Keywords: crash, intermittent-failure)

Crash Data

Attachments

(1 file, 2 obsolete files)

https://tbpl.mozilla.org/php/getParsedLog.php?id=43965707&tree=Fx-Team
Ubuntu VM 12.04 x64 fx-team debug test mochitest-3 on 2014-07-16 13:42:18 PDT for push dcad44d79eee

slave: tst-linux64-spot-194



13:49:40     INFO -  (stun/INFO) Skipping SOURCE-ADDRESS
13:49:40     INFO -  (stun/INFO) Skipping CHANGED-ADDRESS
13:49:40     INFO -  (stun/INFO) Translating obsolete XOR-MAPPED-ADDRESS type
13:49:40     INFO -  -1815087360[7ff5a6443a40]: NrIceCtx(PC:1405543780171587 (id=420 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_dataChannel_basicAudio.html)): trickling candidate candidate:1 1 UDP 1686110207 63.245.214.82 59097 typ srflx raddr 10.134.57.32 rport 50196
13:49:40     INFO -  (stun/INFO) Skipping SOURCE-ADDRESS
13:49:40     INFO -  (stun/INFO) Skipping CHANGED-ADDRESS
13:49:40     INFO -  (stun/INFO) Translating obsolete XOR-MAPPED-ADDRESS type
13:49:40     INFO -  -1815087360[7ff5a6443a40]: NrIceCtx(PC:1405543780171587 (id=420 url=http://mochi.test:8888/tests/dom/media/tests/mochitest/test_dataChannel_basicAudio.html)): trickling candidate candidate:1 2 UDP 1686110206 63.245.214.82 58730 typ srflx raddr 10.134.57.32 rport 33407
13:49:40     INFO -  Assertion failure: mCanRunMessagesSynchronously, at /builds/slave/fx-team-l64-d-0000000000000000/build/content/media/MediaStreamGraph.cpp:1761
13:50:17     INFO -  mozilla::dom::HTMLMediaElement::Pause(mozilla::ErrorResult&) [content/html/content/src/HTMLMediaElement.cpp:1636]
13:50:17     INFO -  mozilla::dom::HTMLMediaElement::Pause() [content/html/content/src/HTMLMediaElement.cpp:1645]
13:50:17     INFO -  mozilla::dom::HTMLMediaElement::PlaybackEnded() [content/html/content/src/HTMLMediaElement.cpp:3043]
13:50:17     INFO -  mozilla::dom::HTMLMediaElement::StreamListener::DoNotifyFinished() [content/html/content/src/HTMLMediaElement.cpp:2715]
13:50:17     INFO -  nsRunnableMethodImpl<void (mozilla::dom::HTMLMediaElement::StreamListener::*)(), void, true>::Run() [obj-firefox/dist/include/nsThreadUtils.h:394]
13:50:17     INFO -  mozilla::MediaStreamGraphImpl::RunInStableState() [obj-firefox/dist/include/nsTArray.h:323]
13:50:17     INFO -  mozilla::::MediaStreamGraphStableStateRunnable::Run [content/media/MediaStreamGraph.cpp:1567]
13:50:17     INFO -  nsThread::ProcessNextEvent(bool, bool*) [xpcom/threads/nsThread.cpp:766]
13:50:17     INFO -  NS_ProcessNextEvent(nsIThread*, bool) [xpcom/glue/nsThreadUtils.cpp:265]
13:50:17     INFO -  nsThread::Shutdown() [xpcom/threads/nsThread.cpp:597]
13:50:17     INFO -  mozilla::MediaManager::Observe(nsISupports*, char const*, char16_t const*) [obj-firefox/dist/include/nsCOMPtr.h:1172]
13:50:17     INFO -  nsObserverList::NotifyObservers(nsISupports*, char const*, char16_t const*) [obj-firefox/dist/include/nsTArray.h:323]
13:50:17     INFO -  nsObserverService::NotifyObservers(nsISupports*, char const*, char16_t const*) [xpcom/ds/nsObserverService.cpp:333]
13:50:17     INFO -  mozilla::ShutdownXPCOM(nsIServiceManager*) [xpcom/build/nsXPComInit.cpp:811]
13:50:17     INFO -  XRE_TermEmbedding [toolkit/xre/nsEmbedFunctions.cpp:192]
13:50:17     INFO -  mozilla::ipc::ScopedXREEmbed::Stop() [ipc/glue/ScopedXREEmbed.cpp:111]
13:50:17     INFO -  XRE_InitChildProcess [toolkit/xre/nsEmbedFunctions.cpp:535]
13:50:17     INFO -  main [ipc/app/MozillaRuntimeMain.cpp:152]
13:50:17     INFO -  libc.so.6 + 0x2176d


LATER



13:50:19     INFO -  654 INFO TEST-INFO | MEMORY STAT vsize after test: 1315360768
13:50:19     INFO -  655 INFO TEST-INFO | MEMORY STAT residentFast after test: 326967296
13:50:19     INFO -  [Parent 1789] WARNING: MediaPipeline Transport failed. This is not properly cleaned up yet: file /builds/slave/fx-team-l64-d-0000000000000000/build/media/webrtc/signaling/src/mediapipeline/MediaPipeline.cpp, line 290
13:50:19     INFO -  [Parent 1789] WARNING: MediaPipeline Transport failed. This is not properly cleaned up yet: file /builds/slave/fx-team-l64-d-0000000000000000/build/media/webrtc/signaling/src/mediapipeline/MediaPipeline.cpp, line 290
13:50:19     INFO -  656 INFO TEST-INFO | MEMORY STAT heapAllocated after test: 98948000
13:50:19     INFO -  -1482991808[7ff5a6443380]: Deleting DataChannelConnection 7ff56ca5aba0
13:50:19     INFO -  -1482991808[7ff5a6443380]: [main|def] ccapi_call.c:57: SIPCC-SIP_CC_PROV: CCAPI_Call_releaseCallInfo: ref=0x7ff56c738800: count=1
13:50:19     INFO -  -1482991808[7ff5a6443380]: [main|def] ccapi_call.c:57: SIPCC-SIP_CC_PROV: CCAPI_Call_releaseCallInfo: ref=0x7ff57512ec00: count=1
13:50:19     INFO -  657 ERROR TEST-UNEXPECTED-FAIL | /tests/dom/media/tests/mochitest/test_dataChannel_basicAudio.html | This test left crash dumps behind, but we weren't expecting it to!
13:50:19     INFO -  658 INFO TEST-INFO | Found unexpected crash dump file /tmp/tmpFT2aGk.mozrunner/minidumps/4e691af6-a78a-4b07-670144e9-5727a3a8.dmp.
13:50:19     INFO -  659 INFO TEST-INFO | Found unexpected crash dump file /tmp/tmpFT2aGk.mozrunner/minidumps/4e691af6-a78a-4b07-670144e9-5727a3a8.extra.
13:50:19     INFO -  660 INFO TEST-END | /tests/dom/media/tests/mochitest/test_dataChannel_basicAudio.html | finished in 40170ms
13:50:19     INFO -  ++DOMWINDOW == 24 (0x7ff576aa8400) [pid = 1789] [serial = 421] [outer = 0x7ff5788acc00]
13:50:19     INFO -  -1482991808[7ff5a6443380]: [main|PeerConnectionImpl] PeerConnectionImpl.cpp:1675: CloseInt: Closing PeerConnectionImpl 9299afb5c3256a7a; ending call
13:50:19     INFO -  -1832073472[7ff575e20260]: [CCAPP Task|def] ccapi.c:1446: SIPCC-CC_API: 1/11, cc_int_onhook: UI -> GSM: ONHOOK
13:50:19     INFO -  -1832073472[7ff575e20260]: [CCAPP Task|def] ccapi.c:1448: (1/11) On-hook called from /builds/slave/fx-team-l64-d-0000000000000000/build/media/webrtc/signaling/src/sipcc/core/ccapp/ccprovider.c:657
13:50:19     INFO -  -1832663296[7ff5753af700]: [GSM Task|def] dcsm.c:532: SIPCC-DCSM: dcsm_process_event: DCSM 11  :(DCSM_READY:ONHOOK )
13:50:19     INFO -  -1482991808[7ff5a6443380]: [main|PeerConnectionImpl] PeerConnectionImpl.cpp:1675: CloseInt: Closing PeerConnectionImpl e96bd76fe9633829; ending call
13:50:19     INFO -  -1832073472[7ff575e20260]: [CCAPP Task|def] ccapi.c:1446: SIPCC-CC_API: 1/12, cc_int_onhook: UI -> GSM: ONHOOK
13:50:19     INFO -  -1832073472[7ff575e20260]: [CCAPP Task|def] ccapi.c:1448: (1/12) On-hook called from /builds/slave/fx-team-l64-d-0000000000000000/build/media/webrtc/signaling/src/sipcc/core/ccapp/ccprovider.c:657
13:50:19     INFO -  -1832663296[7ff5753af700]: [GSM Task|def] dcsm.c:532: SIPCC-DCSM: dcsm_process_event: DCSM 11  :(DCSM_READY:ONHOOK )
13:50:20     INFO -  661 INFO TEST-START | /tests/dom/media/tests/mochitest/test_dataChannel_basicAudioVideo.html



LATER



14:09:02     INFO -  INFO | zombiecheck | Checking for orphan process with PID: 1835
14:09:02     INFO -  INFO | zombiecheck | Checking for orphan process with PID: 1865
14:09:02     INFO -  INFO | zombiecheck | Checking for orphan process with PID: 1888
14:09:02     INFO -  INFO | zombiecheck | Checking for orphan process with PID: 1909
14:09:02     INFO -  INFO | zombiecheck | Checking for orphan process with PID: 1930
14:09:02     INFO -  INFO | zombiecheck | Checking for orphan process with PID: 1944
14:09:02     INFO -  INFO | zombiecheck | Checking for orphan process with PID: 2030
14:09:02     INFO -  INFO | zombiecheck | Checking for orphan process with PID: 2445
14:09:02     INFO -  INFO | zombiecheck | Checking for orphan process with PID: 2449
14:09:02     INFO -  INFO | zombiecheck | Checking for orphan process with PID: 2454
14:09:02     INFO -  INFO | zombiecheck | Checking for orphan process with PID: 2458
14:09:02     INFO -  INFO | zombiecheck | Checking for orphan process with PID: 2463
14:09:02     INFO -  INFO | zombiecheck | Checking for orphan process with PID: 2467
14:09:02     INFO -  INFO | zombiecheck | Checking for orphan process with PID: 2473
14:09:02     INFO -  INFO | zombiecheck | Checking for orphan process with PID: 2477
14:09:02     INFO -  INFO | zombiecheck | Checking for orphan process with PID: 2485
14:09:10  WARNING -  PROCESS-CRASH | Main app process exited normally | application crashed [@ mozilla::MediaStreamGraphImpl::AppendMessage(mozilla::ControlMessage*)]
14:09:10     INFO -  Crash dump filename: /tmp/tmpFT2aGk.mozrunner/minidumps/4e691af6-a78a-4b07-670144e9-5727a3a8.dmp
14:09:10     INFO -  Operating system: Linux
14:09:10     INFO -                    0.0.0 Linux 3.2.0-23-generic #36-Ubuntu SMP Tue Apr 10 20:39:51 UTC 2012 x86_64
14:09:10     INFO -  CPU: amd64
14:09:10     INFO -       family 6 model 45 stepping 7
14:09:10     INFO -       1 CPU
14:09:10     INFO -  Crash reason:  SIGSEGV
14:09:10     INFO -  Crash address: 0x0
14:09:10     INFO -  Thread 0 (crashed)
14:09:10     INFO -   0  libxul.so!mozilla::MediaStreamGraphImpl::AppendMessage(mozilla::ControlMessage*) [MediaStreamGraph.cpp:dcad44d79eee : 1761 + 0x18]
14:09:10     INFO -      rbx = 0x00007fd3839cabc0   r12 = 0x00007fd3635324a0
14:09:10     INFO -      r13 = 0x00000000ffffffff   r14 = 0x00007fffb8342f01
14:09:10     INFO -      r15 = 0xffffffffffffffff   rip = 0x00007fd398b0bd41
14:09:10     INFO -      rsp = 0x00007fffb8342ca0   rbp = 0x00007fffb8342cc0
14:09:10     INFO -      Found by: given as instruction pointer in context
14:09:10     INFO -   1  libxul.so!mozilla::dom::HTMLMediaElement::Pause(mozilla::ErrorResult&) [HTMLMediaElement.cpp:dcad44d79eee : 1633 + 0xd]
14:09:10     INFO -      rbx = 0x00007fd37f638c00   r12 = 0x0000000000000000
14:09:10     INFO -      r13 = 0x00000000ffffffff   r14 = 0x00007fffb8342f01
14:09:10     INFO -      r15 = 0xffffffffffffffff   rip = 0x00007fd398a8961f
14:09:10     INFO -      rsp = 0x00007fffb8342cd0   rbp = 0x00007fffb8342cf0
14:09:10     INFO -      Found by: call frame info
14:09:10     INFO -   2  libxul.so!mozilla::dom::HTMLMediaElement::Pause() [HTMLMediaElement.cpp:dcad44d79eee : 1644 + 0x4]
14:09:10     INFO -      rbx = 0x00007fd37f638c00   r12 = 0x0000000000000000
14:09:10     INFO -      r13 = 0x00000000ffffffff   r14 = 0x00007fffb8342f01
14:09:10     INFO -      r15 = 0xffffffffffffffff   rip = 0x00007fd398a8967b
14:09:10     INFO -      rsp = 0x00007fffb8342d00   rbp = 0x00007fffb8342d30
14:09:10     INFO -      Found by: call frame info
14:09:10     INFO -   3  libxul.so!mozilla::dom::HTMLMediaElement::PlaybackEnded() [HTMLMediaElement.cpp:dcad44d79eee : 3041 + 0x8]
14:09:10     INFO -      rbx = 0x00007fd37f638c00   r12 = 0x0000000000000000
14:09:10     INFO -      r13 = 0x00000000ffffffff   r14 = 0x00007fffb8342f01
14:09:10     INFO -      r15 = 0xffffffffffffffff   rip = 0x00007fd398a89490
14:09:10     INFO -      rsp = 0x00007fffb8342d40   rbp = 0x00007fffb8342d90
14:09:10     INFO -      Found by: call frame info
14:09:10     INFO -   4  libxul.so!mozilla::dom::HTMLMediaElement::StreamListener::DoNotifyFinished() [HTMLMediaElement.cpp:dcad44d79eee : 2715 + 0x8]
14:09:10     INFO -      rbx = 0x00007fd373590d40   r12 = 0x0000000000000001
14:09:10     INFO -      r13 = 0x00007fd361fff098   r14 = 0x00007fffb8342f01
14:09:10     INFO -      r15 = 0x0000000000000001   rip = 0x00007fd398a89543
14:09:10     INFO -      rsp = 0x00007fffb8342da0   rbp = 0x00007fffb8342dc0
14:09:10     INFO -      Found by: call frame info
Findings so far, for the last stack trace by TBPL Robot (only one still around).

Log at: http://ftp.mozilla.org/pub/mozilla.org/firefox/tinderbox-builds/mozilla-inbound-linux64-debug/1418763733/mozilla-inbound_ubuntu64_vm-debug_test-mochitest-3-bm113-tests1-linux64-build424.txt.gz

Stack trace leading to failure is:
14:01:51     INFO -  Assertion failure: mCanRunMessagesSynchronously, at /builds/slave/m-in-l64-d-0000000000000000000/build/src/dom/media/MediaStreamGraph.cpp:1776
14:02:13     INFO -  #01: mozilla::dom::HTMLMediaElement::Pause(mozilla::ErrorResult&) [dom/html/HTMLMediaElement.cpp:1617]
14:02:13     INFO -  #02: mozilla::dom::HTMLMediaElement::Pause() [dom/html/HTMLMediaElement.cpp:1626]
14:02:13     INFO -  #03: mozilla::dom::HTMLMediaElement::PlaybackEnded() [dom/html/HTMLMediaElement.cpp:3033]
14:02:13     INFO -  #04: mozilla::dom::HTMLMediaElement::StreamListener::DoNotifyFinished() [dom/html/HTMLMediaElement.cpp:2726]
14:02:13     INFO -  #05: nsRunnableMethodImpl<void (mozilla::dom::HTMLMediaElement::StreamListener::*)(), void, true>::Run() [xpcom/glue/nsThreadUtils.h:391]
14:02:13     INFO -  #06: mozilla::MediaStreamGraphImpl::RunInStableState(bool) [xpcom/glue/nsTArray.h:330]
14:02:13     INFO -  #07: mozilla::::MediaStreamGraphStableStateRunnable::Run [dom/media/MediaStreamGraph.cpp:1539]
14:02:13     INFO -  #08: nsThread::ProcessNextEvent(bool, bool*) [xpcom/threads/nsThread.cpp:835]
14:02:13     INFO -  #09: NS_ProcessNextEvent(nsIThread*, bool) [xpcom/glue/nsThreadUtils.cpp:265]
14:02:13     INFO -  #10: nsThread::Shutdown() [xpcom/threads/nsThread.cpp:641]
14:02:13     INFO -  #11: mozilla::MediaEngineWebRTC::Shutdown() [xpcom/glue/nsCOMPtr.h:1031]
14:02:13     INFO -  #12: mozilla::MediaEngineWebRTC::~MediaEngineWebRTC() [xpcom/base/StaticPtr.h:137]
14:02:13     INFO -  #13: mozilla::MediaEngineWebRTC::~MediaEngineWebRTC() [memory/mozalloc/mozalloc.h:234]
14:02:13     INFO -  #14: mozilla::MediaEngine::Release() [dom/media/webrtc/MediaEngine.h:55]
14:02:13     INFO -  #15: mozilla::MediaManager::Observe(nsISupports*, char const*, char16_t const*) [dom/media/MediaManager.cpp:2028]
14:02:13     INFO -  #16: nsObserverList::NotifyObservers(nsISupports*, char const*, char16_t const*) [xpcom/glue/nsTArray.h:330]
14:02:13     INFO -  #17: nsObserverService::NotifyObservers(nsISupports*, char const*, char16_t const*) [xpcom/ds/nsObserverService.cpp:333]
14:02:13     INFO -  #18: mozilla::ShutdownXPCOM(nsIServiceManager*) [xpcom/build/XPCOMInit.cpp:842]
14:02:13     INFO -  #19: XRE_TermEmbedding [toolkit/xre/nsEmbedFunctions.cpp:207]
14:02:13     INFO -  #20: mozilla::ipc::ScopedXREEmbed::Stop() [ipc/glue/ScopedXREEmbed.cpp:116]
14:02:13     INFO -  #21: XRE_InitChildProcess [toolkit/xre/nsEmbedFunctions.cpp:576]
14:02:13     INFO -  #22: content_process_main(int, char**) [ipc/contentproc/plugin-container.cpp:214]
14:02:13     INFO -  #23: libc.so.6 + 0x2176d
14:02:13     INFO -  #24: _start


Some facts that might or might not help:

* We're on the main thread, shutting down another thread (I noted "AudioGUM" from MediaEngineWebRTC, but not sure if it's relevant)

* While waiting for shutdown ack from "AudioGUM" we're processing main thread events - in the fail cases it's MediaStreamGraphStableStateRunnable.

* mCanRunMessagesSynchronously is set to false from two places (except on init), both on the main thread.
One is reset to true in the same scope so it can't be that one.
The other is at: http://dxr.mozilla.org/mozilla-central/source/dom/media/MediaStreamGraph.cpp#1722
>   mCanRunMessagesSynchronously = mDetectedNotRunning &&
>     mLifecycleState >= LIFECYCLE_WAITING_FOR_THREAD_SHUTDOWN;

* The condition for hitting the assert is:
http://dxr.mozilla.org/mozilla-central/source/dom/media/MediaStreamGraph.cpp#1776
>   if (mDetectedNotRunning &&
>       mLifecycleState > LIFECYCLE_WAITING_FOR_MAIN_THREAD_CLEANUP) {
>     // The graph control loop is not running and main thread cleanup has
>     // happened. From now on we can't append messages to mCurrentTaskMessageQueue,
>     // because that will never be processed again, so just RunDuringShutdown
>     // this message.
>     // This should only happen during forced shutdown, or after a non-realtime
>     // graph has finished processing.
> #ifdef DEBUG
>     MOZ_ASSERT(mCanRunMessagesSynchronously);

* Life cycle state looks like:
http://dxr.mozilla.org/mozilla-central/source/dom/media/MediaStreamGraphImpl.h#578
>   enum LifecycleState {
>     // The graph thread hasn't started yet.
>     LIFECYCLE_THREAD_NOT_STARTED,
>     // RunThread() is running normally.
>     LIFECYCLE_RUNNING,
>     // In the following states, the graph thread is not running so
>     // all "graph thread only" state in this class can be used safely
>     // on the main thread.
>     // RunThread() has exited and we're waiting for the next
>     // RunInStableState(), at which point we can clean up the main-thread
>     // side of the graph.
>     LIFECYCLE_WAITING_FOR_MAIN_THREAD_CLEANUP,
>     // RunInStableState() posted a ShutdownRunnable, and we're waiting for it
>     // to shut down the graph thread(s).
>     LIFECYCLE_WAITING_FOR_THREAD_SHUTDOWN,
>     // Graph threads have shut down but we're waiting for remaining streams
>     // to be destroyed. Only happens during application shutdown and on
>     // completed non-realtime graphs, since normally we'd only shut down a
>     // realtime graph when it has no streams.
>     LIFECYCLE_WAITING_FOR_STREAM_DESTRUCTION
>   };

* mDetectedNotRunning must have gone from false to true OR mLifecycleState from < LIFECYCLE_WAITING_FOR_THREAD_SHUTDOWN to >= LIFECYCLE_WAITING_FOR_THREAD_SHUTDOWN after setting mCanRunMessagesSynchronously but before the assert. Hmm. I can't find any cases where this would hold if the cycle finishes, but if we hit the assert before mCanRunMessagesSynchronously is set at all, it could work.

* The previous holds here:
http://dxr.mozilla.org/mozilla-central/source/dom/media/MediaStreamGraph.cpp#1689
>     if ((mForceShutDown || !mRealtime) &&
>         mLifecycleState == LIFECYCLE_WAITING_FOR_MAIN_THREAD_CLEANUP) {
>       // Defer calls to RunDuringShutdown() to happen while mMonitor is not held.
>       for (uint32_t i = 0; i < mBackMessageQueue.Length(); ++i) {
>         MessageBlock& mb = mBackMessageQueue[i];
>         controlMessagesToRunDuringShutdown.MoveElementsFrom(mb.mMessages);
>       }
>       mBackMessageQueue.Clear();
>       MOZ_ASSERT(mCurrentTaskMessageQueue.IsEmpty());
>       // Stop MediaStreamGraph threads. Do not clear gGraph since
>       // we have outstanding DOM objects that may need it.
> -->   mLifecycleState = LIFECYCLE_WAITING_FOR_THREAD_SHUTDOWN;
>       nsCOMPtr<nsIRunnable> event = new MediaStreamGraphShutDownRunnable(this);
>       NS_DispatchToMainThread(event);
>     }
> 
> --> mDetectedNotRunning = mLifecycleState > LIFECYCLE_RUNNING;
(...)
>   for (uint32_t i = 0; i < controlMessagesToRunDuringShutdown.Length(); ++i) {
> --> controlMessagesToRunDuringShutdown[i]->RunDuringShutdown(); <-- ASSERT
>   }
(...)
>   mCanRunMessagesSynchronously = mDetectedNotRunning &&
>     mLifecycleState >= LIFECYCLE_WAITING_FOR_THREAD_SHUTDOWN;


Ok, I must say that it looked damn hard to reproduce and debug at first, but I think I got BINGO on the analysis.
Assignee: nobody → pehrsons
Status: NEW → ASSIGNED
Flags: needinfo?(pehrsons)
Bug 1020411 is related, though I don't have access to it so I can't follow its discussion - would have been nice :/

(Also couldn't set it as 'See Also' due to not being authorized...)
You can now :)
Thanks!

(In reply to Andreas Pehrson [:pehrsons] (Telenor) from comment #10)
> >   for (uint32_t i = 0; i < controlMessagesToRunDuringShutdown.Length(); ++i) {
> > --> controlMessagesToRunDuringShutdown[i]->RunDuringShutdown(); <-- ASSERT

Oh, this is wrong. DoNotifyOutput is an NS_NewRunnableMethod:
http://dxr.mozilla.org/mozilla-central/source/dom/html/HTMLMediaElement.cpp#2806

And NS_NewRunnableMethod doesn't have any RunDuringShutdown() override:
http://dxr.mozilla.org/mozilla-central/source/xpcom/glue/nsThreadUtils.h#408


Instead, the assert must be happening here:
http://dxr.mozilla.org/mozilla-central/source/dom/media/MediaStreamGraph.cpp#1715
>   for (uint32_t i = 0; i < runnables.Length(); ++i) {
>     runnables[i]->Run();
>   }

(Which is obvious from the stack trace in comment 10 as well...)
See Also: → CVE-2014-1550
Here's a candidate patch. I'm not completely sure this is allowed yet, but well.. try will tell if it's really bad at least :-p

https://treeherder.mozilla.org/#/jobs?repo=try&revision=eac1130afa18
(In reply to Andreas Pehrson [:pehrsons] (Telenor) from comment #14)
> Created attachment 8537965 [details] [diff] [review]
> Make sure mCanRunMessagesSynchronously is in sync with mDetectedNotRunning
> 
> Here's a candidate patch. I'm not completely sure this is allowed yet, but
> well.. try will tell if it's really bad at least :-p

Having had another look I do think this patch is bad, because it would make ControlMessages appear out of order. I'll work on a proper fix tomorrow.
roc: you may want to look at this (roc wrote most of the shutdown code)
Flags: needinfo?(roc)
I think this is a more appropriate patch. Since the update runnables are allowed to append messages we need to take care of them and run them in order with existing ControlMessages.

roc, what do you think of this approach? Could it be done simpler?

https://treeherder.mozilla.org/#/jobs?repo=try&revision=25bfbb12006e
Attachment #8537965 - Attachment is obsolete: true
Attachment #8539264 - Flags: feedback?(roc)
Comment on attachment 8539264 [details] [diff] [review]
Handle ControlMessages appended by update runnables during MSG shutdown initialisation

Review of attachment 8539264 [details] [diff] [review]:
-----------------------------------------------------------------

Looks good but MSG shutdown is tricky so requesting additional review from Karl.
Attachment #8539264 - Flags: review?(karlt)
Attachment #8539264 - Flags: feedback?(roc)
Attachment #8539264 - Flags: feedback+
Comment on attachment 8539264 [details] [diff] [review]
Handle ControlMessages appended by update runnables during MSG shutdown initialisation

The goal of mCanRunMessagesSynchronously was to ensure that ControlMessages
(from AppendMessage()) ran in order, which can be particularly important
because they have only a raw pointer to their MediaStream.

Here it seems that an nsIRunnable from
mUpdateRunnables/DispatchToMainThreadAfterStreamStateUpdate() is calling
AppendMessage(), something that I unfortunately did not consider in bug
1020411.  The assertion failure here may not be so bad in this particular situation because the ControlMessage is not from
MediaStream::Destroy(), but ControlMessages should still run in order, which
is what is being fixed here.

I wonder whether this could be simpler if there was just a reordering of the handling of runnables and controlMessagesToRunDuringShutdown so that
mCanRunMessagesSynchronously is updated after
controlMessagesToRunDuringShutdown are RunDuringShutdown() but before runnables are Run()?
I'm not aware of any reason that DispatchToMainThreadAfterStreamStateUpdate()
should ensure a runnable runs before any ControlMessages.

Removing review request for now, but please re-request if you still think this is the right approach.
Attachment #8539264 - Flags: review?(karlt)
I agree, reordering the code so the mUpdateRunnables run after the controlMessagesToRunDuringShutdown should work and be simpler.
Comment on attachment 8539264 [details] [diff] [review]
Handle ControlMessages appended by update runnables during MSG shutdown initialisation

Review of attachment 8539264 [details] [diff] [review]:
-----------------------------------------------------------------

changed status per above comments
Attachment #8539264 - Flags: feedback+ → feedback-
All right, thanks for the reviews guys. This is a new patch per Karl's suggestion.

Looking good on try so far: https://treeherder.mozilla.org/ui/#/jobs?repo=try&revision=9d20ee878999
Attachment #8539264 - Attachment is obsolete: true
Flags: needinfo?(roc)
Attachment #8545921 - Flags: review?(roc)
Attachment #8545921 - Flags: review?(karlt)
Attachment #8545921 - Flags: review?(karlt) → review+
Keywords: checkin-needed
https://hg.mozilla.org/mozilla-central/rev/2e983faaa3a5
Status: ASSIGNED → RESOLVED
Closed: 9 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla37
I think we're going to need Aurora36 and b2g34 approval requests on this :)
Comment on attachment 8545921 [details] [diff] [review]
Let ControlMessages added by runnables in stable state be run during shutdown

[Approval Request Comment]
Bug caused by (feature/regressing bug #): MediaStreamGraph shutdown sequence (bug 1020411 related but not a cause)
User impact if declined: MediaStreamGraph ControlMessages could be run out of order, most likely without impact but possibly with unexpected behavior, e.g., crashes.
Testing completed: All tests using MediaStreams cover the patched code
Risk to taking this patch (and alternatives if risky): Low
String or UUID changes made by this patch: none
Flags: needinfo?(pehrsons)
Attachment #8545921 - Flags: approval-mozilla-b2g34?
Attachment #8545921 - Flags: approval-mozilla-aurora?
Attachment #8545921 - Flags: approval-mozilla-aurora? → approval-mozilla-aurora+
Attachment #8545921 - Flags: approval-mozilla-b2g34? → approval-mozilla-b2g34+
Flags: qe-verify-
You need to log in before you can comment on or make changes to this bug.