Open Bug 1813406 Opened 2 years ago Updated 1 day ago

High frequent devtools/server/tests/xpcshell/test_extension_storage_actor.js | single tracking bug

Categories

(DevTools :: General, defect, P5)

defect

Tracking

(firefox-esr128 unaffected, firefox132 unaffected, firefox133 unaffected, firefox134 affected, firefox135 affected)

REOPENED
Tracking Status
firefox-esr128 --- unaffected
firefox132 --- unaffected
firefox133 --- unaffected
firefox134 --- affected
firefox135 --- affected

People

(Reporter: intermittent-bug-filer, Unassigned, NeedInfo)

References

(Regression)

Details

(Keywords: intermittent-failure, regression, Whiteboard: [stockwell disable-recommended])

Filed by: mlaza [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=403898621&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/Mfe_kgzzTg6Kd_ACH8UvOA/runs/0/artifacts/public/logs/live_backing.log
Reftest URL: https://hg.mozilla.org/mozilla-central/raw-file/tip/layout/tools/reftest/reftest-analyzer.xhtml#logurl=https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/Mfe_kgzzTg6Kd_ACH8UvOA/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1


[task 2023-01-29T21:40:03.566Z] 21:40:03     INFO -  TEST-START | devtools/server/tests/xpcshell/test_extension_storage_actor.js
[task 2023-01-29T21:40:06.430Z] 21:40:06  WARNING -  TEST-UNEXPECTED-FAIL | devtools/server/tests/xpcshell/test_extension_storage_actor.js | xpcshell return code: 0
[task 2023-01-29T21:40:06.430Z] 21:40:06     INFO -  TEST-INFO took 2863ms
[task 2023-01-29T21:40:06.430Z] 21:40:06     INFO -  >>>>>>>
...
[task 2023-01-29T21:40:06.688Z] 21:40:06     INFO -  TEST-PASS | devtools/server/tests/xpcshell/test_extension_storage_actor.js | test_panel_data_matches_extension_with_no_pages_open - [test_panel_data_matches_extension_with_no_pages_open : 404] Got the expected results on populated storage.local - [{"name":"a","value":{"str":"123"},"area":"local","isValueEditable":true}] deepEqual [{"area":"local","name":"a","value":{"str":"123"},"isValueEditable":true}]
[task 2023-01-29T21:40:06.688Z] 21:40:06     INFO -  PID 14648 | DBG-TEST: head_dbg.js observed a console message: 1675028406315	addons.xpi	DEBUG	Calling bootstrap method shutdown on e79dd720347307cb0f89a34b54be55ccefaf0924@temporary-addon version 1.0
[task 2023-01-29T21:40:06.689Z] 21:40:06     INFO -  "CONSOLE_MESSAGE: (info) 1675028406315	addons.xpi	DEBUG	Calling bootstrap method shutdown on e79dd720347307cb0f89a34b54be55ccefaf0924@temporary-addon version 1.0"
[task 2023-01-29T21:40:06.690Z] 21:40:06     INFO -  (xpcshell/head.js) | test run_next_test 6 pending (2)
[task 2023-01-29T21:40:06.691Z] 21:40:06     INFO -  (xpcshell/head.js) | test test_panel_data_matches_extension_with_no_pages_open finished (2)
[task 2023-01-29T21:40:06.691Z] 21:40:06     INFO -  PID 14648 | DBG-TEST: head_dbg.js observed a console message: 1675028406319	addons.xpi	DEBUG	Calling bootstrap method uninstall on e79dd720347307cb0f89a34b54be55ccefaf0924@temporary-addon version 1.0
[task 2023-01-29T21:40:06.692Z] 21:40:06     INFO -  "CONSOLE_MESSAGE: (info) 1675028406319	addons.xpi	DEBUG	Calling bootstrap method uninstall on e79dd720347307cb0f89a34b54be55ccefaf0924@temporary-addon version 1.0"
[task 2023-01-29T21:40:06.693Z] 21:40:06     INFO -  PID 14648 | DBG-TEST: head_dbg.js observed a console message: 1675028406320	addons.xpi	DEBUG	Disabling XPIState for e79dd720347307cb0f89a34b54be55ccefaf0924@temporary-addon
[task 2023-01-29T21:40:06.693Z] 21:40:06     INFO -  "CONSOLE_MESSAGE: (info) 1675028406320	addons.xpi	DEBUG	Disabling XPIState for e79dd720347307cb0f89a34b54be55ccefaf0924@temporary-addon"
[task 2023-01-29T21:40:06.694Z] 21:40:06  WARNING -  TEST-UNEXPECTED-FAIL | devtools/server/tests/xpcshell/test_extension_storage_actor.js | test_panel_data_matches_extension_with_no_pages_open - [test_panel_data_matches_extension_with_no_pages_open : 266] A promise chain failed to handle a rejection: Message handler threw uncatchable exception - stack: _do_main@/builds/worker/workspace/build/tests/xpcshell/head.js:238:6
[task 2023-01-29T21:40:06.694Z] 21:40:06     INFO -  _execute_test@/builds/worker/workspace/build/tests/xpcshell/head.js:585:5
[task 2023-01-29T21:40:06.695Z] 21:40:06     INFO -  @-e:1:1
[task 2023-01-29T21:40:06.695Z] 21:40:06     INFO -  Rejection date: Sun Jan 29 2023 21:40:06 GMT+0000 (Coordinated Universal Time) - false == true
[task 2023-01-29T21:40:06.696Z] 21:40:06     INFO -  resource://testing-common/PromiseTestUtils.sys.mjs:assertNoUncaughtRejections:266
[task 2023-01-29T21:40:06.696Z] 21:40:06     INFO -  /builds/worker/workspace/build/tests/xpcshell/head.js:_run_next_test:1698
[task 2023-01-29T21:40:06.696Z] 21:40:06     INFO -  /builds/worker/workspace/build/tests/xpcshell/head.js:run:807
[task 2023-01-29T21:40:06.697Z] 21:40:06     INFO -  /builds/worker/workspace/build/tests/xpcshell/head.js:_do_main:238
[task 2023-01-29T21:40:06.697Z] 21:40:06     INFO -  /builds/worker/workspace/build/tests/xpcshell/head.js:_execute_test:585
[task 2023-01-29T21:40:06.697Z] 21:40:06     INFO -  -e:null:1
[task 2023-01-29T21:40:06.698Z] 21:40:06     INFO -  exiting test
[task 2023-01-29T21:40:06.698Z] 21:40:06     INFO -  (xpcshell/head.js) | test run_next_test 6 finished (1)
[task 2023-01-29T21:40:06.698Z] 21:40:06     INFO -  exiting test
[task 2023-01-29T21:40:06.699Z] 21:40:06     INFO -  "Force a GC"
[task 2023-01-29T21:40:06.699Z] 21:40:06     INFO -  PID 14648 | DBG-TEST: head_dbg.js observed a console message: 1675028406369	addons.manager	DEBUG	before shutdown
[task 2023-01-29T21:40:06.700Z] 21:40:06     INFO -  "CONSOLE_MESSAGE: (info) 1675028406369	addons.manager	DEBUG	before shutdown"
[task 2023-01-29T21:40:06.701Z] 21:40:06     INFO -  PID 14648 | DBG-TEST: head_dbg.js observed a console message: 1675028406369	addons.manager	DEBUG	shutdown
[task 2023-01-29T21:40:06.701Z] 21:40:06     INFO -  "CONSOLE_MESSAGE: (info) 1675028406369	addons.manager	DEBUG	shutdown"
[task 2023-01-29T21:40:06.702Z] 21:40:06     INFO -  PID 14648 | DBG-TEST: head_dbg.js observed a console message: 1675028406369	addons.manager	DEBUG	Calling shutdown blocker for XPIProvider
[task 2023-01-29T21:40:06.702Z] 21:40:06     INFO -  "CONSOLE_MESSAGE: (info) 1675028406369	addons.manager	DEBUG	Calling shutdown blocker for XPIProvider"
[task 2023-01-29T21:40:06.703Z] 21:40:06     INFO -  PID 14648 | DBG-TEST: head_dbg.js observed a console message: 1675028406370	addons.xpi	DEBUG	shutdown
[task 2023-01-29T21:40:06.704Z] 21:40:06     INFO -  "CONSOLE_MESSAGE: (info) 1675028406370	addons.xpi	DEBUG	shutdown"
[task 2023-01-29T21:40:06.704Z] 21:40:06     INFO -  PID 14648 | DBG-TEST: head_dbg.js observed a console message: 1675028406370	addons.xpi-utils	DEBUG	shutdown
[task 2023-01-29T21:40:06.705Z] 21:40:06     INFO -  "CONSOLE_MESSAGE: (info) 1675028406370	addons.xpi-utils	DEBUG	shutdown"
[task 2023-01-29T21:40:06.706Z] 21:40:06     INFO -  PID 14648 | DBG-TEST: head_dbg.js observed a console message: 1675028406370	addons.manager	DEBUG	Calling shutdown blocker for SitePermsAddonProvider
[task 2023-01-29T21:40:06.707Z] 21:40:06     INFO -  "CONSOLE_MESSAGE: (info) 1675028406370	addons.manager	DEBUG	Calling shutdown blocker for SitePermsAddonProvider"
[task 2023-01-29T21:40:06.707Z] 21:40:06     INFO -  PID 14648 | DBG-TEST: head_dbg.js observed a console message: 1675028406370	addons.manager	DEBUG	Calling shutdown blocker for GMPProvider
[task 2023-01-29T21:40:06.708Z] 21:40:06     INFO -  "CONSOLE_MESSAGE: (info) 1675028406370	addons.manager	DEBUG	Calling shutdown blocker for GMPProvider"
[task 2023-01-29T21:40:06.708Z] 21:40:06     INFO -  PID 14648 | DBG-TEST: head_dbg.js observed a console message: 1675028406373	addons.manager	DEBUG	Async provider shutdown done
[task 2023-01-29T21:40:06.709Z] 21:40:06     INFO -  "CONSOLE_MESSAGE: (info) 1675028406373	addons.manager	DEBUG	Async provider shutdown done"
[task 2023-01-29T21:40:06.709Z] 21:40:06     INFO -  <<<<<<<
[task 2023-01-29T21:40:06.710Z] 21:40:06     INFO -  TEST-START | devtools/server/tests/xpcshell/test_extension_storage_actor.js
Status: NEW → RESOLVED
Closed: 2 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Summary: Intermittent TV [tier 2] devtools/server/tests/xpcshell/test_extension_storage_actor.js | single tracking bug → Intermittent devtools/server/tests/xpcshell/test_extension_storage_actor.js | single tracking bug
Status: REOPENED → RESOLVED
Closed: 2 years ago8 months ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 8 months ago2 months ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---

This failure is getting high frequent after the landing of bug 1754452.
Retriggers and backfills confirm this
@Alexandre, could you take a look ?

Flags: needinfo?(poirot.alex)
Regressed by: 1754452
No longer regressed by: 1666534, 1810095
Summary: Intermittent devtools/server/tests/xpcshell/test_extension_storage_actor.js | single tracking bug → High frequent devtools/server/tests/xpcshell/test_extension_storage_actor.js | single tracking bug

Set release status flags based on info from the regressing bug 1754452

Set release status flags based on info from the regressing bug 1754452

Adding RDP logs prevents reproducing the failure:
https://treeherder.mozilla.org/jobs?repo=try&selectedTaskRun=VqffpLgFTVu8_9rnffymCQ.0&revision=2c2a371903bcb856327aaa1481de9859fa32d03f

So it is most likely a race condition, but this makes it hard to investigate.

You need to log in before you can comment on or make changes to this bug.