Closed Bug 1739343 Opened 4 years ago Closed 1 year ago

Intermittent 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",

Categories

(Toolkit :: Places, defect, P5)

defect

Tracking

()

RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure)

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

The Bugbug bot thinks this bug should belong to the 'Toolkit::Places' component, and is moving the bug to that component. Please revert this change in case you think the bot is wrong.

Component: General → Places
Product: Firefox → Toolkit
Status: NEW → RESOLVED
Closed: 4 years ago
Resolution: --- → INCOMPLETE
Status: REOPENED → RESOLVED
Closed: 4 years ago4 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Summary: Intermittent [tier 2] 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", → Intermittent 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",
Status: REOPENED → RESOLVED
Closed: 4 years ago3 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 3 years ago3 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 3 years ago3 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 3 years ago2 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 2 years ago2 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 2 years ago2 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 2 years ago2 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 2 years ago1 year ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 1 year ago1 year ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.