Closed
Bug 1060400
Opened 10 years ago
Closed 10 years ago
Intermittent browser_whitelist7.js | application crashed [@ mozalloc_abort(char const*)] after "AsyncShutdown timeout in AddonManager: Waiting for clients to shut down"
Categories
(Toolkit :: Add-ons Manager, defect)
Toolkit
Add-ons Manager
Tracking
()
RESOLVED
DUPLICATE
of bug 995027
People
(Reporter: RyanVM, Unassigned)
Details
(Keywords: assertion, crash, intermittent-failure)
https://tbpl.mozilla.org/php/getParsedLog.php?id=47030053&tree=Fx-Team Ubuntu VM 12.04 x64 fx-team pgo test mochitest-browser-chrome-3 on 2014-08-29 07:25:09 PDT for push ce756025b879 slave: tst-linux64-spot-360 07:54:13 INFO - 10970 INFO TEST-START | chrome://mochitests/content/browser/toolkit/mozapps/extensions/test/xpinstall/browser_whitelist7.js 07:54:14 INFO - 10971 INFO 1409324054034 addons.xpi DEBUG Cancelling download of http://example.com/browser/toolkit/mozapps/extensions/test/xpinstall/unsigned.xpi 07:54:14 INFO - 10972 INFO 1409324054036 addons.xpi DEBUG removeTemporaryFile: http://example.com/browser/toolkit/mozapps/extensions/test/xpinstall/unsigned.xpi does not own temp file 07:54:14 INFO - 10973 INFO ************************************************************ 07:54:14 INFO - 10974 INFO * Call to xpconnect wrapped JSObject produced this error: * 07:54:14 INFO - 10975 INFO [Exception... "[JavaScript Error: "installInfo.originatingURI is null" {file: "chrome://browser/content/browser.js" line: 265}]'[JavaScript Error: "installInfo.originatingURI is null" {file: "chrome://browser/content/browser.js" line: 265}]' when calling method: [nsIObserver::observe]" nsresult: "0x80570021 (NS_ERROR_XPC_JAVASCRIPT_ERROR_WITH_DETAILS)" location: "JS frame :: resource://gre/components/amWebInstallListener.js :: extWebInstallListener_onWebInstallBlocked :: line 302" data: yes] 07:54:14 INFO - 10976 INFO ************************************************************ 07:54:14 INFO - 10977 INFO TEST-OK | chrome://mochitests/content/browser/toolkit/mozapps/extensions/test/xpinstall/browser_whitelist7.js | took 135ms 07:54:18 INFO - 10978 INFO ###!!! [Parent][OnMaybeDequeueOne] Error: Channel closing: too late to send/recv, messages will be lost 07:54:18 INFO - 10979 INFO console.error: 07:54:18 INFO - 10980 INFO Message: Error: SessionFile is closed 07:54:18 INFO - 10981 INFO Stack: 07:54:18 INFO - 10982 INFO SessionFileInternal.write@resource://app/modules/sessionstore/SessionFile.jsm:266:29 07:54:18 INFO - 10983 INFO this.SessionFile.write@resource://app/modules/sessionstore/SessionFile.jsm:65:12 07:54:18 INFO - 10984 INFO SessionSaverInternal._writeState@resource://app/modules/sessionstore/SessionSaver.jsm:264:19 07:54:18 INFO - 10985 INFO SessionSaverInternal._saveState@resource://app/modules/sessionstore/SessionSaver.jsm:227:12 07:54:18 INFO - 10986 INFO SessionSaverInternal.run@resource://app/modules/sessionstore/SessionSaver.jsm:129:12 07:54:18 INFO - 10987 INFO this.SessionSaver<.run@resource://app/modules/sessionstore/SessionSaver.jsm:72:12 07:54:18 INFO - 10988 INFO ssi_uninit@resource:///modules/sessionstore/SessionStore.jsm:498:7 07:54:18 INFO - 10989 INFO ssi_onQuitApplication@resource:///modules/sessionstore/SessionStore.jsm:1133:5 07:54:18 INFO - 10990 INFO ssi_observe@resource:///modules/sessionstore/SessionStore.jsm:529:9 07:54:18 INFO - 10991 INFO testsFinished@chrome://mochikit/content/browser-harness.xul:279:9 07:54:18 INFO - 10992 INFO Tester_finish@chrome://mochikit/content/browser-test.js:280:7 07:54:18 INFO - 10993 INFO Tester.prototype.nextTest</</</<@chrome://mochikit/content/browser-test.js:529:15 07:54:18 INFO - 10994 INFO Tester.prototype.nextTest</</checkForLeakedGlobalWindows/</<@chrome://mochikit/content/browser-test.js:512:15 07:54:18 INFO - 10995 INFO CCAnalyzer.prototype.processLog@chrome://mochikit/content/cc-analyzer.js:49:9 07:54:18 INFO - 10996 INFO ###!!! [Parent][OnMaybeDequeueOne] Error: Channel closing: too late to send/recv, messages will be lost 07:54:18 INFO - 10997 INFO 1409324058570 Browser.Experiments.Experiments TRACE Experiments #0::uninit: started 07:54:18 INFO - 10998 INFO 1409324058577 Browser.Experiments.Experiments TRACE Experiments #0::uninit: finished with _loadTask 07:54:18 INFO - 10999 INFO 1409324058577 Browser.Experiments.Experiments TRACE Experiments #0::uninit: no previous shutdown 07:54:18 INFO - 11000 INFO 1409324058577 Browser.Experiments.Experiments TRACE Experiments #0::Unregistering instance with Addon Manager. 07:54:18 INFO - 11001 INFO 1409324058578 Browser.Experiments.Experiments TRACE Experiments #0::Removing install listener from add-on manager. 07:54:18 INFO - 11002 INFO 1409324058578 Browser.Experiments.Experiments TRACE Experiments #0::Removing addon listener from add-on manager. 07:54:18 INFO - 11003 INFO 1409324058578 Browser.Experiments.Experiments TRACE Experiments #0::Finished unregistering with addon manager. 07:54:18 INFO - 11004 INFO 1409324058578 Browser.Experiments.Experiments TRACE Experiments #0::Unregistering previous experiment add-on provider. 07:54:18 INFO - 11005 INFO 1409324058579 Browser.Experiments.Experiments TRACE PreviousExperimentProvider #4::shutdown() 07:54:18 INFO - 11006 INFO 1409324058580 Browser.Experiments.Experiments TRACE Experiments #0::uninit: waiting on _mainTask 07:54:18 INFO - 11007 INFO 1409324058589 Browser.Experiments.Experiments TRACE Experiments #0::uninit: started 07:54:18 INFO - 11008 INFO 1409324058591 Browser.Experiments.Experiments TRACE Experiments #0::uninit: finished with _loadTask 07:54:18 INFO - 11009 INFO 1409324058592 Browser.Experiments.Experiments TRACE Experiments #0::uninit: waiting on _mainTask 07:54:18 INFO - 11010 INFO 1409324058593 Browser.Experiments.Experiments TRACE Experiments #0::uninit: started 07:54:18 INFO - 11011 INFO 1409324058594 Browser.Experiments.Experiments TRACE Experiments #0::uninit: finished with _loadTask 07:54:18 INFO - 11012 INFO 1409324058595 Browser.Experiments.Experiments TRACE Experiments #0::uninit: waiting on _mainTask 07:54:18 INFO - 11013 INFO 1409324058601 Browser.Experiments.Experiments TRACE Experiments #0::uninit: started 07:54:18 INFO - 11014 INFO 1409324058602 Browser.Experiments.Experiments TRACE Experiments #0::uninit: finished with _loadTask 07:54:18 INFO - 11015 INFO 1409324058603 Browser.Experiments.Experiments TRACE Experiments #0::uninit: waiting on _mainTask 07:54:18 INFO - 11016 INFO 1409324058604 Browser.Experiments.Experiments TRACE Experiments #0::uninit: started 07:54:18 INFO - 11017 INFO 1409324058605 Browser.Experiments.Experiments TRACE Experiments #0::uninit: finished with _loadTask 07:54:18 INFO - 11018 INFO 1409324058606 Browser.Experiments.Experiments TRACE Experiments #0::uninit: waiting on _mainTask 07:54:28 INFO - 11019 INFO WARNING: At least one completion condition is taking too long to complete. Conditions: [{"name":"Experiments.jsm shutdown","state":{"isShutdown":true,"isEnabled":true,"isRefresh":false,"isDirty":false,"isFirstEvaluate":false,"hasLoadTask":false,"hasMainTask":true,"hasTimer":false,"hasAddonProvider":false,"latestLogs":["10: uninit: waiting on _mainTask","10: uninit: started","10: uninit: finished with _loadTask","10: uninit: waiting on _mainTask","10: uninit: started","10: uninit: finished with _loadTask","10: uninit: waiting on _mainTask","10: uninit: started","10: uninit: finished with _loadTask","10: uninit: waiting on _mainTask"],"experiments":{},"terminateReason":null},"filename":"resource://app/modules/experiments/Experiments.jsm","lineNumber":433,"stack":["resource://app/modules/experiments/Experiments.jsm:Experiments.Experiments.prototype.init:433","resource://app/modules/experiments/Experiments.jsm:Experiments.Experiments:414","resource://app/modules/experiments/Experiments.jsm:Experiments.instance:249","resource://app/components/ExperimentsService.js:ExperimentsService.prototype._delayedInit:65","resource://services-common/utils.js:notify:182","null:null:0"]},{"name":"Experiments.jsm shutdown","state":{"isShutdown":true,"isEnabled":true,"isRefresh":false,"isDirty":false,"isFirstEvaluate":false,"hasLoadTask":false,"hasMainTask":true,"hasTimer":false,"hasAddonProvider":false,"latestLogs":["10: uninit: waiting on _mainTask","10: uninit: started","10: uninit: finished with _loadTask","10: uninit: waiting on _mainTask","10: uninit: started","10: uninit: finished with _loadTask","10: uninit: waiting on _mainTask","10: uninit: started","10: uninit: finished with _loadTask","10: uninit: waiting on _mainTask"],"experiments":{},"terminateReason":null},"filename":"resource://app/modules/experiments/Experiments.jsm","lineNumber":433,"stack":["resource://app/modules/experiments/Experiments.jsm:Experiments.Experiments.prototype.init:433","chrome://mochitests/content/browser/toolkit/mozapps/extensions/test/browser/browser_experiments.js:testActivateExperiment:298","Handler.prototype.process@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:865:23","this.PromiseWalker.walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:744:7",""]},{"name":"Experiments.jsm shutdown","state":{"isShutdown":true,"isEnabled":true,"isRefresh":false,"isDirty":false,"isFirstEvaluate":false,"hasLoadTask":false,"hasMainTask":true,"hasTimer":false,"hasAddonProvider":false,"latestLogs":["10: uninit: waiting on _mainTask","10: uninit: started","10: uninit: finished with _loadTask","10: uninit: waiting on _mainTask","10: uninit: started","10: uninit: finished with _loadTask","10: uninit: waiting on _mainTask","10: uninit: started","10: uninit: finished with _loadTask","10: uninit: waiting on _mainTask"],"experiments":{},"terminateReason":null},"filename":"resource://app/modules/experiments/Experiments.jsm","lineNumber":433,"stack":["resource://app/modules/experiments/Experiments.jsm:Experiments.Experiments.prototype.init:433","chrome://mochitests/content/browser/toolkit/mozapps/extensions/test/browser/browser_experiments.js:testCleanup:635","Handler.prototype.process@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:865:23","this.PromiseWalker.walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:744:7",""]},{"name":"Experiments.jsm shutdown","state":{"isShutdown":true,"isEnabled":true,"isRefresh":false,"isDirty":false,"isFirstEvaluate":false,"hasLoadTask":false,"hasMainTask":true,"hasTimer":false,"hasAddonProvider":false,"latestLogs":["10: uninit: waiting on _mainTask","10: uninit: started","10: uninit: finished with _loadTask","10: uninit: waiting on _mainTask","10: uninit: started","10: uninit: finished with _loadTask","10: uninit: waiting on _mainTask","10: uninit: started","10: uninit: finished with _loadTask","10: uninit: waiting on _mainTask"],"experiments":{},"terminateReason":null},"filename":"resource://app/modules/experiments/Experiments.jsm","lineNumber":433,"stack":["resource://app/modules/experiments/Experiments.jsm:Experiments.Experiments.prototype.init:433","chrome://mochitests/content/browser/toolkit/mozapps/extensions/test/browser/test-window/browser_experiments.js:testActivateExperiment:298","Handler.prototype.process@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:865:23","this.PromiseWalker.walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:744:7",""]},{"name":"Experiments.jsm shutdown","state":{"isShutdown":true,"isEnabled":true,"isRefresh":false,"isDirty":false,"isFirstEvaluate":false,"hasLoadTask":false,"hasMainTask":true,"hasTimer":false,"hasAddonProvider":false,"latestLogs":["10: uninit: waiting on _mainTask","10: uninit: started","10: uninit: finished with _loadTask","10: uninit: waiting on _mainTask","10: uninit: started","10: uninit: finished with _loadTask","10: uninit: waiting on _mainTask","10: uninit: started","10: uninit: finished with _loadTask","10: uninit: waiting on _mainTask"],"experiments":{},"terminateReason":null},"filename":"resource://app/modules/experiments/Experiments.jsm","lineNumber":433,"stack":["resource://app/modules/experiments/Experiments.jsm:Experiments.Experiments.prototype.init:433","chrome://mochitests/content/browser/toolkit/mozapps/extensions/test/browser/test-window/browser_experiments.js:testCleanup:635","Handler.prototype.process@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:865:23","this.PromiseWalker.walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:744:7",""]}] Barrier: AddonManager: Waiting for clients to shut down. 07:54:28 INFO - 11020 INFO WARNING: At least one completion condition is taking too long to complete. Conditions: [{"name":"AddonManager: shutting down providers","state":"(none)","filename":"resource://gre/modules/AddonManager.jsm","lineNumber":741,"stack":["resource://gre/modules/AddonManager.jsm:AMI_startup:741","resource://gre/modules/AddonManager.jsm:AMP_startup:2319","resource://gre/components/addonManager.js:AMC_observe:55","null:null:0"]}] Barrier: profile-before-change 07:54:48 INFO - 11021 INFO 1409324088319 addons.update-checker WARN HTTP Request failed for an unknown reason 07:54:48 INFO - 11022 INFO 1409324088321 addons.update-checker WARN HTTP Request failed for an unknown reason 07:54:48 INFO - 11023 INFO 1409324088322 addons.update-checker WARN HTTP Request failed for an unknown reason 07:54:48 INFO - 11024 INFO 1409324088323 addons.update-checker WARN HTTP Request failed for an unknown reason 07:54:48 INFO - 11025 INFO 1409324088324 addons.update-checker WARN HTTP Request failed for an unknown reason 07:54:48 INFO - 11026 INFO 1409324088326 addons.update-checker WARN HTTP Request failed for an unknown reason 07:55:19 INFO - 11027 INFO FATAL ERROR: AsyncShutdown timeout in AddonManager: Waiting for clients to shut down. Conditions: [{"name":"Experiments.jsm shutdown","state":{"isShutdown":true,"isEnabled":true,"isRefresh":false,"isDirty":false,"isFirstEvaluate":false,"hasLoadTask":false,"hasMainTask":true,"hasTimer":false,"hasAddonProvider":false,"latestLogs":["10: uninit: waiting on _mainTask","10: uninit: started","10: uninit: finished with _loadTask","10: uninit: waiting on _mainTask","10: uninit: started","10: uninit: finished with _loadTask","10: uninit: waiting on _mainTask","10: uninit: started","10: uninit: finished with _loadTask","10: uninit: waiting on _mainTask"],"experiments":{},"terminateReason":null},"filename":"resource://app/modules/experiments/Experiments.jsm","lineNumber":433,"stack":["resource://app/modules/experiments/Experiments.jsm:Experiments.Experiments.prototype.init:433","resource://app/modules/experiments/Experiments.jsm:Experiments.Experiments:414","resource://app/modules/experiments/Experiments.jsm:Experiments.instance:249","resource://app/components/ExperimentsService.js:ExperimentsService.prototype._delayedInit:65","resource://services-common/utils.js:notify:182","null:null:0"]},{"name":"Experiments.jsm shutdown","state":{"isShutdown":true,"isEnabled":true,"isRefresh":false,"isDirty":false,"isFirstEvaluate":false,"hasLoadTask":false,"hasMainTask":true,"hasTimer":false,"hasAddonProvider":false,"latestLogs":["10: uninit: waiting on _mainTask","10: uninit: started","10: uninit: finished with _loadTask","10: uninit: waiting on _mainTask","10: uninit: started","10: uninit: finished with _loadTask","10: uninit: waiting on _mainTask","10: uninit: started","10: uninit: finished with _loadTask","10: uninit: waiting on _mainTask"],"experiments":{},"terminateReason":null},"filename":"resource://app/modules/experiments/Experiments.jsm","lineNumber":433,"stack":["resource://app/modules/experiments/Experiments.jsm:Experiments.Experiments.prototype.init:433","chrome://mochitests/content/browser/toolkit/mozapps/extensions/test/browser/browser_experiments.js:testActivateExperiment:298","Handler.prototype.process@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:865:23","this.PromiseWalker.walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:744:7",""]},{"name":"Experiments.jsm shutdown","state":{"isShutdown":true,"isEnabled":true,"isRefresh":false,"isDirty":false,"isFirstEvaluate":false,"hasLoadTask":false,"hasMainTask":true,"hasTimer":false,"hasAddonProvider":false,"latestLogs":["10: uninit: waiting on _mainTask","10: uninit: started","10: uninit: finished with _loadTask","10: uninit: waiting on _mainTask","10: uninit: started","10: uninit: finished with _loadTask","10: uninit: waiting on _mainTask","10: uninit: started","10: uninit: finished with _loadTask","10: uninit: waiting on _mainTask"],"experiments":{},"terminateReason":null},"filename":"resource://app/modules/experiments/Experiments.jsm","lineNumber":433,"stack":["resource://app/modules/experiments/Experiments.jsm:Experiments.Experiments.prototype.init:433","chrome://mochitests/content/browser/toolkit/mozapps/extensions/test/browser/browser_experiments.js:testCleanup:635","Handler.prototype.process@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:865:23","this.PromiseWalker.walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:744:7",""]},{"name":"Experiments.jsm shutdown","state":{"isShutdown":true,"isEnabled":true,"isRefresh":false,"isDirty":false,"isFirstEvaluate":false,"hasLoadTask":false,"hasMainTask":true,"hasTimer":false,"hasAddonProvider":false,"latestLogs":["10: uninit: waiting on _mainTask","10: uninit: started","10: uninit: finished with _loadTask","10: uninit: waiting on _mainTask","10: uninit: started","10: uninit: finished with _loadTask","10: uninit: waiting on _mainTask","10: uninit: started","10: uninit: finished with _loadTask","10: uninit: waiting on _mainTask"],"experiments":{},"terminateReason":null},"filename":"resource://app/modules/experiments/Experiments.jsm","lineNumber":433,"stack":["resource://app/modules/experiments/Experiments.jsm:Experiments.Experiments.prototype.init:433","chrome://mochitests/content/browser/toolkit/mozapps/extensions/test/browser/test-window/browser_experiments.js:testActivateExperiment:298","Handler.prototype.process@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:865:23","this.PromiseWalker.walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:744:7",""]},{"name":"Experiments.jsm shutdown","state":{"isShutdown":true,"isEnabled":true,"isRefresh":false,"isDirty":false,"isFirstEvaluate":false,"hasLoadTask":false,"hasMainTask":true,"hasTimer":false,"hasAddonProvider":false,"latestLogs":["10: uninit: waiting on _mainTask","10: uninit: started","10: uninit: finished with _loadTask","10: uninit: waiting on _mainTask","10: uninit: started","10: uninit: finished with _loadTask","10: uninit: waiting on _mainTask","10: uninit: started","10: uninit: finished with _loadTask","10: uninit: waiting on _mainTask"],"experiments":{},"terminateReason":null},"filename":"resource://app/modules/experiments/Experiments.jsm","lineNumber":433,"stack":["resource://app/modules/experiments/Experiments.jsm:Experiments.Experiments.prototype.init:433","chrome://mochitests/content/browser/toolkit/mozapps/extensions/test/browser/test-window/browser_experiments.js:testCleanup:635","Handler.prototype.process@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:865:23","this.PromiseWalker.walkerLoop@resource://gre/modules/Promise.jsm -> resource://gre/modules/Promise-backend.js:744:7",""]}] 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. 07:55:19 INFO - 11028 INFO [Parent 2128] ###!!! ABORT: file resource://app/modules/experiments/Experiments.jsm, line 433 07:55:19 INFO - 11029 INFO [Parent 2128] ###!!! ABORT: file resource://app/modules/experiments/Experiments.jsm, line 433 07:55:20 INFO - TEST-INFO | Main app process: killed by SIGSEGV
| Comment hidden (Legacy TBPL/Treeherder Robot) |
| Comment hidden (Legacy TBPL/Treeherder Robot) |
| Comment hidden (Legacy TBPL/Treeherder Robot) |
| Comment hidden (Legacy TBPL/Treeherder Robot) |
| Comment hidden (Legacy TBPL/Treeherder Robot) |
| Comment hidden (Legacy TBPL/Treeherder Robot) |
| Comment hidden (Legacy TBPL/Treeherder Robot) |
|
||
Comment 8•10 years ago
|
||
Looks like a dup of bug 995027.
Status: NEW → RESOLVED
Closed: 10 years ago
Resolution: --- → DUPLICATE
You need to log in
before you can comment on or make changes to this bug.
Description
•