Closed Bug 1733292 Opened 4 years ago Closed 4 years ago

Intermittent toolkit/components/extensions/test/xpcshell/test_ext_background_service_worker.js | test_fail_spawn_extension_worker_for_disabled_extension - [test_fail_spawn_extension_worker_for_disabled_extension : 259] Missing expected exception. Got the

Categories

(WebExtensions :: General, defect, P5)

defect

Tracking

(Not tracked)

RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure)

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


[task 2021-09-30T01:22:50.207Z] 01:22:50     INFO -  TEST-START | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_background_service_worker.js
[task 2021-09-30T01:22:58.262Z] 01:22:58  WARNING -  TEST-UNEXPECTED-FAIL | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_background_service_worker.js | xpcshell return code: 0
[task 2021-09-30T01:22:58.263Z] 01:22:58     INFO -  TEST-INFO took 8055ms
[task 2021-09-30T01:22:58.264Z] 01:22:58     INFO -  >>>>>>>
[task 2021-09-30T01:22:58.264Z] 01:22:58     INFO -  (xpcshell/head.js) | test MAIN run_test pending (1)
[task 2021-09-30T01:22:58.264Z] 01:22:58     INFO -  (xpcshell/head.js) | test run_next_test 0 pending (2)
[task 2021-09-30T01:22:58.265Z] 01:22:58     INFO -  (xpcshell/head.js) | test MAIN run_test finished (2)
[task 2021-09-30T01:22:58.265Z] 01:22:58     INFO -  running event loop
[task 2021-09-30T01:22:58.266Z] 01:22:58     INFO -  xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_background_service_worker.js | Starting check_remote
[task 2021-09-30T01:22:58.266Z] 01:22:58     INFO -  (xpcshell/head.js) | test check_remote pending (2)
[task 2021-09-30T01:22:58.267Z] 01:22:58     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_background_service_worker.js | check_remote - [check_remote : 1] useRemoteWebExtensions matches - true == true
[task 2021-09-30T01:22:58.267Z] 01:22:58     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_background_service_worker.js | check_remote - [check_remote : 1] testing from extension process - false == false
[task 2021-09-30T01:22:58.268Z] 01:22:58     INFO -  (xpcshell/head.js) | test run_next_test 0 finished (2)
[task 2021-09-30T01:22:58.269Z] 01:22:58     INFO -  (xpcshell/head.js) | test run_next_test 1 pending (2)
[task 2021-09-30T01:22:58.269Z] 01:22:58     INFO -  (xpcshell/head.js) | test check_remote finished (2)
[task 2021-09-30T01:22:58.270Z] 01:22:58     INFO -  xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_background_service_worker.js | Starting setup
[task 2021-09-30T01:22:58.270Z] 01:22:58     INFO -  (xpcshell/head.js) | test setup pending (2)
[task 2021-09-30T01:22:58.271Z] 01:22:58     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_background_service_worker.js | setup - [setup : 27] Expect remote-webextensions mode enabled - true == true
[task 2021-09-30T01:22:58.271Z] 01:22:58     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_background_service_worker.js | setup - [setup : 31] Expect remote-webextensions mode enabled - true == true
[task 2021-09-30T01:22:58.274Z] 01:22:58     INFO -  "CONSOLE_MESSAGE: (info) 1632964971797	addons.manager	DEBUG	Application has been upgraded"
[task 2021-09-30T01:22:58.274Z] 01:22:58     INFO -  "CONSOLE_MESSAGE: (info) 1632964971800	addons.manager	DEBUG	Loaded provider scope for resource://gre/modules/addons/XPIProvider.jsm: ["XPIProvider", "XPIInternal"]"
[task 2021-09-30T01:22:58.275Z] 01:22:58     INFO -  "CONSOLE_MESSAGE: (info) 1632964971857	addons.manager	DEBUG	Loaded provider scope for resource://gre/modules/addons/GMPProvider.jsm"
[task 2021-09-30T01:22:58.275Z] 01:22:58     INFO -  "CONSOLE_MESSAGE: (info) 1632964971858	addons.manager	DEBUG	Starting provider: XPIProvider"
[task 2021-09-30T01:22:58.275Z] 01:22:58     INFO -  "CONSOLE_MESSAGE: (info) 1632964971859	addons.xpi	DEBUG	startup"
[task 2021-09-30T01:22:58.275Z] 01:22:58     INFO -  "CONSOLE_MESSAGE: (info) 1632964971863	addons.xpi	INFO	SystemAddonLocation directory is missing"
[task 2021-09-30T01:22:58.275Z] 01:22:58     INFO -  "CONSOLE_MESSAGE: (info) 1632964971975	addons.xpi	INFO	Removing all system add-on upgrades."
[task 2021-09-30T01:22:58.276Z] 01:22:58     INFO -  "CONSOLE_MESSAGE: (info) 1632964971978	addons.xpi	DEBUG	checkForChanges"
[task 2021-09-30T01:22:58.276Z] 01:22:58     INFO -  "CONSOLE_MESSAGE: (info) 1632964971979	addons.xpi	DEBUG	Loaded add-on state: ${}"
[task 2021-09-30T01:22:58.276Z] 01:22:58     INFO -  "CONSOLE_MESSAGE: (info) 1632964971987	addons.xpi	DEBUG	scanForChanges changed: false, state: {}"
[task 2021-09-30T01:22:58.276Z] 01:22:58     INFO -  "CONSOLE_MESSAGE: (info) 1632964971989	addons.xpi	DEBUG	Empty XPI database, setting schema version preference to 33"
[task 2021-09-30T01:22:58.276Z] 01:22:58     INFO -  "CONSOLE_MESSAGE: (info) 1632964971990	addons.xpi	DEBUG	No changes found"
[task 2021-09-30T01:22:58.276Z] 01:22:58     INFO -  "CONSOLE_MESSAGE: (info) 1632964972071	addons.xpi-utils	DEBUG	Synchronously loading the add-ons database"
[task 2021-09-30T01:22:58.276Z] 01:22:58     INFO -  "CONSOLE_MESSAGE: (info) 1632964972073	addons.xpi-utils	DEBUG	Starting async load of XPI database /tmp/xpc-profile-zzc55p2v/extensions.json"
[task 2021-09-30T01:22:58.277Z] 01:22:58     INFO -  (xpcshell/head.js) | test run_next_test 1 finished (2)
[task 2021-09-30T01:22:58.277Z] 01:22:58     INFO -  "CONSOLE_MESSAGE: (info) 1632964972100	addons.xpi-utils	DEBUG	Rebuilding XPI database with no extensions"
[task 2021-09-30T01:22:58.277Z] 01:22:58     INFO -  "CONSOLE_MESSAGE: (info) 1632964972115	addons.manager	DEBUG	Registering shutdown blocker for XPIProvider"
[task 2021-09-30T01:22:58.277Z] 01:22:58     INFO -  "CONSOLE_MESSAGE: (info) 1632964972116	addons.manager	DEBUG	Provider finished startup: XPIProvider"
[task 2021-09-30T01:22:58.278Z] 01:22:58     INFO -  "CONSOLE_MESSAGE: (info) 1632964972117	addons.manager	DEBUG	Completed startup sequence"
[task 2021-09-30T01:22:58.278Z] 01:22:58     INFO -  (xpcshell/head.js) | test run_next_test 2 pending (2)
[task 2021-09-30T01:22:58.279Z] 01:22:58     INFO -  (xpcshell/head.js) | test setup finished (2)
[task 2021-09-30T01:22:58.280Z] 01:22:58     INFO -  xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_background_service_worker.js | Starting test_fail_spawn_extension_worker_for_disabled_extension
[task 2021-09-30T01:22:58.280Z] 01:22:58     INFO -  (xpcshell/head.js) | test test_fail_spawn_extension_worker_for_disabled_extension pending (2)
[task 2021-09-30T01:22:58.281Z] 01:22:58     INFO -  (xpcshell/head.js) | test run_next_test 2 finished (2)
[task 2021-09-30T01:22:58.286Z] 01:22:58     INFO -  "CONSOLE_MESSAGE: (info) 1632964973999	addons.xpi-utils	DEBUG	Make addon app-temporary:test-bg-sw@mochi.test visible"
[task 2021-09-30T01:22:58.286Z] 01:22:58     INFO -  "CONSOLE_MESSAGE: (info) 1632964974001	addons.xpi	DEBUG	XPIStates adding add-on test-bg-sw@mochi.test in {}: /tmp/xpc-profile-zzc55p2v/temp/generated-extension.xpi"
[task 2021-09-30T01:22:58.286Z] 01:22:58     INFO -  "CONSOLE_MESSAGE: (info) 1632964974006	addons.xpi	DEBUG	Updating XPIState for {"id":"test-bg-sw@mochi.test","syncGUID":"{c886edfd-1afc-4073-b560-cea61a4c81a3}","version":"1.0","type":"extension","loader":null,"updateURL":null,"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":1632964973999,"applyBackgroundUpdates":1,"path":"/tmp/xpc-profile-zzc55p2v/temp/generated-extension.xpi","skinnable":false,"sourceURI":null,"releaseNotesURI":null,"softDisabled":false,"foreignInstall":false,"strictCompatibility":true,"locales":[],"targetApplications":[{"id":"toolkit@mozilla.org","minVersion":null,"maxVersion":null}],"targetPlatforms":[],"signedState":4,"signedDate":null,"seen":true,"dependencies":[],"incognito":"spanning","userPermissions":{"permissions":[],"origins":[]},"optionalPermissions":{"permissions":[],"origins":[]},"icons":{},"iconURL":null,"blocklistState":0,"blocklistURL":null,"startupData":null,"hidden":false,"installTelemetryInfo":null,"recommendationState":null,"rootURI":"jar:file:///tmp/xpc-profile-zzc55p2v/temp/generated-extension.xpi!/","location":"app-temporary"}"
[task 2021-09-30T01:22:58.286Z] 01:22:58     INFO -  "CONSOLE_MESSAGE: (info) 1632964974039	addons.xpi	DEBUG	Loading bootstrap scope from jar:file:///tmp/xpc-profile-zzc55p2v/temp/generated-extension.xpi!/"
[task 2021-09-30T01:22:58.286Z] 01:22:58     INFO -  "CONSOLE_MESSAGE: (info) 1632964974040	addons.xpi	DEBUG	Calling bootstrap method install on test-bg-sw@mochi.test version 1.0"
[task 2021-09-30T01:22:58.286Z] 01:22:58     INFO -  "CONSOLE_MESSAGE: (info) 1632964974041	addons.xpi	DEBUG	Calling bootstrap method startup on test-bg-sw@mochi.test version 1.0"
[task 2021-09-30T01:22:58.286Z] 01:22:58     INFO -  "Extension attached"
[task 2021-09-30T01:22:58.286Z] 01:22:58     INFO -  "CONSOLE_MESSAGE: (info) 1632964974123	addons.xpi-utils	DEBUG	XPI Database saved, setting schema version preference to 33"
[task 2021-09-30T01:22:58.286Z] 01:22:58     INFO -  "CONSOLE_MESSAGE: (info) 1632964974252	addons.manager	DEBUG	Starting provider: GMPProvider"
[task 2021-09-30T01:22:58.286Z] 01:22:58     INFO -  "CONSOLE_MESSAGE: (info) 1632964974270	addons.manager	DEBUG	Registering shutdown blocker for GMPProvider"
[task 2021-09-30T01:22:58.287Z] 01:22:58     INFO -  "CONSOLE_MESSAGE: (info) 1632964974271	addons.manager	DEBUG	Provider finished startup: GMPProvider"
[task 2021-09-30T01:22:58.287Z] 01:22:58     INFO -  PID 23814 | Background ServiceWorker - executed
[task 2021-09-30T01:22:58.287Z] 01:22:58     INFO -  "Wait for the background service worker to be spawned"
[task 2021-09-30T01:22:58.287Z] 01:22:58     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_background_service_worker.js | test_fail_spawn_extension_worker_for_disabled_extension - [test_fail_spawn_extension_worker_for_disabled_extension : 208] The extension service worker has been spawned as expected - {"workerType":2,"workerUrl":"moz-extension://57f2b021-92c3-4a52-a5c3-7fa7850f4159/sw.js"} == true
[task 2021-09-30T01:22:58.287Z] 01:22:58     INFO -  "Wait for the background service worker to be terminated"
[task 2021-09-30T01:22:58.288Z] 01:22:58     INFO -  "CONSOLE_MESSAGE: (info) 1632964975743	addons.xpi	DEBUG	Install of temporary addon in /tmp/xpc-profile-zzc55p2v/temp/generated-extension.xpi completed."
[task 2021-09-30T01:22:58.290Z] 01:22:58     INFO -  PID 23814 | Background ServiceWorker - executed
[task 2021-09-30T01:22:58.290Z] 01:22:58     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_background_service_worker.js | test_fail_spawn_extension_worker_for_disabled_extension - [test_fail_spawn_extension_worker_for_disabled_extension : 214] The extension service worker has been terminated as expected - {"workerType":2,"workerUrl":"moz-extension://57f2b021-92c3-4a52-a5c3-7fa7850f4159/sw.js"} == true
[task 2021-09-30T01:22:58.291Z] 01:22:58     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_background_service_worker.js | test_fail_spawn_extension_worker_for_disabled_extension - [test_fail_spawn_extension_worker_for_disabled_extension : 228] Got a service worker registration - [object Object] == true
[task 2021-09-30T01:22:58.293Z] 01:22:58     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_background_service_worker.js | test_fail_spawn_extension_worker_for_disabled_extension - [test_fail_spawn_extension_worker_for_disabled_extension : 229] Got an active worker - [object Object] == true
[task 2021-09-30T01:22:58.293Z] 01:22:58     INFO -  "Spawn the active worker by attaching the debugger"
[task 2021-09-30T01:22:58.294Z] 01:22:58     INFO -  "Wait for the background service worker to be spawned after attaching the debugger"
[task 2021-09-30T01:22:58.294Z] 01:22:58     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_background_service_worker.js | test_fail_spawn_extension_worker_for_disabled_extension - [test_fail_spawn_extension_worker_for_disabled_extension : 239] The extension service worker has been spawned as expected - {"workerType":2,"workerUrl":"moz-extension://57f2b021-92c3-4a52-a5c3-7fa7850f4159/sw.js"} == true
[task 2021-09-30T01:22:58.295Z] 01:22:58     INFO -  "Wait for the background service worker to be terminated after detaching the debugger"
[task 2021-09-30T01:22:58.295Z] 01:22:58     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_background_service_worker.js | test_fail_spawn_extension_worker_for_disabled_extension - [test_fail_spawn_extension_worker_for_disabled_extension : 248] The extension service worker has been terminated as expected - {"workerType":2,"workerUrl":"moz-extension://57f2b021-92c3-4a52-a5c3-7fa7850f4159/sw.js"} == true
[task 2021-09-30T01:22:58.295Z] 01:22:58     INFO -  "Disabling the addon policy, and then double-check that the worker can't be spawned"
[task 2021-09-30T01:22:58.296Z] 01:22:58  WARNING -  TEST-UNEXPECTED-FAIL | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_background_service_worker.js | test_fail_spawn_extension_worker_for_disabled_extension - [test_fail_spawn_extension_worker_for_disabled_extension : 259] Missing expected exception. Got the expected extension when trying to spawn a worker for a disabled addon
[task 2021-09-30T01:22:58.296Z] 01:22:58     INFO -  /builds/worker/workspace/build/tests/xpcshell/tests/toolkit/components/extensions/test/xpcshell/test_ext_background_service_worker.js:test_fail_spawn_extension_worker_for_disabled_extension:259
[task 2021-09-30T01:22:58.297Z] 01:22:58     INFO -  /builds/worker/workspace/build/tests/xpcshell/head.js:_do_main:240
[task 2021-09-30T01:22:58.298Z] 01:22:58     INFO -  /builds/worker/workspace/build/tests/xpcshell/head.js:_execute_test:597
[task 2021-09-30T01:22:58.298Z] 01:22:58     INFO -  -e:null:1
[task 2021-09-30T01:22:58.299Z] 01:22:58     INFO -  exiting test
[task 2021-09-30T01:22:58.300Z] 01:22:58     INFO -  Unexpected exception NS_ERROR_ABORT:
[task 2021-09-30T01:22:58.300Z] 01:22:58     INFO -  _abort_failed_test@/builds/worker/workspace/build/tests/xpcshell/head.js:868:20
[task 2021-09-30T01:22:58.301Z] 01:22:58     INFO -  do_report_result@/builds/worker/workspace/build/tests/xpcshell/head.js:969:5
[task 2021-09-30T01:22:58.302Z] 01:22:58     INFO -  Assert<@/builds/worker/workspace/build/tests/xpcshell/head.js:75:21
[task 2021-09-30T01:22:58.302Z] 01:22:58     INFO -  proto.report@resource://testing-common/Assert.jsm:228:10
[task 2021-09-30T01:22:58.303Z] 01:22:58     INFO -  proto.throws@resource://testing-common/Assert.jsm:459:10
[task 2021-09-30T01:22:58.303Z] 01:22:58     INFO -  test_fail_spawn_extension_worker_for_disabled_extension@/builds/worker/workspace/build/tests/xpcshell/tests/toolkit/components/extensions/test/xpcshell/test_ext_background_service_worker.js:259:18
[task 2021-09-30T01:22:58.304Z] 01:22:58     INFO -  _do_main@/builds/worker/workspace/build/tests/xpcshell/head.js:240:6
[task 2021-09-30T01:22:58.305Z] 01:22:58     INFO -  _execute_test@/builds/worker/workspace/build/tests/xpcshell/head.js:597:5
[task 2021-09-30T01:22:58.305Z] 01:22:58     INFO -  @-e:1:1
[task 2021-09-30T01:22:58.306Z] 01:22:58     INFO -  exiting test
[task 2021-09-30T01:22:58.306Z] 01:22:58  WARNING -  TEST-UNEXPECTED-FAIL | xpcshell.ini:toolkit/components/extensions/test/xpcshell/test_ext_background_service_worker.js | test_fail_spawn_extension_worker_for_disabled_extension - [test_fail_spawn_extension_worker_for_disabled_extension : 97] Extension left running at test shutdown - "running" == "unloaded"
[task 2021-09-30T01:22:58.306Z] 01:22:58     INFO -  resource://testing-common/ExtensionXPCShellUtils.jsm:ExtensionWrapper/<:97
[task 2021-09-30T01:22:58.306Z] 01:22:58     INFO -  /builds/worker/workspace/build/tests/xpcshell/head.js:_execute_test/<:661
[task 2021-09-30T01:22:58.307Z] 01:22:58     INFO -  /builds/worker/workspace/build/tests/xpcshell/head.js:_execute_test:670
[task 2021-09-30T01:22:58.308Z] 01:22:58     INFO -  -e:null:1
[task 2021-09-30T01:22:58.308Z] 01:22:58     INFO -  exiting test
[task 2021-09-30T01:22:58.308Z] 01:22:58     INFO -  NS_ERROR_ABORT:
[task 2021-09-30T01:22:58.309Z] 01:22:58     INFO -  _abort_failed_test@/builds/worker/workspace/build/tests/xpcshell/head.js:868:20
[task 2021-09-30T01:22:58.309Z] 01:22:58     INFO -  do_report_result@/builds/worker/workspace/build/tests/xpcshell/head.js:969:5
[task 2021-09-30T01:22:58.309Z] 01:22:58     INFO -  Assert<@/builds/worker/workspace/build/tests/xpcshell/head.js:75:21
[task 2021-09-30T01:22:58.309Z] 01:22:58     INFO -  proto.report@resource://testing-common/Assert.jsm:228:10
[task 2021-09-30T01:22:58.309Z] 01:22:58     INFO -  equal@resource://testing-common/Assert.jsm:270:8
[task 2021-09-30T01:22:58.309Z] 01:22:58     INFO -  ExtensionWrapper/<@resource://testing-common/ExtensionXPCShellUtils.jsm:97:24
[task 2021-09-30T01:22:58.309Z] 01:22:58     INFO -  _execute_test/<@/builds/worker/workspace/build/tests/xpcshell/head.js:661:28
[task 2021-09-30T01:22:58.310Z] 01:22:58     INFO -  _execute_test@/builds/worker/workspace/build/tests/xpcshell/head.js:670:5
[task 2021-09-30T01:22:58.310Z] 01:22:58     INFO -  @-e:1:1
[task 2021-09-30T01:22:58.310Z] 01:22:58     INFO -  Error: Found unexpected files in temporary directory: generated-extension.xpi at resource://testing-common/AddonTestUtils.jsm:416
[task 2021-09-30T01:22:58.310Z] 01:22:58     INFO -  init/<@resource://testing-common/AddonTestUtils.jsm:416:15
[task 2021-09-30T01:22:58.310Z] 01:22:58     INFO -  _execute_test/<@/builds/worker/workspace/build/tests/xpcshell/head.js:661:28
[task 2021-09-30T01:22:58.310Z] 01:22:58     INFO -  _execute_test@/builds/worker/workspace/build/tests/xpcshell/head.js:673:16
[task 2021-09-30T01:22:58.310Z] 01:22:58     INFO -  @-e:1:1
[task 2021-09-30T01:22:58.310Z] 01:22:58     INFO -  PID 23814 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-09-30T01:22:58.310Z] 01:22:58     INFO -  PID 23814 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-09-30T01:22:58.311Z] 01:22:58     INFO -  PID 23814 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-09-30T01:22:58.311Z] 01:22:58     INFO -  PID 23814 | [warn] evsig_handler: received signal 17, but have no base configured
[task 2021-09-30T01:22:58.311Z] 01:22:58     INFO -  <<<<<<<
[task 2021-09-30T01:22:58.311Z] 01:22:58     INFO -  INFO | Result summary:
[task 2021-09-30T01:22:58.311Z] 01:22:58     INFO -  INFO | Passed: 187
[task 2021-09-30T01:22:58.311Z] 01:22:58  WARNING -  INFO | Failed: 1
[task 2021-09-30T01:22:58.311Z] 01:22:58  WARNING -  One or more unittests failed.
[task 2021-09-30T01:22:58.311Z] 01:22:58     INFO -  INFO | Todo: 0
[task 2021-09-30T01:22:58.311Z] 01:22:58     INFO -  INFO | Retried: 1
[task 2021-09-30T01:22:58.311Z] 01:22:58     INFO -  SUITE-END | took 1923s
[task 2021-09-30T01:22:58.312Z] 01:22:58     INFO -  Node moz-http2 server shutting down ...
[task 2021-09-30T01:22:58.312Z] 01:22:58     INFO -  http3Server server shutting down ...
[task 2021-09-30T01:22:58.433Z] 01:22:58    ERROR - Return code: 1
[task 2021-09-30T01:22:58.434Z] 01:22:58     INFO - TinderboxPrint: xpcshell-xpcshell<br/>187/<em class="testfail">1</em>/0
[task 2021-09-30T01:22:58.434Z] 01:22:58  WARNING - # TBPL FAILURE #
[task 2021-09-30T01:22:58.434Z] 01:22:58  WARNING - setting return code to 2
[task 2021-09-30T01:22:58.434Z] 01:22:58  WARNING - The xpcshell suite: xpcshell ran with return status: FAILURE
[task 2021-09-30T01:22:58.435Z] 01:22:58     INFO - Running post-action listener: _package_coverage_data
[task 2021-09-30T01:22:58.435Z] 01:22:58     INFO - Running post-action listener: _resource_record_post_action
[task 2021-09-30T01:22:58.435Z] 01:22:58     INFO - Running post-action listener: process_java_coverage_data
[task 2021-09-30T01:22:58.435Z] 01:22:58     INFO - [mozharness: 2021-09-30 01:22:58.434592Z] Finished run-tests step (success)
[task 2021-09-30T01:22:58.435Z] 01:22:58     INFO - Running post-run listener: _resource_record_post_run
[task 2021-09-30T01:22:58.563Z] 01:22:58     INFO - Validating Perfherder data against /builds/worker/workspace/mozharness/external_tools/performance-artifact-schema.json
[task 2021-09-30T01:22:58.567Z] 01:22:58     INFO - PERFHERDER_DATA: {"framework": {"name": "job_resource_usage"}, "suites": [{"name": "xpcshell.xpcshell.overall", "extraOptions": ["e10s", "taskcluster-m5.large"], "subtests": [{"name": "cpu_percent", "value": 81.91180487804873}, {"name": "io_write_bytes", "value": 3652935680}, {"name": "io.read_bytes", "value": 62824448}, {"name": "io_write_time", "value": 471424}, {"name": "io_read_time", "value": 5696}]}, {"name": "xpcshell.xpcshell.start-pulseaudio", "subtests": [{"name": "time", "value": 0.028124094009399414}]}, {"name": "xpcshell.xpcshell.install", "subtests": [{"name": "time", "value": 33.934112787246704}, {"name": "cpu_percent", "value": 50.2921875}]}, {"name": "xpcshell.xpcshell.stage-files", "subtests": [{"name": "time", "value": 0.053666114807128906}]}, {"name": "xpcshell.xpcshell.run-tests", "subtests": [{"name": "time", "value": 2018.9294826984406}, {"name": "cpu_percent", "value": 82.44481646825392}]}]}
[task 2021-09-30T01:22:58.567Z] 01:22:58     INFO - Total resource usage - Wall time: 2053s; CPU: 82%; Read bytes: 62824448; Write bytes: 3652935680; Read time: 5696; Write time: 471424
[task 2021-09-30T01:22:58.568Z] 01:22:58     INFO - TinderboxPrint: CPU usage<br/>82.4%
[task 2021-09-30T01:22:58.568Z] 01:22:58     INFO - TinderboxPrint: I/O read bytes / time<br/>62,824,448 / 5,696
[task 2021-09-30T01:22:58.569Z] 01:22:58     INFO - TinderboxPrint: I/O write bytes / time<br/>3,652,935,680 / 471,424
[task 2021-09-30T01:22:58.570Z] 01:22:58     INFO - TinderboxPrint: CPU idle<br/>735.9 (17.9%)
[task 2021-09-30T01:22:58.570Z] 01:22:58     INFO - TinderboxPrint: CPU system<br/>313.7 (7.6%)
[task 2021-09-30T01:22:58.571Z] 01:22:58     INFO - TinderboxPrint: CPU user<br/>3,048.1 (74.3%)
[task 2021-09-30T01:22:58.571Z] 01:22:58     INFO - TinderboxPrint: Swap in / out<br/>0 / 0
[task 2021-09-30T01:22:58.572Z] 01:22:58     INFO - start-pulseaudio - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2021-09-30T01:22:58.572Z] 01:22:58     INFO - install - Wall time: 34s; CPU: 50%; Read bytes: 32768; Write bytes: 1370968064; Read time: 292; Write time: 135476
[task 2021-09-30T01:22:58.573Z] 01:22:58     INFO - stage-files - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2021-09-30T01:22:58.582Z] 01:22:58     INFO - run-tests - Wall time: 2019s; CPU: 82%; Read bytes: 62783488; Write bytes: 2007502848; Read time: 5292; Write time: 298648
[task 2021-09-30T01:22:58.814Z] 01:22:58  WARNING - returning nonzero exit status 2
[task 2021-09-30T01:22:58.844Z] cleanup
[task 2021-09-30T01:22:58.844Z] + cleanup
[task 2021-09-30T01:22:58.844Z] + local rv=2
[task 2021-09-30T01:22:58.844Z] + [[ -s /builds/worker/.xsession-errors ]]
[task 2021-09-30T01:22:58.845Z] + cp /builds/worker/.xsession-errors /builds/worker/artifacts/public/xsession-errors.log
[task 2021-09-30T01:22:58.848Z] + '[' ']'
[task 2021-09-30T01:22:58.848Z] + true
[task 2021-09-30T01:22:58.848Z] + cleanup_xvfb
[task 2021-09-30T01:22:58.848Z] ++ pidof Xvfb
[task 2021-09-30T01:22:58.866Z] + local xvfb_pid=49
[task 2021-09-30T01:22:58.879Z] + local vnc=false
[task 2021-09-30T01:22:58.880Z] + local interactive=false
[task 2021-09-30T01:22:58.881Z] + '[' -n 49 ']'
[task 2021-09-30T01:22:58.881Z] + [[ false == false ]]
[task 2021-09-30T01:22:58.882Z] + [[ false == false ]]
[task 2021-09-30T01:22:58.882Z] + kill 49
[task 2021-09-30T01:22:58.882Z] + screen -XS xvfb quit
[task 2021-09-30T01:22:58.916Z] + exit 2
[taskcluster 2021-09-30 01:22:59.204Z] === Task Finished ===
[taskcluster 2021-09-30 01:23:02.213Z] Unsuccessful task run with exit code: 2 completed in 2160.262 seconds
Status: NEW → RESOLVED
Closed: 4 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.