1880388 - Intermittent browser/components/urlbar/tests/quicksuggest/unit/test_weather.js | single tracking bug

Status: NEW

(Firefox :: Address Bar, defect, P5)

Description

[Treeherder Bug Filer]

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

---

[task 2024-02-14T21:37:21.369Z] 21:37:21     INFO -  TEST-START | browser/components/urlbar/tests/quicksuggest/unit/test_weather.js
[task 2024-02-14T21:37:22.337Z] 21:37:22  WARNING -  TEST-UNEXPECTED-FAIL | browser/components/urlbar/tests/quicksuggest/unit/test_weather.js | xpcshell return code: 0
[task 2024-02-14T21:37:22.345Z] 21:37:22     INFO -  TEST-INFO took 968ms
[task 2024-02-14T21:37:22.345Z] 21:37:22     INFO -  >>>>>>>
[task 2024-02-14T21:37:22.345Z] 21:37:22     INFO -  "MerinoTestUtils init: Depth is now 1"
[task 2024-02-14T21:37:22.345Z] 21:37:22     INFO -  "MockMerinoServer constructor"
[task 2024-02-14T21:37:22.346Z] 21:37:22     INFO -  (xpcshell/head.js) | test MAIN run_test pending (1)
[task 2024-02-14T21:37:22.346Z] 21:37:22     INFO -  (xpcshell/head.js) | test run_next_test 0 pending (2)
[task 2024-02-14T21:37:22.346Z] 21:37:22     INFO -  (xpcshell/head.js) | test MAIN run_test finished (2)
[task 2024-02-14T21:37:22.346Z] 21:37:22     INFO -  running event loop
[task 2024-02-14T21:37:22.347Z] 21:37:22     INFO -  browser/components/urlbar/tests/quicksuggest/unit/test_weather.js | Starting setup setUpQuickSuggestXpcshellTest
[task 2024-02-14T21:37:22.347Z] 21:37:22     INFO -  (xpcshell/head.js) | test setUpQuickSuggestXpcshellTest pending (2)
[task 2024-02-14T21:37:22.347Z] 21:37:22     INFO -  (xpcshell/head.js) | test run_next_test 0 finished (2)
[task 2024-02-14T21:37:22.347Z] 21:37:22     INFO -  (xpcshell/head.js) | test run_next_test 1 pending (2)
[task 2024-02-14T21:37:22.347Z] 21:37:22     INFO -  (xpcshell/head.js) | test setUpQuickSuggestXpcshellTest finished (2)
[task 2024-02-14T21:37:22.348Z] 21:37:22     INFO -  browser/components/urlbar/tests/quicksuggest/unit/test_weather.js | Starting setup
[task 2024-02-14T21:37:22.348Z] 21:37:22     INFO -  (xpcshell/head.js) | test pending (2)
[task 2024-02-14T21:37:22.349Z] 21:37:22     INFO -  "QuickSuggestTestUtils.ensureQuickSuggestInit Started, preparing remote settings server"
[task 2024-02-14T21:37:22.349Z] 21:37:22     INFO -  (xpcshell/head.js) | test run_next_test 1 finished (2)
[task 2024-02-14T21:37:22.349Z] 21:37:22     INFO -  "QuickSuggestTestUtils.ensureQuickSuggestInit Starting remote settings server"
[task 2024-02-14T21:37:22.349Z] 21:37:22     INFO -  PID 6368 | 1707946641736	RemoteSettingsServer	INFO	Starting
[task 2024-02-14T21:37:22.350Z] 21:37:22     INFO -  PID 6368 | 1707946641737	RemoteSettingsServer	INFO	Server is now started at http://localhost:65396/v1
[task 2024-02-14T21:37:22.350Z] 21:37:22     INFO -  "QuickSuggestTestUtils.ensureQuickSuggestInit Remote settings server started"
[task 2024-02-14T21:37:22.350Z] 21:37:22     INFO -  "QuickSuggestTestUtils.ensureQuickSuggestInit Calling QuickSuggest.init() and setting prefs"
[task 2024-02-14T21:37:22.350Z] 21:37:22     INFO -  PID 6368 | [ERROR error_support::handling] suggest-unexpected: Error opening database: Error executing SQL: table meta already exists
[task 2024-02-14T21:37:22.351Z] 21:37:22     INFO -  PID 6368 | 1707946641824	RemoteSettingsServer	INFO	< HTTP 1.1 GET /v1/buckets/main/collections/quicksuggest/records?_sort=last_modified
[task 2024-02-14T21:37:22.351Z] 21:37:22     INFO -  PID 6368 | 1707946641824	RemoteSettingsServer	INFO	> 200 /v1/buckets/main/collections/quicksuggest/records
[task 2024-02-14T21:37:22.352Z] 21:37:22     INFO -  "CONSOLE_MESSAGE: (error) [JavaScript Error: "1707946641825	urlbar	ERROR	QuickSuggest.SuggestBackendRust :: Ingest error: Error opening database: Error executing SQL: table meta already exists" {file: "resource://gre/modules/Log.sys.mjs" line: 722}]
[task 2024-02-14T21:37:22.352Z] 21:37:22     INFO -  append@resource://gre/modules/Log.sys.mjs:722:12
[task 2024-02-14T21:37:22.352Z] 21:37:22     INFO -  log@resource://gre/modules/Log.sys.mjs:376:16
[task 2024-02-14T21:37:22.352Z] 21:37:22     INFO -  getLoggerWithMessagePrefix/proxy.log@resource://gre/modules/Log.sys.mjs:505:18
[task 2024-02-14T21:37:22.353Z] 21:37:22     INFO -  error@resource://gre/modules/Log.sys.mjs:384:10
[task 2024-02-14T21:37:22.353Z] 21:37:22     INFO -  #ingest@resource:///modules/urlbar/private/SuggestBackendRust.sys.mjs:292:19
[task 2024-02-14T21:37:22.353Z] 21:37:22     INFO -  _do_main@Z:\\task_170794601022064\\build\\tests\\xpcshell\\head.js:245:6
[task 2024-02-14T21:37:22.353Z] 21:37:22     INFO -  _execute_test@Z:\\task_170794601022064\\build\\tests\\xpcshell\\head.js:596:5
[task 2024-02-14T21:37:22.354Z] 21:37:22     INFO -  @-e:1:1
[task 2024-02-14T21:37:22.354Z] 21:37:22     INFO -  "
[task 2024-02-14T21:37:22.354Z] 21:37:22     INFO -  "QuickSuggestTestUtils.forceSync Started"
[task 2024-02-14T21:37:22.354Z] 21:37:22     INFO -  "QuickSuggestTestUtils.forceSync Syncing Rust backend"
[task 2024-02-14T21:37:22.354Z] 21:37:22     INFO -  PID 6368 | 1707946641913	RemoteSettingsServer	INFO	< HTTP 1.1 GET /v1/buckets/main/collections/quicksuggest/records?_sort=last_modified
[task 2024-02-14T21:37:22.355Z] 21:37:22     INFO -  PID 6368 | 1707946641914	RemoteSettingsServer	INFO	> 200 /v1/buckets/main/collections/quicksuggest/records
[task 2024-02-14T21:37:22.355Z] 21:37:22     INFO -  "QuickSuggestTestUtils.forceSync Done syncing Rust backend"
[task 2024-02-14T21:37:22.355Z] 21:37:22     INFO -  "QuickSuggestTestUtils.forceSync Done"
[task 2024-02-14T21:37:22.355Z] 21:37:22     INFO -  "QuickSuggestTestUtils.ensureQuickSuggestInit Done"
[task 2024-02-14T21:37:22.356Z] 21:37:22     INFO -  "MockMerinoServer initializing weather, starting server"
[task 2024-02-14T21:37:22.356Z] 21:37:22     INFO -  "MockMerinoServer starting"
[task 2024-02-14T21:37:22.356Z] 21:37:22     INFO -  "MockMerinoServer waiting to start serving..."
[task 2024-02-14T21:37:22.357Z] 21:37:22     INFO -  "MockMerinoServer received request with query string: """
[task 2024-02-14T21:37:22.357Z] 21:37:22     INFO -  "MockMerinoServer replying with response: {"status":200,"contentType":"application/json","body":{"request_id":"request_id","suggestions":[{"provider":"adm","full_keyword":"amp","title":"Amp Suggestion","url":"http://example.com/amp","icon":null,"impression_url":"http://example.com/amp-impression","click_url":"http://example.com/amp-click","block_id":1,"advertiser":"Amp","iab_category":"22 - Shopping","is_sponsored":true,"score":1}]}}"
[task 2024-02-14T21:37:22.358Z] 21:37:22     INFO -  "MockMerinoServer is now serving"
[task 2024-02-14T21:37:22.358Z] 21:37:22     INFO -  "MockMerinoServer initializing weather, server now started"
[task 2024-02-14T21:37:22.358Z] 21:37:22     INFO -  "MockMerinoServer initializing weather, waiting for fetch"
[task 2024-02-14T21:37:22.358Z] 21:37:22     INFO -  "MockMerinoServer received request with query string: "q=&sid=70173e7d-35b8-445d-a5e8-4839366bb2e1&seq=0&providers=accuweather""
[task 2024-02-14T21:37:22.359Z] 21:37:22     INFO -  "MockMerinoServer replying with response: {"status":200,"contentType":"application/json","body":{"request_id":"request_id","suggestions":[{"title":"Weather for San Francisco","url":"https://example.com/weather","provider":"accuweather","is_sponsored":false,"score":0.2,"icon":null,"city_name":"San Francisco","current_conditions":{"url":"https://example.com/weather-current-conditions","summary":"Mostly cloudy","icon_id":6,"temperature":{"c":15.5,"f":60}},"forecast":{"url":"https://example.com/weather-forecast","summary":"Pleasant Saturday","high":{"c":21.1,"f":70},"low":{"c":13.9,"f":57}}}]}}"
[task 2024-02-14T21:37:22.359Z] 21:37:22     INFO -  "MockMerinoServer initializing weather, got fetch"
[task 2024-02-14T21:37:22.360Z] 21:37:22     INFO -  TEST-PASS | browser/components/urlbar/tests/quicksuggest/unit/test_weather.js |  - No pending fetches after awaiting initial fetch - 0 == 0

Comment 1

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

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

For more information, please visit BugBot documentation.

Comment 2

[Drew Willcoxon :adw]

Ingest error: Error opening database: Error executing SQL: table meta already exists

Needs investigation. I wonder if it can happen in the real world. I'll move this to Application Services since the error indicates the Sqlite database, but it might also be related to how desktop interacts with the Rust component.

Comment 3

[Drew Willcoxon :adw]

Hopefully bug 1880416 fixed this. I'll move this back to Address Bar because it's likely a problem with how desktop does ingest, sorry for the noise.

Comment 4

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

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

Comment 5

[Norisz Fay [:noriszfay]]

Tier 1 failure here

Comment 6

[Intermittent Failures Robot]

5 failures in 3125 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 4
• mozilla-central: 1

Platform and build breakdown:

• windows11-32-2009-qr: 2
  • opt: 2
• windows11-64-2009-qr: 2
  • debug: 1
  • opt: 1
• windows11-32-2009-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1880388&startday=2024-02-12&endday=2024-02-18&tree=all

Comment 7

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

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

Comment 9

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 1
• autoland: 1

Platform and build breakdown:

• windows11-64-2009-ccov-qr: 1
  • opt: 1
• linux1804-64-shippable-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1880388&startday=2024-03-04&endday=2024-03-10&tree=all

Comment 10

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-release: 1

Platform and build breakdown:

• macosx1015-64-shippable-qr: 1
  • opt: 1

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

Comment 11

[Intermittent Failures Robot]

3 failures in 3235 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 3

Platform and build breakdown:

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

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1880388&startday=2024-04-08&endday=2024-04-14&tree=all