Open
Bug 1419183
Opened 2 years ago
Updated 2 years ago
Intermittent toolkit/components/extensions/test/xpcshell/test_ext_management.js | test_management_getAll - [test_management_getAll : 253] A promise chain failed to handle a rejection: The ExtensionSettingsStore was accessed before the initialize
Categories
(WebExtensions :: General, defect, P3)
WebExtensions
General
P3
Tracking
(Not tracked)
NEW
People
(Reporter: intermittent-bug-filer, Assigned: mstriemer)
References
Details
(Keywords: intermittent-failure, leave-open, Whiteboard: [stockwell disabled])
Attachments
(1 file)
891 bytes,
patch
|
jmaher
:
review+
|
Details | Diff | Splinter Review |
Filed by: archaeopteryx [at] coole-files.de https://treeherder.mozilla.org/logviewer.html#?job_id=145996861&repo=autoland https://queue.taskcluster.net/v1/task/V5zG6xanSPK3-rFGjFsXOQ/runs/0/artifacts/public/logs/live_backing.log 01:32:08 INFO - TEST-PASS | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_management.js | test_management_getAll - [test_management_getAll : 65] Additional extension metadata was correct - "get_all_test1@tests.mozilla.com" == "get_all_test1@tests.mozilla.com" 01:32:08 INFO - TEST-PASS | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_management.js | test_management_getAll - [test_management_getAll : 69] The extension with id get_all_test2@tests.mozilla.com was returned by get. - "get_all_test2@tests.mozilla.com" == "get_all_test2@tests.mozilla.com" 01:32:08 INFO - TEST-PASS | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_management.js | test_management_getAll - [test_management_getAll : 70] Additional extension metadata was correct - "get_all_test2@tests.mozilla.com" == "get_all_test2@tests.mozilla.com" 01:32:08 INFO - PID 10916 | JavaScript strict warning: resource://gre/modules/ExtensionStorage.jsm, line 334: ReferenceError: reference to undefined property "processType" 01:32:08 INFO - PID 10916 | JavaScript strict warning: resource://gre/modules/EventEmitter.jsm, line 123: ReferenceError: reference to undefined property "_originalListener" 01:32:08 INFO - (xpcshell/head.js) | test run_next_test 3 pending (2) 01:32:08 INFO - (xpcshell/head.js) | test test_management_getAll finished (2) 01:32:08 INFO - "CONSOLE_MESSAGE: (warn) [JavaScript Warning: "ReferenceError: reference to undefined property "processType"" {file: "resource://gre/modules/ExtensionStorage.jsm" line: 334}]" 01:32:08 INFO - "CONSOLE_MESSAGE: (warn) [JavaScript Warning: "ReferenceError: reference to undefined property "_originalListener"" {file: "resource://gre/modules/EventEmitter.jsm" line: 123}]" 01:32:08 INFO - (xpcshell/head.js) | test run_next_test 3 finished (1) 01:32:08 INFO - exiting test 01:32:08 INFO - PID 10916 | JavaScript error: resource://gre/modules/ExtensionSettingsStore.jsm, line 103: Error: The ExtensionSettingsStore was accessed before the initialize promise resolved. 01:32:08 INFO - PID 10916 | JavaScript error: resource://gre/modules/ExtensionSettingsStore.jsm, line 103: Error: The ExtensionSettingsStore was accessed before the initialize promise resolved. 01:32:08 INFO - PID 10916 | JavaScript error: resource://gre/modules/ExtensionSettingsStore.jsm, line 103: Error: The ExtensionSettingsStore was accessed before the initialize promise resolved. 01:32:08 INFO - PID 10916 | JavaScript error: resource://gre/modules/ExtensionSettingsStore.jsm, line 103: Error: The ExtensionSettingsStore was accessed before the initialize promise resolved. 01:32:08 INFO - "CONSOLE_MESSAGE: (error) [JavaScript Error: "Error: The ExtensionSettingsStore was accessed before the initialize promise resolved." {file: "resource://gre/modules/ExtensionSettingsStore.jsm" line: 103}]" 01:32:08 INFO - "CONSOLE_MESSAGE: (error) [JavaScript Error: "Error: The ExtensionSettingsStore was accessed before the initialize promise resolved." {file: "resource://gre/modules/ExtensionSettingsStore.jsm" line: 103}]" 01:32:08 INFO - "CONSOLE_MESSAGE: (error) [JavaScript Error: "Error: The ExtensionSettingsStore was accessed before the initialize promise resolved." {file: "resource://gre/modules/ExtensionSettingsStore.jsm" line: 103}]" 01:32:08 INFO - "CONSOLE_MESSAGE: (error) [JavaScript Error: "Error: The ExtensionSettingsStore was accessed before the initialize promise resolved." {file: "resource://gre/modules/ExtensionSettingsStore.jsm" line: 103}]" 01:32:08 WARNING - TEST-UNEXPECTED-FAIL | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_management.js | test_management_getAll - [test_management_getAll : 253] A promise chain failed to handle a rejection: The ExtensionSettingsStore was accessed before the initialize promise resolved. - stack: observe@resource://gre/modules/AsyncShutdown.jsm:535:9 01:32:08 INFO - _execute_test@Z:\\task_1511137528\\build\\tests\\xpcshell\\head.js:626:5 01:32:08 INFO - @-e:1:1 01:32:08 INFO - Rejection date: Mon Nov 20 2017 01:32:08 GMT+0000 (Coordinated Universal Time) - false == true 01:32:08 INFO - resource://testing-common/PromiseTestUtils.jsm:assertNoUncaughtRejections:253 01:32:08 INFO - Z:\task_1511137528\build\tests\xpcshell\head.js:_execute_test:634 01:32:08 INFO - -e:null:1 01:32:08 INFO - exiting test 01:32:08 INFO - PID 10916 | JavaScript error: , line 0: uncaught exception: 2147500036 01:32:08 INFO - PID 10916 | [GPU 6012, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346 01:32:08 INFO - <<<<<<<
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 12•2 years ago
|
||
There have been a total of 33 failures in the last week, according to Orange Factor. Occurrences per platform: -windows10-64: 20 -Windows 7: 9 -windows10-64-nightly: 2 -android-6-0-armv8-api16: 1 Occurrences per build type: -debug: 1 -opt: 5 -pgo: 27 Here is a recent log file and a snippet with the failure: https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-central&job_id=159301866&lineNumber=10275 12:06:20 INFO - TEST-START | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_management.js 12:06:20 WARNING - TEST-UNEXPECTED-FAIL | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_management.js | xpcshell return code: 0 12:06:20 INFO - TEST-INFO took 693ms The duplicate bug: 1422180 was resolved. :andym could you please take a look?
Flags: needinfo?(amckay)
Whiteboard: [stockwell needswork]
Comment 13•2 years ago
|
||
I'll take a look at this.
Assignee: nobody → bob.silverberg
Flags: needinfo?(amckay)
Priority: P5 → P3
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 16•2 years ago
|
||
I've done some digging into this, and am able to reproduce this fairly frequently on Windows 10. Dumping a stack trace where the error is occurring, I see the following: ensureType@resource://gre/modules/ExtensionSettingsStore.jsm:104:28 getItem@resource://gre/modules/ExtensionSettingsStore.jsm:135:3 getSetting@resource://gre/modules/ExtensionSettingsStore.jsm:445:12 removeEngine@chrome://browser/content/ext-chrome-settings-overrides.js:71:22 async*removeSearchSettings@chrome://browser/content/ext-chrome-settings-overrides.js:88:5 onUninstall@chrome://browser/content/ext-chrome-settings-overrides.js:94:5 apiManager</</<@resource://gre/modules/ExtensionParent.jsm:107:9 Async*apiManager</<@resource://gre/modules/ExtensionParent.jsm:105:26 emit@resource://gre/modules/ExtensionUtils.jsm:234:40 uninstall@resource://gre/modules/Extension.jsm:1032:5 callBootstrapMethod@resource://gre/modules/addons/XPIProvider.jsm:4420:20 uninstallAddon@resource://gre/modules/addons/XPIProvider.jsm:4685:11 uninstall@resource://gre/modules/addons/XPIProvider.jsm:5615:5 unload@resource://testing-common/ExtensionXPCShellUtils.jsm:319:7 async*unload@resource://testing-common/ExtensionXPCShellUtils.jsm:568:12 async*test_management_getAll@c:/mozilla-source/mozilla-central/obj-ff-opt-artifact/_tests/xpcshell/toolkit/components/extensions/test/xpcshell/test_ext_management.js:73:9 etc... So what seems to be happening is that when the test extension is unloaded, the onUninstall method in ext-chrome-settings-overrides.js is called, which in turn calls removeEngine in ext-chrome-settings-overrides.js. removeEngine then interacts with the ExtensionSettingsStore, which results in the "The ExtensionSettingsStore was accessed before the initialize promise resolved." exception, BUT, it doesn't seem like that should be happening. removeEngine calls await ExtensionSettingsStore.initialize() before attempting to interact with the settings store [1], and that's supposed to ensure that the exception above cannot happen. So I'm not sure what's happening here. It seems like either removeEngine isn't actually waiting for that promise to resolve before calling ExtensionSettingsStore.getSetting, or that the promise returned from ExtensionSettingsStore.initialize doesn't actually do what we expect it to do, and can resolve before the store is actually initialized. Andrew, do you have any ideas about what might be happening here? [1] https://searchfox.org/mozilla-central/rev/e06af9c36a73a27864302cd2f829e6200dee8541/browser/components/extensions/ext-chrome-settings-overrides.js#70
Flags: needinfo?(aswan)
Comment 17•2 years ago
|
||
(In reply to Bob Silverberg [:bsilverberg] from comment #16) > removeEngine calls await ExtensionSettingsStore.initialize() before > attempting to interact with the settings store [1], and that's supposed to > ensure that the exception above cannot happen. So I'm not sure what's > happening here. It seems like either removeEngine isn't actually waiting for > that promise to resolve before calling ExtensionSettingsStore.getSetting, or > that the promise returned from ExtensionSettingsStore.initialize doesn't > actually do what we expect it to do, and can resolve before the store is > actually initialized. It looks like removeSearchSettings() doesn't actually wait for the removeEngine() promise. And even if it did, onUninstall() also doesn't wait for removeSearchSettings()
Flags: needinfo?(aswan)
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 20•2 years ago
|
||
This in the last 7 days still has 52 failures and this in the conditions that the trees were closed in the last 12h and nothing has been pushed. Most of them on windows10-64 pgo (39), some on windows 7 (7) and some on windows10-64-nightly (5) and one on windows10-64-devedition. :bsilverberg would you try a fix for it or do you think we could disabled it for now until you have a fix? Thank you.
Flags: needinfo?(bob.silverberg)
Comment 21•2 years ago
|
||
(In reply to Cosmin Sabou [:cosmin_s] from comment #20) > This in the last 7 days still has 52 failures and this in the conditions > that the trees were closed in the last 12h and nothing has been pushed. Most > of them on windows10-64 pgo (39), some on windows 7 (7) and some on > windows10-64-nightly (5) and one on windows10-64-devedition. > > :bsilverberg would you try a fix for it or do you think we could disabled it > for now until you have a fix? Thank you. mstriemer has kindly offered to take another look at this, so I'm reassigning to him, and if we could hold off disabling it for a few more days that would be great. Thanks!
Assignee: bob.silverberg → mstriemer
Flags: needinfo?(bob.silverberg)
Comment hidden (Intermittent Failures Robot) |
Comment 23•2 years ago
|
||
Hi! Another patch for review. Thanks.
Attachment #8952764 -
Flags: review?(jmaher)
Updated•2 years ago
|
Attachment #8952764 -
Flags: review?(jmaher) → review+
Comment 24•2 years ago
|
||
Pushed by csabou@mozilla.com: https://hg.mozilla.org/integration/mozilla-inbound/rev/655aa8e5fb99 Disable toolkit/components/extensions/test/xpcshell/test_ext_management.js for frequent failures. r=jmaher
Updated•2 years ago
|
Keywords: leave-open
Updated•2 years ago
|
Whiteboard: [stockwell disable-recommended] → [stockwell disabled]
Comment 25•2 years ago
|
||
bugherder |
https://hg.mozilla.org/mozilla-central/rev/655aa8e5fb99
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Updated•2 years ago
|
Product: Toolkit → WebExtensions
You need to log in
before you can comment on or make changes to this bug.
Description
•