Intermittent devtools/server/tests/xpcshell/test_extension_storage_actor.js | xpcshell return code: 0
Categories
(DevTools :: General, defect, P5)
Tracking
(Not tracked)
People
(Reporter: intermittent-bug-filer, Assigned: jdescottes)
References
Details
(Keywords: intermittent-failure, Whiteboard: [stockwell disabled])
Attachments
(2 files)
Filed by: ncsoregi [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=290463132&repo=mozilla-beta
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/RH0aire9RG-9l2cr7aGfOg/runs/0/artifacts/public/logs/live_backing.log
[task 2020-02-26T00:18:47.175Z] 00:18:47 INFO - TEST-START | devtools/server/tests/xpcshell/test_extension_storage_actor.js
[task 2020-02-26T00:18:53.304Z] 00:18:53 WARNING - TEST-UNEXPECTED-FAIL | devtools/server/tests/xpcshell/test_extension_storage_actor.js | xpcshell return code: 0
[task 2020-02-26T00:18:53.305Z] 00:18:53 INFO - TEST-INFO took 6125ms
[task 2020-02-26T00:18:53.305Z] 00:18:53 INFO - >>>>>>>
[task 2020-02-26T00:18:53.306Z] 00:18:53 INFO - (xpcshell/head.js) | test MAIN run_test pending (1)
[task 2020-02-26T00:18:53.306Z] 00:18:53 INFO - (xpcshell/head.js) | test run_next_test 0 pending (2)
[task 2020-02-26T00:18:53.306Z] 00:18:53 INFO - (xpcshell/head.js) | test MAIN run_test finished (2)
[task 2020-02-26T00:18:53.307Z] 00:18:53 INFO - running event loop
[task 2020-02-26T00:18:53.307Z] 00:18:53 INFO - devtools/server/tests/xpcshell/test_extension_storage_actor.js | Starting setup
[task 2020-02-26T00:18:53.307Z] 00:18:53 INFO - (xpcshell/head.js) | test setup pending (2)
[task 2020-02-26T00:18:53.308Z] 00:18:53 INFO - PID 15888 | 1582676327405 addons.manager DEBUG Application has been upgraded
[task 2020-02-26T00:18:53.308Z] 00:18:53 INFO - PID 15888 | 1582676327406 addons.manager DEBUG Loaded provider scope for resource://gre/modules/addons/XPIProvider.jsm: ["XPIProvider", "XPIInternal"]
[task 2020-02-26T00:18:53.308Z] 00:18:53 INFO - PID 15888 | 1582676327409 addons.manager DEBUG Loaded provider scope for resource://gre/modules/addons/GMPProvider.jsm
[task 2020-02-26T00:18:53.309Z] 00:18:53 INFO - PID 15888 | 1582676327413 addons.manager DEBUG Loaded provider scope for resource://gre/modules/addons/PluginProvider.jsm
[task 2020-02-26T00:18:53.309Z] 00:18:53 INFO - PID 15888 | 1582676327413 addons.manager DEBUG Starting provider: XPIProvider
[task 2020-02-26T00:18:53.309Z] 00:18:53 INFO - PID 15888 | 1582676327413 addons.xpi DEBUG startup
[task 2020-02-26T00:18:53.310Z] 00:18:53 INFO - PID 15888 | 1582676327413 addons.xpi WARN List of valid built-in add-ons could not be parsed.: [Exception... "Component returned failure code: 0xc1f30001 (NS_ERROR_NOT_INITIALIZED) [nsIXPCComponents_Utils.readUTF8URI]" nsresult: "0xc1f30001 (NS_ERROR_NOT_INITIALIZED)" location: "JS frame :: resource://gre/modules/addons/XPIProvider.jsm :: startup :: line 2372" data: no] Stack trace: startup()@resource://gre/modules/addons/XPIProvider.jsm:2372
[task 2020-02-26T00:18:53.310Z] 00:18:53 INFO - PID 15888 | callProvider()@resource://gre/modules/AddonManager.jsm:215
[task 2020-02-26T00:18:53.311Z] 00:18:53 INFO - PID 15888 | _startProvider()@resource://gre/modules/AddonManager.jsm:587
[task 2020-02-26T00:18:53.311Z] 00:18:53 INFO - PID 15888 | startup()@resource://gre/modules/AddonManager.jsm:811
[task 2020-02-26T00:18:53.311Z] 00:18:53 INFO - PID 15888 | startup()@resource://gre/modules/AddonManager.jsm:3482
[task 2020-02-26T00:18:53.312Z] 00:18:53 INFO - PID 15888 | observe()@resource://gre/modules/addonManager.js:87
[task 2020-02-26T00:18:53.312Z] 00:18:53 INFO - PID 15888 | promiseStartupManager()@resource://testing-common/AddonTestUtils.jsm:1003
[task 2020-02-26T00:18:53.313Z] 00:18:53 INFO - PID 15888 | setup()@Z:/task_1582675384/build/tests/xpcshell/tests/devtools/server/tests/xpcshell/test_extension_storage_actor.js:204
[task 2020-02-26T00:18:53.313Z] 00:18:53 INFO - PID 15888 | run_next_test/_run_next_test/<()@Z:\task_1582675384\build\tests\xpcshell\head.js:1567
[task 2020-02-26T00:18:53.314Z] 00:18:53 INFO - PID 15888 | _run_next_test()@Z:\task_1582675384\build\tests\xpcshell\head.js:1567
[task 2020-02-26T00:18:53.314Z] 00:18:53 INFO - PID 15888 | run()@Z:\task_1582675384\build\tests\xpcshell\head.js:735
[task 2020-02-26T00:18:53.314Z] 00:18:53 INFO - PID 15888 | _do_main()@Z:\task_1582675384\build\tests\xpcshell\head.js:246
[task 2020-02-26T00:18:53.315Z] 00:18:53 INFO - PID 15888 | _execute_test()@Z:\task_1582675384\build\tests\xpcshell\head.js:573
[task 2020-02-26T00:18:53.315Z] 00:18:53 INFO - PID 15888 | -e:1
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
![]() |
||
Comment 4•5 years ago
|
||
[task 2020-02-26T00:18:53.412Z] 00:18:53 INFO - TEST-PASS | devtools/server/tests/xpcshell/test_extension_storage_actor.js | test_panel_live_updates - [test_panel_live_updates : 458] Got the expected results on populated storage.local - [] deepEqual []
[task 2020-02-26T00:18:53.413Z] 00:18:53 INFO - PID 15888 | console.warn: "Error while detaching the browsing context target front:" (new Error("wrongState", "resource://devtools/shared/protocol/Front.js", 276))
[task 2020-02-26T00:18:53.413Z] 00:18:53 INFO - PID 15888 | 1582676329519 addons.xpi DEBUG Calling bootstrap method shutdown on 0df02dd475392ad4c6e4f7261a5bb299d31c1bf3@temporary-addon version 1.0
[task 2020-02-26T00:18:53.413Z] 00:18:53 INFO - "CONSOLE_MESSAGE: (info) 1582676329519 addons.xpi DEBUG Calling bootstrap method shutdown on 0df02dd475392ad4c6e4f7261a5bb299d31c1bf3@temporary-addon version 1.0"
[task 2020-02-26T00:18:53.414Z] 00:18:53 INFO - PID 15888 | DBG-TEST: head_dbg.js observed a console message: 1582676329519 addons.xpi DEBUG Calling bootstrap method shutdown on 0df02dd475392ad4c6e4f7261a5bb299d31c1bf3@temporary-addon version 1.0
[task 2020-02-26T00:18:53.414Z] 00:18:53 INFO - "CONSOLE_MESSAGE: (error) [JavaScript Error: "sendRemoveListener on closed conduit 0df02dd475392ad4c6e4f7261a5bb299d31c1bf3@temporary-addon.412316860416" {file: "resource://gre/modules/ConduitsChild.jsm" line: 108}]
[task 2020-02-26T00:18:53.414Z] 00:18:53 INFO - _send@resource://gre/modules/ConduitsChild.jsm:108:13
[task 2020-02-26T00:18:53.414Z] 00:18:53 INFO - removeListener@resource://gre/modules/ExtensionChild.jsm:1138:34
[task 2020-02-26T00:18:53.415Z] 00:18:53 INFO - removeListener@resource://gre/modules/ExtensionChild.jsm:1361:40
[task 2020-02-26T00:18:53.415Z] 00:18:53 INFO - getAPI/register/<.storage.onChanged@chrome://extensions/content/child/ext-storage.js:333:22
[task 2020-02-26T00:18:53.415Z] 00:18:53 INFO - removeListener@resource://gre/modules/ExtensionCommon.jsm:2544:7
[task 2020-02-26T00:18:53.415Z] 00:18:53 INFO - revoke@resource://gre/modules/ExtensionCommon.jsm:2566:12
[task 2020-02-26T00:18:53.415Z] 00:18:53 INFO - close@resource://gre/modules/ExtensionCommon.jsm:2571:10
[task 2020-02-26T00:18:53.416Z] 00:18:53 INFO - unload@resource://gre/modules/ExtensionCommon.jsm:910:11
[task 2020-02-26T00:18:53.416Z] 00:18:53 INFO - unload@resource://gre/modules/ExtensionPageChild.jsm:261:11
[task 2020-02-26T00:18:53.416Z] 00:18:53 INFO - unload@resource://gre/modules/ExtensionPageChild.jsm:310:11
[task 2020-02-26T00:18:53.417Z] 00:18:53 INFO - destroyExtensionContext@resource://gre/modules/ExtensionPageChild.jsm:494:15
[task 2020-02-26T00:18:53.417Z] 00:18:53 INFO - observe@resource://gre/modules/ExtensionPageChild.jsm:407:12
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 hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 19•5 years ago
|
||
Julian, you were working on bug 1644913. Is there more we can do here?
Honza
Assignee | ||
Comment 20•5 years ago
|
||
The error is different from the one I fixed in Bug 1644913. Also the spike started on June 14th while my fix landed on June 11th, so I don't think there is a direct connection.
I seem to reproduce the failure consistently locally though, so I'll try to bisect & investigate.
Assignee | ||
Comment 21•5 years ago
|
||
According to my bisect the spike was caused by https://bugzilla.mozilla.org/show_bug.cgi?id=1583738 and especially the last patch in the queue: https://hg.mozilla.org/mozilla-central/rev/623d3cc37bb4
Something about attaching the webextension target seems to confuse the test.
We could add a test only variant to Descriptor::getTarget, such as getDetachedTarget
.
For now I am trying to understand more what causes the failure.
Assignee | ||
Comment 22•5 years ago
•
|
||
The failure only occurs locally when I use an attached target for the test_panel_live_reload test function.
And it only happens if we perform the extension.upgrade
call during the test.
Most of the time it seems linked to a "frameUpdated" event fired when the webextension is being updated.
But even after commenting out the event, the test remains intermittent (albeit with a much lower frequency)
A first option would be to expose a new API on the webextension descriptor front in order to create
detached targets.
But it seems that isolating the live_reload test in a dedicated file also fixes the intermittent.
It makes the fix a bit obscure, and it probably means we won't look into the issue much further but
I would prefer to avoid test-only APIs in the codebase.
Updated•5 years ago
|
Comment 23•5 years ago
|
||
Thanks for working on this Julian!
Honza
Comment 24•5 years ago
|
||
Jan, this bug is on our disable-recommended filter. Could we land the patch after it is reviewed?
Comment 25•5 years ago
|
||
Comment hidden (Intermittent Failures Robot) |
Comment 27•5 years ago
|
||
Razvan, yes, it's ok to land your patch and disable the test.
Thanks for the help here!
Updated•5 years ago
|
Comment 28•5 years ago
|
||
Comment 29•5 years ago
|
||
bugherder |
Comment 30•5 years ago
|
||
Comment 31•5 years ago
|
||
Comment 32•5 years ago
|
||
bugherder |
Comment hidden (Intermittent Failures Robot) |
Assignee | ||
Comment 34•5 years ago
|
||
Should be fixed now.
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) |
Description
•