Filed by: nfay [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=356960136&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/TxlbGmlrRo-ofY0Blo-LYQ/runs/0/artifacts/public/logs/live_backing.log
[task 2021-11-04T09:04:32.005Z] 09:04:32 INFO - TEST-START | Shutdown
[task 2021-11-04T09:04:32.005Z] 09:04:32 INFO - Passed: 269
[task 2021-11-04T09:04:32.006Z] 09:04:32 INFO - Failed: 0
[task 2021-11-04T09:04:32.007Z] 09:04:32 INFO - Todo: 0
[task 2021-11-04T09:04:32.007Z] 09:04:32 INFO - Mode: e10s
[task 2021-11-04T09:04:32.008Z] 09:04:32 INFO - Slowest: 1183ms - /tests/dom/tests/mochitest/sessionstorage/test_sessionStorageBase.html
[task 2021-11-04T09:04:32.009Z] 09:04:32 INFO - SimpleTest FINISHED
[task 2021-11-04T09:04:32.009Z] 09:04:32 INFO - TEST-INFO | Ran 1 Loops
[task 2021-11-04T09:04:32.010Z] 09:04:32 INFO - SimpleTest FINISHED
[task 2021-11-04T09:04:32.066Z] 09:04:32 INFO - GECKO(9064) | JavaScript error: resource://gre/modules/AsyncShutdown.jsm, line 575: NotFoundError: No such JSWindowActor 'SpecialPowers'
[task 2021-11-04T09:04:32.115Z] 09:04:32 INFO - GECKO(9064) | 1636016672114 Marionette TRACE Received observer notification quit-application
[task 2021-11-04T09:04:32.115Z] 09:04:32 INFO - GECKO(9064) | 1636016672114 Marionette INFO Stopped listening on port 2828
[task 2021-11-04T09:04:32.115Z] 09:04:32 INFO - GECKO(9064) | 1636016672114 Marionette DEBUG Marionette stopped listening
[task 2021-11-04T09:04:32.143Z] 09:04:32 INFO - GECKO(9064) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-11-04T09:04:32.168Z] 09:04:32 INFO - GECKO(9064) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-11-04T09:04:32.175Z] 09:04:32 INFO - GECKO(9064) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-11-04T09:04:33.422Z] 09:04:33 INFO - GECKO(9064) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-11-04T09:04:33.422Z] 09:04:33 INFO - GECKO(9064) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-11-04T09:04:33.427Z] 09:04:33 INFO - GECKO(9064) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-11-04T09:04:33.428Z] 09:04:33 INFO - GECKO(9064) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-11-04T09:04:33.428Z] 09:04:33 INFO - GECKO(9064) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-11-04T09:04:33.429Z] 09:04:33 INFO - GECKO(9064) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-11-04T09:04:33.429Z] 09:04:33 INFO - GECKO(9064) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-11-04T09:05:38.897Z] 09:05:38 INFO - GECKO(9064) | WARNING: At least one completion condition is taking too long to complete. Conditions: [{"name":"Places Connection shutdown","state":{"PlacesShutdownProgress":5},"filename":"Z:/task_163600244221201/build/src/toolkit/components/places/Database.cpp","lineNumber":467,"stack":["resource://gre/modules/nsAsyncShutdown.jsm:addBlocker:162","resource://gre/modules/XPCOMUtils.jsm:XPCU_serviceLambda:161","resource://gre/modules/XPCOMUtils.jsm:get:62","resource:///modules/BrowserGlue.jsm:BG__onFirstWindowLoaded:1681","resource:///modules/BrowserGlue.jsm:BG_observe:997","chrome://browser/content/browser.js:_delayedStartup:2119"]}] Barrier: profile-before-change
[task 2021-11-04T09:05:38.905Z] 09:05:38 INFO - GECKO(9064) | console.error: (new Error("SessionFile is closed", "resource:///modules/sessionstore/SessionFile.jsm", 446))
[task 2021-11-04T09:05:38.906Z] 09:05:38 INFO - GECKO(9064) | JavaScript error: resource://gre/modules/CrashManager.jsm, line 828: AbortError: IOUtils: Shutting down and refusing additional I/O tasks
[task 2021-11-04T09:05:38.908Z] 09:05:38 INFO - GECKO(9064) | FATAL ERROR: AsyncShutdown timeout in profile-before-change Conditions: [{"name":"Places Connection shutdown","state":{"PlacesShutdownProgress":5},"filename":"Z:/task_163600244221201/build/src/toolkit/components/places/Database.cpp","lineNumber":467,"stack":["resource://gre/modules/nsAsyncShutdown.jsm:addBlocker:162","resource://gre/modules/XPCOMUtils.jsm:XPCU_serviceLambda:161","resource://gre/modules/XPCOMUtils.jsm:get:62","resource:///modules/BrowserGlue.jsm:BG__onFirstWindowLoaded:1681","resource:///modules/BrowserGlue.jsm:BG_observe:997","chrome://browser/content/browser.js:_delayedStartup:2119"]}] 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.
[task 2021-11-04T09:05:38.908Z] 09:05:38 INFO - GECKO(9064) | [Parent 8888, Main Thread] ###!!! ABORT: file Z:/task_163600244221201/build/src/toolkit/components/places/Database.cpp:467
[task 2021-11-04T09:05:38.909Z] 09:05:38 INFO - GECKO(9064) | RunWatchdog: Mainthread nested event loops during hang:
[task 2021-11-04T09:05:38.909Z] 09:05:38 INFO - GECKO(9064) | --- nsThread::Shutdown: mozStorage #2
[task 2021-11-04T09:05:39.032Z] 09:05:39 INFO - TEST-INFO | Main app process: exit 80000003
[task 2021-11-04T09:05:39.034Z] 09:05:39 INFO - Buffered messages finished
[task 2021-11-04T09:05:39.035Z] 09:05:39 ERROR - TEST-UNEXPECTED-FAIL | Last test finished | application terminated with exit code 2147483651
[task 2021-11-04T09:05:39.035Z] 09:05:39 INFO - runtests.py | Application ran for: 0:01:20.101647
[task 2021-11-04T09:05:39.036Z] 09:05:39 INFO - zombiecheck | Reading PID log: C:\Users\task_163601471013814\AppData\Local\Temp\tmpdp3xk22wpidlog
[task 2021-11-04T09:05:39.037Z] 09:05:39 INFO - ==> process 8888 launched child process 1884 ("Z:\task_163601471013814\build\application\firefox\firefox.exe" -contentproc --channel="8888.0.239343270\114419693" -parentBuildID 20211104045127 -prefsHandle 2196 -prefMapHandle 2188 -prefsLen 1 -prefMapSize 252504 -appDir "Z:\task_163601471013814\build\application\firefox\browser" - 8888 "\\.\pipe\gecko-crash-server-pipe.8888" 2268 202ea463438 gpu)
<...>
[task 2021-11-04T09:05:48.644Z] 09:05:48 INFO - GECKO(7952) | 1636016748643 Marionette DEBUG 1 <- [1,6,null,{"value":null}]
[task 2021-11-04T09:05:48.657Z] 09:05:48 INFO - GECKO(7952) | 1636016748658 Marionette DEBUG 1 -> [0,7,"Marionette:SetContext",{"value":"content"}]
[task 2021-11-04T09:05:48.659Z] 09:05:48 INFO - GECKO(7952) | 1636016748659 Marionette DEBUG 1 <- [1,7,null,{"value":null}]
[task 2021-11-04T09:05:48.668Z] 09:05:48 INFO - GECKO(7952) | 1636016748667 Marionette DEBUG 1 -> [0,8,"WebDriver:DeleteSession",{}]
[task 2021-11-04T09:05:48.671Z] 09:05:48 INFO - GECKO(7952) | 1636016748671 Marionette DEBUG 1 <- [1,8,null,{"value":null}]
[task 2021-11-04T09:05:48.673Z] 09:05:48 INFO - runtests.py | Waiting for browser...
[task 2021-11-04T09:05:48.674Z] 09:05:48 INFO - GECKO(7952) | 1636016748674 Marionette DEBUG Closed connection 1
[task 2021-11-04T09:05:49.007Z] 09:05:49 INFO - SimpleTest START
[task 2021-11-04T09:05:49.022Z] 09:05:49 INFO - Dumping test context:
[task 2021-11-04T09:05:49.022Z] 09:05:49 INFO - fission.autostart=false
[task 2021-11-04T09:05:49.024Z] 09:05:49 INFO - TEST-START | dom/webauthn/tests/test_webauthn_isexternalctap2securitykeysupported.html
Description
•