Closed Bug 1598117 Opened 4 years ago Closed 4 years ago

Enable GraphRunner by default

Categories

(Core :: Audio/Video: MediaStreamGraph, task, P2)

65 Branch
task

Tracking

()

RESOLVED FIXED
mozilla73
Tracking Status
firefox73 --- fixed

People

(Reporter: karlt, Assigned: karlt)

References

Details

Attachments

(1 file)

+++ This bug was initially created as a clone of Bug #1551855 +++

We want to be able to enable GraphRunner by default before enabling audio worklets by default, to be sure it's working as intended, and to distinguish any issues from audio worklet-specific ones.

Is there anything we need before doing this?

IIUC we don't have the full benefit of the priority enhancement from bug 1429847 until we have AudioIPC everywhere (bug 1362220), but the benefit from bumping GraphRunner priority may be sufficient to use GraphRunner now.

Perhaps we can toggle this pref early in 73. i.e. after 2019-12-02

A bit of audio callback tracing would be good to see that we're not regressing much. Otherwise I'm not aware of anything.

When following the link, be aware that we have s/MSGTracing/AudioCallbackTracing/ now.

Assignee: nobody → karlt
Status: NEW → ASSIGNED
Pushed by ktomlinson@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/4e8f478cc40d
enable GraphRunner by default r=pehrsons

Backed out changeset 4e8f478cc40d (Bug 1598117) for mda failures at src/dom/media/GraphDriver.cpp

Backout: https://hg.mozilla.org/integration/autoland/rev/da5e21f20361766f4cf9d8c732a96619c375574b

Failure push: https://treeherder.mozilla.org/#/jobs?repo=autoland&revision=4e8f478cc40dc6fbc84f67ee013e61f09c8a1a7e

Failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=279226068&repo=autoland&lineNumber=42826

[task 2019-12-03T02:01:24.198Z] 02:01:24 INFO - TEST-START | dom/media/webaudio/test/test_audioContextSuspendResumeClose.html
[task 2019-12-03T02:01:24.240Z] 02:01:24 INFO - GECKO(1843) | [Parent 1843, Main Thread] WARNING: we only accept nsIURI interface type, patch welcome: file /builds/worker/workspace/build/src/dom/ipc/PropertyBagUtils.cpp, line 112
[task 2019-12-03T02:01:24.509Z] 02:01:24 INFO - GECKO(1843) | [1848, MainThread] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file /builds/worker/workspace/build/src/xpcom/base/nsTraceRefcnt.cpp, line 198
[task 2019-12-03T02:01:24.509Z] 02:01:24 INFO - GECKO(1843) | [1848, MainThread] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file /builds/worker/workspace/build/src/xpcom/base/nsTraceRefcnt.cpp, line 198
[task 2019-12-03T02:01:24.509Z] 02:01:24 INFO - GECKO(1843) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /var/folders/bl/ctlr2b4x6015gys3ldlbtyx8000017/T/tmp26sRF0.mozrunner/runtests_leaks_rdd_pid1848.log
[task 2019-12-03T02:01:24.510Z] 02:01:24 INFO - GECKO(1843) | [1848, MainThread] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file /builds/worker/workspace/build/src/xpcom/base/nsTraceRefcnt.cpp, line 198
[task 2019-12-03T02:01:24.510Z] 02:01:24 INFO - GECKO(1843) | [1848, MainThread] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file /builds/worker/workspace/build/src/xpcom/base/nsTraceRefcnt.cpp, line 198
[task 2019-12-03T02:01:24.594Z] 02:01:24 INFO - GECKO(1843) | _RegisterApplication(), FAILED TO establish the default connection to the WindowServer, _CGSDefaultConnection() is NULL.
[task 2019-12-03T02:01:27.031Z] 02:01:27 INFO - GECKO(1843) | [2019-12-03T02:01:26Z WARN audio_thread_priority::rt_mach] thread 54543 priority restored.
[task 2019-12-03T02:01:27.031Z] 02:01:27 INFO - GECKO(1843) | [2019-12-03T02:01:26Z WARN audio_thread_priority::rt_mach] thread 55567 priority restored.
[task 2019-12-03T02:01:27.148Z] 02:01:27 INFO - GECKO(1843) | Assertion failure: !OnGraphThread(), at /builds/worker/workspace/build/src/dom/media/GraphDriver.cpp:971
[task 2019-12-03T02:01:51.481Z] 02:01:51 INFO - GECKO(1843) | #01: <cubeb_coreaudio::backend::AudioUnitStream as cubeb_backend::traits::StreamOps>::stop [media/libcubeb/cubeb-coreaudio-rs/src/backend/mod.rs:3437]
[task 2019-12-03T02:01:51.481Z] 02:01:51 INFO -
[task 2019-12-03T02:01:51.481Z] 02:01:51 INFO - GECKO(1843) | #02: cubeb_backend::capi::capi_stream_stop [third_party/rust/cubeb-backend/src/capi.rs:186]
[task 2019-12-03T02:01:51.481Z] 02:01:51 INFO -
[task 2019-12-03T02:01:51.481Z] 02:01:51 INFO - GECKO(1843) | #03: mozilla::AudioCallbackDriver::Stop() [dom/media/GraphDriver.cpp:713]
[task 2019-12-03T02:01:51.481Z] 02:01:51 INFO -
[task 2019-12-03T02:01:51.481Z] 02:01:51 INFO - GECKO(1843) | #04: mozilla::AsyncCubebTask::Run() [dom/media/GraphDriver.cpp:435]
[task 2019-12-03T02:01:51.481Z] 02:01:51 INFO -
[task 2019-12-03T02:01:51.481Z] 02:01:51 INFO - GECKO(1843) | #05: nsThreadSyncDispatch::Run() [xpcom/threads/nsThreadSyncDispatch.h:36]
[task 2019-12-03T02:01:51.482Z] 02:01:51 INFO -
[task 2019-12-03T02:01:51.482Z] 02:01:51 INFO - GECKO(1843) | #06: nsThreadPool::Run() [xpcom/threads/nsThreadPool.cpp:306]
[task 2019-12-03T02:01:51.482Z] 02:01:51 INFO -
[task 2019-12-03T02:01:51.482Z] 02:01:51 INFO - GECKO(1843) | #07: non-virtual thunk to nsThreadPool::Run() [xpcom/threads/nsThreadPool.cpp:0]
[task 2019-12-03T02:01:51.482Z] 02:01:51 INFO -
[task 2019-12-03T02:01:51.482Z] 02:01:51 INFO - GECKO(1843) | #08: nsThread::ProcessNextEvent(bool, bool*) [mfbt/RefPtr.h:306]
[task 2019-12-03T02:01:51.482Z] 02:01:51 INFO -
[task 2019-12-03T02:01:51.482Z] 02:01:51 INFO - GECKO(1843) | #09: NS_ProcessNextEvent(nsIThread*, bool) [xpcom/threads/nsThreadUtils.cpp:486]
[task 2019-12-03T02:01:51.482Z] 02:01:51 INFO -
[task 2019-12-03T02:01:51.482Z] 02:01:51 INFO - GECKO(1843) | #10: mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate*) [ipc/glue/MessagePump.cpp:333]
[task 2019-12-03T02:01:51.482Z] 02:01:51 INFO -
[task 2019-12-03T02:01:51.482Z] 02:01:51 INFO - GECKO(1843) | #11: MessageLoop::Run() [ipc/chromium/src/base/message_loop.cc:291]
[task 2019-12-03T02:01:51.482Z] 02:01:51 INFO -
[task 2019-12-03T02:01:51.482Z] 02:01:51 INFO - GECKO(1843) | #12: nsThread::ThreadFunc(void*) [xpcom/threads/nsThread.cpp:460]
[task 2019-12-03T02:01:51.483Z] 02:01:51 INFO -
[task 2019-12-03T02:01:52.018Z] 02:01:52 INFO - GECKO(1843) | #13: _pt_root [nsprpub/pr/src/pthreads/ptthread.c:204]
[task 2019-12-03T02:01:52.018Z] 02:01:52 INFO -
[task 2019-12-03T02:01:52.018Z] 02:01:52 INFO - GECKO(1843) | #14: libsystem_pthread.dylib + 0x32eb

