Open Bug 1476870 Opened 6 years ago Updated 3 days ago

Intermittent FATAL ERROR: AsyncShutdown timeout in xpcom-will-shutdown Conditions: [{"name":"GeckoMediaPluginServiceParent: shutdown","state":"(none)","filename":"z:/build/build/src/dom/media/gmp/GMPServiceParent.cpp","lineNumber":1657

Categories

(Core :: Audio/Video: GMP, defect, P5)

Product:
Core
Component:
Audio/Video: GMP
Type:
defect

Tracking

()

Status:
REOPENED

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: intermittent-failure, Whiteboard: [stockwell unknown]) 

Filed by: ebalazs [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=188867964&repo=autoland

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

INFO -  GECKO(3828) | FATAL ERROR: AsyncShutdown timeout in xpcom-will-shutdown Conditions: [{"name":"GeckoMediaPluginServiceParent: shutdown","state":"(none)","filename":"z:/build/build/src/dom/media/gmp/GMPServiceParent.cpp","lineNumber":1657,"stack":"GeckoMediaPluginServiceParent shutdown"}] At least one completion condition failed to complete within a reasonable amount of time. Causing a crash to ensure that we do not leave the user with an unresponsive process draining resources.
03:15:56     INFO -  GECKO(3828) | WARNING: No crash reporter available
03:15:56     INFO -  GECKO(3828) | [Parent 3828, Main Thread] ###!!! ABORT: file z:/build/build/src/dom/media/gmp/GMPServiceParent.cpp, line 1657
03:15:57     INFO -  TEST-INFO | Main app process: exit 80000003
03:15:57     INFO -  Buffered messages finished
03:15:57    ERROR -  961 ERROR TEST-UNEXPECTED-FAIL | Last test finished | application terminated with exit code 2147483651
Component: Audio/Video → Audio/Video: GMP

There are 36 total failures in the last 7 days. Most of them are occurring on windows10-64 asan. osx-10-10 debug, linux64 asan, windows10-64-qr debug are also affected.

Failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=241678205&repo=mozilla-inbound&lineNumber=6659

08:54:04 INFO - TEST-START | toolkit/components/normandy/test/browser/browser_actions_ShowHeartbeatAction.js
08:57:12 ERROR - TEST-UNEXPECTED-FAIL | Last test finished | application terminated with exit code 2147483651
08:57:12 INFO - runtests.py | Application ran for: 0:03:37.620000
08:57:12 INFO - zombiecheck | Reading PID log: c:\users\task_1555833439\appdata\local\temp\tmpjfdk4bpidlog
08:57:12 INFO - ==> process 908 launched child process 9044 ("Z:\task_1555833439\build\application\firefox\firefox.exe" -contentproc --channel="908.0.1509904163\1032579244" -parentBuildID 20190421073505 -greomni "Z:\task_1555833439\build\application\firefox\omni.ja" -appomni "Z:\task_1555833439\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1555833439\build\application\firefox\browser" - 908 gpu)
08:57:12 INFO - ==> process 908 launched child process 3040 ("Z:\task_1555833439\build\application\firefox\firefox.exe" -contentproc --channel="908.6.1170443378\749360553" -childID 1 -isForBrowser -prefsHandle 2784 -prefMapHandle 2780 -prefsLen 1 -prefMapSize 197224 -parentBuildID 20190421073505 -greomni "Z:\task_1555833439\build\application\firefox\omni.ja" -appomni "Z:\task_1555833439\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1555833439\build\application\firefox\browser" - 908 tab)
08:57:12 INFO - ==> process 908 launched child process 5132 ("Z:\task_1555833439\build\application\firefox\firefox.exe" -contentproc --channel="908.13.786591052\621552267" -childID 2 -isForBrowser -prefsHandle 2960 -prefMapHandle 2816 -prefsLen 98 -prefMapSize 197224 -parentBuildID 20190421073505 -greomni "Z:\task_1555833439\build\application\firefox\omni.ja" -appomni "Z:\task_1555833439\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1555833439\build\application\firefox\browser" - 908 tab)
08:57:12 INFO - ==> process 908 launched child process 9308 ("Z:\task_1555833439\build\application\firefox\firefox.exe" -contentproc --channel="908.20.1309718342\1753484999" -childID 3 -isForBrowser -prefsHandle 3224 -prefMapHandle 3228 -prefsLen 159 -prefMapSize 197224 -parentBuildID 20190421073505 -greomni "Z:\task_1555833439\build\application\firefox\omni.ja" -appomni "Z:\task_1555833439\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1555833439\build\application\firefox\browser" - 908 tab)
08:57:12 INFO - ==> process 908 launched child process 5620 ("Z:\task_1555833439\build\application\firefox\firefox.exe" -contentproc --channel="908.27.34461888\472095627" -childID 4 -isForBrowser -prefsHandle 4368 -prefMapHandle 4372 -prefsLen 9327 -prefMapSize 197224 -parentBuildID 20190421073505 -greomni "Z:\task_1555833439\build\application\firefox\omni.ja" -appomni "Z:\task_1555833439\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1555833439\build\application\firefox\browser" - 908 tab)
08:57:12 INFO - ==> process 908 launched child process 10784 ("Z:\task_1555833439\build\application\firefox\firefox.exe" -contentproc --channel="908.34.1437151884\1189695979" -childID 5 -isForBrowser -prefsHandle 4220 -prefMapHandle 4368 -prefsLen 9407 -prefMapSize 197224 -parentBuildID 20190421073505 -greomni "Z:\task_1555833439\build\application\firefox\omni.ja" -appomni "Z:\task_1555833439\build\application\firefox\browser\omni.ja" -appdir "Z:\task_1555833439\build\application\firefox\browser" - 908 tab)
08:57:12 INFO - zombiecheck | Checking for orphan process with PID: 3040
08:57:12 INFO - zombiecheck | Checking for orphan process with PID: 10784
08:57:12 INFO - zombiecheck | Checking for orphan process with PID: 5132
08:57:12 INFO - zombiecheck | Checking for orphan process with PID: 9044
08:57:12 INFO - zombiecheck | Checking for orphan process with PID: 5620
08:57:12 INFO - zombiecheck | Checking for orphan process with PID: 9308
08:57:12 INFO - Stopping web server
08:57:12 INFO - Stopping web socket server
08:57:12 INFO - Stopping ssltunnel
08:57:12 WARNING - leakcheck | refcount logging is off, so leaks can't be detected!
08:57:12 INFO - runtests.py | Running tests: end.
08:57:12 INFO - Buffered messages finished
08:57:12 INFO - Running manifest: toolkit\components\pictureinpicture\tests\browser.ini
08:57:12 INFO - The following extra prefs will be set:
08:57:12 INFO - media.videocontrols.picture-in-picture.enabled=true
08:57:12 INFO - INFO | runtests.py | ASan using symbolizer at Z:\task_1555833439\build\application\firefox\llvm-symbolizer.exe
08:57:12 INFO - INFO | runtests.py | ASan running in default memory configuration
08:57:13 INFO - Z:\task_1555833439\build\tests\bin\pk12util.exe: PKCS12 IMPORT SUCCESSFUL
08:57:14 INFO - Increasing default timeout to 90 seconds
08:57:14 INFO - INFO | runtests.py | ASan using symbolizer at Z:\task_1555833439\build\application\firefox\llvm-symbolizer.exe
08:57:14 INFO - INFO | runtests.py | ASan running in default memory configuration
08:57:14 INFO - INFO | runtests.py | ASan using symbolizer at Z:\task_1555833439\build\application\firefox\llvm-symbolizer.exe
08:57:14 INFO - INFO | runtests.py | ASan running in default memory configuration
08:57:14 INFO - MochitestServer : launching [u'Z:\task_1555833439\build\tests\bin\xpcshell.exe', '-g', 'Z:\task_1555833439\build\application\firefox', '-f', 'Z:\task_1555833439\build\tests\bin\components\httpd.js', '-e', "const _PROFILE_PATH = 'c:\\users\\task_1555833439\\appdata\\local\\temp\\tmpqzckd1.mozrunner'; const _SERVER_PORT = '8888'; const _SERVER_ADDR = '127.0.0.1'; const _TEST_PREFIX = undefined; const _DISPLAY_RESULTS = false;", '-f', 'Z:\task_1555833439\build\tests\mochitest\server.js']
08:57:14 INFO - runtests.py | Server pid: 6548
08:57:14 INFO - runtests.py | Websocket server pid: 7676
08:57:14 INFO - INFO | runtests.py | ASan using symbolizer at Z:\task_1555833439\build\application\firefox\llvm-symbolizer.exe
08:57:14 INFO - INFO | runtests.py | ASan running in default memory configuration
08:57:14 INFO - runtests.py | SSL tunnel pid: 2052
08:57:14 INFO - runtests.py | Running with scheme: http
08:57:14 INFO - runtests.py | Running with e10s: True
08:57:14 INFO - runtests.py | Running with serviceworker_e10s: False
08:57:14 INFO - runtests.py | Running with socketprocess_e10s: False
08:57:14 INFO - runtests.py | Running tests: start.
08:57:14 INFO -
08:57:14 INFO - Application command: Z:\task_1555833439\build\application\firefox\firefox.exe -marionette --wait-for-browser -foreground -profile c:\users\task_1555833439\appdata\local\temp\tmpqzckd1.mozrunner
08:57:14 INFO - runtests.py | Application pid: 6840

Nils, could you please assign this to someone?

Flags: needinfo?(drno)
Whiteboard: [stockwell needswork:owner]
Summary: Intermittent GECKO(3828) | FATAL ERROR: AsyncShutdown timeout in xpcom-will-shutdown Conditions: [{"name":"GeckoMediaPluginServiceParent: shutdown","state":"(none)","filename":"z:/build/build/src/dom/media/gmp/GMPServiceParent.cpp","lineNumber":1657 → Intermittent FATAL ERROR: AsyncShutdown timeout in xpcom-will-shutdown Conditions: [{"name":"GeckoMediaPluginServiceParent: shutdown","state":"(none)","filename":"z:/build/build/src/dom/media/gmp/GMPServiceParent.cpp","lineNumber":1657

This shutdown hang is caused by GMP machinery blocking shutdown due to consumers still being live. It's probably pretty gnarly to track down what's causing this if it's not just test machines being slow. Assigning myself as I'm probably the best person to look at this if it becomes an issue again, but I don't think it warrants being looked at unless it is an issue.

Assignee: nobody → bvandyk
Flags: needinfo?(drno)

in Bug 1755075 we are splitting some of the mochitest media manifests- this makes it easier to see some failures and easier to run specific tests. This assertion/crash was showing up frequently, so disabling this on:
linux asan|debug

this should reduce the frequency a little bit.

Unassigning bugs assigned to Bryce because he no longer works at Mozilla.

Assignee: brycebugemail → nobody
Severity: normal → S3

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit BugBot documentation.

Status: NEW → RESOLVED
Closed: 10 months ago
Resolution: --- → INCOMPLETE

New failure instance: https://treeherder.mozilla.org/logviewer?job_id=421392380&repo=mozilla-beta

Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
See Also: → 1866742
You need to log in before you can comment on or make changes to this bug.