1751447 - Intermittent toolkit/components/search/tests/xpcshell/test_settings.js | test_settings_write - [test_settings_write : 191] false == true | after xpcshell return code: 0

Status: RESOLVED FIXED

(Firefox :: Search, defect, P5)

Description

[Treeherder Bug Filer]

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

---

[task 2022-01-21T16:05:58.543Z] 16:05:58     INFO -  TEST-START | xpcshell.ini:toolkit/components/search/tests/xpcshell/test_settings.js
[task 2022-01-21T16:06:02.100Z] 16:06:02  WARNING -  TEST-UNEXPECTED-FAIL | xpcshell.ini:toolkit/components/search/tests/xpcshell/test_settings.js | xpcshell return code: 0
[task 2022-01-21T16:06:02.100Z] 16:06:02     INFO -  TEST-INFO took 3557ms
[task 2022-01-21T16:06:02.100Z] 16:06:02     INFO -  >>>>>>>
[task 2022-01-21T16:06:02.100Z] 16:06:02     INFO -  (xpcshell/head.js) | test MAIN run_test pending (1)
[task 2022-01-21T16:06:02.101Z] 16:06:02     INFO -  (xpcshell/head.js) | test run_next_test 0 pending (2)
[task 2022-01-21T16:06:02.101Z] 16:06:02     INFO -  (xpcshell/head.js) | test MAIN run_test finished (2)
[task 2022-01-21T16:06:02.101Z] 16:06:02     INFO -  running event loop
[task 2022-01-21T16:06:02.101Z] 16:06:02     INFO -  xpcshell.ini:toolkit/components/search/tests/xpcshell/test_settings.js | Starting setup
[task 2022-01-21T16:06:02.101Z] 16:06:02     INFO -  (xpcshell/head.js) | test setup pending (2)
[task 2022-01-21T16:06:02.102Z] 16:06:02     INFO -  (xpcshell/head.js) | test run_next_test 0 finished (2)
[task 2022-01-21T16:06:02.102Z] 16:06:02     INFO -  (xpcshell/head.js) | test run_next_test 1 pending (2)
[task 2022-01-21T16:06:02.102Z] 16:06:02     INFO -  (xpcshell/head.js) | test setup finished (2)
[task 2022-01-21T16:06:02.102Z] 16:06:02     INFO -  xpcshell.ini:toolkit/components/search/tests/xpcshell/test_settings.js | Starting test_legacy_setting_engine_properties
[task 2022-01-21T16:06:02.103Z] 16:06:02     INFO -  (xpcshell/head.js) | test test_legacy_setting_engine_properties pending (2)
[task 2022-01-21T16:06:02.103Z] 16:06:02     INFO -  "init search service"
[task 2022-01-21T16:06:02.103Z] 16:06:02     INFO -  (xpcshell/head.js) | test run_next_test 1 finished (2)
[task 2022-01-21T16:06:02.103Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "init"
[task 2022-01-21T16:06:02.103Z] 16:06:02     INFO -  PID 1865 | console.info: Region.jsm: "_getRegion called"
[task 2022-01-21T16:06:02.104Z] 16:06:02     INFO -  PID 1865 | console.info: Region.jsm: "_getRegion url is: " ""
[task 2022-01-21T16:06:02.104Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_loadEngines: start"
[task 2022-01-21T16:06:02.104Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchEngineSelector: "fetchEngineConfiguration en-US:default:default:::xpcshell:42"
[task 2022-01-21T16:06:02.104Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchEngineSelector: "fetchEngineConfiguration: [e-mail],[e-mail]"
[task 2022-01-21T16:06:02.105Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_loadEnginesFromConfig"
[task 2022-01-21T16:06:02.105Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "makeEngineFromConfig:" ({webExtension:{id:"[e-mail]", locale:"default"}, orderHint:10000, default:"yes"})
[task 2022-01-21T16:06:02.105Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "addEnginesFromExtension: [e-mail]"
[task 2022-01-21T16:06:02.105Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "addEnginesFromExtension: Ignoring builtIn engine."
[task 2022-01-21T16:06:02.106Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchEngine: "_setIcon: Setting icon url for" "engine1" "to" "moz-extension://abb946e3-a41a-476f-8335-e0834e2776e6/favicon.ico"
[task 2022-01-21T16:06:02.106Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "makeEngineFromConfig:" ({webExtension:{id:"[e-mail]", locale:"default"}, orderHint:7000, default:"no"})
[task 2022-01-21T16:06:02.106Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "addEnginesFromExtension: [e-mail]"
[task 2022-01-21T16:06:02.106Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "addEnginesFromExtension: Ignoring builtIn engine."
[task 2022-01-21T16:06:02.107Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchEngine: "_setIcon: Setting icon url for" "engine2" "to" "moz-extension://e48421db-ecd1-4073-99df-772bb9a63094/favicon.ico"
[task 2022-01-21T16:06:02.107Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_addEngineToStore: Adding engine:" "engine1"
[task 2022-01-21T16:06:02.107Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_addEngineToStore: Adding engine:" "engine2"
[task 2022-01-21T16:06:02.107Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_loadEngines: loading" 0 "engines reported by AddonManager startup"
[task 2022-01-21T16:06:02.108Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_loadEnginesFromSettings: Loading" 3 "engines from settings"
[task 2022-01-21T16:06:02.108Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_addEngineToStore: Adding engine:" "Test search engine"
[task 2022-01-21T16:06:02.108Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_loadEnginesFromSettings: skipped" 2 "built-in engines."
[task 2022-01-21T16:06:02.108Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_loadEnginesMetadataFromSettings, transfering metadata for" "engine1" ({alias:"testAlias"})
[task 2022-01-21T16:06:02.109Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_loadEnginesMetadataFromSettings, transfering metadata for" "engine2" ({alias:null, hidden:true})
[task 2022-01-21T16:06:02.109Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_loadEnginesMetadataFromSettings, transfering metadata for" "Test search engine" ({})
[task 2022-01-21T16:06:02.109Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_loadEngines: done"
[task 2022-01-21T16:06:02.109Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_init: engines loaded, writing settings"
[task 2022-01-21T16:06:02.110Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "Completed _init"
[task 2022-01-21T16:06:02.110Z] 16:06:02     INFO -  "init'd search service"
[task 2022-01-21T16:06:02.110Z] 16:06:02     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/search/tests/xpcshell/test_settings.js | test_legacy_setting_engine_properties - [test_legacy_setting_engine_properties : 66] true == true
[task 2022-01-21T16:06:02.110Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_handleIgnoreListUpdated"
[task 2022-01-21T16:06:02.111Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchSettings: "batchTask: Invalidating engine settings"
[task 2022-01-21T16:06:02.111Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchSettings: "_write: Writing to settings file."
[task 2022-01-21T16:06:02.111Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchSettings: "_write: settings file written to disk."
[task 2022-01-21T16:06:02.111Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "init"
[task 2022-01-21T16:06:02.112Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "getEngines: getting all engines"
[task 2022-01-21T16:06:02.112Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_buildSortedEngineList: using saved order"
[task 2022-01-21T16:06:02.112Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_saveSortedEngineList"
[task 2022-01-21T16:06:02.112Z] 16:06:02     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/search/tests/xpcshell/test_settings.js | test_legacy_setting_engine_properties - [test_legacy_setting_engine_properties : 72] Should have loaded the correct first engine - "engine1" == "engine1"
[task 2022-01-21T16:06:02.113Z] 16:06:02     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/search/tests/xpcshell/test_settings.js | test_legacy_setting_engine_properties - [test_legacy_setting_engine_properties : 77] Should have set the alias - "testAlias" == "testAlias"
[task 2022-01-21T16:06:02.113Z] 16:06:02     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/search/tests/xpcshell/test_settings.js | test_legacy_setting_engine_properties - [test_legacy_setting_engine_properties : 78] Should have not hidden the engine - false == false
[task 2022-01-21T16:06:02.113Z] 16:06:02     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/search/tests/xpcshell/test_settings.js | test_legacy_setting_engine_properties - [test_legacy_setting_engine_properties : 79] Should have loaded the correct second engine - "engine2" == "engine2"
[task 2022-01-21T16:06:02.114Z] 16:06:02     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/search/tests/xpcshell/test_settings.js | test_legacy_setting_engine_properties - [test_legacy_setting_engine_properties : 84] Should have not set the alias - "" == ""
<...>
[task 2022-01-21T16:06:02.138Z] 16:06:02     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/search/tests/xpcshell/test_settings.js | test_legacy_setting_engine_properties - [test_legacy_setting_engine_properties : 115] Should have cleared the legacy pref. - true == true
[task 2022-01-21T16:06:02.139Z] 16:06:02     INFO -  (xpcshell/head.js) | test run_next_test 2 pending (2)
[task 2022-01-21T16:06:02.139Z] 16:06:02     INFO -  (xpcshell/head.js) | test test_legacy_setting_engine_properties finished (2)
[task 2022-01-21T16:06:02.139Z] 16:06:02     INFO -  xpcshell.ini:toolkit/components/search/tests/xpcshell/test_settings.js | Starting test_current_setting_engine_properties
[task 2022-01-21T16:06:02.139Z] 16:06:02     INFO -  (xpcshell/head.js) | test test_current_setting_engine_properties pending (2)
[task 2022-01-21T16:06:02.139Z] 16:06:02     INFO -  "init search service"
[task 2022-01-21T16:06:02.140Z] 16:06:02     INFO -  (xpcshell/head.js) | test run_next_test 2 finished (2)
[task 2022-01-21T16:06:02.140Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "init"
[task 2022-01-21T16:06:02.140Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_loadEngines: start"
[task 2022-01-21T16:06:02.140Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchEngineSelector: "fetchEngineConfiguration en-US:default:default:::xpcshell:42"
[task 2022-01-21T16:06:02.141Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchEngineSelector: "fetchEngineConfiguration: [e-mail],[e-mail]"
[task 2022-01-21T16:06:02.141Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_loadEnginesFromConfig"
[task 2022-01-21T16:06:02.141Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "makeEngineFromConfig:" ({webExtension:{id:"[e-mail]", locale:"default"}, orderHint:10000, default:"yes"})
[task 2022-01-21T16:06:02.141Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchEngine: "_setIcon: Setting icon url for" "engine1" "to" "moz-extension://abb946e3-a41a-476f-8335-e0834e2776e6/favicon.ico"
[task 2022-01-21T16:06:02.142Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "makeEngineFromConfig:" ({webExtension:{id:"[e-mail]", locale:"default"}, orderHint:7000, default:"no"})
[task 2022-01-21T16:06:02.142Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchEngine: "_setIcon: Setting icon url for" "engine2" "to" "moz-extension://e48421db-ecd1-4073-99df-772bb9a63094/favicon.ico"
[task 2022-01-21T16:06:02.142Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_addEngineToStore: Adding engine:" "engine1"
[task 2022-01-21T16:06:02.142Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_addEngineToStore: Adding engine:" "engine2"
[task 2022-01-21T16:06:02.143Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_loadEngines: loading" 0 "engines reported by AddonManager startup"
[task 2022-01-21T16:06:02.143Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_loadEnginesFromSettings: Loading" 3 "engines from settings"
[task 2022-01-21T16:06:02.143Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_addEngineToStore: Adding engine:" "Test search engine"
[task 2022-01-21T16:06:02.143Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_loadEnginesFromSettings: skipped" 2 "built-in engines."
[task 2022-01-21T16:06:02.144Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_loadEnginesMetadataFromSettings, transfering metadata for" "engine1" ({alias:"testAlias"})
[task 2022-01-21T16:06:02.144Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_loadEnginesMetadataFromSettings, transfering metadata for" "engine2" ({alias:null, hidden:true})
[task 2022-01-21T16:06:02.144Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_loadEnginesMetadataFromSettings, transfering metadata for" "Test search engine" ({})
[task 2022-01-21T16:06:02.144Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_loadEngines: done"
[task 2022-01-21T16:06:02.144Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_init: engines loaded, writing settings"
[task 2022-01-21T16:06:02.144Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "Completed _init"
[task 2022-01-21T16:06:02.145Z] 16:06:02     INFO -  "init'd search service"
[task 2022-01-21T16:06:02.145Z] 16:06:02     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/search/tests/xpcshell/test_settings.js | test_current_setting_engine_properties - [test_current_setting_engine_properties : 66] true == true
[task 2022-01-21T16:06:02.145Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_handleIgnoreListUpdated"
[task 2022-01-21T16:06:02.145Z] 16:06:02     INFO -  "CONSOLE_MESSAGE: (error) [JavaScript Error: "NetworkError: Network request failed" {file: "resource://services-settings/Utils.jsm" line: 132}]
[task 2022-01-21T16:06:02.146Z] 16:06:02     INFO -  fetch/</request.onerror@resource://services-settings/Utils.jsm:132:26
[task 2022-01-21T16:06:02.146Z] 16:06:02     INFO -  _do_main@/opt/worker/tasks/task_164278043814686/build/tests/xpcshell/head.js:240:6
[task 2022-01-21T16:06:02.146Z] 16:06:02     INFO -  _execute_test@/opt/worker/tasks/task_164278043814686/build/tests/xpcshell/head.js:604:5
[task 2022-01-21T16:06:02.146Z] 16:06:02     INFO -  @-e:1:1
[task 2022-01-21T16:06:02.146Z] 16:06:02     INFO -  "
[task 2022-01-21T16:06:02.147Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchSettings: "batchTask: Invalidating engine settings"
[task 2022-01-21T16:06:02.147Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchSettings: "_write: Writing to settings file."
[task 2022-01-21T16:06:02.147Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchSettings: "_write: settings file written to disk."
[task 2022-01-21T16:06:02.147Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "init"
[task 2022-01-21T16:06:02.147Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "getEngines: getting all engines"
[task 2022-01-21T16:06:02.148Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_buildSortedEngineList: using default orders"
[task 2022-01-21T16:06:02.148Z] 16:06:02     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/search/tests/xpcshell/test_settings.js | test_current_setting_engine_properties - [test_current_setting_engine_properties : 72] Should have loaded the correct first engine - "engine1" == "engine1"
[task 2022-01-21T16:06:02.148Z] 16:06:02     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/search/tests/xpcshell/test_settings.js | test_current_setting_engine_properties - [test_current_setting_engine_properties : 77] Should have set the alias - "testAlias" == "testAlias"
<...>
[task 2022-01-21T16:06:02.174Z] 16:06:02     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/search/tests/xpcshell/test_settings.js | test_current_setting_engine_properties - [test_current_setting_engine_properties : 100] Should have set the useSavedOrder metadata correctly. - false == false
[task 2022-01-21T16:06:02.174Z] 16:06:02     INFO -  (xpcshell/head.js) | test run_next_test 3 pending (2)
[task 2022-01-21T16:06:02.174Z] 16:06:02     INFO -  (xpcshell/head.js) | test test_current_setting_engine_properties finished (2)
[task 2022-01-21T16:06:02.174Z] 16:06:02     INFO -  xpcshell.ini:toolkit/components/search/tests/xpcshell/test_settings.js | Starting test_settings_metadata_properties
[task 2022-01-21T16:06:02.174Z] 16:06:02     INFO -  (xpcshell/head.js) | test test_settings_metadata_properties pending (2)
[task 2022-01-21T16:06:02.175Z] 16:06:02     INFO -  "init search service"
[task 2022-01-21T16:06:02.175Z] 16:06:02     INFO -  (xpcshell/head.js) | test run_next_test 3 finished (2)
[task 2022-01-21T16:06:02.175Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "init"
[task 2022-01-21T16:06:02.175Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_loadEngines: start"
[task 2022-01-21T16:06:02.176Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchEngineSelector: "fetchEngineConfiguration en-US:default:default:::xpcshell:42"
[task 2022-01-21T16:06:02.176Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchEngineSelector: "fetchEngineConfiguration: [e-mail],[e-mail]"
[task 2022-01-21T16:06:02.176Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_loadEnginesFromConfig"
[task 2022-01-21T16:06:02.176Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "makeEngineFromConfig:" ({webExtension:{id:"[e-mail]", locale:"default"}, orderHint:10000, default:"yes"})
[task 2022-01-21T16:06:02.177Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchEngine: "_setIcon: Setting icon url for" "engine1" "to" "moz-extension://abb946e3-a41a-476f-8335-e0834e2776e6/favicon.ico"
[task 2022-01-21T16:06:02.177Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "makeEngineFromConfig:" ({webExtension:{id:"[e-mail]", locale:"default"}, orderHint:7000, default:"no"})
[task 2022-01-21T16:06:02.177Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchEngine: "_setIcon: Setting icon url for" "engine2" "to" "moz-extension://e48421db-ecd1-4073-99df-772bb9a63094/favicon.ico"
[task 2022-01-21T16:06:02.177Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_addEngineToStore: Adding engine:" "engine1"
[task 2022-01-21T16:06:02.178Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_addEngineToStore: Adding engine:" "engine2"
[task 2022-01-21T16:06:02.178Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_loadEngines: loading" 0 "engines reported by AddonManager startup"
[task 2022-01-21T16:06:02.178Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_loadEnginesFromSettings: Loading" 3 "engines from settings"
[task 2022-01-21T16:06:02.178Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_addEngineToStore: Adding engine:" "Test search engine"
[task 2022-01-21T16:06:02.179Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_loadEnginesFromSettings: skipped" 2 "built-in engines."
[task 2022-01-21T16:06:02.179Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_loadEnginesMetadataFromSettings, transfering metadata for" "engine1" ({alias:"testAlias"})
[task 2022-01-21T16:06:02.179Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_loadEnginesMetadataFromSettings, transfering metadata for" "engine2" ({alias:null, hidden:true})
[task 2022-01-21T16:06:02.180Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_loadEnginesMetadataFromSettings, transfering metadata for" "Test search engine" ({})
[task 2022-01-21T16:06:02.180Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_loadEngines: done"
[task 2022-01-21T16:06:02.180Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_init: engines loaded, writing settings"
[task 2022-01-21T16:06:02.180Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "Completed _init"
[task 2022-01-21T16:06:02.180Z] 16:06:02     INFO -  "init'd search service"
[task 2022-01-21T16:06:02.181Z] 16:06:02     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/search/tests/xpcshell/test_settings.js | test_settings_metadata_properties - [test_settings_metadata_properties : 134] true == true
[task 2022-01-21T16:06:02.181Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchSettings: "batchTask: Invalidating engine settings"
[task 2022-01-21T16:06:02.181Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchSettings: "_write: Writing to settings file."
[task 2022-01-21T16:06:02.181Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchSettings: "_write: settings file written to disk."
[task 2022-01-21T16:06:02.182Z] 16:06:02     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/search/tests/xpcshell/test_settings.js | test_settings_metadata_properties - [test_settings_metadata_properties : 147] Search settings should have locale property defined. - "en-US" != "undefined"
[task 2022-01-21T16:06:02.182Z] 16:06:02     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/search/tests/xpcshell/test_settings.js | test_settings_metadata_properties - [test_settings_metadata_properties : 147] Search settings should have region property defined. - "default" != "undefined"
[task 2022-01-21T16:06:02.182Z] 16:06:02     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/search/tests/xpcshell/test_settings.js | test_settings_metadata_properties - [test_settings_metadata_properties : 147] Search settings should have channel property defined. - "default" != "undefined"
[task 2022-01-21T16:06:02.183Z] 16:06:02     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/search/tests/xpcshell/test_settings.js | test_settings_metadata_properties - [test_settings_metadata_properties : 147] Search settings should have experiment property defined. - "" != "undefined"
[task 2022-01-21T16:06:02.183Z] 16:06:02     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/search/tests/xpcshell/test_settings.js | test_settings_metadata_properties - [test_settings_metadata_properties : 147] Search settings should have distroID property defined. - "" != "undefined"
[task 2022-01-21T16:06:02.183Z] 16:06:02     INFO -  (xpcshell/head.js) | test run_next_test 4 pending (2)
[task 2022-01-21T16:06:02.184Z] 16:06:02     INFO -  (xpcshell/head.js) | test test_settings_metadata_properties finished (2)
[task 2022-01-21T16:06:02.184Z] 16:06:02     INFO -  xpcshell.ini:toolkit/components/search/tests/xpcshell/test_settings.js | Starting test_settings_write
[task 2022-01-21T16:06:02.184Z] 16:06:02     INFO -  (xpcshell/head.js) | test test_settings_write pending (2)
[task 2022-01-21T16:06:02.184Z] 16:06:02     INFO -  "test settings writing"
[task 2022-01-21T16:06:02.184Z] 16:06:02     INFO -  (xpcshell/head.js) | test run_next_test 4 finished (2)
[task 2022-01-21T16:06:02.185Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "init"
[task 2022-01-21T16:06:02.185Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_loadEngines: start"
[task 2022-01-21T16:06:02.185Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchEngineSelector: "fetchEngineConfiguration en-US:default:default:::xpcshell:42"
[task 2022-01-21T16:06:02.185Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchEngineSelector: "fetchEngineConfiguration: [e-mail],[e-mail]"
[task 2022-01-21T16:06:02.186Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_loadEnginesFromConfig"
[task 2022-01-21T16:06:02.186Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "makeEngineFromConfig:" ({webExtension:{id:"[e-mail]", locale:"default"}, orderHint:10000, default:"yes"})
[task 2022-01-21T16:06:02.186Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchEngine: "_setIcon: Setting icon url for" "engine1" "to" "moz-extension://abb946e3-a41a-476f-8335-e0834e2776e6/favicon.ico"
[task 2022-01-21T16:06:02.186Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "makeEngineFromConfig:" ({webExtension:{id:"[e-mail]", locale:"default"}, orderHint:7000, default:"no"})
[task 2022-01-21T16:06:02.187Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchEngine: "_setIcon: Setting icon url for" "engine2" "to" "moz-extension://e48421db-ecd1-4073-99df-772bb9a63094/favicon.ico"
[task 2022-01-21T16:06:02.187Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_addEngineToStore: Adding engine:" "engine1"
[task 2022-01-21T16:06:02.187Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_addEngineToStore: Adding engine:" "engine2"
[task 2022-01-21T16:06:02.188Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_loadEngines: loading" 0 "engines reported by AddonManager startup"
[task 2022-01-21T16:06:02.188Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_loadEnginesFromSettings: Loading" 3 "engines from settings"
[task 2022-01-21T16:06:02.188Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_addEngineToStore: Adding engine:" "Test search engine"
[task 2022-01-21T16:06:02.188Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_loadEnginesFromSettings: skipped" 2 "built-in engines."
[task 2022-01-21T16:06:02.189Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_loadEnginesMetadataFromSettings, transfering metadata for" "engine1" ({alias:"testAlias"})
[task 2022-01-21T16:06:02.189Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_loadEnginesMetadataFromSettings, transfering metadata for" "engine2" ({alias:null, hidden:true})
[task 2022-01-21T16:06:02.189Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_loadEnginesMetadataFromSettings, transfering metadata for" "Test search engine" ({})
[task 2022-01-21T16:06:02.190Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_loadEngines: done"
[task 2022-01-21T16:06:02.190Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_init: engines loaded, writing settings"
[task 2022-01-21T16:06:02.190Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "Completed _init"
[task 2022-01-21T16:06:02.190Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_handleIgnoreListUpdated"
[task 2022-01-21T16:06:02.191Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchService: "_handleIgnoreListUpdated"
[task 2022-01-21T16:06:02.191Z] 16:06:02     INFO -  "CONSOLE_MESSAGE: (error) [JavaScript Error: "NetworkError: Network request failed" {file: "resource://services-settings/Utils.jsm" line: 132}]
[task 2022-01-21T16:06:02.191Z] 16:06:02     INFO -  fetch/</request.onerror@resource://services-settings/Utils.jsm:132:26
[task 2022-01-21T16:06:02.191Z] 16:06:02     INFO -  _do_main@/opt/worker/tasks/task_164278043814686/build/tests/xpcshell/head.js:240:6
[task 2022-01-21T16:06:02.191Z] 16:06:02     INFO -  _execute_test@/opt/worker/tasks/task_164278043814686/build/tests/xpcshell/head.js:604:5
[task 2022-01-21T16:06:02.192Z] 16:06:02     INFO -  @-e:1:1
[task 2022-01-21T16:06:02.192Z] 16:06:02     INFO -  "
[task 2022-01-21T16:06:02.192Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchSettings: "batchTask: Invalidating engine settings"
[task 2022-01-21T16:06:02.192Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchSettings: "_write: Writing to settings file."
[task 2022-01-21T16:06:02.192Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchSettings: "batchTask: Invalidating engine settings"
[task 2022-01-21T16:06:02.192Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchSettings: "_write: Writing to settings file."
[task 2022-01-21T16:06:02.193Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchSettings: "_write: settings file written to disk."
[task 2022-01-21T16:06:02.193Z] 16:06:02     INFO -  TEST-PASS | xpcshell.ini:toolkit/components/search/tests/xpcshell/test_settings.js | test_settings_write - [test_settings_write : 173] true == true
[task 2022-01-21T16:06:02.193Z] 16:06:02     INFO -  "Next step is forcing flush"
[task 2022-01-21T16:06:02.193Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchSettings: "_write: settings file written to disk."
[task 2022-01-21T16:06:02.194Z] 16:06:02     INFO -  "Settings write complete"
[task 2022-01-21T16:06:02.194Z] 16:06:02  WARNING -  TEST-UNEXPECTED-FAIL | xpcshell.ini:toolkit/components/search/tests/xpcshell/test_settings.js | test_settings_write - [test_settings_write : 191] false == true
[task 2022-01-21T16:06:02.194Z] 16:06:02     INFO -  /opt/worker/tasks/task_164278043814686/build/tests/xpcshell/tests/toolkit/components/search/tests/xpcshell/test_settings.js:test_settings_write:191
[task 2022-01-21T16:06:02.194Z] 16:06:02     INFO -  /opt/worker/tasks/task_164278043814686/build/tests/xpcshell/head.js:_do_main:240
[task 2022-01-21T16:06:02.195Z] 16:06:02     INFO -  /opt/worker/tasks/task_164278043814686/build/tests/xpcshell/head.js:_execute_test:604
[task 2022-01-21T16:06:02.195Z] 16:06:02     INFO -  -e:null:1
[task 2022-01-21T16:06:02.195Z] 16:06:02     INFO -  exiting test
[task 2022-01-21T16:06:02.195Z] 16:06:02     INFO -  Unexpected exception NS_ERROR_ABORT:
[task 2022-01-21T16:06:02.195Z] 16:06:02     INFO -  _abort_failed_test@/opt/worker/tasks/task_164278043814686/build/tests/xpcshell/head.js:875:20
[task 2022-01-21T16:06:02.196Z] 16:06:02     INFO -  do_report_result@/opt/worker/tasks/task_164278043814686/build/tests/xpcshell/head.js:976:5
[task 2022-01-21T16:06:02.196Z] 16:06:02     INFO -  Assert<@/opt/worker/tasks/task_164278043814686/build/tests/xpcshell/head.js:75:21
[task 2022-01-21T16:06:02.196Z] 16:06:02     INFO -  proto.report@resource://testing-common/Assert.jsm:228:10
[task 2022-01-21T16:06:02.196Z] 16:06:02     INFO -  proto.ok@resource://testing-common/Assert.jsm:254:10
[task 2022-01-21T16:06:02.197Z] 16:06:02     INFO -  test_settings_write@/opt/worker/tasks/task_164278043814686/build/tests/xpcshell/tests/toolkit/components/search/tests/xpcshell/test_settings.js:191:10
[task 2022-01-21T16:06:02.197Z] 16:06:02     INFO -  _do_main@/opt/worker/tasks/task_164278043814686/build/tests/xpcshell/head.js:240:6
[task 2022-01-21T16:06:02.197Z] 16:06:02     INFO -  _execute_test@/opt/worker/tasks/task_164278043814686/build/tests/xpcshell/head.js:604:5
[task 2022-01-21T16:06:02.197Z] 16:06:02     INFO -  @-e:1:1
[task 2022-01-21T16:06:02.197Z] 16:06:02     INFO -  exiting test
[task 2022-01-21T16:06:02.198Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchSettings: "batchTask: Invalidating engine settings"
[task 2022-01-21T16:06:02.198Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchSettings: "_write: Writing to settings file."
[task 2022-01-21T16:06:02.198Z] 16:06:02     INFO -  PID 1865 | console.debug: SearchSettings: "_write: settings file written to disk."
[task 2022-01-21T16:06:02.198Z] 16:06:02     INFO -  <<<<<<<
[task 2022-01-21T16:06:02.199Z] 16:06:02     INFO -  TEST-START | xpcshell.ini:toolkit/components/search/tests/xpcshell/test_settings.js

Comment 1

[Sandor Molnar[:smolnar]]

Started happening on tier 1 jobs

Comment 2

[Andreea Pavel [:apavel]]

Mandy, can you please take a look?

Comment 3

[Mandy Cheang [:mcheang][she/her]]

Yes, I'm taking a look at it now.

Comment 4

[Intermittent Failures Robot]

15 failures in 3444 pushes (0.004 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 12
• mozilla-central: 1
• comm-central: 1
• try: 1

Platform and build breakdown:

• windows10-64-2004-qr: 6
  • opt: 6
• windows10-32-2004-qr: 1
  • opt: 1
• macosx1015-64-qr: 3
  • opt: 2
  • debug: 1
• windows10-64-2004-shippable-qr: 4
  • opt: 4
• windows10-32-2004-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1751447&startday=2022-01-17&endday=2022-01-23&tree=all

Comment 5

[BugBot [:suhaib / :marco/ :calixte]]

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

Comment 6

[Intermittent Failures Robot]

24 failures in 3445 pushes (0.007 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• try: 5
• autoland: 13
• mozilla-central: 3
• comm-central: 3

Platform and build breakdown:

• windows10-64-2004-devedition-qr: 2
  • opt: 2
• windows10-64-2004-qr: 11
  • opt: 11
• windows10-64-2004-shippable-qr: 8
  • opt: 8
• macosx1015-64-qr: 1
  • opt: 1
• windows10-32-2004-qr: 1
  • opt: 1
• windows10-32-2004-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1751447&startday=2022-01-24&endday=2022-01-30&tree=all

Comment 7

[Intermittent Failures Robot]

22 failures in 3165 pushes (0.007 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• try: 1
• autoland: 15
• comm-central: 2
• mozilla-central: 4

Platform and build breakdown:

• windows10-64-2004-shippable-qr: 10
  • opt: 10
• windows10-64-2004-qr: 10
  • opt: 10
• windows10-32-2004-qr: 1
  • opt: 1
• windows10-32-2004-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1751447&startday=2022-01-31&endday=2022-02-06&tree=all

Comment 8

[Intermittent Failures Robot]

22 failures in 3711 pushes (0.006 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-beta: 2
• autoland: 12
• mozilla-central: 2
• try: 3
• comm-central: 3

Platform and build breakdown:

• windows10-64-2004-devedition-qr: 2
  • opt: 2
• windows10-64-2004-qr: 9
  • opt: 9
• windows10-64-2004-shippable-qr: 8
  • opt: 8
• windows10-32-2004-qr: 1
  • opt: 1
• macosx1015-64-shippable-qr: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1751447&startday=2022-02-07&endday=2022-02-13&tree=all

Comment 9

[Intermittent Failures Robot]

22 failures in 3281 pushes (0.007 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 16
• mozilla-central: 2
• try: 2
• mozilla-beta: 2

Platform and build breakdown:

• windows10-64-2004-qr: 13
  • opt: 13
• windows10-64-2004-shippable-qr: 7
  • opt: 7
• windows10-64-2004-ccov-qr: 1
  • opt: 1
• windows10-64-2004-devedition-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1751447&startday=2022-02-14&endday=2022-02-20&tree=all

Comment 10

[Intermittent Failures Robot]

23 failures in 2992 pushes (0.008 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 13
• try: 2
• mozilla-beta: 3
• mozilla-central: 5

Platform and build breakdown:

• windows10-64-2004-qr: 8
  • opt: 8
• windows10-64-2004-shippable-qr: 11
  • opt: 11
• macosx1015-64-qr: 1
  • opt: 1
• windows10-64-2004-devedition-qr: 3
  • opt: 3

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1751447&startday=2022-02-21&endday=2022-02-27&tree=all

Comment 11

[Mandy Cheang [:mcheang][she/her]]

Attachment: Bug 1751447 - Fix intermittent failure by creating only one instance of Search Service. r?standard8

Comment 12

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/2cf05c89ca61
Fix intermittent failure by creating only one instance of Search Service. r=Standard8

Comment 13

[Andreea Pavel [:apavel]]

https://hg.mozilla.org/mozilla-central/rev/2cf05c89ca61

Comment 14

[Intermittent Failures Robot]

13 failures in 3063 pushes (0.004 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 10
• mozilla-central: 3

Platform and build breakdown:

• windows10-64-2004-qr: 7
  • opt: 7
• windows10-64-2004-ccov-qr: 1
  • opt: 1
• windows10-64-2004-shippable-qr: 4
  • opt: 4
• macosx1100-64-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1751447&startday=2022-02-28&endday=2022-03-06&tree=all