Closed Bug 1799582 Opened 2 years ago Closed 2 years ago

Intermittent [TV] browser/components/urlbar/tests/quicksuggest/unit/test_merinoClient.js | providers_arg_single - [providers_arg_single : 576] Expected suggestions - [] deepEqual [{"full_keyword":"full_keyword","title":"title","url":"url","icon":null,"

Categories

(Firefox :: Address Bar, defect, P5)

defect

Tracking

()

RESOLVED FIXED
109 Branch
Tracking Status
firefox-esr102 --- unaffected
firefox106 --- unaffected
firefox107 --- unaffected
firefox108 --- fixed
firefox109 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: adw)

References

(Regression)

Details

(Keywords: intermittent-failure, regression)

Attachments

(1 file)

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


INFO -  TEST-PASS | browser/components/urlbar/tests/quicksuggest/unit/test_merinoClient.js | clientVariants_providers_preferences - [clientVariants_providers_preferences : 466] Session ID is a UUID - true == true
[task 2022-11-08T03:10:34.677Z] 03:10:34     INFO -  (xpcshell/head.js) | test run_next_test 15 pending (2)
[task 2022-11-08T03:10:34.677Z] 03:10:34     INFO -  (xpcshell/head.js) | test clientVariants_providers_preferences finished (2)
[task 2022-11-08T03:10:34.678Z] 03:10:34     INFO -  browser/components/urlbar/tests/quicksuggest/unit/test_merinoClient.js | Starting providers_arg_single
[task 2022-11-08T03:10:34.678Z] 03:10:34     INFO -  (xpcshell/head.js) | test providers_arg_single pending (2)
[task 2022-11-08T03:10:34.678Z] 03:10:34     INFO -  (xpcshell/head.js) | test run_next_test 15 finished (2)
[task 2022-11-08T03:10:34.678Z] 03:10:34     INFO -  "MockMerinoServer received request with query string: "q=search&sid=677a1399-be96-4859-ad68-710b7ef562d2&seq=0&providers=argShouldBeUsed""
[task 2022-11-08T03:10:34.679Z] 03:10:34     INFO -  "MockMerinoServer replying with response: {"status":200,"contentType":"application/json","body":{"request_id":"request_id","suggestions":[{"full_keyword":"full_keyword","title":"title","url":"url","icon":null,"impression_url":"impression_url","click_url":"click_url","block_id":1,"advertiser":"advertiser","is_sponsored":true,"score":1}]}}"
[task 2022-11-08T03:10:34.679Z] 03:10:34  WARNING -  TEST-UNEXPECTED-FAIL | browser/components/urlbar/tests/quicksuggest/unit/test_merinoClient.js | providers_arg_single - [providers_arg_single : 576] Expected suggestions - [] deepEqual [{"full_keyword":"full_keyword","title":"title","url":"url","icon":null,"impression_url":"impression_url","click_url":"click_url","block_id":1,"advertiser":"advertiser","is_sponsored":true,"score":1,"request_id":"request_id","source":"merino"}]
[task 2022-11-08T03:10:34.680Z] 03:10:34     INFO -  /opt/worker/tasks/task_166787556645356/build/tests/xpcshell/tests/browser/components/urlbar/tests/quicksuggest/unit/test_merinoClient.js:fetchAndCheckSuggestions:576
[task 2022-11-08T03:10:34.680Z] 03:10:34     INFO -  /opt/worker/tasks/task_166787556645356/build/tests/xpcshell/head.js:_do_main:240
[task 2022-11-08T03:10:34.680Z] 03:10:34     INFO -  /opt/worker/tasks/task_166787556645356/build/tests/xpcshell/head.js:_execute_test:597
[task 2022-11-08T03:10:34.680Z] 03:10:34     INFO -  -e:null:1
[task 2022-11-08T03:10:34.680Z] 03:10:34     INFO -  exiting test
[task 2022-11-08T03:10:34.681Z] 03:10:34     INFO -  Unexpected exception NS_ERROR_ABORT:
[task 2022-11-08T03:10:34.681Z] 03:10:34     INFO -  _abort_failed_test@/opt/worker/tasks/task_166787556645356/build/tests/xpcshell/head.js:875:20
[task 2022-11-08T03:10:34.681Z] 03:10:34     INFO -  do_report_result@/opt/worker/tasks/task_166787556645356/build/tests/xpcshell/head.js:976:5
[task 2022-11-08T03:10:34.681Z] 03:10:34     INFO -  Assert<@/opt/worker/tasks/task_166787556645356/build/tests/xpcshell/head.js:73:21
[task 2022-11-08T03:10:34.682Z] 03:10:34     INFO -  proto.report@resource://testing-common/Assert.jsm:228:10
[task 2022-11-08T03:10:34.682Z] 03:10:34     INFO -  deepEqual@resource://testing-common/Assert.jsm:305:8
[task 2022-11-08T03:10:34.682Z] 03:10:34     INFO -  fetchAndCheckSuggestions@/opt/worker/tasks/task_166787556645356/build/tests/xpcshell/tests/browser/components/urlbar/tests/quicksuggest/unit/test_merinoClient.js:576:10
[task 2022-11-08T03:10:34.682Z] 03:10:34     INFO -  _do_main@/opt/worker/tasks/task_166787556645356/build/tests/xpcshell/head.js:240:6
[task 2022-11-08T03:10:34.683Z] 03:10:34     INFO -  _execute_test@/opt/worker/tasks/task_166787556645356/build/tests/xpcshell/head.js:597:5
[task 2022-11-08T03:10:34.683Z] 03:10:34     INFO -  @-e:1:1
[task 2022-11-08T03:10:34.683Z] 03:10:34     INFO -  exiting test
[task 2022-11-08T03:10:34.683Z] 03:10:34     INFO -  "MockMerinoServer stopping"
[task 2022-11-08T03:10:34.683Z] 03:10:34     INFO -  "MockMerinoServer is now stopped"
[task 2022-11-08T03:10:34.683Z] 03:10:34     INFO -  "Force a GC"
[task 2022-11-08T03:10:34.684Z] 03:10:34     INFO -  <<<<<<<
[task 2022-11-08T03:10:34.684Z] 03:10:34     INFO -  TEST-START | browser/components/urlbar/tests/quicksuggest/unit/test_merinoClient.js
[task 2022-11-08T03:10:48.402Z] 03:10:48     INFO -  TEST-PASS | browser/components/urlbar/tests/quicksuggest/unit/test_merinoClient.js | took 13784ms

:adw, since you are the author of the regressor, bug 1799265, could you take a look?

For more information, please visit auto_nag documentation.

Flags: needinfo?(adw)

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

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

Assignee: nobody → adw
Status: NEW → ASSIGNED
Flags: needinfo?(adw)

The test sometimes receives zero Merino suggestions when it expects some. I
noticed a few potential problems:

  1. The merino.timeoutMs pref keeps its default value of 200ms throughout most
    of the test. That's low enough that it might cause the client to time out
    waiting for Merino, especially on slow machines in verify mode. To fix that,
    I set the timeout pref to a large value at the start of the test.
  2. The Merino test server should probably cancel its delayed-response timers
    when reset() is called on it. Otherwise the server will still send
    responses once the timers elapse, which might interfere with later tasks.
  3. I'm not sure about this, but the test server's #handleRequest() method
    probably shouldn't be async. Right now it's async to handle sending delayed
    responses. This patch makes it sync and it just handles that using a then()
    instead.

Retriggers on try are green.

Pushed by dwillcoxon@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/f1b198709159 Fix intermittent failure in test_merinoClient.js. r=daisuke
Status: ASSIGNED → RESOLVED
Closed: 2 years ago
Resolution: --- → FIXED
Target Milestone: --- → 109 Branch

The patch landed in nightly and beta is affected.
:adw, is this bug important enough to require an uplift?

  • If yes, please nominate the patch for beta approval.
  • If no, please set status-firefox108 to wontfix.

For more information, please visit auto_nag documentation.

Flags: needinfo?(adw)

Thanks for uplifting.

Flags: needinfo?(adw)
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: