Open
Bug 1942712
Opened 26 days ago
Updated 19 days ago
Intermittent toolkit/components/extensions/test/xpcshell/test_ext_userScripts_mv3_worlds.js | single tracking bug
Categories
(WebExtensions :: General, defect, P5)
WebExtensions
General
Tracking
(Not tracked)
NEW
People
(Reporter: intermittent-bug-filer, Unassigned)
Details
(Keywords: intermittent-failure, intermittent-testcase)
Filed by: agoloman [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=490964009&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/U0YFXAFWSw2LcGRlrkJQbQ/runs/0/artifacts/public/logs/live_backing.log
[task 2025-01-20T21:53:51.007Z] 21:53:51 INFO - TEST-PASS | xpcshell.toml:toolkit/components/extensions/test/xpcshell/test_ext_secfetch.js | took 12017ms
[task 2025-01-20T21:53:51.076Z] 21:53:51 INFO - Cleaning up profile for /builds/worker/workspace/build/tests/xpcshell/tests/toolkit/components/extensions/test/xpcshell/test_ext_secfetch.js folder: /data/local/tmp/test_root/xpc/p/287e4541-a131-4a6a-a439-429358c9bd8f
[task 2025-01-20T21:53:51.268Z] 21:53:51 INFO - TEST-START | xpcshell.toml:toolkit/mozapps/extensions/test/xpcshell/test_upgrade.js
[task 2025-01-20T21:53:51.268Z] 21:53:51 INFO - TEST-SKIP | xpcshell.toml:toolkit/mozapps/extensions/test/xpcshell/test_upgrade.js | took 0ms
[task 2025-01-20T21:53:51.268Z] 21:53:51 INFO - Retrying tests that failed when run in parallel.
[task 2025-01-20T21:53:51.725Z] 21:53:51 INFO - TEST-START | xpcshell.toml:toolkit/components/extensions/test/xpcshell/test_ext_userScripts_mv3_worlds.js
[task 2025-01-20T21:53:51.770Z] 21:53:51 INFO - adb launch_application: am startservice -W -n 'org.mozilla.geckoview.test_runner/org.mozilla.geckoview.test_runner.XpcshellTestRunnerService$i0' -a android.intent.action.MAIN --es env0 XPCOM_DEBUG_BREAK=stack-and-abort --es env1 MOZ_CRASHREPORTER=1 --es env2 MOZ_CRASHREPORTER_NO_REPORT=1 --es env3 MOZ_DISABLE_NONLOCAL_CONNECTIONS=1 --es env4 MOZ_DEVELOPER_REPO_DIR=/builds/worker/checkouts/gecko --es env5 MOZ_DEVELOPER_OBJ_DIR=/builds/worker/workspace/obj-build --es env6 MOZ_DISABLE_CONTENT_SANDBOX=1 --es env7 MOZ_FETCHES_DIR=/builds/worker/fetches --es env8 MOZ_DISABLE_SOCKET_PROCESS=1 --es env9 LD_LIBRARY_PATH=/data/local/tmp/test_root/xpcb --es env10 MOZ_LINKER_CACHE=/data/local/tmp/test_root/xpcb --es env11 GRE_HOME=/data/local/tmp/test_root/xpcb --es env12 XPCSHELL_TEST_PROFILE_DIR=/data/local/tmp/test_root/xpc/p/5bd8a6b3-15e4-4103-ac82-d2d69475c97f --es env13 HOME=/data/local/tmp/test_root/xpc/p --es env14 XPCSHELL_TEST_TEMP_DIR=/data/local/tmp/test_root/xpc/tmp/78e30a5d-9aae-43ee-b43e-5048c71db470 --es env15 MOZ_ANDROID_DATA_DIR=/data/local/tmp/test_root/xpcb --es env16 MOZ_IN_AUTOMATION=1 --es env17 MOZ_ANDROID_CPU_ABI=x86_64 --es env18 MOZHTTP2_PORT=34671 --es env19 MOZNODE_EXEC_PORT=35709 --es env20 MOZHTTP3_PORT=37324 --es env21 MOZHTTP3_PORT_FAILED=37220 --es env22 MOZHTTP3_PORT_ECH=48780 --es env23 MOZHTTP3_PORT_PROXY=59584 --es env24 MOZHTTP3_PORT_NO_RESPONSE=41546 --es env25 MOZHTTP3_ECH=AE3+DQBJBwAgACBbBx5sgdOu+o+G7oeTwuNnmuuQ6Q+QE4v2eiZNeChHPgAQAAEAAQABAAMAAgABAAIAA0AOcHVibGljLmV4YW1wbGUAAA== --es env26 MOZ_HTTP3_SERVER_PATH=/builds/worker/fetches/hostutils/http3server --es env27 MOZ_HTTP3_CERT_DB_PATH=/builds/worker/workspace/build/tests/xpcshell/http3server/http3serverDB --es env28 TMPDIR=/data/local/tmp/test_root/xpc/p/5bd8a6b3-15e4-4103-ac82-d2d69475c97f --es env29 XPCSHELL_MINIDUMP_DIR=/data/local/tmp/test_root/xpc/minidumps/5bd8a6b3-15e4-4103-ac82-d2d69475c97f --es arg0 -g --es arg1 /data/local/tmp/test_root/xpcb --es arg2 --greomni --es arg3 /data/local/tmp/test_root/xpcb/geckoview-test_runner.apk --es arg4 -m --es arg5 -e --es arg6 'const _HEAD_JS_PATH = "/data/local/tmp/test_root/xpc/head.js";' --es arg7 -e --es arg8 'const _MOZINFO_JS_PATH = "/data/local/tmp/test_root/xpc/p/5bd8a6b3-15e4-4103-ac82-d2d69475c97f/mozinfo.json";' --es arg9 -e --es arg10 'const _PREFS_FILE = "/data/local/tmp/test_root/xpc/tmp/78e30a5d-9aae-43ee-b43e-5048c71db470/user.js";' --es arg11 -e --es arg12 'const _TESTING_MODULES_DIR = "/data/local/tmp/test_root/xpc/m";' --es arg13 -f --es arg14 /data/local/tmp/test_root/xpc/head.js --es arg15 -e --es arg16 'const _HEAD_FILES = ["/data/local/tmp/test_root/xpc/toolkit/components/extensions/test/xpcshell/head.js", "/data/local/tmp/test_root/xpc/toolkit/components/extensions/test/xpcshell/head_telemetry.js", "/data/local/tmp/test_root/xpc/toolkit/components/extensions/test/xpcshell/head_sync.js", "/data/local/tmp/test_root/xpc/toolkit/components/extensions/test/xpcshell/head_storage.js"];' --es arg17 -e --es arg18 'const _JSDEBUGGER_PORT = 0;' --es arg19 -e --es arg20 'const _TEST_CWD = "/data/local/tmp/test_root/xpc/toolkit/components/extensions/test/xpcshell";' --es arg21 -e --es arg22 'const _TEST_FILE = ["test_ext_userScripts_mv3_worlds.js"];' --es arg23 -e --es arg24 'const _TEST_NAME = "xpcshell.toml:toolkit/components/extensions/test/xpcshell/test_ext_userScripts_mv3_worlds.js";' --es arg25 -e --es arg26 '_execute_test(); quit(0);' --es out_file /data/local/tmp/test_root/xpc/logs/xpcshell-498f36cf-b45e-4e2c-9448-769d88c55a30.log
[task 2025-01-20T21:53:51.985Z] 21:53:51 INFO - remotexpcshelltests.py | xpcshell.toml:toolkit/components/extensions/test/xpcshell/test_ext_userScripts_mv3_worlds.js | 31404 | Launched Test App
[task 2025-01-20T21:54:03.670Z] 21:54:03 INFO - remotexpcshelltests.py | xpcshell.toml:toolkit/components/extensions/test/xpcshell/test_ext_userScripts_mv3_worlds.js | 31404 | Application ran for: 0:00:11.944967
[task 2025-01-20T21:54:03.735Z] 21:54:03 WARNING - TEST-UNEXPECTED-FAIL | xpcshell.toml:toolkit/components/extensions/test/xpcshell/test_ext_userScripts_mv3_worlds.js | xpcshell return code: 0
[task 2025-01-20T21:54:03.735Z] 21:54:03 INFO - TEST-INFO took 12010ms
[task 2025-01-20T21:54:03.735Z] 21:54:03 INFO - >>>>>>>
[task 2025-01-20T21:54:03.735Z] 21:54:03 INFO - (xpcshell/head.js) | test MAIN run_test pending (1)
[task 2025-01-20T21:54:03.735Z] 21:54:03 INFO - (xpcshell/head.js) | test run_next_test 0 pending (2)
[task 2025-01-20T21:54:03.736Z] 21:54:03 INFO - (xpcshell/head.js) | test MAIN run_test finished (2)
[task 2025-01-20T21:54:03.736Z] 21:54:03 INFO - running event loop
[task 2025-01-20T21:54:03.736Z] 21:54:03 INFO - xpcshell.toml:toolkit/components/extensions/test/xpcshell/test_ext_userScripts_mv3_worlds.js | Starting setup check_remote
[task 2025-01-20T21:54:03.736Z] 21:54:03 INFO - (xpcshell/head.js) | test check_remote pending (2)
[task 2025-01-20T21:54:03.736Z] 21:54:03 INFO - TEST-PASS | xpcshell.toml:toolkit/components/extensions/test/xpcshell/test_ext_userScripts_mv3_worlds.js | check_remote - [check_remote : 1] useRemoteWebExtensions matches - false == false
[task 2025-01-20T21:54:03.736Z] 21:54:03 INFO - TEST-PASS | xpcshell.toml:toolkit/components/extensions/test/xpcshell/test_ext_userScripts_mv3_worlds.js | check_remote - [check_remote : 1] testing from extension process - true == true
[task 2025-01-20T21:54:03.736Z] 21:54:03 INFO - (xpcshell/head.js) | test run_next_test 0 finished (2)
[task 2025-01-20T21:54:03.736Z] 21:54:03 INFO - (xpcshell/head.js) | test run_next_test 1 pending (2)
[task 2025-01-20T21:54:03.736Z] 21:54:03 INFO - (xpcshell/head.js) | test check_remote finished (2)
[task 2025-01-20T21:54:03.737Z] 21:54:03 INFO - xpcshell.toml:toolkit/components/extensions/test/xpcshell/test_ext_userScripts_mv3_worlds.js | Starting setup
[task 2025-01-20T21:54:03.737Z] 21:54:03 INFO - (xpcshell/head.js) | test pending (2)
[task 2025-01-20T21:54:03.737Z] 21:54:03 INFO - (xpcshell/head.js) | test run_next_test 1 finished (2)
[task 2025-01-20T21:54:03.737Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410032226 addons.manager DEBUG Application has been upgraded"
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410032227 addons.manager DEBUG Starting provider: XPIProvider"
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410032227 addons.xpi DEBUG startup"
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410032228 addons.xpi INFO SystemAddonLocation directory is missing"
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410032236 addons.xpi INFO Removing all system add-on upgrades."
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410032237 addons.xpi DEBUG checkForChanges"
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410032237 addons.xpi DEBUG Loaded add-on state: ${}"
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410032238 addons.xpi DEBUG scanForChanges changed: false, state: {}"
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410032239 addons.xpi DEBUG Empty XPI database, setting schema version preference to 37"
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410032239 addons.xpi DEBUG No changes found"
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410032244 addons.manager DEBUG Registering shutdown blocker for XPIProvider"
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410032245 addons.manager DEBUG Provider finished startup: XPIProvider"
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410032246 addons.manager DEBUG Completed startup sequence"
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - (xpcshell/head.js) | test run_next_test 2 pending (2)
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - (xpcshell/head.js) | test finished (2)
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - xpcshell.toml:toolkit/components/extensions/test/xpcshell/test_ext_userScripts_mv3_worlds.js | Starting default_USER_SCRIPT_world_behavior
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - (xpcshell/head.js) | test default_USER_SCRIPT_world_behavior pending (2)
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - (xpcshell/head.js) | test run_next_test 2 finished (2)
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (error) [JavaScript Error: "Could not download addons-mlbf.bin" {file: "resource://services-settings/Attachments.sys.mjs" line: 17}]
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - DownloadError@resource://services-settings/Attachments.sys.mjs:17:5
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - #fetchAttachment@resource://services-settings/Attachments.sys.mjs:456:11
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - async*download@resource://services-settings/Attachments.sys.mjs:171:33
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - download@resource://services-settings/RemoteSettingsClient.sys.mjs:233:26
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - _getMLBFData@resource://gre/modules/Blocklist.sys.mjs:931:40
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - _fetchMLBF@resource://gre/modules/Blocklist.sys.mjs:951:12
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - _updateMLBF/updatePromise<@resource://gre/modules/Blocklist.sys.mjs:1041:49
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - async*_updateMLBF@resource://gre/modules/Blocklist.sys.mjs:1052:7
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - getEntry@resource://gre/modules/Blocklist.sys.mjs:1196:18
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - getAddonBlocklistEntry@resource://gre/modules/Blocklist.sys.mjs:1550:36
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - findBlocklistEntry@resource://gre/modules/addons/XPIDatabase.sys.mjs:687:27
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - updateBlocklistState@resource://gre/modules/addons/XPIDatabase.sys.mjs:699:28
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - loadManifest@resource://gre/modules/addons/XPIInstall.sys.mjs:743:17
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - async*loadManifest@resource://gre/modules/addons/XPIInstall.sys.mjs:1584:28
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - init@resource://gre/modules/addons/XPIInstall.sys.mjs:2240:18
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - createLocalInstall@resource://gre/modules/addons/XPIInstall.sys.mjs:3290:20
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - getInstallForFile@resource://gre/modules/addons/XPIInstall.sys.mjs:4589:25
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - XPIProvider[meth]@resource://gre/modules/addons/XPIProvider.sys.mjs:3338:39
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - promiseCallProvider@resource://gre/modules/AddonManager.sys.mjs:251:31
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - getInstallForFile/<@resource://gre/modules/AddonManager.sys.mjs:1816:29
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - getInstallForFile@resource://gre/modules/AddonManager.sys.mjs:1830:7
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - getInstallForFile@resource://gre/modules/AddonManager.sys.mjs:4273:33
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - _install@resource://testing-common/ExtensionXPCShellUtils.sys.mjs:555:32
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - async*startup@resource://testing-common/ExtensionXPCShellUtils.sys.mjs:593:17
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - default_USER_SCRIPT_world_behavior@test_ext_userScripts_mv3_worlds.js:81:19
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - async*_run_next_test/<@/data/local/tmp/test_root/xpc/head.js:1759:22
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - _run_next_test@/data/local/tmp/test_root/xpc/head.js:1759:38
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - run@/data/local/tmp/test_root/xpc/head.js:808:9
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - _do_main@/data/local/tmp/test_root/xpc/head.js:245:6
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - _execute_test@/data/local/tmp/test_root/xpc/head.js:596:5
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - @-e:1:1
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - "
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410032591 addons.repository DEBUG cacheAddons: enabled false IDs ["@default_USER_SCRIPT_world_behavior"]"
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410032591 addons.xpi-utils DEBUG Starting async load of XPI database /data/local/tmp/test_root/xpc/p/5bd8a6b3-15e4-4103-ac82-d2d69475c97f/extensions.json"
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410032603 addons.xpi-utils DEBUG Rebuilding XPI database with no extensions"
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410032606 addons.xpi DEBUG Starting install of @default_USER_SCRIPT_world_behavior from file:///data/local/tmp/test_root/xpc/p/5bd8a6b3-15e4-4103-ac82-d2d69475c97f/temp/generated-extension.xpi"
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410032615 addons.xpi DEBUG Addon @default_USER_SCRIPT_world_behavior will be installed as a packed xpi"
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410032619 addons.xpi-utils DEBUG Make addon app-profile:@default_USER_SCRIPT_world_behavior visible"
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410032620 addons.xpi DEBUG XPIStates adding add-on @default_USER_SCRIPT_world_behavior in {"addons":{},"staged":{},"path":"/data/local/tmp/test_root/xpc/p/5bd8a6b3-15e4-4103-ac82-d2d69475c97f/extensions"}: /data/local/tmp/test_root/xpc/p/5bd8a6b3-15e4-4103-ac82-d2d69475c97f/extensions/@default_USER_SCRIPT_world_behavior.xpi"
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410032621 addons.xpi DEBUG Updating XPIState for {"id":"@default_USER_SCRIPT_world_behavior","syncGUID":"{d0a77f3e-f296-4c57-b1ca-498137e83a6d}","version":"1.0","type":"extension","loader":null,"updateURL":null,"installOrigins":null,"manifestVersion":3,"optionsURL":null,"optionsType":null,"optionsBrowserStyle":true,"aboutURL":null,"defaultLocale":{"name":"Generated extension","creator":null,"developers":null,"translators":null,"contributors":null},"visible":true,"active":true,"userDisabled":false,"appDisabled":false,"embedderDisabled":false,"installDate":1737410032604,"updateDate":1737410032604,"applyBackgroundUpdates":1,"path":"/data/local/tmp/test_root/xpc/p/5bd8a6b3-15e4-4103-ac82-d2d69475c97f/extensions/@default_USER_SCRIPT_world_behavior.xpi","skinnable":false,"sourceURI":"file:///data/local/tmp/test_root/xpc/p/5bd8a6b3-15e4-4103-ac82-d2d69475c97f/temp/generated-extension.xpi","releaseNotesURI":null,"softDisabled":false,"foreignInstall":false,"strictCompatibility":true,"locales":[],"targetApplications":[{"id":"toolkit@mozilla.org","minVersion":null,"maxVersion":null}],"targetPlatforms":[],"signedState":4,"signedTypes":[2],"signedDate":null,"seen":true,"dependencies":[],"incognito":"spanning","userPermissions":{"permissions":[],"origins":[]},"optionalPermissions":{"permissions":["userScripts"],"origins":["*://example.com/*"]},"requestedPermissions":{"permissions":[],"origins":["*://example.com/*"]},"icons":{},"iconURL":null,"blocklistAttentionDismissed":false,"blocklistState":0,"blocklistURL":null,"startupData":null,"hidden":false,"installTelemetryInfo":null,"recommendationState":null,"rootURI":"jar:file:///data/local/tmp/test_root/xpc/p/5bd8a6b3-15e4-4103-ac82-d2d69475c97f/extensions/@default_USER_SCRIPT_world_behavior.xpi!/","location":"app-profile"}"
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410032622 addons.xpi DEBUG Install of file:///data/local/tmp/test_root/xpc/p/5bd8a6b3-15e4-4103-ac82-d2d69475c97f/temp/generated-extension.xpi completed."
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410032623 addons.xpi DEBUG Loading bootstrap scope from jar:file:///data/local/tmp/test_root/xpc/p/5bd8a6b3-15e4-4103-ac82-d2d69475c97f/extensions/@default_USER_SCRIPT_world_behavior.xpi!/"
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410032624 addons.xpi DEBUG Calling bootstrap method install on @default_USER_SCRIPT_world_behavior version 1.0"
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410032624 addons.xpi DEBUG Calling bootstrap method startup on @default_USER_SCRIPT_world_behavior version 1.0"
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - "Extension attached"
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410032933 addons.xpi DEBUG removeTemporaryFile: file:///data/local/tmp/test_root/xpc/p/5bd8a6b3-15e4-4103-ac82-d2d69475c97f/temp/generated-extension.xpi does not own temp file"
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410038363 addons.xpi-utils DEBUG XPI Database saved, setting schema version preference to 37"
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (error) [JavaScript Error: "Content-Security-Policy: The page’s settings blocked a JavaScript eval (script-src) from being executed because it violates the following directive: “script-src 'self' 'wasm-unsafe-eval'” (Missing 'unsafe-eval')" {file: "moz-extension://f0950e08-1b1e-41e8-81ec-e2abd823d702/world_checker.js" line: 14}]"
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - TEST-PASS | xpcshell.toml:toolkit/components/extensions/test/xpcshell/test_ext_userScripts_mv3_worlds.js | default_USER_SCRIPT_world_behavior - [default_USER_SCRIPT_world_behavior : 85] browser (extension APIs) should be undefined - true == true
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - TEST-PASS | xpcshell.toml:toolkit/components/extensions/test/xpcshell/test_ext_userScripts_mv3_worlds.js | default_USER_SCRIPT_world_behavior - [default_USER_SCRIPT_world_behavior : 86] eval() should be blocked by default in the USER_SCRIPT world - "call to eval() blocked by CSP" == "call to eval() blocked by CSP"
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410038699 addons.xpi DEBUG Calling bootstrap method shutdown on @default_USER_SCRIPT_world_behavior version 1.0"
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - (xpcshell/head.js) | test run_next_test 3 pending (2)
[task 2025-01-20T21:54:03.743Z] 21:54:03 INFO - (xpcshell/head.js) | test default_USER_SCRIPT_world_behavior finished (2)
[task 2025-01-20T21:54:03.744Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410038754 addons.xpi DEBUG Calling bootstrap method uninstall on @default_USER_SCRIPT_world_behavior version 1.0"
[task 2025-01-20T21:54:03.744Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410038756 addons.xpi DEBUG Disabling XPIState for @default_USER_SCRIPT_world_behavior"
[task 2025-01-20T21:54:03.744Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410038760 addons.xpi DEBUG uninstallAddon: flushing jar cache /data/local/tmp/test_root/xpc/p/5bd8a6b3-15e4-4103-ac82-d2d69475c97f/extensions/@default_USER_SCRIPT_world_behavior.xpi for addon @default_USER_SCRIPT_world_behavior"
[task 2025-01-20T21:54:03.744Z] 21:54:03 INFO - xpcshell.toml:toolkit/components/extensions/test/xpcshell/test_ext_userScripts_mv3_worlds.js | Starting multiple_scripts_share_same_default_world
[task 2025-01-20T21:54:03.744Z] 21:54:03 INFO - (xpcshell/head.js) | test multiple_scripts_share_same_default_world pending (2)
[task 2025-01-20T21:54:03.744Z] 21:54:03 INFO - (xpcshell/head.js) | test run_next_test 3 finished (2)
[task 2025-01-20T21:54:03.744Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410038862 addons.repository DEBUG cacheAddons: enabled false IDs ["@multiple_scripts_share_same_default_world"]"
[task 2025-01-20T21:54:03.744Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410038864 addons.xpi DEBUG Starting install of @multiple_scripts_share_same_default_world from file:///data/local/tmp/test_root/xpc/p/5bd8a6b3-15e4-4103-ac82-d2d69475c97f/temp/generated-extension.xpi"
[task 2025-01-20T21:54:03.745Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410038873 addons.xpi DEBUG Addon @multiple_scripts_share_same_default_world will be installed as a packed xpi"
[task 2025-01-20T21:54:03.745Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410038877 addons.xpi-utils DEBUG Make addon app-profile:@multiple_scripts_share_same_default_world visible"
[task 2025-01-20T21:54:03.745Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410038877 addons.xpi DEBUG XPIStates adding add-on @multiple_scripts_share_same_default_world in {"addons":{},"staged":{},"path":"/data/local/tmp/test_root/xpc/p/5bd8a6b3-15e4-4103-ac82-d2d69475c97f/extensions"}: /data/local/tmp/test_root/xpc/p/5bd8a6b3-15e4-4103-ac82-d2d69475c97f/extensions/@multiple_scripts_share_same_default_world.xpi"
[task 2025-01-20T21:54:03.746Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410038878 addons.xpi DEBUG Updating XPIState for {"id":"@multiple_scripts_share_same_default_world","syncGUID":"{c8a83d11-7cc6-44b2-bb0d-e56daf029e71}","version":"1.0","type":"extension","loader":null,"updateURL":null,"installOrigins":null,"manifestVersion":3,"optionsURL":null,"optionsType":null,"optionsBrowserStyle":true,"aboutURL":null,"defaultLocale":{"name":"Generated extension","creator":null,"developers":null,"translators":null,"contributors":null},"visible":true,"active":true,"userDisabled":false,"appDisabled":false,"embedderDisabled":false,"installDate":1737410038863,"updateDate":1737410038863,"applyBackgroundUpdates":1,"path":"/data/local/tmp/test_root/xpc/p/5bd8a6b3-15e4-4103-ac82-d2d69475c97f/extensions/@multiple_scripts_share_same_default_world.xpi","skinnable":false,"sourceURI":"file:///data/local/tmp/test_root/xpc/p/5bd8a6b3-15e4-4103-ac82-d2d69475c97f/temp/generated-extension.xpi","releaseNotesURI":null,"softDisabled":false,"foreignInstall":false,"strictCompatibility":true,"locales":[],"targetApplications":[{"id":"toolkit@mozilla.org","minVersion":null,"maxVersion":null}],"targetPlatforms":[],"signedState":4,"signedTypes":[2],"signedDate":null,"seen":true,"dependencies":[],"incognito":"spanning","userPermissions":{"permissions":[],"origins":[]},"optionalPermissions":{"permissions":["userScripts"],"origins":["*://example.com/*"]},"requestedPermissions":{"permissions":[],"origins":["*://example.com/*"]},"icons":{},"iconURL":null,"blocklistAttentionDismissed":false,"blocklistState":0,"blocklistURL":null,"startupData":null,"hidden":false,"installTelemetryInfo":null,"recommendationState":null,"rootURI":"jar:file:///data/local/tmp/test_root/xpc/p/5bd8a6b3-15e4-4103-ac82-d2d69475c97f/extensions/@multiple_scripts_share_same_default_world.xpi!/","location":"app-profile"}"
[task 2025-01-20T21:54:03.746Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410038879 addons.xpi DEBUG Install of file:///data/local/tmp/test_root/xpc/p/5bd8a6b3-15e4-4103-ac82-d2d69475c97f/temp/generated-extension.xpi completed."
[task 2025-01-20T21:54:03.747Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410038880 addons.xpi DEBUG Loading bootstrap scope from jar:file:///data/local/tmp/test_root/xpc/p/5bd8a6b3-15e4-4103-ac82-d2d69475c97f/extensions/@multiple_scripts_share_same_default_world.xpi!/"
[task 2025-01-20T21:54:03.747Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410038880 addons.xpi DEBUG Calling bootstrap method install on @multiple_scripts_share_same_default_world version 1.0"
[task 2025-01-20T21:54:03.747Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410038880 addons.xpi DEBUG Calling bootstrap method startup on @multiple_scripts_share_same_default_world version 1.0"
[task 2025-01-20T21:54:03.747Z] 21:54:03 INFO - "Extension attached"
[task 2025-01-20T21:54:03.747Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410039032 addons.xpi DEBUG removeTemporaryFile: file:///data/local/tmp/test_root/xpc/p/5bd8a6b3-15e4-4103-ac82-d2d69475c97f/temp/generated-extension.xpi does not own temp file"
[task 2025-01-20T21:54:03.748Z] 21:54:03 INFO - TEST-PASS | xpcshell.toml:toolkit/components/extensions/test/xpcshell/test_ext_userScripts_mv3_worlds.js | multiple_scripts_share_same_default_world - [multiple_scripts_share_same_default_world : 158] Web page cannot see vars from USER_SCRIPT world - "undefined" == "undefined"
[task 2025-01-20T21:54:03.748Z] 21:54:03 INFO - TEST-PASS | xpcshell.toml:toolkit/components/extensions/test/xpcshell/test_ext_userScripts_mv3_worlds.js | multiple_scripts_share_same_default_world - [multiple_scripts_share_same_default_world : 159] All user scripts should share the same scope - "12345_6789" == "12345_6789"
[task 2025-01-20T21:54:03.748Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410039439 addons.xpi DEBUG Calling bootstrap method shutdown on @multiple_scripts_share_same_default_world version 1.0"
[task 2025-01-20T21:54:03.748Z] 21:54:03 INFO - (xpcshell/head.js) | test run_next_test 4 pending (2)
[task 2025-01-20T21:54:03.748Z] 21:54:03 INFO - (xpcshell/head.js) | test multiple_scripts_share_same_default_world finished (2)
[task 2025-01-20T21:54:03.748Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410039492 addons.xpi DEBUG Calling bootstrap method uninstall on @multiple_scripts_share_same_default_world version 1.0"
[task 2025-01-20T21:54:03.748Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410039493 addons.xpi DEBUG Disabling XPIState for @multiple_scripts_share_same_default_world"
[task 2025-01-20T21:54:03.749Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410039493 addons.xpi DEBUG uninstallAddon: flushing jar cache /data/local/tmp/test_root/xpc/p/5bd8a6b3-15e4-4103-ac82-d2d69475c97f/extensions/@multiple_scripts_share_same_default_world.xpi for addon @multiple_scripts_share_same_default_world"
[task 2025-01-20T21:54:03.749Z] 21:54:03 INFO - xpcshell.toml:toolkit/components/extensions/test/xpcshell/test_ext_userScripts_mv3_worlds.js | Starting test_worldId_validation
[task 2025-01-20T21:54:03.749Z] 21:54:03 INFO - (xpcshell/head.js) | test test_worldId_validation pending (2)
[task 2025-01-20T21:54:03.749Z] 21:54:03 INFO - (xpcshell/head.js) | test run_next_test 4 finished (2)
[task 2025-01-20T21:54:03.749Z] 21:54:03 INFO - "Extension attached"
[task 2025-01-20T21:54:03.749Z] 21:54:03 INFO - TEST-PASS | xpcshell.toml:toolkit/components/extensions/test/xpcshell/test_ext_userScripts_mv3_worlds.js | test_worldId_validation - [test_worldId_validation : 157] Promise rejected, expecting rejection to match '"Invalid worldId: _"', got 'Error: Invalid worldId: _': worldId starting with underscore are reserved - true == true
[task 2025-01-20T21:54:03.750Z] 21:54:03 INFO - "worldId containing underscore after start is OK"
[task 2025-01-20T21:54:03.750Z] 21:54:03 INFO - TEST-PASS | xpcshell.toml:toolkit/components/extensions/test/xpcshell/test_ext_userScripts_mv3_worlds.js | test_worldId_validation - [test_worldId_validation : 157] Promise rejected, expecting rejection to match '/^Invalid worldId: x{257}$/', got 'Error: Invalid worldId: xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx': Too long worldId is rejected - true == true
[task 2025-01-20T21:54:03.750Z] 21:54:03 INFO - "worldId length of 256 characters is OK"
[task 2025-01-20T21:54:03.750Z] 21:54:03 INFO - "worldId length of 256 double-byte characters is OK"
[task 2025-01-20T21:54:03.751Z] 21:54:03 INFO - TEST-PASS | xpcshell.toml:toolkit/components/extensions/test/xpcshell/test_ext_userScripts_mv3_worlds.js | test_worldId_validation - [test_worldId_validation : 157] Promise rejected, expecting rejection to match '/^Invalid worldId: \\u{1f00d}{256}$/u', got 'Error: Invalid worldId: 🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍🀍': worldId length of 256 multi-code unit characters is rejected. - true == true
[task 2025-01-20T21:54:03.751Z] 21:54:03 INFO - TEST-PASS | xpcshell.toml:toolkit/components/extensions/test/xpcshell/test_ext_userScripts_mv3_worlds.js | test_worldId_validation - [test_worldId_validation : 157] Function threw, expecting error to match '/worldId: Expected string instead of 123/', got 'Error: Type error for parameter scripts (Error processing 0.worldId: Expected string instead of 123) for userScripts.register.': Non-string worldId is rejected. - true == true
[task 2025-01-20T21:54:03.752Z] 21:54:03 INFO - TEST-PASS | xpcshell.toml:toolkit/components/extensions/test/xpcshell/test_ext_userScripts_mv3_worlds.js | test_worldId_validation - [test_worldId_validation : 157] Promise rejected, expecting rejection to match '"worldId cannot be used with MAIN world."', got 'Error: worldId cannot be used with MAIN world.': Should not support worldId with MAIN world - true == true
[task 2025-01-20T21:54:03.752Z] 21:54:03 INFO - TEST-PASS | xpcshell.toml:toolkit/components/extensions/test/xpcshell/test_ext_userScripts_mv3_worlds.js | test_worldId_validation - [test_worldId_validation : 157] Promise rejected, expecting rejection to match '"worldId cannot be used with MAIN world."', got 'Error: worldId cannot be used with MAIN world.': Should not support worldId with MAIN world - true == true
[task 2025-01-20T21:54:03.752Z] 21:54:03 INFO - TEST-PASS | xpcshell.toml:toolkit/components/extensions/test/xpcshell/test_ext_userScripts_mv3_worlds.js | test_worldId_validation - [test_worldId_validation : 157] Promise rejected, expecting rejection to match '"worldId cannot be used with MAIN world."', got 'Error: worldId cannot be used with MAIN world.': Should not update worldId to non-default world for world MAIN - true == true
[task 2025-01-20T21:54:03.752Z] 21:54:03 INFO - "Updating worldId + world=USER_SCRIPT at once is OK"
[task 2025-01-20T21:54:03.753Z] 21:54:03 INFO - TEST-PASS | xpcshell.toml:toolkit/components/extensions/test/xpcshell/test_ext_userScripts_mv3_worlds.js | test_worldId_validation - [test_worldId_validation : 157] Promise rejected, expecting rejection to match '"worldId cannot be used with MAIN world."', got 'Error: worldId cannot be used with MAIN world.': Should not change world to MAIN when worldId is non-default worldId - true == true
[task 2025-01-20T21:54:03.753Z] 21:54:03 INFO - "Update can set world=MAIN and clear worldId at once"
[task 2025-01-20T21:54:03.753Z] 21:54:03 INFO - (xpcshell/head.js) | test run_next_test 5 pending (2)
[task 2025-01-20T21:54:03.753Z] 21:54:03 INFO - (xpcshell/head.js) | test test_worldId_validation finished (2)
[task 2025-01-20T21:54:03.753Z] 21:54:03 INFO - xpcshell.toml:toolkit/components/extensions/test/xpcshell/test_ext_userScripts_mv3_worlds.js | Starting test_default_and_many_non_default_worldIds
[task 2025-01-20T21:54:03.753Z] 21:54:03 INFO - (xpcshell/head.js) | test test_default_and_many_non_default_worldIds pending (2)
[task 2025-01-20T21:54:03.753Z] 21:54:03 INFO - (xpcshell/head.js) | test run_next_test 5 finished (2)
[task 2025-01-20T21:54:03.754Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410039923 addons.repository DEBUG cacheAddons: enabled false IDs ["@test_default_and_many_non_default_worldIds"]"
[task 2025-01-20T21:54:03.754Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410039926 addons.xpi DEBUG Starting install of @test_default_and_many_non_default_worldIds from file:///data/local/tmp/test_root/xpc/p/5bd8a6b3-15e4-4103-ac82-d2d69475c97f/temp/generated-extension.xpi"
[task 2025-01-20T21:54:03.754Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410039933 addons.xpi DEBUG Addon @test_default_and_many_non_default_worldIds will be installed as a packed xpi"
[task 2025-01-20T21:54:03.754Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410039938 addons.xpi-utils DEBUG Make addon app-profile:@test_default_and_many_non_default_worldIds visible"
[task 2025-01-20T21:54:03.754Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410039938 addons.xpi DEBUG XPIStates adding add-on @test_default_and_many_non_default_worldIds in {"addons":{},"staged":{},"path":"/data/local/tmp/test_root/xpc/p/5bd8a6b3-15e4-4103-ac82-d2d69475c97f/extensions"}: /data/local/tmp/test_root/xpc/p/5bd8a6b3-15e4-4103-ac82-d2d69475c97f/extensions/@test_default_and_many_non_default_worldIds.xpi"
[task 2025-01-20T21:54:03.756Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410039938 addons.xpi DEBUG Updating XPIState for {"id":"@test_default_and_many_non_default_worldIds","syncGUID":"{4ac8958f-0c5a-4987-9f20-31a3b8558411}","version":"1.0","type":"extension","loader":null,"updateURL":null,"installOrigins":null,"manifestVersion":3,"optionsURL":null,"optionsType":null,"optionsBrowserStyle":true,"aboutURL":null,"defaultLocale":{"name":"Generated extension","creator":null,"developers":null,"translators":null,"contributors":null},"visible":true,"active":true,"userDisabled":false,"appDisabled":false,"embedderDisabled":false,"installDate":1737410039924,"updateDate":1737410039924,"applyBackgroundUpdates":1,"path":"/data/local/tmp/test_root/xpc/p/5bd8a6b3-15e4-4103-ac82-d2d69475c97f/extensions/@test_default_and_many_non_default_worldIds.xpi","skinnable":false,"sourceURI":"file:///data/local/tmp/test_root/xpc/p/5bd8a6b3-15e4-4103-ac82-d2d69475c97f/temp/generated-extension.xpi","releaseNotesURI":null,"softDisabled":false,"foreignInstall":false,"strictCompatibility":true,"locales":[],"targetApplications":[{"id":"toolkit@mozilla.org","minVersion":null,"maxVersion":null}],"targetPlatforms":[],"signedState":4,"signedTypes":[2],"signedDate":null,"seen":true,"dependencies":[],"incognito":"spanning","userPermissions":{"permissions":[],"origins":[]},"optionalPermissions":{"permissions":["userScripts"],"origins":["*://example.com/*"]},"requestedPermissions":{"permissions":[],"origins":["*://example.com/*"]},"icons":{},"iconURL":null,"blocklistAttentionDismissed":false,"blocklistState":0,"blocklistURL":null,"startupData":null,"hidden":false,"installTelemetryInfo":null,"recommendationState":null,"rootURI":"jar:file:///data/local/tmp/test_root/xpc/p/5bd8a6b3-15e4-4103-ac82-d2d69475c97f/extensions/@test_default_and_many_non_default_worldIds.xpi!/","location":"app-profile"}"
[task 2025-01-20T21:54:03.756Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410039939 addons.xpi DEBUG Install of file:///data/local/tmp/test_root/xpc/p/5bd8a6b3-15e4-4103-ac82-d2d69475c97f/temp/generated-extension.xpi completed."
[task 2025-01-20T21:54:03.756Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410039940 addons.xpi DEBUG Loading bootstrap scope from jar:file:///data/local/tmp/test_root/xpc/p/5bd8a6b3-15e4-4103-ac82-d2d69475c97f/extensions/@test_default_and_many_non_default_worldIds.xpi!/"
[task 2025-01-20T21:54:03.756Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410039941 addons.xpi DEBUG Calling bootstrap method install on @test_default_and_many_non_default_worldIds version 1.0"
[task 2025-01-20T21:54:03.756Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410039941 addons.xpi DEBUG Calling bootstrap method startup on @test_default_and_many_non_default_worldIds version 1.0"
[task 2025-01-20T21:54:03.756Z] 21:54:03 INFO - "Extension attached"
[task 2025-01-20T21:54:03.756Z] 21:54:03 INFO - "CONSOLE_MESSAGE: (info) 1737410040192 addons.xpi DEBUG removeTemporaryFile: file:///data/local/tmp/test_root/xpc/p/5bd8a6b3-15e4-4103-ac82-d2d69475c97f/temp/generated-extension.xpi does not own temp file"
[task 2025-01-20T21:54:03.757Z] 21:54:03 INFO - "Actual result (unsorted): -3,-2,-1,1,2,3,4,5,6,7,8,9,10,11,12,13,14,15,16,17,18,19,20,21,22,23,24,25,26,27,28,29,30,31,32,33,34,35,36,37,38,39,40,41,42,43,44,45"
[task 2025-01-20T21:54:03.757Z] 21:54:03 WARNING - TEST-UNEXPECTED-FAIL | xpcshell.toml:toolkit/components/extensions/test/xpcshell/test_ext_userScripts_mv3_worlds.js | test_default_and_many_non_default_worldIds - [test_default_and_many_non_default_worldIds : 359] Every script should execute in the world specified by worldId - [-3,-2,-1,1,2,3,4,5,6,7,8,9,10,11,12,13,14,15,16,17,18,19,20,21,22,23,24,25,26,27,28,29,30,31,32,33,34,35,36,37,38,39,40,41,42,43,44,45] deepEqual [-3,-2,-1,1,2,3,4,5,6,7,8,9,10,11,12,13,14,15,16,17,18,19,20,21,22,23,24,25,26,27,28,29,30,31,32,33,34,35,36,37,38,39,40,41,42,43,44,45,46,47,48,49,50]
[task 2025-01-20T21:54:03.757Z] 21:54:03 INFO - test_ext_userScripts_mv3_worlds.js:test_default_and_many_non_default_worldIds:359
[task 2025-01-20T21:54:03.757Z] 21:54:03 INFO - exiting test
[task 2025-01-20T21:54:03.757Z] 21:54:03 INFO - Unexpected exception NS_ERROR_ABORT:
[task 2025-01-20T21:54:03.757Z] 21:54:03 INFO - _abort_failed_test@/data/local/tmp/test_root/xpc/head.js:869:20
[task 2025-01-20T21:54:03.757Z] 21:54:03 INFO - do_report_result@/data/local/tmp/test_root/xpc/head.js:981:5
[task 2025-01-20T21:54:03.757Z] 21:54:03 INFO - Assert<@/data/local/tmp/test_root/xpc/head.js:70:21
[task 2025-01-20T21:54:03.758Z] 21:54:03 INFO - Assert.prototype.report@resource://testing-common/Assert.sys.mjs:251:10
[task 2025-01-20T21:54:03.758Z] 21:54:03 INFO - deepEqual@resource://testing-common/Assert.sys.mjs:331:8
[task 2025-01-20T21:54:03.758Z] 21:54:03 INFO - test_default_and_many_non_default_worldIds@test_ext_userScripts_mv3_worlds.js:359:10
[task 2025-01-20T21:54:03.758Z] 21:54:03 INFO - async*_run_next_test/<@/data/local/tmp/test_root/xpc/head.js:1759:22
[task 2025-01-20T21:54:03.758Z] 21:54:03 INFO - _run_next_test@/data/local/tmp/test_root/xpc/head.js:1759:38
[task 2025-01-20T21:54:03.758Z] 21:54:03 INFO - run@/data/local/tmp/test_root/xpc/head.js:808:9
[task 2025-01-20T21:54:03.758Z] 21:54:03 INFO - _do_main@/data/local/tmp/test_root/xpc/head.js:245:6
[task 2025-01-20T21:54:03.758Z] 21:54:03 INFO - _execute_test@/data/local/tmp/test_root/xpc/head.js:596:5
[task 2025-01-20T21:54:03.758Z] 21:54:03 INFO - @-e:1:1
[task 2025-01-20T21:54:03.758Z] 21:54:03 INFO - exiting test
[task 2025-01-20T21:54:03.758Z] 21:54:03 WARNING - TEST-UNEXPECTED-FAIL | xpcshell.toml:toolkit/components/extensions/test/xpcshell/test_ext_userScripts_mv3_worlds.js | test_default_and_many_non_default_worldIds - [test_default_and_many_non_default_worldIds : 67] Extension left running at test shutdown - "running" == "unloaded"
[task 2025-01-20T21:54:03.758Z] 21:54:03 INFO - resource://testing-common/ExtensionXPCShellUtils.sys.mjs:ExtensionWrapper/<:67
[task 2025-01-20T21:54:03.759Z] 21:54:03 INFO - /data/local/tmp/test_root/xpc/head.js:_execute_test/<:660
[task 2025-01-20T21:54:03.759Z] 21:54:03 INFO - /data/local/tmp/test_root/xpc/head.js:_execute_test:669
[task 2025-01-20T21:54:03.759Z] 21:54:03 INFO - -e:null:1
[task 2025-01-20T21:54:03.759Z] 21:54:03 INFO - exiting test
[task 2025-01-20T21:54:03.759Z] 21:54:03 INFO - NS_ERROR_ABORT:
[task 2025-01-20T21:54:03.759Z] 21:54:03 INFO - _abort_failed_test@/data/local/tmp/test_root/xpc/head.js:869:20
[task 2025-01-20T21:54:03.759Z] 21:54:03 INFO - do_report_result@/data/local/tmp/test_root/xpc/head.js:981:5
[task 2025-01-20T21:54:03.759Z] 21:54:03 INFO - Assert<@/data/local/tmp/test_root/xpc/head.js:70:21
[task 2025-01-20T21:54:03.759Z] 21:54:03 INFO - Assert.prototype.report@resource://testing-common/Assert.sys.mjs:251:10
[task 2025-01-20T21:54:03.759Z] 21:54:03 INFO - equal@resource://testing-common/Assert.sys.mjs:293:8
[task 2025-01-20T21:54:03.759Z] 21:54:03 INFO - ExtensionWrapper/<@resource://testing-common/ExtensionXPCShellUtils.sys.mjs:67:24
[task 2025-01-20T21:54:03.759Z] 21:54:03 INFO - _execute_test/<@/data/local/tmp/test_root/xpc/head.js:660:28
[task 2025-01-20T21:54:03.759Z] 21:54:03 INFO - _execute_test@/data/local/tmp/test_root/xpc/head.js:669:5
[task 2025-01-20T21:54:03.759Z] 21:54:03 INFO - @-e:1:1
[task 2025-01-20T21:54:03.759Z] 21:54:03 INFO - "Force a GC"
[task 2025-01-20T21:54:03.760Z] 21:54:03 INFO - Error: Found unexpected files in temporary directory: generated-extension.xpi at resource://testing-common/AddonTestUtils.sys.mjs:363
[task 2025-01-20T21:54:03.760Z] 21:54:03 INFO - init/<@resource://testing-common/AddonTestUtils.sys.mjs:363:15
[task 2025-01-20T21:54:03.760Z] 21:54:03 INFO - _execute_test/<@/data/local/tmp/test_root/xpc/head.js:660:28
[task 2025-01-20T21:54:03.760Z] 21:54:03 INFO - async*_execute_test@/data/local/tmp/test_root/xpc/head.js:669:5
[task 2025-01-20T21:54:03.760Z] 21:54:03 INFO - @-e:1:1
[task 2025-01-20T21:54:03.760Z] 21:54:03 INFO - <<<<<<<
[task 2025-01-20T21:54:03.816Z] 21:54:03 INFO - Cleaning up profile for /builds/worker/workspace/build/tests/xpcshell/tests/toolkit/components/extensions/test/xpcshell/test_ext_userScripts_mv3_worlds.js folder: /data/local/tmp/test_root/xpc/p/5bd8a6b3-15e4-4103-ac82-d2d69475c97f
[task 2025-01-20T21:54:04.010Z] 21:54:04 INFO - INFO | Result summary:
[task 2025-01-20T21:54:04.010Z] 21:54:04 INFO - INFO | Passed: 469
[task 2025-01-20T21:54:04.010Z] 21:54:04 WARNING - INFO | Failed: 1
[task 2025-01-20T21:54:04.010Z] 21:54:04 WARNING - One or more unittests failed.
[task 2025-01-20T21:54:04.010Z] 21:54:04 INFO - INFO | Todo: 0
[task 2025-01-20T21:54:04.010Z] 21:54:04 INFO - INFO | Retried: 1
[task 2025-01-20T21:54:04.010Z] 21:54:04 INFO - SUITE-END | took 1117s
[task 2025-01-20T21:54:04.010Z] 21:54:04 INFO - Node moz-http2 server shutting down ...
[task 2025-01-20T21:54:04.017Z] 21:54:04 INFO - cleared MOZHTTP2_PORT connection for port tcp:34671
[task 2025-01-20T21:54:04.023Z] 21:54:04 INFO - cleared MOZNODE_EXEC_PORT connection for port tcp:35709
[task 2025-01-20T21:54:04.023Z] 21:54:04 INFO - http3Server server shutting down ...
[task 2025-01-20T21:54:04.151Z] 21:54:04 INFO - Return code: 1
[task 2025-01-20T21:54:04.152Z] 21:54:04 INFO - TinderboxPrint: xpcshell<br/>469/<em class="testfail">1</em>/0
[task 2025-01-20T21:54:04.152Z] 21:54:04 INFO - ##### xpcshell log ends
[task 2025-01-20T21:54:04.152Z] 21:54:04 WARNING - setting return code to 1
[task 2025-01-20T21:54:04.152Z] 21:54:04 INFO - The xpcshell suite: xpcshell ran with return status: WARNING
[task 2025-01-20T21:54:04.152Z] 21:54:04 INFO - Running post-action listener: _package_coverage_data
[task 2025-01-20T21:54:04.152Z] 21:54:04 INFO - Running post-action listener: _resource_record_post_action
[task 2025-01-20T21:54:04.152Z] 21:54:04 INFO - Running post-action listener: process_java_coverage_data
[task 2025-01-20T21:54:04.152Z] 21:54:04 INFO - Running post-action listener: stop_device
[task 2025-01-20T21:54:04.445Z] 21:54:04 INFO - Killing logcat pid 1354.
[task 2025-01-20T21:54:04.445Z] 21:54:04 INFO - Killing every process called qemu-system-x86_64
[task 2025-01-20T21:54:04.451Z] 21:54:04 INFO - [mozharness: 2025-01-20 21:54:04.451049Z] Finished run-tests step (success)
[task 2025-01-20T21:54:04.451Z] 21:54:04 INFO - Running post-run listener: _resource_record_post_run
[task 2025-01-20T21:54:04.971Z] 21:54:04 INFO - Total resource usage - Wall time: 1171s; CPU: 47%; Read bytes: 0; Write bytes: 1652158464; Read time: 0; Write time: 1208232
[task 2025-01-20T21:54:04.972Z] 21:54:04 INFO - TinderboxPrint: CPU usage<br/>46.7%
[task 2025-01-20T21:54:04.972Z] 21:54:04 INFO - TinderboxPrint: I/O read bytes / time<br/>0 / 0
[task 2025-01-20T21:54:04.972Z] 21:54:04 INFO - TinderboxPrint: I/O write bytes / time<br/>1,652,158,464 / 1,208,232
[task 2025-01-20T21:54:04.972Z] 21:54:04 INFO - TinderboxPrint: CPU guest<br/>2,850.8 (23.5%)
[task 2025-01-20T21:54:04.972Z] 21:54:04 INFO - TinderboxPrint: CPU idle<br/>4,925.3 (40.6%)
[task 2025-01-20T21:54:04.972Z] 21:54:04 INFO - TinderboxPrint: CPU system<br/>1,267.6 (10.4%)
[task 2025-01-20T21:54:04.972Z] 21:54:04 INFO - TinderboxPrint: CPU user<br/>3,063.0 (25.2%)
[task 2025-01-20T21:54:04.972Z] 21:54:04 INFO - TinderboxPrint: Swap in / out<br/>0 / 0
[task 2025-01-20T21:54:04.973Z] 21:54:04 INFO - start-emulator - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2025-01-20T21:54:04.977Z] 21:54:04 INFO - verify-device - Wall time: 31s; CPU: 27%; Read bytes: 0; Write bytes: 6647808; Read time: 0; Write time: 4348
[task 2025-01-20T21:54:04.980Z] 21:54:04 INFO - install - Wall time: 10s; CPU: 35%; Read bytes: 0; Write bytes: 215093248; Read time: 0; Write time: 183784
[task 2025-01-20T21:54:05.073Z] 21:54:05 INFO - run-tests - Wall time: 1129s; CPU: 47%; Read bytes: 0; Write bytes: 1430401024; Read time: 0; Write time: 1020068
[task 2025-01-20T21:54:07.649Z] 21:54:07 WARNING - returning nonzero exit status 1
[task 2025-01-20T21:54:07.881Z] cleanup
[task 2025-01-20T21:54:07.881Z] + cleanup
[task 2025-01-20T21:54:07.881Z] + local rv=1
[task 2025-01-20T21:54:07.881Z] + [[ -s /builds/worker/.xsession-errors ]]
[task 2025-01-20T21:54:07.881Z] + cp /builds/worker/.xsession-errors /builds/worker/artifacts/public/xsession-errors.log
[task 2025-01-20T21:54:07.882Z] + false
[task 2025-01-20T21:54:07.882Z] + '[' ']'
[task 2025-01-20T21:54:07.882Z] + true
[task 2025-01-20T21:54:07.882Z] + cleanup_xvfb
[task 2025-01-20T21:54:07.883Z] ++ pidof Xvfb
[task 2025-01-20T21:54:07.886Z] + local xvfb_pid=55
[task 2025-01-20T21:54:07.886Z] + local vnc=false
[task 2025-01-20T21:54:07.886Z] + local interactive=false
[task 2025-01-20T21:54:07.886Z] + '[' -n 55 ']'
[task 2025-01-20T21:54:07.886Z] + [[ false == false ]]
[task 2025-01-20T21:54:07.886Z] + [[ false == false ]]
[task 2025-01-20T21:54:07.886Z] + kill 55
[task 2025-01-20T21:54:07.886Z] + exit 1
[taskcluster 2025-01-20 21:54:08.679Z] === Task Finished ===
[taskcluster 2025-01-20 21:54:12.324Z] Unsuccessful task run with exit code: 1 completed in 1477.235 seconds
Comment hidden (Intermittent Failures Robot) |
You need to log in
before you can comment on or make changes to this bug.
Description
•