Closed Bug 1903497 Opened 2 years ago Closed 2 years ago

Intermittent toolkit/mozapps/extensions/test/xpcshell/test_sideloads_after_rebuild.js | single tracking bug

Categories

(Toolkit :: Add-ons Manager, defect, P5)

Product:
Toolkit
Component:
Add-ons Manager
Type:
defect

Tracking

()

Status:
RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure, intermittent-testcase)

Filed by: imoraru [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=463083698&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/c9ecj977Qi6B6NuPTSg8-Q/runs/0/artifacts/public/logs/live_backing.log

[task 2024-06-19T06:48:10.187Z] 06:48:10     INFO -  TEST-START | xpcshell.toml:toolkit/mozapps/extensions/test/xpcshell/test_sideloads_after_rebuild.js
[task 2024-06-19T06:48:10.734Z] 06:48:10  WARNING -  TEST-UNEXPECTED-FAIL | xpcshell.toml:toolkit/mozapps/extensions/test/xpcshell/test_sideloads_after_rebuild.js | xpcshell return code: 0
[task 2024-06-19T06:48:10.735Z] 06:48:10     INFO -  TEST-INFO took 546ms
[task 2024-06-19T06:48:10.735Z] 06:48:10     INFO -  >>>>>>>
[task 2024-06-19T06:48:10.736Z] 06:48:10     INFO -  (xpcshell/head.js) | test MAIN run_test pending (1)
[task 2024-06-19T06:48:10.736Z] 06:48:10     INFO -  (xpcshell/head.js) | test run_next_test 0 pending (2)
[task 2024-06-19T06:48:10.736Z] 06:48:10     INFO -  (xpcshell/head.js) | test MAIN run_test finished (2)
[task 2024-06-19T06:48:10.736Z] 06:48:10     INFO -  running event loop
[task 2024-06-19T06:48:10.737Z] 06:48:10     INFO -  xpcshell.toml:toolkit/mozapps/extensions/test/xpcshell/test_sideloads_after_rebuild.js | Starting test_sideloads_after_rebuild
[task 2024-06-19T06:48:10.737Z] 06:48:10     INFO -  (xpcshell/head.js) | test test_sideloads_after_rebuild pending (2)
[task 2024-06-19T06:48:10.738Z] 06:48:10     INFO -  (xpcshell/head.js) | test run_next_test 0 finished (2)
[task 2024-06-19T06:48:10.738Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690308	addons.manager	DEBUG	Application has been upgraded"
[task 2024-06-19T06:48:10.738Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690310	addons.manager	DEBUG	Loaded provider scope for resource://gre/modules/addons/GMPProvider.sys.mjs"
[task 2024-06-19T06:48:10.739Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690311	addons.manager	DEBUG	Loaded provider scope for resource://gre/modules/addons/SitePermsAddonProvider.sys.mjs"
[task 2024-06-19T06:48:10.739Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690311	addons.manager	DEBUG	Starting provider: XPIProvider"
[task 2024-06-19T06:48:10.739Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690311	addons.xpi	DEBUG	startup"
[task 2024-06-19T06:48:10.740Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690311	addons.xpi	INFO	SystemAddonLocation directory is missing"
[task 2024-06-19T06:48:10.740Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690316	addons.xpi	INFO	Removing all system add-on upgrades."
[task 2024-06-19T06:48:10.740Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690316	addons.xpi	DEBUG	checkForChanges"
[task 2024-06-19T06:48:10.740Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690316	addons.xpi	DEBUG	Loaded add-on state: ${}"
[task 2024-06-19T06:48:10.741Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690317	addons.xpi	DEBUG	New add-on legacy-profile@tests.mozilla.org in app-profile"
[task 2024-06-19T06:48:10.741Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690317	addons.xpi	DEBUG	New add-on legacy-user@tests.mozilla.org in app-system-user"
[task 2024-06-19T06:48:10.742Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690317	addons.xpi	DEBUG	New add-on legacy-app@tests.mozilla.org in app-global"
[task 2024-06-19T06:48:10.742Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690318	addons.xpi	DEBUG	New add-on legacy-global@tests.mozilla.org in app-system-share"
[task 2024-06-19T06:48:10.742Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690318	addons.xpi	DEBUG	scanForChanges changed: true, state: {}"
[task 2024-06-19T06:48:10.743Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690321	addons.xpi-utils	DEBUG	Synchronously loading the add-ons database"
[task 2024-06-19T06:48:10.743Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690322	addons.xpi-utils	DEBUG	Starting async load of XPI database /tmp/xpc-profile-80q7yks1/extensions.json"
[task 2024-06-19T06:48:10.743Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690324	addons.xpi-utils	DEBUG	New add-on legacy-profile@tests.mozilla.org installed in app-profile"
[task 2024-06-19T06:48:10.744Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690359	addons.webextension.legacy-profile@tests.mozilla.org	WARN	Loading extension 'legacy-profile@tests.mozilla.org': Reading manifest: Warning processing version: version must be a version string consisting of at most 4 integers of at most 9 digits without leading zeros, and separated with dots"
[task 2024-06-19T06:48:10.744Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690489	addons.xpi-utils	WARN	Disabling foreign installed add-on legacy-profile@tests.mozilla.org in app-profile"
[task 2024-06-19T06:48:10.749Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690489	addons.xpi-utils	DEBUG	New add-on legacy-user@tests.mozilla.org installed in app-system-user"
[task 2024-06-19T06:48:10.749Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690490	addons.webextension.legacy-user@tests.mozilla.org	WARN	Loading extension 'legacy-user@tests.mozilla.org': Reading manifest: Warning processing version: version must be a version string consisting of at most 4 integers of at most 9 digits without leading zeros, and separated with dots"
[task 2024-06-19T06:48:10.749Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690491	addons.xpi-utils	WARN	Disabling foreign installed add-on legacy-user@tests.mozilla.org in app-system-user"
[task 2024-06-19T06:48:10.749Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690492	addons.xpi-utils	DEBUG	New add-on legacy-app@tests.mozilla.org installed in app-global"
[task 2024-06-19T06:48:10.750Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690493	addons.webextension.legacy-app@tests.mozilla.org	WARN	Loading extension 'legacy-app@tests.mozilla.org': Reading manifest: Warning processing version: version must be a version string consisting of at most 4 integers of at most 9 digits without leading zeros, and separated with dots"
[task 2024-06-19T06:48:10.750Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690494	addons.xpi-utils	WARN	Disabling foreign installed add-on legacy-app@tests.mozilla.org in app-global"
[task 2024-06-19T06:48:10.750Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690494	addons.xpi-utils	DEBUG	New add-on legacy-global@tests.mozilla.org installed in app-system-share"
[task 2024-06-19T06:48:10.751Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690495	addons.webextension.legacy-global@tests.mozilla.org	WARN	Loading extension 'legacy-global@tests.mozilla.org': Reading manifest: Warning processing version: version must be a version string consisting of at most 4 integers of at most 9 digits without leading zeros, and separated with dots"
[task 2024-06-19T06:48:10.751Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690496	addons.xpi-utils	WARN	Disabling foreign installed add-on legacy-global@tests.mozilla.org in app-system-share"
[task 2024-06-19T06:48:10.751Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690496	addons.manager	DEBUG	Registering startup change 'installed' for legacy-profile@tests.mozilla.org"
[task 2024-06-19T06:48:10.751Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690498	addons.xpi	DEBUG	Loading bootstrap scope from jar:file:///tmp/xpc-profile-80q7yks1/extensions/legacy-profile@tests.mozilla.org.xpi!/"
[task 2024-06-19T06:48:10.751Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690498	addons.xpi	DEBUG	Calling bootstrap method install on legacy-profile@tests.mozilla.org version profile.0"
[task 2024-06-19T06:48:10.752Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690498	addons.xpi-utils	DEBUG	Make addon app-profile:legacy-profile@tests.mozilla.org visible"
[task 2024-06-19T06:48:10.752Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690498	addons.xpi	DEBUG	Updating XPIState for {"id":"legacy-profile@tests.mozilla.org","syncGUID":"{d9c31b8d-f804-461e-a77b-db040ec70a39}","version":"profile.0","type":"extension","loader":null,"updateURL":null,"installOrigins":null,"manifestVersion":2,"optionsURL":null,"optionsType":null,"optionsBrowserStyle":true,"aboutURL":null,"defaultLocale":{"name":"Generated extension","creator":null,"developers":null,"translators":null,"contributors":null},"visible":true,"active":false,"userDisabled":true,"appDisabled":false,"embedderDisabled":false,"installDate":1718779690279,"updateDate":1718779690279,"applyBackgroundUpdates":1,"path":"/tmp/xpc-profile-80q7yks1/extensions/legacy-profile@tests.mozilla.org.xpi","skinnable":false,"sourceURI":null,"releaseNotesURI":null,"softDisabled":false,"foreignInstall":true,"strictCompatibility":true,"locales":[],"targetApplications":[{"id":"toolkit@mozilla.org","minVersion":null,"maxVersion":null}],"targetPlatforms":[],"signedState":4,"signedTypes":[2],"signedDate":null,"seen":false,"dependencies":[],"incognito":"spanning","userPermissions":{"permissions":[],"origins":[]},"optionalPermissions":{"permissions":[],"origins":[]},"requestedPermissions":{"permissions":[],"origins":[]},"icons":{},"iconURL":null,"blocklistState":0,"blocklistURL":null,"startupData":null,"hidden":false,"installTelemetryInfo":{"source":"app-profile","method":"sideload"},"recommendationState":null,"rootURI":"jar:file:///tmp/xpc-profile-80q7yks1/extensions/legacy-profile@tests.mozilla.org.xpi!/","location":"app-profile"}"
[task 2024-06-19T06:48:10.753Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690499	addons.manager	DEBUG	Registering startup change 'installed' for legacy-user@tests.mozilla.org"
<...>
[task 2024-06-19T06:48:10.888Z] 06:48:10     INFO -  TEST-PASS | xpcshell.toml:toolkit/mozapps/extensions/test/xpcshell/test_sideloads_after_rebuild.js | test_sideloads_after_rebuild - [test_sideloads_after_rebuild : 101] addons installed - 5 == 5
[task 2024-06-19T06:48:10.888Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690616	addons.webextension.sideload-profile@tests.mozilla.org	WARN	Loading extension 'sideload-profile@tests.mozilla.org': Reading manifest: Warning processing version: version must be a version string consisting of at most 4 integers of at most 9 digits without leading zeros, and separated with dots"
[task 2024-06-19T06:48:10.890Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690618	addons.xpi	DEBUG	Calling bootstrap method shutdown on sideload-profile@tests.mozilla.org version sideload-profile.0"
[task 2024-06-19T06:48:10.891Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690618	addons.xpi	DEBUG	Calling bootstrap method shutdown on default-theme@mozilla.org version 1.3"
[task 2024-06-19T06:48:10.892Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690618	addons.manager	DEBUG	before shutdown"
[task 2024-06-19T06:48:10.892Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690618	addons.manager	DEBUG	shutdown"
[task 2024-06-19T06:48:10.893Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690619	addons.manager	DEBUG	Calling shutdown blocker for XPIProvider"
[task 2024-06-19T06:48:10.893Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690619	addons.xpi	DEBUG	shutdown"
[task 2024-06-19T06:48:10.893Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690619	addons.xpi-utils	DEBUG	shutdown"
[task 2024-06-19T06:48:10.894Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690620	addons.xpi-utils	DEBUG	XPI Database saved, setting schema version preference to 36"
[task 2024-06-19T06:48:10.894Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690620	addons.manager	DEBUG	Async provider shutdown done"
[task 2024-06-19T06:48:10.894Z] 06:48:10     INFO -  "**** restart AOM and rebuild XPI database"
[task 2024-06-19T06:48:10.895Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690626	addons.manager	DEBUG	Loaded provider scope for resource://gre/modules/addons/GMPProvider.sys.mjs"
[task 2024-06-19T06:48:10.895Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690626	addons.manager	DEBUG	Loaded provider scope for resource://gre/modules/addons/SitePermsAddonProvider.sys.mjs"
[task 2024-06-19T06:48:10.896Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690626	addons.manager	DEBUG	Starting provider: XPIProvider"
[task 2024-06-19T06:48:10.897Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690626	addons.xpi	DEBUG	startup"
[task 2024-06-19T06:48:10.898Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690626	addons.xpi	INFO	SystemAddonLocation directory is missing"
[task 2024-06-19T06:48:10.898Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690626	addons.xpi	DEBUG	checkForChanges"
[task 2024-06-19T06:48:10.899Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690626	addons.xpi	DEBUG	Loaded add-on state: ${}"
[task 2024-06-19T06:48:10.899Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690626	addons.xpi	DEBUG	New add-on legacy-profile@tests.mozilla.org in app-profile"
[task 2024-06-19T06:48:10.900Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690627	addons.xpi	DEBUG	New add-on sideload-profile@tests.mozilla.org in app-profile"
[task 2024-06-19T06:48:10.900Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690627	addons.xpi	DEBUG	New add-on sideload-profile-2@tests.mozilla.org in app-profile"
[task 2024-06-19T06:48:10.901Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690627	addons.xpi	DEBUG	scanForChanges changed: true, state: {}"
[task 2024-06-19T06:48:10.902Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690630	addons.xpi-utils	DEBUG	Synchronously loading the add-ons database"
[task 2024-06-19T06:48:10.903Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690630	addons.xpi-utils	DEBUG	Starting async load of XPI database /tmp/xpc-profile-80q7yks1/extensions.json"
[task 2024-06-19T06:48:10.904Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690631	addons.xpi-utils	DEBUG	Finished async read of XPI database, parsing..."
[task 2024-06-19T06:48:10.905Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (error) [JavaScript Error: "1718779690631	addons.xpi-utils	ERROR	Failed to load XPI JSON data from profile: Error: Bad JSON file contents(resource://gre/modules/addons/XPIDatabase.sys.mjs?3:2004:21) JS Stack trace: parseDB@resource://gre/modules/addons/XPIDatabase.sys.mjs?3:2004:21
[task 2024-06-19T06:48:10.905Z] 06:48:10     INFO -  asyncLoadDB/this._dbPromise<@resource://gre/modules/addons/XPIDatabase.sys.mjs?3:2127:20
[task 2024-06-19T06:48:10.905Z] 06:48:10     INFO -  awaitPromise@resource://gre/modules/addons/XPIProvider.sys.mjs?3:215:15
[task 2024-06-19T06:48:10.905Z] 06:48:10     INFO -  syncLoadDB@resource://gre/modules/addons/XPIDatabase.sys.mjs?3:1981:30
[task 2024-06-19T06:48:10.905Z] 06:48:10     INFO -  checkForChanges@resource://gre/modules/addons/XPIProvider.sys.mjs?3:3119:32
[task 2024-06-19T06:48:10.906Z] 06:48:10     INFO -  startup@resource://gre/modules/addons/XPIProvider.sys.mjs?3:2526:12
[task 2024-06-19T06:48:10.906Z] 06:48:10     INFO -  callProvider@AddonManager.sys.mjs:226:31
[task 2024-06-19T06:48:10.906Z] 06:48:10     INFO -  _startProvider@AddonManager.sys.mjs:535:17
[task 2024-06-19T06:48:10.906Z] 06:48:10     INFO -  startup@AddonManager.sys.mjs:748:14
[task 2024-06-19T06:48:10.907Z] 06:48:10     INFO -  startup@AddonManager.sys.mjs:3645:26
[task 2024-06-19T06:48:10.907Z] 06:48:10     INFO -  observe@amManager.sys.mjs:73:29
[task 2024-06-19T06:48:10.907Z] 06:48:10     INFO -  promiseStartupManager@AddonTestUtils.sys.mjs:853:34
[task 2024-06-19T06:48:10.907Z] 06:48:10     INFO -  test_sideloads_after_rebuild@test_sideloads_after_rebuild.js:128:9
[task 2024-06-19T06:48:10.908Z] 06:48:10     INFO -  _do_main@head.js:245:6
[task 2024-06-19T06:48:10.908Z] 06:48:10     INFO -  _execute_test@head.js:596:5
[task 2024-06-19T06:48:10.908Z] 06:48:10     INFO -  @-e:1:1" {file: "resource://gre/modules/Log.sys.mjs" line: 722}]
[task 2024-06-19T06:48:10.908Z] 06:48:10     INFO -  append@resource://gre/modules/Log.sys.mjs:722:12
[task 2024-06-19T06:48:10.908Z] 06:48:10     INFO -  log@resource://gre/modules/Log.sys.mjs:376:16
[task 2024-06-19T06:48:10.909Z] 06:48:10     INFO -  error@resource://gre/modules/Log.sys.mjs:384:10
[task 2024-06-19T06:48:10.909Z] 06:48:10     INFO -  parseDB@resource://gre/modules/addons/XPIDatabase.sys.mjs?3:2067:16
[task 2024-06-19T06:48:10.909Z] 06:48:10     INFO -  asyncLoadDB/this._dbPromise<@resource://gre/modules/addons/XPIDatabase.sys.mjs?3:2127:20
[task 2024-06-19T06:48:10.909Z] 06:48:10     INFO -  awaitPromise@resource://gre/modules/addons/XPIProvider.sys.mjs?3:215:15
[task 2024-06-19T06:48:10.909Z] 06:48:10     INFO -  syncLoadDB@resource://gre/modules/addons/XPIDatabase.sys.mjs?3:1981:30
[task 2024-06-19T06:48:10.909Z] 06:48:10     INFO -  checkForChanges@resource://gre/modules/addons/XPIProvider.sys.mjs?3:3119:32
[task 2024-06-19T06:48:10.909Z] 06:48:10     INFO -  startup@resource://gre/modules/addons/XPIProvider.sys.mjs?3:2526:12
[task 2024-06-19T06:48:10.910Z] 06:48:10     INFO -  callProvider@resource://gre/modules/AddonManager.sys.mjs:226:31
[task 2024-06-19T06:48:10.910Z] 06:48:10     INFO -  _startProvider@resource://gre/modules/AddonManager.sys.mjs:535:17
[task 2024-06-19T06:48:10.910Z] 06:48:10     INFO -  startup@resource://gre/modules/AddonManager.sys.mjs:748:14
[task 2024-06-19T06:48:10.911Z] 06:48:10     INFO -  startup@resource://gre/modules/AddonManager.sys.mjs:3645:26
[task 2024-06-19T06:48:10.911Z] 06:48:10     INFO -  observe@resource://gre/modules/amManager.sys.mjs:73:29
[task 2024-06-19T06:48:10.911Z] 06:48:10     INFO -  promiseStartupManager@resource://testing-common/AddonTestUtils.sys.mjs:853:34
[task 2024-06-19T06:48:10.911Z] 06:48:10     INFO -  test_sideloads_after_rebuild@/builds/worker/workspace/build/tests/xpcshell/tests/toolkit/mozapps/extensions/test/xpcshell/test_sideloads_after_rebuild.js:128:9
[task 2024-06-19T06:48:10.911Z] 06:48:10     INFO -  _do_main@/builds/worker/workspace/build/tests/xpcshell/head.js:245:6
[task 2024-06-19T06:48:10.911Z] 06:48:10     INFO -  _execute_test@/builds/worker/workspace/build/tests/xpcshell/head.js:596:5
[task 2024-06-19T06:48:10.911Z] 06:48:10     INFO -  @-e:1:1
[task 2024-06-19T06:48:10.911Z] 06:48:10     INFO -  "
[task 2024-06-19T06:48:10.911Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690631	addons.xpi-utils	WARN	Rebuilding add-ons database from installed extensions."
[task 2024-06-19T06:48:10.912Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690631	addons.xpi-utils	DEBUG	New add-on legacy-profile@tests.mozilla.org installed in app-profile"
[task 2024-06-19T06:48:10.912Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690637	addons.webextension.legacy-profile@tests.mozilla.org	WARN	Loading extension 'legacy-profile@tests.mozilla.org': Reading manifest: Warning processing version: version must be a version string consisting of at most 4 integers of at most 9 digits without leading zeros, and separated with dots"
<...>
[task 2024-06-19T06:48:10.951Z] 06:48:10     INFO -  TEST-PASS | xpcshell.toml:toolkit/mozapps/extensions/test/xpcshell/test_sideloads_after_rebuild.js | test_sideloads_after_rebuild - [test_sideloads_after_rebuild : 146] true == true
[task 2024-06-19T06:48:10.951Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690655	addons.xpi	DEBUG	Calling bootstrap method shutdown on sideload-profile@tests.mozilla.org version sideload-profile.0"
[task 2024-06-19T06:48:10.951Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690655	addons.xpi	DEBUG	Calling bootstrap method shutdown on sideload-profile-2@tests.mozilla.org version sideload-profile.0"
[task 2024-06-19T06:48:10.952Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690656	addons.xpi	DEBUG	Calling bootstrap method shutdown on legacy-profile@tests.mozilla.org version profile.0"
[task 2024-06-19T06:48:10.952Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690656	addons.xpi	DEBUG	Calling bootstrap method shutdown on default-theme@mozilla.org version 1.3"
[task 2024-06-19T06:48:10.953Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690656	addons.manager	DEBUG	before shutdown"
[task 2024-06-19T06:48:10.953Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690656	addons.manager	DEBUG	shutdown"
[task 2024-06-19T06:48:10.953Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690656	addons.manager	DEBUG	Calling shutdown blocker for XPIProvider"
[task 2024-06-19T06:48:10.954Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690656	addons.xpi	DEBUG	shutdown"
[task 2024-06-19T06:48:10.954Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690656	addons.xpi-utils	DEBUG	shutdown"
[task 2024-06-19T06:48:10.954Z] 06:48:10     INFO -  (xpcshell/head.js) | test run_next_test 1 pending (2)
[task 2024-06-19T06:48:10.955Z] 06:48:10     INFO -  (xpcshell/head.js) | test test_sideloads_after_rebuild finished (2)
[task 2024-06-19T06:48:10.955Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690657	addons.xpi-utils	DEBUG	XPI Database saved, setting schema version preference to 36"
[task 2024-06-19T06:48:10.955Z] 06:48:10     INFO -  "CONSOLE_MESSAGE: (info) 1718779690657	addons.manager	DEBUG	Async provider shutdown done"
[task 2024-06-19T06:48:10.956Z] 06:48:10     INFO -  (xpcshell/head.js) | test run_next_test 1 finished (1)
[task 2024-06-19T06:48:10.956Z] 06:48:10     INFO -  exiting test
[task 2024-06-19T06:48:10.956Z] 06:48:10     INFO -  "Force a GC"
[task 2024-06-19T06:48:10.957Z] 06:48:10  WARNING -  TEST-UNEXPECTED-FAIL | xpcshell.toml:toolkit/mozapps/extensions/test/xpcshell/test_sideloads_after_rebuild.js | test_sideloads_after_rebuild - [test_sideloads_after_rebuild : 266] A promise chain failed to handle a rejection: Phase "IOUtils: waiting for profileBeforeChange IO to complete" is finished, it is too late to register completion condition "Flush WebExtension StartupCache" - stack: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:718:15
[task 2024-06-19T06:48:10.957Z] 06:48:10     INFO -  save@resource://gre/modules/ExtensionParent.sys.mjs:2253:35
[task 2024-06-19T06:48:10.957Z] 06:48:10     INFO -  set@resource://gre/modules/ExtensionParent.sys.mjs:2192:18
[task 2024-06-19T06:48:10.958Z] 06:48:10     INFO -  ensureDOMPromiseRejectionsProcessed@resource://testing-common/PromiseTestUtils.sys.mjs:115:17
[task 2024-06-19T06:48:10.958Z] 06:48:10     INFO -  _execute_test@/builds/worker/workspace/build/tests/xpcshell/head.js:721:23
[task 2024-06-19T06:48:10.958Z] 06:48:10     INFO -  @-e:1:1
[task 2024-06-19T06:48:10.959Z] 06:48:10     INFO -  Rejection date: Wed Jun 19 2024 06:48:10 GMT+0000 (Coordinated Universal Time) - false == true
[task 2024-06-19T06:48:10.959Z] 06:48:10     INFO -  resource://testing-common/PromiseTestUtils.sys.mjs:assertNoUncaughtRejections:266
[task 2024-06-19T06:48:10.959Z] 06:48:10     INFO -  /builds/worker/workspace/build/tests/xpcshell/head.js:_execute_test:722
[task 2024-06-19T06:48:10.960Z] 06:48:10     INFO -  -e:null:1
[task 2024-06-19T06:48:10.960Z] 06:48:10     INFO -  exiting test
[task 2024-06-19T06:48:10.960Z] 06:48:10     INFO -  PID 25877 | JavaScript error: /builds/worker/workspace/build/tests/xpcshell/head.js, line 869: NS_ERROR_ABORT:
[task 2024-06-19T06:48:10.961Z] 06:48:10     INFO -  PID 25877 | JavaScript error: resource://gre/modules/AsyncShutdown.sys.mjs, line 718: Error: Phase "IOUtils: waiting for profileBeforeChange IO to complete" is finished, it is too late to register completion condition "Flush WebExtension StartupCache"
[task 2024-06-19T06:48:10.961Z] 06:48:10     INFO -  <<<<<<<
[task 2024-06-19T06:48:10.961Z] 06:48:10     INFO -  TEST-START | netwerk/test/unit/test_http3_early_hint_listener.js

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit BugBot documentation.

Status: NEW → RESOLVED
Closed: 2 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.