Flags: needinfo?(karlt)

Alex, do you know whether AudioOutputUnitStop() waits for the processing graph to stop before it returns?

Flags: needinfo?(karlt)
Flags: needinfo?(achronop)

Are we getting a StateCallback while we're in a DataCallback?

This is from a sync dispatch. The only one we have is https://searchfox.org/mozilla-central/rev/04d8e7629354bab9e6a285183e763410860c5006/dom/media/MediaTrackGraph.cpp#1508

We know the graph has stopped if we get there, since it's in LIFECYCLE_WAITING_FOR_MAIN_THREAD_CLEANUP.

There must be a bug somewhere, I'd guess either with the lifecycle state (unlikely), stopping cubeb as expected when returning aFrames - 1 from DataCallback (so it runs another when it shouldn't) (unlikely), or something related to thread ids or how the GraphRunner checks them. I haven't found anything that stands out..

Depends on: 1599922

One possible scenario is that in [1] both GraphRunner::mAudioDriverThreadId == AudioCallbackDriver::mAudioThreadId == std::thread::id() from [2] and [3], which can happen during shutdown (after GraphRunner::Shutdown()).

[1] https://searchfox.org/mozilla-central/rev/04d8e7629354bab9e6a285183e763410860c5006/dom/media/GraphRunner.cpp#133
[2] https://searchfox.org/mozilla-central/rev/04d8e7629354bab9e6a285183e763410860c5006/dom/media/GraphRunner.cpp#87
[3] https://searchfox.org/mozilla-central/rev/04d8e7629354bab9e6a285183e763410860c5006/dom/media/GraphDriver.cpp#791

I was about to post the below, but maybe Alex is onto something.

The question is how we'd get past OnThread() when the thread is shut down and all. Perhaps that's the bug.


It seems unlikely but the only gap I see is if the driver calls SignalMainThreadCleanup and then gets switched out such that the stable state runnable runs on main thread; and the shutdown runnable runs on main thread; and AudioCallbackDriver::Shutdown's cubeb shutdown task runs on the CubebOperation thread, all before the DataCallback gets switched back in again.

With all that thread hopping that seems very unlikely.

But there's some evidence, without much history, that there has been some similar problem in the past: https://hg.mozilla.org/mozilla-central/rev/509e62e4bc1a#l3.16 What happens if you enable that assert? Perhaps checking GraphDriver::ThreadRunning() instead, it should be guaranteed false here, as it's set before SignalMainThreadCleanup.

Perhaps there's another failure mode with similar symptoms that we're missing.

Thank you Alex and Andreas :)

(In reply to Andreas Pehrson [:pehrsons] from comment #10)

I was about to post the below, but maybe Alex is onto something.

The question is how we'd get past OnThread() when the thread is shut down and all. Perhaps that's the bug.

Yes. See bug 1599922.

Pushed by ktomlinson@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/a15b23029889
enable GraphRunner by default r=pehrsons
Status: ASSIGNED → RESOLVED
Closed: 4 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla73
Regressions: 1605033
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: