Closed Bug 1610640 Opened 4 years ago Closed 3 years ago

Investigate browser chrome shutdown hang occurring when AudioIPC is enabled

Categories

(Core :: Audio/Video: cubeb, defect, P2)

All
Windows
defect

Tracking

()

RESOLVED FIXED
87 Branch
Tracking Status
firefox74 --- wontfix
firefox87 --- fixed

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.

See Also: → 1590249
Summary: Investigate browser chrome shutdown hang occurring AudioIPC is enabled → Investigate browser chrome shutdown hang occurring when AudioIPC is enabled

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

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.

Pushed by mgregan@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/0a79007d32ff
Reenable AudioIPC in browser chrome tests.  r=cubeb-reviewers,chunmin
Status: ASSIGNED → RESOLVED
Closed: 3 years ago
Resolution: --- → FIXED
Target Milestone: --- → 87 Branch
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: