Closed Bug 1696027 Opened 3 years ago Closed 3 years ago

Remove use of addEngineWithDetails from Mochitests

Categories

(Firefox :: Search, task, P2)

Product:
Firefox
Component:
Search
Type:
task
Points:
3

Tracking

()

Status:
RESOLVED FIXED
Milestone:
88 Branch
Iteration:
88.2 - Mar 8 - Mar 21
Tracking Flags:
Tracking Status
firefox88 --- fixed

People

(Reporter: standard8, Assigned: standard8)

References

Details

Attachments

(1 file)

Bug 1696027 - Remove use of nsISearchEngine.addEngineWithDetails from mochitests.
48 bytes, text/x-phabricator-request
Details | Review

Splitting out from bug 1649186 to split up review load and reduce landing risk, also to allow some time to for xpcshell-tests to figure out bug 1694409.

Pushed by mbanner@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/395e7278e415
Remove use of nsISearchEngine.addEngineWithDetails from mochitests. r=daleharvey
Flags: qe-verify-

Backed out 2 changesets (bug 369739, bug 1696027) for test_TelemetryEnvironment.js xpcshell failures.

Push with failures: https://treeherder.mozilla.org/jobs?repo=autoland&group_state=expanded&fromchange=37aae4f2c6cf87ed3d43dc59b8202316af47ac0d&test_paths=toolkit%2Fcomponents%2Ftelemetry%2Ftests%2Funit&selectedTaskRun=VXnhoc3bRiS9kIwvCLxbFw.0&tochange=cf95656a040db7c8a12a9393362d90726cebccfa

Backout link: https://hg.mozilla.org/integration/autoland/rev/8d9fd8fb263d498b93036f8f27309f78fd435efb

Failure log: https://treeherder.mozilla.org/logviewer?job_id=332652617&repo=autoland&lineNumber=3178

[task 2021-03-10T08:39:14.774Z] 08:39:14     INFO -  TEST-START | toolkit/components/telemetry/tests/unit/test_TelemetryEnvironment.js
[task 2021-03-10T08:39:15.252Z] 08:39:15  WARNING -  TEST-UNEXPECTED-FAIL | toolkit/components/telemetry/tests/unit/test_TelemetryEnvironment.js | xpcshell return code: 0
[task 2021-03-10T08:39:15.253Z] 08:39:15     INFO -  TEST-INFO took 471ms
[task 2021-03-10T08:39:15.254Z] 08:39:15     INFO -  >>>>>>>
[task 2021-03-10T08:39:15.254Z] 08:39:15     INFO -  NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIProperties.get]
[task 2021-03-10T08:39:15.255Z] 08:39:15     INFO -  FileUtils_getDir@resource://gre/modules/FileUtils.jsm:74:27
[task 2021-03-10T08:39:15.255Z] 08:39:15     INFO -  initMochitest@resource://testing-common/AddonTestUtils.jsm:463:33
[task 2021-03-10T08:39:15.256Z] 08:39:15     INFO -  init@resource://testing-common/SearchTestUtils.jsm:35:22
[task 2021-03-10T08:39:15.256Z] 08:39:15     INFO -  @/builds/worker/workspace/build/tests/xpcshell/tests/toolkit/components/telemetry/tests/unit/test_TelemetryEnvironment.js:50:17
[task 2021-03-10T08:39:15.257Z] 08:39:15     INFO -  load_file@/builds/worker/workspace/build/tests/xpcshell/head.js:717:11
[task 2021-03-10T08:39:15.258Z] 08:39:15     INFO -  _load_files@/builds/worker/workspace/build/tests/xpcshell/head.js:734:10
[task 2021-03-10T08:39:15.258Z] 08:39:15     INFO -  _execute_test@/builds/worker/workspace/build/tests/xpcshell/head.js:539:14
[task 2021-03-10T08:39:15.259Z] 08:39:15     INFO -  @-e:1:1
[task 2021-03-10T08:39:15.259Z] 08:39:15     INFO -  (xpcshell/head.js) | test MAIN run_test pending (1)
[task 2021-03-10T08:39:15.260Z] 08:39:15     INFO -  (xpcshell/head.js) | test run_next_test 0 pending (2)
[task 2021-03-10T08:39:15.260Z] 08:39:15     INFO -  (xpcshell/head.js) | test MAIN run_test finished (2)
[task 2021-03-10T08:39:15.261Z] 08:39:15     INFO -  running event loop
[task 2021-03-10T08:39:15.261Z] 08:39:15     INFO -  (xpcshell/head.js) | test run_next_test 0 finished (1)
[task 2021-03-10T08:39:15.262Z] 08:39:15     INFO -  exiting test
[task 2021-03-10T08:39:15.264Z] 08:39:15     INFO -  "CONSOLE_MESSAGE: (error) [JavaScript Error: "1615365555178	Toolkit.Telemetry	ERROR	TelemetrySend::shutdown - failed to remove observer for idle-daily: [Exception... "Component returned failure code: 0x80070057 (NS_ERROR_ILLEGAL_VALUE) [nsIObserverService.removeObserver]"  nsresult: "0x80070057 (NS_ERROR_ILLEGAL_VALUE)"  location: "JS frame :: resource://gre/modules/TelemetrySend.jsm :: shutdown :: line 865"  data: no] Stack trace: shutdown()@resource://gre/modules/TelemetrySend.jsm:865
[task 2021-03-10T08:39:15.265Z] 08:39:15     INFO -  shutdown()@resource://gre/modules/TelemetrySend.jsm:231
[task 2021-03-10T08:39:15.266Z] 08:39:15     INFO -  /builds/worker/workspace/build/tests/xpcshell/tests/toolkit/components/telemetry/tests/unit/head.js:573
[task 2021-03-10T08:39:15.267Z] 08:39:15     INFO -  _execute_test/<()@/builds/worker/workspace/build/tests/xpcshell/head.js:631
[task 2021-03-10T08:39:15.268Z] 08:39:15     INFO -  _execute_test()@/builds/worker/workspace/build/tests/xpcshell/head.js:640
[task 2021-03-10T08:39:15.269Z] 08:39:15     INFO -  -e:1" {file: "resource://gre/modules/Log.jsm" line: 723}]
[task 2021-03-10T08:39:15.270Z] 08:39:15     INFO -  append@resource://gre/modules/Log.jsm:723:12
[task 2021-03-10T08:39:15.270Z] 08:39:15     INFO -  log@resource://gre/modules/Log.jsm:379:16
[task 2021-03-10T08:39:15.271Z] 08:39:15     INFO -  getLoggerWithMessagePrefix/proxy.log@resource://gre/modules/Log.jsm:508:18
[task 2021-03-10T08:39:15.272Z] 08:39:15     INFO -  error@resource://gre/modules/Log.jsm:387:10
[task 2021-03-10T08:39:15.273Z] 08:39:15     INFO -  shutdown@resource://gre/modules/TelemetrySend.jsm:867:19
[task 2021-03-10T08:39:15.274Z] 08:39:15     INFO -  shutdown@resource://gre/modules/TelemetrySend.jsm:231:30
[task 2021-03-10T08:39:15.275Z] 08:39:15     INFO -  @/builds/worker/workspace/build/tests/xpcshell/tests/toolkit/components/telemetry/tests/unit/head.js:573:47
[task 2021-03-10T08:39:15.275Z] 08:39:15     INFO -  _execute_test/<@/builds/worker/workspace/build/tests/xpcshell/head.js:631:28
[task 2021-03-10T08:39:15.276Z] 08:39:15     INFO -  _execute_test@/builds/worker/workspace/build/tests/xpcshell/head.js:640:5
[task 2021-03-10T08:39:15.277Z] 08:39:15     INFO -  @-e:1:1
[task 2021-03-10T08:39:15.278Z] 08:39:15     INFO -  "
[task 2021-03-10T08:39:15.279Z] 08:39:15     INFO -  "CONSOLE_MESSAGE: (error) [JavaScript Error: "1615365555180	Toolkit.Telemetry	ERROR	TelemetrySend::shutdown - failed to remove observer for quit-application-granted: [Exception... "Component returned failure code: 0x80070057 (NS_ERROR_ILLEGAL_VALUE) [nsIObserverService.removeObserver]"  nsresult: "0x80070057 (NS_ERROR_ILLEGAL_VALUE)"  location: "JS frame :: resource://gre/modules/TelemetrySend.jsm :: shutdown :: line 865"  data: no] Stack trace: shutdown()@resource://gre/modules/TelemetrySend.jsm:865
[task 2021-03-10T08:39:15.281Z] 08:39:15     INFO -  shutdown()@resource://gre/modules/TelemetrySend.jsm:231
[task 2021-03-10T08:39:15.282Z] 08:39:15     INFO -  /builds/worker/workspace/build/tests/xpcshell/tests/toolkit/components/telemetry/tests/unit/head.js:573
[task 2021-03-10T08:39:15.283Z] 08:39:15     INFO -  _execute_test/<()@/builds/worker/workspace/build/tests/xpcshell/head.js:631
[task 2021-03-10T08:39:15.284Z] 08:39:15     INFO -  _execute_test()@/builds/worker/workspace/build/tests/xpcshell/head.js:640
[task 2021-03-10T08:39:15.285Z] 08:39:15     INFO -  -e:1" {file: "resource://gre/modules/Log.jsm" line: 723}]
[task 2021-03-10T08:39:15.286Z] 08:39:15     INFO -  append@resource://gre/modules/Log.jsm:723:12
[task 2021-03-10T08:39:15.286Z] 08:39:15     INFO -  log@resource://gre/modules/Log.jsm:379:16
[task 2021-03-10T08:39:15.287Z] 08:39:15     INFO -  getLoggerWithMessagePrefix/proxy.log@resource://gre/modules/Log.jsm:508:18
[task 2021-03-10T08:39:15.288Z] 08:39:15     INFO -  error@resource://gre/modules/Log.jsm:387:10
[task 2021-03-10T08:39:15.289Z] 08:39:15     INFO -  shutdown@resource://gre/modules/TelemetrySend.jsm:867:19
[task 2021-03-10T08:39:15.290Z] 08:39:15     INFO -  shutdown@resource://gre/modules/TelemetrySend.jsm:231:30
[task 2021-03-10T08:39:15.291Z] 08:39:15     INFO -  @/builds/worker/workspace/build/tests/xpcshell/tests/toolkit/components/telemetry/tests/unit/head.js:573:47
[task 2021-03-10T08:39:15.292Z] 08:39:15     INFO -  _execute_test/<@/builds/worker/workspace/build/tests/xpcshell/head.js:631:28
[task 2021-03-10T08:39:15.293Z] 08:39:15     INFO -  _execute_test@/builds/worker/workspace/build/tests/xpcshell/head.js:640:5
[task 2021-03-10T08:39:15.294Z] 08:39:15     INFO -  @-e:1:1
[task 2021-03-10T08:39:15.295Z] 08:39:15     INFO -  "
[task 2021-03-10T08:39:15.296Z] 08:39:15     INFO -  "CONSOLE_MESSAGE: (error) [JavaScript Error: "1615365555181	Toolkit.Telemetry	ERROR	TelemetrySend::shutdown - failed to remove observer for quit-application-forced: [Exception... "Component returned failure code: 0x80070057 (NS_ERROR_ILLEGAL_VALUE) [nsIObserverService.removeObserver]"  nsresult: "0x80070057 (NS_ERROR_ILLEGAL_VALUE)"  location: "JS frame :: resource://gre/modules/TelemetrySend.jsm :: shutdown :: line 865"  data: no] Stack trace: shutdown()@resource://gre/modules/TelemetrySend.jsm:865
[task 2021-03-10T08:39:15.299Z] 08:39:15     INFO -  shutdown()@resource://gre/modules/TelemetrySend.jsm:231
[task 2021-03-10T08:39:15.299Z] 08:39:15     INFO -  /builds/worker/workspace/build/tests/xpcshell/tests/toolkit/components/telemetry/tests/unit/head.js:573
[task 2021-03-10T08:39:15.300Z] 08:39:15     INFO -  _execute_test/<()@/builds/worker/workspace/build/tests/xpcshell/head.js:631
[task 2021-03-10T08:39:15.301Z] 08:39:15     INFO -  _execute_test()@/builds/worker/workspace/build/tests/xpcshell/head.js:640
[task 2021-03-10T08:39:15.302Z] 08:39:15     INFO -  -e:1" {file: "resource://gre/modules/Log.jsm" line: 723}]
[task 2021-03-10T08:39:15.303Z] 08:39:15     INFO -  append@resource://gre/modules/Log.jsm:723:12
[task 2021-03-10T08:39:15.304Z] 08:39:15     INFO -  log@resource://gre/modules/Log.jsm:379:16
[task 2021-03-10T08:39:15.305Z] 08:39:15     INFO -  getLoggerWithMessagePrefix/proxy.log@resource://gre/modules/Log.jsm:508:18
[task 2021-03-10T08:39:15.306Z] 08:39:15     INFO -  error@resource://gre/modules/Log.jsm:387:10
[task 2021-03-10T08:39:15.307Z] 08:39:15     INFO -  shutdown@resource://gre/modules/TelemetrySend.jsm:867:19
[task 2021-03-10T08:39:15.308Z] 08:39:15     INFO -  shutdown@resource://gre/modules/TelemetrySend.jsm:231:30
[task 2021-03-10T08:39:15.309Z] 08:39:15     INFO -  @/builds/worker/workspace/build/tests/xpcshell/tests/toolkit/components/telemetry/tests/unit/head.js:573:47
[task 2021-03-10T08:39:15.310Z] 08:39:15     INFO -  _execute_test/<@/builds/worker/workspace/build/tests/xpcshell/head.js:631:28
[task 2021-03-10T08:39:15.311Z] 08:39:15     INFO -  _execute_test@/builds/worker/workspace/build/tests/xpcshell/head.js:640:5
[task 2021-03-10T08:39:15.312Z] 08:39:15     INFO -  @-e:1:1
[task 2021-03-10T08:39:15.313Z] 08:39:15     INFO -  "
[task 2021-03-10T08:39:15.314Z] 08:39:15     INFO -  "CONSOLE_MESSAGE: (error) [JavaScript Error: "1615365555182	Toolkit.Telemetry	ERROR	TelemetrySend::shutdown - failed to remove observer for profile-change-net-teardown: [Exception... "Component returned failure code: 0x80070057 (NS_ERROR_ILLEGAL_VALUE) [nsIObserverService.removeObserver]"  nsresult: "0x80070057 (NS_ERROR_ILLEGAL_VALUE)"  location: "JS frame :: resource://gre/modules/TelemetrySend.jsm :: shutdown :: line 865"  data: no] Stack trace: shutdown()@resource://gre/modules/TelemetrySend.jsm:865
[task 2021-03-10T08:39:15.317Z] 08:39:15     INFO -  shutdown()@resource://gre/modules/TelemetrySend.jsm:231
[task 2021-03-10T08:39:15.318Z] 08:39:15     INFO -  /builds/worker/workspace/build/tests/xpcshell/tests/toolkit/components/telemetry/tests/unit/head.js:573
[task 2021-03-10T08:39:15.319Z] 08:39:15     INFO -  _execute_test/<()@/builds/worker/workspace/build/tests/xpcshell/head.js:631
[task 2021-03-10T08:39:15.320Z] 08:39:15     INFO -  _execute_test()@/builds/worker/workspace/build/tests/xpcshell/head.js:640
[task 2021-03-10T08:39:15.321Z] 08:39:15     INFO -  -e:1" {file: "resource://gre/modules/Log.jsm" line: 723}]
[task 2021-03-10T08:39:15.322Z] 08:39:15     INFO -  append@resource://gre/modules/Log.jsm:723:12
[task 2021-03-10T08:39:15.323Z] 08:39:15     INFO -  log@resource://gre/modules/Log.jsm:379:16
[task 2021-03-10T08:39:15.324Z] 08:39:15     INFO -  getLoggerWithMessagePrefix/proxy.log@resource://gre/modules/Log.jsm:508:18
[task 2021-03-10T08:39:15.324Z] 08:39:15     INFO -  error@resource://gre/modules/Log.jsm:387:10
[task 2021-03-10T08:39:15.325Z] 08:39:15     INFO -  shutdown@resource://gre/modules/TelemetrySend.jsm:867:19
[task 2021-03-10T08:39:15.326Z] 08:39:15     INFO -  shutdown@resource://gre/modules/TelemetrySend.jsm:231:30
[task 2021-03-10T08:39:15.327Z] 08:39:15     INFO -  @/builds/worker/workspace/build/tests/xpcshell/tests/toolkit/components/telemetry/tests/unit/head.js:573:47
[task 2021-03-10T08:39:15.328Z] 08:39:15     INFO -  _execute_test/<@/builds/worker/workspace/build/tests/xpcshell/head.js:631:28
[task 2021-03-10T08:39:15.329Z] 08:39:15     INFO -  _execute_test@/builds/worker/workspace/build/tests/xpcshell/head.js:640:5
[task 2021-03-10T08:39:15.330Z] 08:39:15     INFO -  @-e:1:1
[task 2021-03-10T08:39:15.330Z] 08:39:15     INFO -  "
[task 2021-03-10T08:39:15.330Z] 08:39:15     INFO -  "CONSOLE_MESSAGE: (info) 1615365555183	Toolkit.Telemetry	TRACE	TelemetrySend::Scheduler::shutdown"
[task 2021-03-10T08:39:15.331Z] 08:39:15     INFO -  "CONSOLE_MESSAGE: (info) 1615365555183	Toolkit.Telemetry	TRACE	TelemetrySend::promisePendingPingActivity - Waiting for ping task"
[task 2021-03-10T08:39:15.331Z] 08:39:15     INFO -  <<<<<<<
[task 2021-03-10T08:39:15.331Z] 08:39:15     INFO -  INFO | Result summary:
[task 2021-03-10T08:39:15.332Z] 08:39:15     INFO -  INFO | Passed: 471
[task 2021-03-10T08:39:15.332Z] 08:39:15  WARNING -  INFO | Failed: 1
[task 2021-03-10T08:39:15.332Z] 08:39:15  WARNING -  One or more unittests failed.
[task 2021-03-10T08:39:15.332Z] 08:39:15     INFO -  INFO | Todo: 0
[task 2021-03-10T08:39:15.333Z] 08:39:15     INFO -  INFO | Retried: 1
[task 2021-03-10T08:39:15.333Z] 08:39:15     INFO -  SUITE-END | took 448s
[task 2021-03-10T08:39:15.333Z] 08:39:15     INFO -  Node moz-http2 server shutting down ...
[task 2021-03-10T08:39:15.341Z] 08:39:15    ERROR - Return code: 1
[task 2021-03-10T08:39:15.341Z] 08:39:15     INFO - TinderboxPrint: xpcshell-xpcshell<br/>471/<em class="testfail">1</em>/0
[task 2021-03-10T08:39:15.342Z] 08:39:15  WARNING - # TBPL FAILURE #
[task 2021-03-10T08:39:15.342Z] 08:39:15  WARNING - setting return code to 2
Flags: needinfo?(standard8)

Missed running the xpcshell tests. For the telemetry test ExtensionTestUtils does exist, so SearchTestUtils thinks it is in a mochitest rather than xpcshell. I've switched across to use a different method, so hopefully that will work better now.

I also fixed a minor issue in test_TelemetryEnvironment.js which was caused by the change to how we generate Ids (which makes things simpler overall).

Flags: needinfo?(standard8)
Pushed by mbanner@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/6e5ccf3eeaa6
Remove use of nsISearchEngine.addEngineWithDetails from mochitests. r=daleharvey

Backed out 2 changesets (bug 369739, bug 1696027) for browser_searchChangedEngine.js and test_webextensions_upgrade.js failures.

Push with failures:
https://treeherder.mozilla.org/jobs?repo=autoland&group_state=expanded&fromchange=f088cf41fc03ae1acfd956bf9150ca0bdf0a6c1e&test_paths=browser%2Fcomponents%2Fpreferences%2Ftests&selectedTaskRun=A2HkrrXIQKWaggprbA7tEQ.0&tochange=2760de845c282752271101abe78c834d82304587
https://treeherder.mozilla.org/jobs?repo=autoland&group_state=expanded&selectedTaskRun=AD6Hnm6YT3a_J_7YT5tj8A.0&fromchange=f088cf41fc03ae1acfd956bf9150ca0bdf0a6c1e&test_paths=toolkit%2Fcomponents%2Fsearch%2Ftests%2Fxpcshell&tochange=2760de845c282752271101abe78c834d82304587
Backout link: https://hg.mozilla.org/integration/autoland/rev/2760de845c282752271101abe78c834d82304587

