1412231 - Intermittent Assertion failure: mAudioContextOperation == AudioContextOperation::Close (We should be reviving the graph?), at /builds/worker/workspace/build/src/dom/media/MediaStreamGraph.cpp:4051

Status: RESOLVED FIXED

(Core :: Audio/Video: MediaStreamGraph, defect, P3)

Description

[Treeherder Bug Filer]

Filed by: archaeopteryx [at] coole-files.de

https://treeherder.mozilla.org/logviewer.html#?job_id=139860182&repo=mozilla-inbound

https://queue.taskcluster.net/v1/task/V9kMB5NCRpuet5d3r_2LPw/runs/0/artifacts/public/logs/live_backing.log

This is how it fails on Linux. On OS X and Windows, the failure is bug 1412229.

[task 2017-10-26T13:45:40.354Z] 13:45:40     INFO - REFTEST SUITE-START | Running 1 tests
[task 2017-10-26T13:45:40.355Z] 13:45:40     INFO - REFTEST TEST-START | file:///builds/worker/workspace/build/tests/reftest/tests/dom/media/tests/crashtests/1185191.html
[task 2017-10-26T13:45:40.357Z] 13:45:40     INFO - REFTEST INFO | SET PREFERENCE pref(media.navigator.permission.disabled,true)
[task 2017-10-26T13:45:40.358Z] 13:45:40     INFO - REFTEST TEST-LOAD | file:///builds/worker/workspace/build/tests/reftest/tests/dom/media/tests/crashtests/1185191.html | 0 / 1 (0%)
[task 2017-10-26T13:45:40.360Z] 13:45:40     INFO - ++DOMWINDOW == 3 (0x7fb38ad54800) [pid = 1261] [serial = 3] [outer = 0x7fb38c5e0800]
[task 2017-10-26T13:45:40.588Z] 13:45:40     INFO - REFTEST TEST-PASS | file:///builds/worker/workspace/build/tests/reftest/tests/dom/media/tests/crashtests/1185191.html | (LOAD ONLY)
[task 2017-10-26T13:45:40.588Z] 13:45:40     INFO - REFTEST TEST-END | file:///builds/worker/workspace/build/tests/reftest/tests/dom/media/tests/crashtests/1185191.html
[task 2017-10-26T13:45:40.599Z] 13:45:40     INFO - ++DOMWINDOW == 4 (0x7fb38ad47800) [pid = 1261] [serial = 4] [outer = 0x7fb38c5e0800]
[task 2017-10-26T13:45:40.667Z] 13:45:40     INFO - REFTEST INFO | RESTORE PREFERENCE pref(media.navigator.permission.disabled,false)
[task 2017-10-26T13:45:40.669Z] 13:45:40     INFO - REFTEST INFO | Result summary:
[task 2017-10-26T13:45:40.671Z] 13:45:40     INFO - REFTEST INFO | Successful: 1 (0 pass, 1 load only)
[task 2017-10-26T13:45:40.672Z] 13:45:40     INFO - REFTEST INFO | Unexpected: 0 (0 unexpected fail, 0 unexpected pass, 0 unexpected asserts, 0 failed load, 0 exception)
[task 2017-10-26T13:45:40.673Z] 13:45:40     INFO - REFTEST INFO | Known problems: 0 (0 known fail, 0 known asserts, 0 random, 0 skipped, 0 slow)
[task 2017-10-26T13:45:40.674Z] 13:45:40     INFO - REFTEST SUITE-END | Shutdown
[task 2017-10-26T13:45:40.675Z] 13:45:40     INFO - REFTEST INFO | Slowest test took 188ms (file:///builds/worker/workspace/build/tests/reftest/tests/dom/media/tests/crashtests/1185191.html)
[task 2017-10-26T13:45:40.676Z] 13:45:40     INFO - REFTEST INFO | Total canvas count = 0
[task 2017-10-26T13:45:41.009Z] 13:45:41     INFO - JavaScript error: chrome://reftest/content/reftest.jsm, line 1502: NS_ERROR_NOT_AVAILABLE: Component returned failure code: 0x80040111 (NS_ERROR_NOT_AVAILABLE) [nsIPropertyBag2.getPropertyAsAString]
[task 2017-10-26T13:45:41.206Z] 13:45:41     INFO - ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpjD2du0.mozrunner/runreftest_leaks_tab_pid1313.log
[task 2017-10-26T13:45:41.951Z] 13:45:41     INFO - --DOCSHELL 0x7f1feb19d000 == 7 [pid = 1180] [id = {795737a9-4b3e-4308-8882-753efa59215e}]
[task 2017-10-26T13:45:42.462Z] 13:45:42     INFO - --DOCSHELL 0x7f2004a53000 == 6 [pid = 1180] [id = {1610f396-c1ee-4e8e-837c-13dcaf4845ac}]
[task 2017-10-26T13:45:42.462Z] 13:45:42     INFO - --DOCSHELL 0x7f2001f98000 == 5 [pid = 1180] [id = {c3d0e888-ca34-43a2-a2f1-557894ee1fe3}]
[task 2017-10-26T13:45:42.463Z] 13:45:42     INFO - --DOCSHELL 0x7f1fefa40000 == 4 [pid = 1180] [id = {cc0b244f-3ef5-4c73-8327-f43d7aca7965}]
[task 2017-10-26T13:45:42.463Z] 13:45:42     INFO - --DOCSHELL 0x7f2002422000 == 3 [pid = 1180] [id = {ccce95d5-fcb9-4f4d-a317-c553deea5f01}]
[task 2017-10-26T13:45:42.463Z] 13:45:42     INFO - --DOCSHELL 0x7f20099ae000 == 2 [pid = 1180] [id = {c5f2aa3a-2d25-4408-867a-c7231c946ffa}]
[task 2017-10-26T13:45:42.498Z] 13:45:42     INFO - JavaScript error: chrome://reftest/content/reftest.jsm, line 1502: NS_ERROR_NOT_AVAILABLE: Component returned failure code: 0x80040111 (NS_ERROR_NOT_AVAILABLE) [nsIPropertyBag2.getPropertyAsAString]
[task 2017-10-26T13:45:42.499Z] 13:45:42     INFO - [Child 1313, Main Thread] WARNING: NS_ENSURE_TRUE(maybeContext) failed: file /builds/worker/workspace/build/src/xpcom/threads/nsThread.cpp, line 795
[task 2017-10-26T13:45:42.501Z] 13:45:42     INFO - [Child 1313, Main Thread] WARNING: '!gThread', file /builds/worker/workspace/build/src/xpcom/threads/nsTimerImpl.cpp, line 399
[task 2017-10-26T13:45:42.623Z] 13:45:42     INFO - [Child 1313, Main Thread] WARNING: '!gThread', file /builds/worker/workspace/build/src/xpcom/threads/nsTimerImpl.cpp, line 399
[task 2017-10-26T13:45:42.623Z] 13:45:42     INFO - [Child 1313, Main Thread] WARNING: '!gThread', file /builds/worker/workspace/build/src/xpcom/threads/nsTimerImpl.cpp, line 399
[task 2017-10-26T13:45:42.659Z] 13:45:42     INFO - [Child 1313, Main Thread] WARNING: '!gThread', file /builds/worker/workspace/build/src/xpcom/threads/nsTimerImpl.cpp, line 399
[task 2017-10-26T13:45:42.667Z] 13:45:42     INFO - Assertion failure: mAudioContextOperation == AudioContextOperation::Close (We should be reviving the graph?), at /builds/worker/workspace/build/src/dom/media/MediaStreamGraph.cpp:4051
[task 2017-10-26T13:46:03.099Z] 13:46:03     INFO - #01: mozilla::MediaStreamGraphImpl::RunInStableState [dom/media/MediaStreamGraph.cpp:1820]
[task 2017-10-26T13:46:03.101Z] 13:46:03     INFO - 
[task 2017-10-26T13:46:03.102Z] 13:46:03     INFO - #02: MediaStreamGraphStableStateRunnable::Run [dom/media/MediaStreamGraph.cpp:1643]
[task 2017-10-26T13:46:03.104Z] 13:46:03     INFO - 
[task 2017-10-26T13:46:03.105Z] 13:46:03     INFO - #03: mozilla::EventTargetWrapper::Runner::Run [xpcom/threads/AbstractThread.cpp:156]
[task 2017-10-26T13:46:03.107Z] 13:46:03     INFO - 
[task 2017-10-26T13:46:03.108Z] 13:46:03     INFO - #04: mozilla::SchedulerGroup::Runnable::Run [xpcom/threads/SchedulerGroup.cpp:396]
[task 2017-10-26T13:46:03.109Z] 13:46:03     INFO - 
[task 2017-10-26T13:46:03.111Z] 13:46:03     INFO - #05: nsThread::ProcessNextEvent [mfbt/Maybe.h:445]
[task 2017-10-26T13:46:03.112Z] 13:46:03     INFO - 
[task 2017-10-26T13:46:03.113Z] 13:46:03     INFO - #06: NS_InvokeByIndex
[task 2017-10-26T13:46:03.114Z] 13:46:03     INFO - 
[task 2017-10-26T13:46:03.116Z] 13:46:03     INFO - #07: CallMethodHelper::Call [js/xpconnect/src/xpcprivate.h:766]
[task 2017-10-26T13:46:03.117Z] 13:46:03     INFO - 
[task 2017-10-26T13:46:03.118Z] 13:46:03     INFO - #08: XPCWrappedNative::CallMethod [js/xpconnect/src/XPCWrappedNative.cpp:1282]
[task 2017-10-26T13:46:03.119Z] 13:46:03     INFO - 
[task 2017-10-26T13:46:03.120Z] 13:46:03     INFO - #09: XPC_WN_CallMethod [js/xpconnect/src/XPCWrappedNativeJSOps.cpp:929]
[task 2017-10-26T13:46:03.121Z] 13:46:03     INFO - 
[task 2017-10-26T13:46:03.122Z] 13:46:03     INFO - #10: ??? (???:???)

Comment 1

[Intermittent Failures Robot]

6 failures in 912 pushes (0.007 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* mozilla-inbound: 6

Platform breakdown:
* linux64: 6

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1412231&startday=2017-10-23&endday=2017-10-29&tree=all

Comment 2

[Paul Adenot (:padenot)]

We probably just want to relax this assert to allow this during force-shutdown (i.e. browser shutdown or tab close or whatnot).

Comment 3

[Paul Adenot (:padenot)]

(In reply to Paul Adenot (:padenot) from comment #2)
> We probably just want to relax this assert to allow this during
> force-shutdown (i.e. browser shutdown or tab close or whatnot).

Not tab close, just browser shutdown.

Comment 4

[Paul Adenot (:padenot)]

Attachment: Bug 1412231 - Don't crash when running AudioContext operation messages that are not Closed during a force-shutdown.

Review commit: https://reviewboard.mozilla.org/r/194528/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/194528/

Comment 5

[Karl Tomlinson (:karlt)]

Comment on attachment 8923323 [details]
Bug 1412231 - Don't crash when running AudioContext operation messages that are not Closed during a force-shutdown.

https://reviewboard.mozilla.org/r/194528/#review199812

::: dom/media/MediaStreamGraph.cpp:4048
(Diff revision 1)
>      void RunDuringShutdown() override
>      {
> -      MOZ_ASSERT(mAudioContextOperation == AudioContextOperation::Close,
> +      MOZ_ASSERT(mAudioContextOperation == AudioContextOperation::Close ||
> +                 mStream->GraphImpl()->mForceShutDown,
>                   "We should be reviving the graph?");

I'm not clear what the purpose of this assert is.
What is it ensuring that doesn't happen?
Is there value in keeping the RunDuringShutdown() method?
If so, could you add a comment to explain, please?

RunDuringShutdown() is called on controlMessagesToRunDuringShutdown which
contains messages only when (mForceShutDown || !mRealtime).

ApplyAudioContextOperation() is called only for realtime contexts.

So this assert would also be satisfied even if it merely asserted
mStream->GraphImpl()->mForceShutDown.

If there were a Close operation when !mForceShutDown, then RunDuringShutdown()
would not be called.

If this is for the sake of future offline operations, then I'd guess that all
current operations (not just Close) would be possible at the completion of processing.

I don't see anything that an operation must do even when the graph is shutting
down.

Comment 6

[Firefox Bug Husbandry Bot]

https://wiki.mozilla.org/Bugmasters#Intermittent_Test_Failure_Cleanup

Comment 7

[Andreas Pehrson [:pehrsons]]

Paul, could you follow through with this? See bug 1468949 for info on reproducing.

Comment 9

[Firefox Bug Husbandry Bot]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup

Comment 10

[Cosmin Sabou [:CosminS]]

https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=222834821&repo=autoland&lineNumber=3242

Comment 11

[Intermittent Failures Robot]

1 failures in 2378 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform breakdown:

• linux64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1412231&startday=2019-01-14&endday=2019-01-20&tree=all

Comment 12

[Paul Adenot (:padenot)]

Alastor, this happened again on your push.

Comment 13

[Alastor Wu [:alwu]]

OK, will take a look later, keep NI.

Comment 14

[Alastor Wu [:alwu]]

Attachment: Bug 1412231 - do not suspend/resume the AudioContext after the shutdown.

Comment 15

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/a3e58d6c6488
do not suspend/resume the AudioContext after the shutdown. r=padenot

Comment 16

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

https://hg.mozilla.org/mozilla-central/rev/a3e58d6c6488