Investigate browser chrome shutdown hang occurring when AudioIPC is enabled
Categories
(Core :: Audio/Video: cubeb, defect, P2)
Tracking
()
People
(Reporter: kinetik, Assigned: kinetik)
References
Details
Attachments
(1 file)
The Windows debug mochitest-browser-chrome-e10s task that runs toolkit/content/tests/browser/browser.ini consistently hangs on shutdown on Try when media.cubeb.sandbox=true, but runs fine locally.
MOZ_CRASH doesn't generate a stack in this case, so I'm not sure where shutdown is stuck. I've attempted a fair bit of debugging via logging on Try, but as far as I can tell AudioIPC is cleanly shutdown (audioipc_server_stop returns, and logging in audioipc/src/core.rs shows the CoreThreads exit) >60s before the MOZ_CRASH occurs.
For bug 1590249, media.cubeb.sandbox=false was added to toolkit/content/tests/browser/browser.ini. This bug covers investigating the cause and removing this workaround.
Assignee | ||
Updated•4 years ago
|
Assignee | ||
Comment 1•4 years ago
|
||
Example failure (with much debug logging): https://treeherder.mozilla.org/logviewer.html#?job_id=285712666&repo=try
[task 2020-01-21T03:17:02.852Z] 03:17:02 INFO - GECKO(4716) | [2020-01-21T03:17:02Z DEBUG audioipc_server] audioipc_server_stop
[task 2020-01-21T03:17:02.852Z] 03:17:02 INFO - GECKO(4716) | [2020-01-21T03:17:02Z DEBUG audioipc_server] Dropping ServerWrapper... core
[task 2020-01-21T03:17:02.852Z] 03:17:02 INFO - GECKO(4716) | [2020-01-21T03:17:02Z DEBUG audioipc::core] Shutting down CoreThread("AudioIPC Server RPC", Handle(Handle { shut_down: false }))
[task 2020-01-21T03:17:02.852Z] 03:17:02 INFO - GECKO(4716) | [2020-01-21T03:17:02Z DEBUG audioipc::core] shutdown channel cancelled=false
[task 2020-01-21T03:17:02.852Z] 03:17:02 INFO - GECKO(4716) | [2020-01-21T03:17:02Z DEBUG audioipc::core] joining thread (no join) 'AudioIPC Server RPC' ThreadId(9)
[task 2020-01-21T03:17:02.852Z] 03:17:02 INFO - GECKO(4716) | [2020-01-21T03:17:02Z DEBUG audioipc::core] Shut down CoreThread("AudioIPC Server RPC", Handle(Handle { shut_down: false }))
[task 2020-01-21T03:17:02.852Z] 03:17:02 INFO - GECKO(4716) | [2020-01-21T03:17:02Z DEBUG audioipc_server] Dropping ServerWrapper... callback
[task 2020-01-21T03:17:02.852Z] 03:17:02 INFO - GECKO(4716) | [2020-01-21T03:17:02Z DEBUG audioipc::core] Shutting down CoreThread("AudioIPC Callback RPC", Handle(Handle { shut_down: false }))
[task 2020-01-21T03:17:02.852Z] 03:17:02 INFO - GECKO(4716) | [2020-01-21T03:17:02Z DEBUG audioipc::core] shutdown channel cancelled=false
[task 2020-01-21T03:17:02.853Z] 03:17:02 INFO - GECKO(4716) | [2020-01-21T03:17:02Z DEBUG audioipc::core] joining thread (no join) 'AudioIPC Callback RPC' ThreadId(7)
[task 2020-01-21T03:17:02.853Z] 03:17:02 INFO - GECKO(4716) | [2020-01-21T03:17:02Z DEBUG audioipc::core] Shut down CoreThread("AudioIPC Callback RPC", Handle(Handle { shut_down: false }))
[task 2020-01-21T03:17:02.853Z] 03:17:02 INFO - GECKO(4716) | [2020-01-21T03:17:02Z DEBUG audioipc_server] Dropped ServerWrapper
[task 2020-01-21T03:17:02.853Z] 03:17:02 INFO - GECKO(4716) | [2020-01-21T03:17:02Z DEBUG audioipc_server] audioipc_server_stop done
[task 2020-01-21T03:17:02.853Z] 03:17:02 INFO - GECKO(4716) | [2020-01-21T03:17:02Z DEBUG audioipc::core] thread shutdown... Runtime { reactor_handle: Handle, timer_handle: Handle { inner: Some(HandlePriv) }, clock: Clock { now: "None" }, executor: CurrentThread { scheduler: Scheduler { ... }, num_futures: 0 } } r=Ok(())
[task 2020-01-21T03:17:02.853Z] 03:17:02 INFO - GECKO(4716) | [2020-01-21T03:17:02Z DEBUG audioipc::core] thread shutdown... Runtime { reactor_handle: Handle, timer_handle: Handle { inner: Some(HandlePriv) }, clock: Clock { now: "None" }, executor: CurrentThread { scheduler: Scheduler { ... }, num_futures: 0 } } r=Ok(())
[task 2020-01-21T03:17:02.853Z] 03:17:02 INFO - GECKO(4716) | [2020-01-21T03:17:02Z DEBUG audioipc::core] thread shutdown done
[task 2020-01-21T03:17:02.853Z] 03:17:02 INFO - GECKO(4716) | [2020-01-21T03:17:02Z DEBUG audioipc::core] thread shutdown done
[task 2020-01-21T03:18:05.411Z] 03:18:05 INFO - GECKO(4716) | XPCOM_MEM_BLOAT_LOG: c:\users\task_1579571824\appdata\local\temp\tmp8yfkqs.mozrunner\runtests_leaks.log
[task 2020-01-21T03:18:05.411Z] 03:18:05 INFO - GECKO(4716) | Writing to log: c:\users\task_1579571824\appdata\local\temp\tmp8yfkqs.mozrunner\runtests_leaks.log
[task 2020-01-21T03:18:05.411Z] 03:18:05 INFO - GECKO(4716) | Hit MOZ_CRASH(Shutdown too long, probably frozen, causing a crash.) at z:/build/build/src/toolkit/components/terminator/nsTerminator.cpp:216
Assignee | ||
Comment 2•3 years ago
|
||
The shutdown hang seems to have disappeared. Not sure if this is due a fix in AudioIPC or changes elsewhere in shutdown behaviour. A fresh Try push with AudioIPC enabled looks clear, any orange in the mochitest-browser-chrome-e10s seems to be unrelated/already known.
Assignee | ||
Comment 3•3 years ago
|
||
Pushed by mgregan@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/0a79007d32ff Reenable AudioIPC in browser chrome tests. r=cubeb-reviewers,chunmin
Comment 5•3 years ago
|
||
bugherder |
Updated•3 years ago
|
Description
•