Failures logs:
https://treeherder.mozilla.org/logviewer?job_id=332687081&repo=autoland&lineNumber=5083

[task 2021-03-10T13:14:29.217Z] 13:14:29     INFO - TEST-START | browser/components/preferences/tests/browser_searchChangedEngine.js
[task 2021-03-10T13:15:14.242Z] 13:15:14     INFO - TEST-INFO | started process screentopng
[task 2021-03-10T13:15:14.635Z] 13:15:14     INFO - TEST-INFO | screentopng: exit 0
[task 2021-03-10T13:15:14.636Z] 13:15:14     INFO - Buffered messages logged at 13:14:29
[task 2021-03-10T13:15:14.637Z] 13:15:14     INFO - Entering test bound test_change_engine
[task 2021-03-10T13:15:14.637Z] 13:15:14     INFO - Extension loaded
[task 2021-03-10T13:15:14.637Z] 13:15:14     INFO - TEST-PASS | browser/components/preferences/tests/browser_searchChangedEngine.js | Search provider extension should be running - "running" == "running" - 
[task 2021-03-10T13:15:14.638Z] 13:15:14     INFO - TEST-PASS | browser/components/preferences/tests/browser_searchChangedEngine.js | Extension ID of search provider should be set - "example@tests.mozilla.org" == true - 
[task 2021-03-10T13:15:14.638Z] 13:15:14     INFO - TEST-PASS | browser/components/preferences/tests/browser_searchChangedEngine.js | Search provider extension should be running - "running" == "running" - 
[task 2021-03-10T13:15:14.639Z] 13:15:14     INFO - TEST-PASS | browser/components/preferences/tests/browser_searchChangedEngine.js | Extension ID of search provider should be set - "example@tests.mozilla.org" == true - 
[task 2021-03-10T13:15:14.639Z] 13:15:14     INFO - TEST-PASS | browser/components/preferences/tests/browser_searchChangedEngine.js | Should have found the entry - 6 != -1 - 
[task 2021-03-10T13:15:14.639Z] 13:15:14     INFO - TEST-PASS | browser/components/preferences/tests/browser_searchChangedEngine.js | Should have the correct image URL - true == true - 
[task 2021-03-10T13:15:14.640Z] 13:15:14     INFO - TEST-PASS | browser/components/preferences/tests/browser_searchChangedEngine.js | Should show the correct keyword - "foo" == "foo" - 
[task 2021-03-10T13:15:14.642Z] 13:15:14     INFO - Extension loaded
[task 2021-03-10T13:15:14.642Z] 13:15:14     INFO - TEST-PASS | browser/components/preferences/tests/browser_searchChangedEngine.js | Search provider extension should be running - "running" == "running" - 
[task 2021-03-10T13:15:14.642Z] 13:15:14     INFO - TEST-PASS | browser/components/preferences/tests/browser_searchChangedEngine.js | Extension ID of search provider should be set - "example2@tests.mozilla.org" == true - 
[task 2021-03-10T13:15:14.642Z] 13:15:14     INFO - TEST-PASS | browser/components/preferences/tests/browser_searchChangedEngine.js | Search provider extension should be running - "running" == "running" - 
[task 2021-03-10T13:15:14.643Z] 13:15:14     INFO - TEST-PASS | browser/components/preferences/tests/browser_searchChangedEngine.js | Extension ID of search provider should be set - "example2@tests.mozilla.org" == true - 
[task 2021-03-10T13:15:14.645Z] 13:15:14     INFO - Buffered messages finished
[task 2021-03-10T13:15:14.646Z] 13:15:14     INFO - TEST-UNEXPECTED-FAIL | browser/components/preferences/tests/browser_searchChangedEngine.js | Test timed out - 
[task 2021-03-10T13:15:14.646Z] 13:15:14     INFO - GECKO(3738) | MEMORY STAT | vsize 3775MB | residentFast 437MB | heapAllocated 134MB
[task 2021-03-10T13:15:14.646Z] 13:15:14     INFO - TEST-OK | browser/components/preferences/tests/browser_searchChangedEngine.js | took 45239ms
[task 2021-03-10T13:15:14.646Z] 13:15:14     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-03-10T13:15:14.648Z] 13:15:14     INFO - TEST-UNEXPECTED-FAIL | browser/components/preferences/tests/browser_searchChangedEngine.js | Found a tab after previous test timed out: about:preferences#search - 
[task 2021-03-10T13:15:14.649Z] 13:15:14     INFO - checking window state

https://treeherder.mozilla.org/logviewer?job_id=332687082&repo=autoland&lineNumber=3864

