1931009 - Intermittent TV toolkit/components/search/tests/xpcshell/test_searchSuggest.js | fetch_twice_in_a_row - [fetch_twice_in_a_row : 342] 0 == 1

Status: NEW

(Firefox :: Search, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: abutkovits [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=482482441&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/FK7KNF0uR_yra4foXE8KBQ/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/FK7KNF0uR_yra4foXE8KBQ/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1

---

[task 2024-11-13T17:49:03.015Z] 17:49:03     INFO -  TEST-PASS | xpcshell.toml:toolkit/components/search/tests/xpcshell/test_searchSuggest.js | took 22708ms
[task 2024-11-13T17:49:03.025Z] 17:49:03     INFO -  TEST-START | xpcshell.toml:toolkit/components/search/tests/xpcshell/test_searchSuggest.js
[task 2024-11-13T17:49:14.042Z] 17:49:14  WARNING -  TEST-UNEXPECTED-FAIL | xpcshell.toml:toolkit/components/search/tests/xpcshell/test_searchSuggest.js | xpcshell return code: 0
[task 2024-11-13T17:49:14.043Z] 17:49:14     INFO -  TEST-INFO took 11018ms
[task 2024-11-13T17:49:14.043Z] 17:49:14     INFO -  >>>>>>>
[task 2024-11-13T17:49:14.043Z] 17:49:14     INFO -  PID 2029 | *** You are running in chaos test mode. See ChaosMode.h. ***
[task 2024-11-13T17:49:14.043Z] 17:49:14     INFO -  (xpcshell/head.js) | test MAIN run_test pending (1)
[task 2024-11-13T17:49:14.043Z] 17:49:14     INFO -  (xpcshell/head.js) | test run_next_test 0 pending (2)
[task 2024-11-13T17:49:14.044Z] 17:49:14     INFO -  (xpcshell/head.js) | test MAIN run_test finished (2)
[task 2024-11-13T17:49:14.044Z] 17:49:14     INFO -  running event loop
[task 2024-11-13T17:49:14.044Z] 17:49:14     INFO -  xpcshell.toml:toolkit/components/search/tests/xpcshell/test_searchSuggest.js | Starting setup
[task 2024-11-13T17:49:14.044Z] 17:49:14     INFO -  (xpcshell/head.js) | test pending (2)
[task 2024-11-13T17:49:14.045Z] 17:49:14     INFO -  PID 2029 | console.debug: SearchService: "addOpenSearchEngine: Adding" "http://localhost:50595/sjs/engineMaker.sjs?{\\"baseURL\\":\\"http://localhost:50595/sjs/\\",\\"name\\":\\"GET suggestion engine\\",\\"method\\":\\"GET\\"}"
[task 2024-11-13T17:49:14.045Z] 17:49:14     INFO -  PID 2029 | console.debug: SearchService: "init"
[task 2024-11-13T17:49:14.045Z] 17:49:14     INFO -  PID 2029 | console.info: Region.sys.mjs: "_getRegion called"
[task 2024-11-13T17:49:14.045Z] 17:49:14     INFO -  PID 2029 | console.info: Region.sys.mjs: "_getRegion url is: " ""
[task 2024-11-13T17:49:14.045Z] 17:49:14     INFO -  (xpcshell/head.js) | test run_next_test 0 finished (2)
[task 2024-11-13T17:49:14.046Z] 17:49:14     INFO -  PID 2029 | console.debug: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open `/var/folders/g7/vplxp93107b0ynpl9047dz78000014/T/xpc-profile-sf_99ue4/search.json.mozlz4': file does not exist (NS_ERROR_FILE_NOT_FOUND)", (void 0), 245))
[task 2024-11-13T17:49:14.046Z] 17:49:14     INFO -  PID 2029 | console.debug: SearchService: "#handleIgnoreListUpdated"
[task 2024-11-13T17:49:14.046Z] 17:49:14     INFO -  PID 2029 | console.debug: SearchEngineSelector: "fetchEngineConfiguration en-US:unknown:default:::XPCShell:48"
[task 2024-11-13T17:49:14.046Z] 17:49:14     INFO -  PID 2029 | console.debug: SearchEngineSelector: "fetchEngineConfiguration: google,ddg,wikipedia"
[task 2024-11-13T17:49:14.047Z] 17:49:14     INFO -  PID 2029 | console.debug: SearchService: "#loadEngines: start"
[task 2024-11-13T17:49:14.047Z] 17:49:14     INFO -  PID 2029 | console.debug: SearchService: "#loadEnginesFromConfig"
[task 2024-11-13T17:49:14.047Z] 17:49:14     INFO -  PID 2029 | console.debug: SearchService: "#addEngineToStore: Adding engine:" "Google"
[task 2024-11-13T17:49:14.047Z] 17:49:14     INFO -  PID 2029 | console.debug: SearchService: "#addEngineToStore: Adding engine:" "DuckDuckGo"
[task 2024-11-13T17:49:14.047Z] 17:49:14     INFO -  PID 2029 | console.debug: SearchService: "#addEngineToStore: Adding engine:" "Wikipedia (en)"
[task 2024-11-13T17:49:14.048Z] 17:49:14     INFO -  PID 2029 | console.debug: SearchService: "#loadStartupEngines: loading" 0 "engines reported by AddonManager startup"
[task 2024-11-13T17:49:14.048Z] 17:49:14     INFO -  PID 2029 | console.debug: SearchService: "#loadEngines: done"
[task 2024-11-13T17:49:14.048Z] 17:49:14     INFO -  PID 2029 | console.debug: SearchService: "Completed #init"
[task 2024-11-13T17:49:14.048Z] 17:49:14     INFO -  PID 2029 | console.debug: OpenSearchLoader: "Downloading OpenSearch engine from:" "http://localhost:50595/sjs/engineMaker.sjs?{%22baseURL%22:%22http://localhost:50595/sjs/%22,%22name%22:%22GET%20suggestion%20engine%22,%22method%22:%22GET%22}"
[task 2024-11-13T17:49:14.049Z] 17:49:14     INFO -  PID 2029 | console.debug: SearchUtils: "loadListener: Starting request:" "http://localhost:50595/sjs/engineMaker.sjs?{%22baseURL%22:%22http://localhost:50595/sjs/%22,%22name%22:%22GET%20suggestion%20engine%22,%22method%22:%22GET%22}"
[task 2024-11-13T17:49:14.049Z] 17:49:14     INFO -  PID 2029 | console.debug: SearchUtils: "loadListener: Stopping request:" "http://localhost:50595/sjs/engineMaker.sjs?{%22baseURL%22:%22http://localhost:50595/sjs/%22,%22name%22:%22GET%20suggestion%20engine%22,%22method%22:%22GET%22}"
[task 2024-11-13T17:49:14.049Z] 17:49:14     INFO -  PID 2029 | console.debug: OpenSearchLoader: "Loading search plugin"
[task 2024-11-13T17:49:14.049Z] 17:49:14     INFO -  PID 2029 | console.debug: SearchService: "#addEngineToStore: Adding engine:" "GET suggestion engine"
[task 2024-11-13T17:49:14.050Z] 17:49:14     INFO -  PID 2029 | console.debug: SearchUtils: "NOTIFY: Engine:" "GET suggestion engine" "Verb:" "engine-added"
[task 2024-11-13T17:49:14.050Z] 17:49:14     INFO -  PID 2029 | console.debug: SearchService: "addOpenSearchEngine: Adding" "http://localhost:50595/sjs/engineMaker.sjs?{\\"baseURL\\":\\"http://localhost:50595/sjs/\\",\\"name\\":\\"POST suggestion engine\\",\\"method\\":\\"POST\\"}"
[task 2024-11-13T17:49:14.050Z] 17:49:14     INFO -  PID 2029 | console.debug: OpenSearchLoader: "Downloading OpenSearch engine from:" "http://localhost:50595/sjs/engineMaker.sjs?{%22baseURL%22:%22http://localhost:50595/sjs/%22,%22name%22:%22POST%20suggestion%20engine%22,%22method%22:%22POST%22}"
[task 2024-11-13T17:49:14.051Z] 17:49:14     INFO -  PID 2029 | console.debug: SearchUtils: "loadListener: Starting request:" "http://localhost:50595/sjs/engineMaker.sjs?{%22baseURL%22:%22http://localhost:50595/sjs/%22,%22name%22:%22POST%20suggestion%20engine%22,%22method%22:%22POST%22}"
[task 2024-11-13T17:49:14.051Z] 17:49:14     INFO -  PID 2029 | console.debug: SearchUtils: "loadListener: Stopping request:" "http://localhost:50595/sjs/engineMaker.sjs?{%22baseURL%22:%22http://localhost:50595/sjs/%22,%22name%22:%22POST%20suggestion%20engine%22,%22method%22:%22POST%22}"
[task 2024-11-13T17:49:14.051Z] 17:49:14     INFO -  PID 2029 | console.debug: OpenSearchLoader: "Loading search plugin"
[task 2024-11-13T17:49:14.051Z] 17:49:14     INFO -  PID 2029 | console.debug: SearchService: "#addEngineToStore: Adding engine:" "POST suggestion engine"
[task 2024-11-13T17:49:14.052Z] 17:49:14     INFO -  PID 2029 | console.debug: SearchUtils: "NOTIFY: Engine:" "POST suggestion engine" "Verb:" "engine-added"
[task 2024-11-13T17:49:14.052Z] 17:49:14     INFO -  PID 2029 | console.debug: SearchService: "addOpenSearchEngine: Adding" "http://localhost:50595/sjs/engineMaker.sjs?{\\"baseURL\\":\\"http://example.invalid/\\",\\"name\\":\\"Offline suggestion engine\\",\\"method\\":\\"GET\\"}"
[task 2024-11-13T17:49:14.052Z] 17:49:14     INFO -  PID 2029 | console.debug: OpenSearchLoader: "Downloading OpenSearch engine from:" "http://localhost:50595/sjs/engineMaker.sjs?{%22baseURL%22:%22http://example.invalid/%22,%22name%22:%22Offline%20suggestion%20engine%22,%22method%22:%22GET%22}"
[task 2024-11-13T17:49:14.052Z] 17:49:14     INFO -  PID 2029 | console.debug: SearchUtils: "loadListener: Starting request:" "http://localhost:50595/sjs/engineMaker.sjs?{%22baseURL%22:%22http://example.invalid/%22,%22name%22:%22Offline%20suggestion%20engine%22,%22method%22:%22GET%22}"
[task 2024-11-13T17:49:14.053Z] 17:49:14     INFO -  PID 2029 | console.debug: SearchUtils: "loadListener: Stopping request:" "http://localhost:50595/sjs/engineMaker.sjs?{%22baseURL%22:%22http://example.invalid/%22,%22name%22:%22Offline%20suggestion%20engine%22,%22method%22:%22GET%22}"
[task 2024-11-13T17:49:14.053Z] 17:49:14     INFO -  PID 2029 | console.debug: OpenSearchLoader: "Loading search plugin"
[task 2024-11-13T17:49:14.053Z] 17:49:14     INFO -  PID 2029 | console.debug: SearchService: "#addEngineToStore: Adding engine:" "Offline suggestion engine"
[task 2024-11-13T17:49:14.053Z] 17:49:14     INFO -  PID 2029 | console.debug: SearchUtils: "NOTIFY: Engine:" "Offline suggestion engine" "Verb:" "engine-added"
[task 2024-11-13T17:49:14.054Z] 17:49:14     INFO -  PID 2029 | console.debug: SearchService: "addOpenSearchEngine: Adding" "http://localhost:50595/sjs/engineMaker.sjs?{\\"baseURL\\":\\"http://localhost:50595/sjs/\\",\\"name\\":\\"Alternative JSON suggestion type\\",\\"method\\":\\"GET\\",\\"alternativeJSONType\\":true}"
[task 2024-11-13T17:49:14.054Z] 17:49:14     INFO -  PID 2029 | console.debug: OpenSearchLoader: "Downloading OpenSearch engine from:" "http://localhost:50595/sjs/engineMaker.sjs?{%22baseURL%22:%22http://localhost:50595/sjs/%22,%22name%22:%22Alternative%20JSON%20suggestion%20type%22,%22method%22:%22GET%22,%22alternativeJSONType%22:true}"
[task 2024-11-13T17:49:14.054Z] 17:49:14     INFO -  PID 2029 | console.debug: SearchUtils: "loadListener: Starting request:" "http://localhost:50595/sjs/engineMaker.sjs?{%22baseURL%22:%22http://localhost:50595/sjs/%22,%22name%22:%22Alternative%20JSON%20suggestion%20type%22,%22method%22:%22GET%22,%22alternativeJSONType%22:true}"
[task 2024-11-13T17:49:14.055Z] 17:49:14     INFO -  PID 2029 | console.debug: SearchUtils: "loadListener: Stopping request:" "http://localhost:50595/sjs/engineMaker.sjs?{%22baseURL%22:%22http://localhost:50595/sjs/%22,%22name%22:%22Alternative%20JSON%20suggestion%20type%22,%22method%22:%22GET%22,%22alternativeJSONType%22:true}"
[task 2024-11-13T17:49:14.055Z] 17:49:14     INFO -  PID 2029 | console.debug: OpenSearchLoader: "Loading search plugin"
[task 2024-11-13T17:49:14.055Z] 17:49:14     INFO -  PID 2029 | console.debug: SearchService: "#addEngineToStore: Adding engine:" "Alternative JSON suggestion type"
[task 2024-11-13T17:49:14.055Z] 17:49:14     INFO -  PID 2029 | console.debug: SearchUtils: "NOTIFY: Engine:" "Alternative JSON suggestion type" "Verb:" "engine-added"
[task 2024-11-13T17:49:14.056Z] 17:49:14     INFO -  (xpcshell/head.js) | test run_next_test 1 pending (2)
[task 2024-11-13T17:49:14.056Z] 17:49:14     INFO -  (xpcshell/head.js) | test finished (2)
[task 2024-11-13T17:49:14.056Z] 17:49:14     INFO -  xpcshell.toml:toolkit/components/search/tests/xpcshell/test_searchSuggest.js | Starting simple_no_result_promise
[task 2024-11-13T17:49:14.056Z] 17:49:14     INFO -  (xpcshell/head.js) | test simple_no_result_promise pending (2)
[task 2024-11-13T17:49:14.056Z] 17:49:14     INFO -  (xpcshell/head.js) | test run_next_test 1 finished (2)
[task 2024-11-13T17:49:14.057Z] 17:49:14     INFO -  TEST-PASS | xpcshell.toml:toolkit/components/search/tests/xpcshell/test_searchSuggest.js | simple_no_result_promise - [simple_no_result_promise : 106] "no remote" == "no remote"

Comment 1

[Intermittent Failures Robot]

2 failures in 4227 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 2

Platform and build breakdown:

• macosx1015-64-qr: 2
  • opt: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1931009&startday=2024-11-11&endday=2024-11-17&tree=all

Comment 2

[Stephanie Cunnane [:scunnane]]

I've occasionally had this test fail locally while running all the tests in toolkit/components/search. It's failing on less than 10% of the runs, I'd guess. Log from my most recent failure:

toolkit/components/search/tests/xpcshell/test_searchSuggest.js
  FAIL slow_timeout_2 - [slow_timeout_2 : 639] 1 == 0
/home/stephanie/firefox/obj-x86_64-pc-linux-gnu/_tests/xpcshell/toolkit/components/search/tests/xpcshell/test_searchSuggest.js:slow_timeout_2:639
  FAIL toolkit/components/search/tests/xpcshell/test_searchSuggest.js - xpcshell return code: 0
ERROR Unexpected exception NS_ERROR_ABORT:
_abort_failed_test@/home/stephanie/firefox/testing/xpcshell/head.js:869:20
do_report_result@/home/stephanie/firefox/testing/xpcshell/head.js:981:5
Assert<@/home/stephanie/firefox/testing/xpcshell/head.js:70:21
Assert.prototype.report@resource://testing-common/Assert.sys.mjs:251:10
equal@resource://testing-common/Assert.sys.mjs:293:8
slow_timeout_2@/home/stephanie/firefox/obj-x86_64-pc-linux-gnu/_tests/xpcshell/toolkit/components/search/tests/xpcshell/test_searchSuggest.js:639:12
async*_run_next_test/<@/home/stephanie/firefox/testing/xpcshell/head.js:1759:22
_run_next_test@/home/stephanie/firefox/testing/xpcshell/head.js:1759:38
run@/home/stephanie/firefox/testing/xpcshell/head.js:808:9
_do_main@/home/stephanie/firefox/testing/xpcshell/head.js:245:6
_execute_test@/home/stephanie/firefox/testing/xpcshell/head.js:596:5
@-e:1:1

Comment 3

[Intermittent Failures Robot]

1 failures were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Table

	no_variant
macosx1470-x86_64/debug	1

For more details, see:

https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1931009&startday=2025-09-01&endday=2025-09-07&tree=all

Comment 4

[Intermittent Failures Robot]

1 failures were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Table

	no_variant
macosx1470-x86_64/opt	1

For more details, see:

https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1931009&startday=2025-09-15&endday=2025-09-21&tree=all