[task 2021-03-10T13:21:02.496Z] 13:21:02     INFO -  TEST-START | xpcshell.ini:toolkit/components/search/tests/xpcshell/test_webextensions_upgrade.js
[task 2021-03-10T13:26:02.496Z] 13:26:02  WARNING -  TEST-UNEXPECTED-TIMEOUT | xpcshell.ini:toolkit/components/search/tests/xpcshell/test_webextensions_upgrade.js | Test timed out
[task 2021-03-10T13:26:02.496Z] 13:26:02     INFO -  TEST-INFO took 300001ms
[task 2021-03-10T13:26:02.496Z] 13:26:02     INFO -  >>>>>>>
[task 2021-03-10T13:26:02.496Z] 13:26:02     INFO -  (xpcshell/head.js) | test MAIN run_test pending (1)
[task 2021-03-10T13:26:02.497Z] 13:26:02     INFO -  (xpcshell/head.js) | test run_next_test 0 pending (2)
[task 2021-03-10T13:26:02.497Z] 13:26:02     INFO -  (xpcshell/head.js) | test MAIN run_test finished (2)
[task 2021-03-10T13:26:02.497Z] 13:26:02     INFO -  running event loop
[task 2021-03-10T13:26:02.497Z] 13:26:02     INFO -  xpcshell.ini:toolkit/components/search/tests/xpcshell/test_webextensions_upgrade.js | Starting setup
[task 2021-03-10T13:26:02.498Z] 13:26:02     INFO -  (xpcshell/head.js) | test setup pending (2)
[task 2021-03-10T13:26:02.499Z] 13:26:02     INFO -  (xpcshell/head.js) | test run_next_test 0 finished (2)
[task 2021-03-10T13:26:02.499Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "init"
[task 2021-03-10T13:26:02.507Z] 13:26:02     INFO -  PID 25433 | console.info: Region.jsm: "_getRegion called"
[task 2021-03-10T13:26:02.508Z] 13:26:02     INFO -  PID 25433 | console.info: Region.jsm: "_getRegion url is: " ""
[task 2021-03-10T13:26:02.508Z] 13:26:02     INFO -  PID 25433 | console.warn: SearchSettings: "get: No settings file exists, new profile?" (new Error("", "(unknown module)"))
[task 2021-03-10T13:26:02.509Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "_loadEngines: start"
[task 2021-03-10T13:26:02.509Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchEngineSelector: "fetchEngineConfiguration en-US:default:default::false:xpcshell:42"
[task 2021-03-10T13:26:02.510Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchEngineSelector: "fetchEngineConfiguration: engine1@search.mozilla.org,engine2@search.mozilla.org"
[task 2021-03-10T13:26:02.511Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "_loadEnginesFromConfig"
[task 2021-03-10T13:26:02.512Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "makeEngineFromConfig:" ({webExtension:{id:"engine1@search.mozilla.org", locale:"default"}, orderHint:10000, default:"yes"})
[task 2021-03-10T13:26:02.513Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "addEnginesFromExtension: engine1@search.mozilla.org"
[task 2021-03-10T13:26:02.515Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "addEnginesFromExtension: Ignoring builtIn engine."
[task 2021-03-10T13:26:02.516Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchEngine: "_setIcon: Setting icon url for" "engine1" "to" "moz-extension://ef22a655-caff-4748-a395-fb3b4338dc3b/favicon.ico"
[task 2021-03-10T13:26:02.517Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "makeEngineFromConfig:" ({webExtension:{id:"engine2@search.mozilla.org", locale:"default"}, orderHint:7000, default:"no"})
[task 2021-03-10T13:26:02.518Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "addEnginesFromExtension: engine2@search.mozilla.org"
[task 2021-03-10T13:26:02.519Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "addEnginesFromExtension: Ignoring builtIn engine."
[task 2021-03-10T13:26:02.519Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchEngine: "_setIcon: Setting icon url for" "engine2" "to" "moz-extension://21d4ff96-fe2f-44f4-a6c2-b2208ae88e90/favicon.ico"
[task 2021-03-10T13:26:02.520Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "_addEngineToStore: Adding engine:" "engine1"
[task 2021-03-10T13:26:02.521Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "_addEngineToStore: Adding engine:" "engine2"
[task 2021-03-10T13:26:02.522Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "_loadEngines: loading" 0 "engines reported by AddonManager startup"
[task 2021-03-10T13:26:02.525Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "_loadEngines: done"
[task 2021-03-10T13:26:02.526Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "_init: engines loaded, writing settings"
[task 2021-03-10T13:26:02.527Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "Completed _init"
[task 2021-03-10T13:26:02.528Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "_handleIgnoreListUpdated"
[task 2021-03-10T13:26:02.529Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchSettings: "batchTask: Invalidating engine settings"
[task 2021-03-10T13:26:02.530Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchSettings: "_write: Writing to settings file."
[task 2021-03-10T13:26:02.530Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchSettings: "_write: settings file written to disk."
[task 2021-03-10T13:26:02.531Z] 13:26:02     INFO -  (xpcshell/head.js) | test run_next_test 1 pending (2)
[task 2021-03-10T13:26:02.534Z] 13:26:02     INFO -  (xpcshell/head.js) | test setup finished (2)
[task 2021-03-10T13:26:02.535Z] 13:26:02     INFO -  xpcshell.ini:toolkit/components/search/tests/xpcshell/test_webextensions_upgrade.js | Starting test_basic_upgrade
[task 2021-03-10T13:26:02.536Z] 13:26:02     INFO -  (xpcshell/head.js) | test test_basic_upgrade pending (2)
[task 2021-03-10T13:26:02.537Z] 13:26:02     INFO -  (xpcshell/head.js) | test run_next_test 1 finished (2)
[task 2021-03-10T13:26:02.537Z] 13:26:02     INFO -  "Extension attached"
[task 2021-03-10T13:26:02.537Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "addEnginesFromExtension: example@tests.mozilla.org"
[task 2021-03-10T13:26:02.538Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "installExtensionEngine:" "example@tests.mozilla.org"
[task 2021-03-10T13:26:02.538Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "addEnginesFromExtension: installing:" "example@tests.mozilla.org" ":" "default"
[task 2021-03-10T13:26:02.539Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "_createAndAddEngine: Adding" "Example"
[task 2021-03-10T13:26:02.539Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "_addEngineToStore: Adding engine:" "Example"
[task 2021-03-10T13:26:02.539Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchUtils: "NOTIFY: Engine:" "Example" "Verb:" "engine-added"
[task 2021-03-10T13:26:02.539Z] 13:26:02     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/search/tests/xpcshell/test_webextensions_upgrade.js | test_basic_upgrade - [test_basic_upgrade : 1853] Search provider extension should be running - "running" == "running"
[task 2021-03-10T13:26:02.540Z] 13:26:02     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/search/tests/xpcshell/test_webextensions_upgrade.js | test_basic_upgrade - [test_basic_upgrade : 1858] Extension ID of search provider should be set - "example@tests.mozilla.org" == true
[task 2021-03-10T13:26:02.540Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "init"
[task 2021-03-10T13:26:02.541Z] 13:26:02     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/search/tests/xpcshell/test_webextensions_upgrade.js | test_basic_upgrade - [test_basic_upgrade : 31] Can fetch engine with alias - {"_name":"Example","_loadPath":"[other]addEngineWithDetails:example@tests.mozilla.org","description":null,"__searchForm":null,"_iconURL":"","_metaData":{},"_urls":[{"params":[{"name":"q","value":"{searchTerms}"},{"name":"version","value":"1.0"}],"rels":[],"template":"https://example.com/"}],"_isAppProvided":false,"_orderHint":"undefined","_telemetryId":null,"_updateInterval":null,"_updateURL":null,"_iconUpdateURL":null,"_extensionID":"example@tests.mozilla.org","_locale":"default","_definedAliases":["foo"],"_hasPreferredIcon":null} == true
[task 2021-03-10T13:26:02.541Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchUtils: "NOTIFY: Engine:" "Example" "Verb:" "engine-changed"
[task 2021-03-10T13:26:02.541Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "init"
[task 2021-03-10T13:26:02.542Z] 13:26:02     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/search/tests/xpcshell/test_webextensions_upgrade.js | test_basic_upgrade - [test_basic_upgrade : 35] Can fetch engine by alias - {"_name":"Example","_loadPath":"[other]addEngineWithDetails:example@tests.mozilla.org","description":null,"__searchForm":null,"_iconURL":"","_metaData":{"alias":"testing"},"_urls":[{"params":[{"name":"q","value":"{searchTerms}"},{"name":"version","value":"1.0"}],"rels":[],"template":"https://example.com/"}],"_isAppProvided":false,"_orderHint":"undefined","_telemetryId":null,"_updateInterval":null,"_updateURL":null,"_iconUpdateURL":null,"_extensionID":"example@tests.mozilla.org","_locale":"default","_definedAliases":["foo"],"_hasPreferredIcon":null} == true
[task 2021-03-10T13:26:02.542Z] 13:26:02     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/search/tests/xpcshell/test_webextensions_upgrade.js | test_basic_upgrade - [test_basic_upgrade : 37] Correct version installed - true == true
[task 2021-03-10T13:26:02.542Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "init"
[task 2021-03-10T13:26:02.543Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchUtils: "NOTIFY: Engine:" "Example" "Verb:" "engine-changed"
[task 2021-03-10T13:26:02.543Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchUtils: "NOTIFY: Engine:" "Example" "Verb:" "engine-default"
[task 2021-03-10T13:26:02.543Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchUtils: "NOTIFY: Engine:" "Example" "Verb:" "engine-default-private"
[task 2021-03-10T13:26:02.544Z] 13:26:02     INFO -  "Extension attached"
[task 2021-03-10T13:26:02.544Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "addEnginesFromExtension: example@tests.mozilla.org"
[task 2021-03-10T13:26:02.544Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchEngineSelector: "fetchEngineConfiguration en-US:default:default::false:xpcshell:42"
[task 2021-03-10T13:26:02.544Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchEngineSelector: "fetchEngineConfiguration: engine1@search.mozilla.org,engine2@search.mozilla.org"
[task 2021-03-10T13:26:02.545Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "init"
[task 2021-03-10T13:26:02.545Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "getEngines: getting all engines for" "example@tests.mozilla.org"
[task 2021-03-10T13:26:02.545Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "_buildSortedEngineList: using default orders"
[task 2021-03-10T13:26:02.545Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchUtils: "NOTIFY: Engine:" "Example" "Verb:" "engine-changed"
[task 2021-03-10T13:26:02.546Z] 13:26:02     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/search/tests/xpcshell/test_webextensions_upgrade.js | test_basic_upgrade - [test_basic_upgrade : 1853] Search provider extension should be running - "running" == "running"
[task 2021-03-10T13:26:02.546Z] 13:26:02     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/search/tests/xpcshell/test_webextensions_upgrade.js | test_basic_upgrade - [test_basic_upgrade : 1858] Extension ID of search provider should be set - "example@tests.mozilla.org" == true
[task 2021-03-10T13:26:02.546Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "init"
[task 2021-03-10T13:26:02.546Z] 13:26:02     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/search/tests/xpcshell/test_webextensions_upgrade.js | test_basic_upgrade - [test_basic_upgrade : 59] Engine still has alias set - {"_name":"Example","_loadPath":"[other]addEngineWithDetails:example@tests.mozilla.org","description":null,"__searchForm":null,"_iconURL":"","_iconMapObj":null,"_metaData":{"alias":"testing","loadPathHash":"WX6FOBi1PFFdICqfod8KWRktZ5IHUMS2202xPnTquX4="},"_urls":[{"params":[{"name":"q","value":"{searchTerms}"},{"name":"version","value":"2.0"}],"rels":[],"template":"https://example.com/"}],"_isAppProvided":false,"_orderHint":"undefined","_telemetryId":null,"_updateInterval":null,"_updateURL":null,"_iconUpdateURL":null,"_extensionID":"example@tests.mozilla.org","_locale":"default","_definedAliases":["bar"],"_hasPreferredIcon":null} == true
[task 2021-03-10T13:26:02.547Z] 13:26:02     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/search/tests/xpcshell/test_webextensions_upgrade.js | test_basic_upgrade - [test_basic_upgrade : 62] Correct version installed - true == true
[task 2021-03-10T13:26:02.547Z] 13:26:02     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/search/tests/xpcshell/test_webextensions_upgrade.js | test_basic_upgrade - [test_basic_upgrade : 64] Should have retained the same default engine - "Example" == "Example"
[task 2021-03-10T13:26:02.547Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "removeWebExtensionEngine:" "example@tests.mozilla.org"
[task 2021-03-10T13:26:02.548Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "getEngines: getting all engines for" "example@tests.mozilla.org"
[task 2021-03-10T13:26:02.548Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "init"
[task 2021-03-10T13:26:02.548Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchUtils: "NOTIFY: Engine:" "engine1" "Verb:" "engine-default"
[task 2021-03-10T13:26:02.548Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchUtils: "NOTIFY: Engine:" "engine1" "Verb:" "engine-default-private"
[task 2021-03-10T13:26:02.549Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "_saveSortedEngineList"
[task 2021-03-10T13:26:02.549Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchUtils: "NOTIFY: Engine:" "Example" "Verb:" "engine-removed"
[task 2021-03-10T13:26:02.549Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "removeWebExtensionEngine:" "example@tests.mozilla.org"
[task 2021-03-10T13:26:02.549Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "getEngines: getting all engines for" "example@tests.mozilla.org"
[task 2021-03-10T13:26:02.550Z] 13:26:02     INFO -  "CONSOLE_MESSAGE: (info) QuotaManager failure: 'Unavailable', file QuotaCommon.h, line 1177 failed with result 0x80520006 (NS_ERROR_FILE_TARGET_DOES_NOT_EXIST)"
[task 2021-03-10T13:26:02.550Z] 13:26:02     INFO -  "CONSOLE_MESSAGE: (info) QuotaManager failure: 'Unavailable', file ActorsParent.cpp, line 9056 failed with result 0x80520006 (NS_ERROR_FILE_TARGET_DOES_NOT_EXIST)"
[task 2021-03-10T13:26:02.550Z] 13:26:02     INFO -  "CONSOLE_MESSAGE: (info) QuotaManager failure: 'Unavailable', file QuotaCommon.h, line 1177 failed with result 0x80520006 (NS_ERROR_FILE_TARGET_DOES_NOT_EXIST)"
[task 2021-03-10T13:26:02.551Z] 13:26:02     INFO -  "CONSOLE_MESSAGE: (info) QuotaManager failure: 'Unavailable', file ActorsParent.cpp, line 9056 failed with result 0x80520006 (NS_ERROR_FILE_TARGET_DOES_NOT_EXIST)"
[task 2021-03-10T13:26:02.551Z] 13:26:02     INFO -  "CONSOLE_MESSAGE: (info) QuotaManager failure: 'Unavailable', file QuotaCommon.h, line 1177 failed with result 0x80520006 (NS_ERROR_FILE_TARGET_DOES_NOT_EXIST)"
[task 2021-03-10T13:26:02.551Z] 13:26:02     INFO -  "CONSOLE_MESSAGE: (info) QuotaManager failure: 'Unavailable', file ActorsParent.cpp, line 9056 failed with result 0x80520006 (NS_ERROR_FILE_TARGET_DOES_NOT_EXIST)"
[task 2021-03-10T13:26:02.552Z] 13:26:02     INFO -  "CONSOLE_MESSAGE: (info) QuotaManager failure: 'Unavailable', file QuotaCommon.h, line 1177 failed with result 0x80520006 (NS_ERROR_FILE_TARGET_DOES_NOT_EXIST)"
[task 2021-03-10T13:26:02.552Z] 13:26:02     INFO -  "CONSOLE_MESSAGE: (info) QuotaManager failure: 'Unavailable', file ActorsParent.cpp, line 9056 failed with result 0x80520006 (NS_ERROR_FILE_TARGET_DOES_NOT_EXIST)"
[task 2021-03-10T13:26:02.552Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchSettings: "batchTask: Invalidating engine settings"
[task 2021-03-10T13:26:02.552Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchSettings: "_write: Writing to settings file."
[task 2021-03-10T13:26:02.553Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchSettings: "_write: settings file written to disk."
[task 2021-03-10T13:26:02.553Z] 13:26:02     INFO -  (xpcshell/head.js) | test run_next_test 2 pending (2)
[task 2021-03-10T13:26:02.553Z] 13:26:02     INFO -  (xpcshell/head.js) | test test_basic_upgrade finished (2)
[task 2021-03-10T13:26:02.554Z] 13:26:02     INFO -  xpcshell.ini:toolkit/components/search/tests/xpcshell/test_webextensions_upgrade.js | Starting test_upgrade_changes_name
[task 2021-03-10T13:26:02.554Z] 13:26:02     INFO -  (xpcshell/head.js) | test test_upgrade_changes_name pending (2)
[task 2021-03-10T13:26:02.554Z] 13:26:02     INFO -  (xpcshell/head.js) | test run_next_test 2 finished (2)
[task 2021-03-10T13:26:02.555Z] 13:26:02     INFO -  "Extension attached"
[task 2021-03-10T13:26:02.555Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "addEnginesFromExtension: engine@tests.mozilla.org"
[task 2021-03-10T13:26:02.555Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "installExtensionEngine:" "engine@tests.mozilla.org"
[task 2021-03-10T13:26:02.556Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "addEnginesFromExtension: installing:" "engine@tests.mozilla.org" ":" "default"
[task 2021-03-10T13:26:02.556Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "_createAndAddEngine: Adding" "engine"
[task 2021-03-10T13:26:02.556Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "_addEngineToStore: Adding engine:" "engine"
[task 2021-03-10T13:26:02.556Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "_saveSortedEngineList"
[task 2021-03-10T13:26:02.557Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchUtils: "NOTIFY: Engine:" "engine" "Verb:" "engine-added"
[task 2021-03-10T13:26:02.557Z] 13:26:02     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/search/tests/xpcshell/test_webextensions_upgrade.js | test_upgrade_changes_name - [test_upgrade_changes_name : 1853] Search provider extension should be running - "running" == "running"
[task 2021-03-10T13:26:02.558Z] 13:26:02     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/search/tests/xpcshell/test_webextensions_upgrade.js | test_upgrade_changes_name - [test_upgrade_changes_name : 1858] Extension ID of search provider should be set - "engine@tests.mozilla.org" == true
[task 2021-03-10T13:26:02.558Z] 13:26:02     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/search/tests/xpcshell/test_webextensions_upgrade.js | test_upgrade_changes_name - [test_upgrade_changes_name : 82] Should have loaded the engine - true == true
[task 2021-03-10T13:26:02.558Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "init"
[task 2021-03-10T13:26:02.559Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchUtils: "NOTIFY: Engine:" "engine" "Verb:" "engine-changed"
[task 2021-03-10T13:26:02.559Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchUtils: "NOTIFY: Engine:" "engine" "Verb:" "engine-default"
[task 2021-03-10T13:26:02.559Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchUtils: "NOTIFY: Engine:" "engine" "Verb:" "engine-default-private"
[task 2021-03-10T13:26:02.560Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "init"
[task 2021-03-10T13:26:02.560Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "getVisibleEngines: getting all visible engines"
[task 2021-03-10T13:26:02.560Z] 13:26:02     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/search/tests/xpcshell/test_webextensions_upgrade.js | test_upgrade_changes_name - [test_upgrade_changes_name : 96] Should have the expected order initially - ["engine1","engine2","engine"] deepEqual ["engine1","engine2","engine"]
[task 2021-03-10T13:26:02.561Z] 13:26:02     INFO -  "Extension attached"
[task 2021-03-10T13:26:02.561Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "addEnginesFromExtension: bar@tests.mozilla.org"
[task 2021-03-10T13:26:02.561Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "installExtensionEngine:" "bar@tests.mozilla.org"
[task 2021-03-10T13:26:02.561Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "addEnginesFromExtension: installing:" "bar@tests.mozilla.org" ":" "default"
[task 2021-03-10T13:26:02.562Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "_createAndAddEngine: Adding" "Bar"
[task 2021-03-10T13:26:02.562Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "_addEngineToStore: Adding engine:" "Bar"
[task 2021-03-10T13:26:02.562Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchService: "_saveSortedEngineList"
[task 2021-03-10T13:26:02.562Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchUtils: "NOTIFY: Engine:" "Bar" "Verb:" "engine-added"
[task 2021-03-10T13:26:02.563Z] 13:26:02     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/search/tests/xpcshell/test_webextensions_upgrade.js | test_upgrade_changes_name - [test_upgrade_changes_name : 1853] Search provider extension should be running - "running" == "running"
[task 2021-03-10T13:26:02.563Z] 13:26:02     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/search/tests/xpcshell/test_webextensions_upgrade.js | test_upgrade_changes_name - [test_upgrade_changes_name : 1858] Extension ID of search provider should be set - "bar@tests.mozilla.org" == true
[task 2021-03-10T13:26:02.563Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchSettings: "batchTask: Invalidating engine settings"
[task 2021-03-10T13:26:02.563Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchSettings: "_write: Writing to settings file."
[task 2021-03-10T13:26:02.564Z] 13:26:02     INFO -  PID 25433 | console.debug: SearchSettings: "_write: settings file written to disk."
[task 2021-03-10T13:26:02.564Z] 13:26:02     INFO -  <<<<<<<
[task 2021-03-10T13:26:02.564Z] 13:26:02     INFO -  xpcshell return code: None
[task 2021-03-10T13:26:02.564Z] 13:26:02     INFO -  xpcshell.ini:toolkit/components/search/tests/xpcshell/test_webextensions_upgrade.js | Process still running after test!
[task 2021-03-10T13:26:02.564Z] 13:26:02     INFO -  >>>>>>>
[task 2021-03-10T13:26:02.565Z] 13:26:02     INFO -  PID 25433 | ExceptionHandler::GenerateDump cloned child 25459
[task 2021-03-10T13:26:02.565Z] 13:26:02     INFO -  PID 25433 | ExceptionHandler::SendContinueSignalToChild sent continue signal to child
[task 2021-03-10T13:26:02.565Z] 13:26:02     INFO -  <<<<<<<
[task 2021-03-10T13:26:02.565Z] 13:26:02     INFO -  INFO | Result summary:
[task 2021-03-10T13:26:02.566Z] 13:26:02     INFO -  INFO | Passed: 816
[task 2021-03-10T13:26:02.566Z] 13:26:02  WARNING -  INFO | Failed: 1
[task 2021-03-10T13:26:02.566Z] 13:26:02  WARNING -  One or more unittests failed.
[task 2021-03-10T13:26:02.566Z] 13:26:02     INFO -  INFO | Todo: 0
[task 2021-03-10T13:26:02.567Z] 13:26:02     INFO -  INFO | Retried: 1
[task 2021-03-10T13:26:02.567Z] 13:26:02     INFO -  SUITE-END | took 988s
[task 2021-03-10T13:26:02.567Z] 13:26:02     INFO -  Node moz-http2 server shutting down ...
[task 2021-03-10T13:26:02.567Z] 13:26:02     INFO -  Process stdout
[task 2021-03-10T13:26:02.568Z] 13:26:02     INFO -  forked process without handler sent: [object Object]
[task 2021-03-10T13:26:02.568Z] 13:26:02     INFO -  Process stderr
[task 2021-03-10T13:26:02.568Z] 13:26:02     INFO -  (node:3189) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 window_update listeners added. Use emitter.setMaxListeners() to increase limit
[task 2021-03-10T13:26:02.568Z] 13:26:02     INFO -  (node:3189) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 window_update listeners added. Use emitter.setMaxListeners() to increase limit
[task 2021-03-10T13:26:02.569Z] 13:26:02     INFO -  (node:3189) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 window_update listeners added. Use emitter.setMaxListeners() to increase limit
[task 2021-03-10T13:26:02.569Z] 13:26:02     INFO -  (node:3189) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 window_update listeners added. Use emitter.setMaxListeners() to increase limit
[task 2021-03-10T13:26:02.570Z] 13:26:02     INFO -  http3Server server shutting down ...
[task 2021-03-10T13:26:02.681Z] 13:26:02    ERROR - Return code: 1
[task 2021-03-10T13:26:02.681Z] 13:26:02     INFO - TinderboxPrint: xpcshell-xpcshell<br/>816/<em class="testfail">1</em>/0
[task 2021-03-10T13:26:02.682Z] 13:26:02  WARNING - # TBPL FAILURE #
[task 2021-03-10T13:26:02.682Z] 13:26:02  WARNING - setting return code to 2
Flags: needinfo?(standard8)

Oops, I'm conflicting with my patches that I landed earlier today :(

Flags: needinfo?(standard8)
Pushed by mbanner@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/35bc754b70cf
Remove use of nsISearchEngine.addEngineWithDetails from mochitests. r=daleharvey
Regressions: 1697523
Regressions: 1697524
Regressions: 1697544
Iteration: 88.1 - Feb 22 - Mar 7 → 88.2 - Mar 8 - Mar 21

https://hg.mozilla.org/mozilla-central/rev/35bc754b70cf

Status: NEW → RESOLVED
Closed: 3 years ago
status-firefox88: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → 88 Branch
Regressions: 1697685
No longer regressions: 1697523
See Also: → 1699898
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: