Intermittent browser/components/urlbar/tests/quicksuggest/browser/browser_weather.js | single tracking bug
Categories
(Firefox :: Address Bar, defect, P3)
Tracking
()
People
(Reporter: intermittent-bug-filer, Assigned: adw)
References
(Regression)
Details
(Keywords: intermittent-failure, intermittent-testcase, regression, Whiteboard: [stockwell disable-recommended][sng])
Attachments
(1 file)
Filed by: nfay [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=415627129&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/JV5T--dCSOKKAhQTOROJ8A/runs/0/artifacts/public/logs/live_backing.log
[task 2023-05-12T22:57:10.650Z] 22:57:10 INFO - TEST-PASS | browser/components/urlbar/tests/quicksuggest/browser/browser_weather.js | The view should remain open clicking the command - true == true -
[task 2023-05-12T22:57:10.650Z] 22:57:10 INFO - TEST-PASS | browser/components/urlbar/tests/quicksuggest/browser/browser_weather.js | Row should have feedback acknowledgment after clicking command - true == true -
[task 2023-05-12T22:57:10.651Z] 22:57:10 INFO - Doing dismissal
[task 2023-05-12T22:57:10.652Z] 22:57:10 INFO - TEST-PASS | browser/components/urlbar/tests/quicksuggest/browser/browser_weather.js | Weather suggestion should be present - "Weather" == "Weather" -
[task 2023-05-12T22:57:10.652Z] 22:57:10 INFO - TEST-PASS | browser/components/urlbar/tests/quicksuggest/browser/browser_weather.js | view should be open - true == true -
[task 2023-05-12T22:57:10.653Z] 22:57:10 INFO - TEST-PASS | browser/components/urlbar/tests/quicksuggest/browser/browser_weather.js | found the menu button at result index 1 - {"elementIndex":2} == true -
[task 2023-05-12T22:57:10.653Z] 22:57:10 INFO - selecting the result at index 1
[task 2023-05-12T22:57:10.654Z] 22:57:10 INFO - waiting for the menu popup to open via mouse
[task 2023-05-12T22:57:10.655Z] 22:57:10 INFO - TEST-PASS | browser/components/urlbar/tests/quicksuggest/browser/browser_weather.js | Checking popup state - "open" == "open" -
[task 2023-05-12T22:57:10.655Z] 22:57:10 INFO - Clicking menu item with selector: [data-l10n-id=firefox-suggest-weather-command-dont-show-this]
[task 2023-05-12T22:57:10.656Z] 22:57:10 INFO - Waiting for submenu popupshown event
[task 2023-05-12T22:57:10.656Z] 22:57:10 INFO - Buffered messages finished
[task 2023-05-12T22:57:10.657Z] 22:57:10 INFO - TEST-UNEXPECTED-FAIL | browser/components/urlbar/tests/quicksuggest/browser/browser_weather.js | Test timed out -
[task 2023-05-12T22:57:10.657Z] 22:57:10 INFO - MerinoTestUtils cleanup function
[task 2023-05-12T22:57:10.658Z] 22:57:10 INFO - MerinoTestUtils uninit: Depth is now 0
[task 2023-05-12T22:57:10.658Z] 22:57:10 INFO - MerinoTestUtils uninit: Now uninitializing
[task 2023-05-12T22:57:10.659Z] 22:57:10 INFO - MockMerinoServer uninit
[task 2023-05-12T22:57:10.660Z] 22:57:10 INFO - Not taking screenshot here: see the one that was previously logged
[task 2023-05-12T22:57:10.660Z] 22:57:10 INFO - TEST-UNEXPECTED-FAIL | browser/components/urlbar/tests/quicksuggest/browser/browser_weather.js | Uncaught exception received from previously timed out test bound showLessFrequentlyAndDismissal - popupshown listener not removed before the end of test
[task 2023-05-12T22:57:10.704Z] 22:57:10 INFO - GECKO(12719) | MEMORY STAT | vsize 3394MB | residentFast 393MB | heapAllocated 203MB
[task 2023-05-12T22:57:10.705Z] 22:57:10 INFO - TEST-OK | browser/components/urlbar/tests/quicksuggest/browser/browser_weather.js | took 46727ms
[task 2023-05-12T22:57:10.725Z] 22:57:10 INFO - checking window state
[task 2023-05-12T22:57:10.753Z] 22:57:10 INFO - GECKO(12719) | Completed ShutdownLeaks collections in process 12719
[task 2023-05-12T22:57:10.753Z] 22:57:10 INFO - TEST-START | Shutdown
[task 2023-05-12T22:57:10.753Z] 22:57:10 INFO - Browser Chrome Test Summary
[task 2023-05-12T22:57:10.753Z] 22:57:10 INFO - Passed: 5774
[task 2023-05-12T22:57:10.753Z] 22:57:10 INFO - Failed: 2
[task 2023-05-12T22:57:10.753Z] 22:57:10 INFO - Todo: 5
[task 2023-05-12T22:57:10.754Z] 22:57:10 INFO - Mode: e10s
[task 2023-05-12T22:57:10.754Z] 22:57:10 INFO - *** End BrowserChrome Test Results ***
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 10•11 months ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit BugBot documentation.
Reporter | ||
Comment 11•11 months ago
|
||
treeherder |
New failure instance: https://treeherder.mozilla.org/logviewer?job_id=425634795&repo=mozilla-beta
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 17•9 months ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit BugBot documentation.
Reporter | ||
Comment 18•9 months ago
|
||
treeherder |
New failure instance: https://treeherder.mozilla.org/logviewer?job_id=431841639&repo=autoland
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 27•5 months ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit BugBot documentation.
Reporter | ||
Comment 28•5 months ago
|
||
treeherder |
New failure instance: https://treeherder.mozilla.org/logviewer?job_id=446454889&repo=autoland
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 33•4 months ago
|
||
Update:
There have been 58 failures within the last 7 days:
• 3 failures on Linux 18.04 x64 WebRender debug
• 16 failures on Linux 18.04 x64 WebRender opt
• 10 failures on Linux 18.04 x64 WebRender Shippable opt
• 1 failures on Linux 18.04 x64 WebRender tsan opt
• 2 failures on OS X 10.15 WebRender opt
• 6 failures on Windows 11 x86 22H2 WebRender opt
• 3 failures on Windows 11 x86 22H2 WebRender Shippable opt
• 3 failures on Windows 11 x64 22H2 asan WebRender opt
• 1 failures on Windows 11 x64 22H2 CCov WebRender opt
• 4 failures on Windows 11 x64 22H2 WebRender debug
• 5 failures on Windows 11 x64 22H2 WebRender opt
• 4 failures on Windows 11 x64 22H2 WebRender Shippable opt
All the failures here have this failure line: TEST-UNEXPECTED-FAIL | browser/components/urlbar/tests/quicksuggest/browser/browser_weather.js | "" == "Mostly cloudy" - {"filename":"chrome://mochitests/content/browser/browser/components/urlbar/tests/quicksuggest/browser/browser_weather.js","name":"simpleUI","sourceId":880,"lineNumber":467,"columnNumber":12,"sourceLine":"","asyncCause":null,"asyncCaller":{"filename":"chrome://mochitests/content/browser/browser/components/urlbar/tests/quicksuggest/browser/head.js","name":"newTaskFn","sourceId":877,"lineNumber":668,"columnNumber":20,"sourceLine":"","asyncCause":null,"asyncCaller":{"filename":"chrome://mochikit/content/browser-test.js","name":"handleTask","sourceId":576,"lineNumber":1139,"columnNumber":26,"sourceLine":"","asyncCause":null,"asyncCaller":null,"caller":{"filename":"chrome://mochikit/content/browser-test.js","name":"_runTaskBasedTest","sourceId":576,"lineNumber":1211,"columnNumber":18,"sourceLine":"","asyncCause":null,"asyncCaller":<...>
Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=449328298&repo=mozilla-central&lineNumber=6346
[task 2024-03-04T00:15:08.855Z] 00:15:08 INFO - TEST-PASS | browser/components/urlbar/tests/quicksuggest/browser/browser_weather.js | Result telemetry type should be 'weather' - "weather" == "weather" -
[task 2024-03-04T00:15:08.856Z] 00:15:08 INFO - Buffered messages finished
[task 2024-03-04T00:15:08.862Z] 00:15:08 INFO - TEST-UNEXPECTED-FAIL | browser/components/urlbar/tests/quicksuggest/browser/browser_weather.js | "" == "Mostly cloudy" - {"filename":"chrome://mochitests/content/browser/browser/components/urlbar/tests/quicksuggest/browser/browser_weather.js","name":"simpleUI","sourceId":880,"lineNumber":467,"columnNumber":12,"sourceLine":"","asyncCause":null,"asyncCaller":{"filename":"chrome://mochitests/content/browser/browser/components/urlbar/tests/quicksuggest/browser/head.js","name":"newTaskFn","sourceId":877,"lineNumber":668,"columnNumber":20,"sourceLine":"","asyncCause":null,"asyncCaller":{"filename":"chrome://mochikit/content/browser-test.js","name":"handleTask","sourceId":576,"lineNumber":1139,"columnNumber":26,"sourceLine":"","asyncCause":null,"asyncCaller":null,"caller":{"filename":"chrome://mochikit/content/browser-test.js","name":"_runTaskBasedTest","sourceId":576,"lineNumber":1211,"columnNumber":18,"sourceLine":"","asyncCause":null,"asyncCaller":{"filename":"chrome://mochikit/content/browser-test.js","name":"Tester_execTest","sourceId":576,"lineNumber":1353,"columnNumber":14,"sourceLine":"","asyncCause":null,"asyncCaller":null,"caller":{"filename":"chrome://mochikit/content/browser-test.js","name":"nextTest/<","sourceId":576,"lineNumber":1128,"columnNumber":14,"sourceLine":"","asyncCause":null,"asyncCaller":null,"caller":{"filename":"chrome://mochikit/content/tests/SimpleTest/SimpleTest.js","name":"SimpleTest.waitForFocus/<","sourceId":601,"lineNumber":1058,"columnNumber":13,"sourceLine":"","asyncCause":null,"asyncCaller":null,"caller":null,"formattedStack":"SimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1058:13\n","nativeSavedFrame":{}},"formattedStack":"nextTest/<@chrome://mochikit/content/browser-test.js:1128:14\nSimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1058:13\n","nativeSavedFrame":{}},"formattedStack":"async*Tester_execTest@chrome://mochikit/content/browser-test.js:1353:14\nnextTest/<@chrome://mochikit/content/browser-test.js:1128:14\nSimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1058:13\n","nativeSavedFrame":{}},"caller":null,"formattedStack":"_runTaskBasedTest@chrome://mochikit/content/browser-test.js:1211:18\nasync*Tester_execTest@chrome://mochikit/content/browser-test.js:1353:14\nnextTest/<@chrome://mochikit/content/browser-test.js:1128:14\nSimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1058:13\n","nativeSavedFrame":{}},"formattedStack":"async*handleTask@chrome://mochikit/content/browser-test.js:1139:26\n_runTaskBasedTest@chrome://mochikit/content/browser-test.js:1211:18\nasync*Tester_execTest@chrome://mochikit/content/browser-test.js:1353:14\nnextTest/<@chrome://mochikit/content/browser-test.js:1128:14\nSimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1058:13\n","nativeSavedFrame":{}},"caller":null,"formattedStack":"async*newTaskFn@chrome://mochitests/content/browser/browser/components/urlbar/tests/quicksuggest/browser/head.js:668:20\nasync*handleTask@chrome://mochikit/content/browser-test.js:1139:26\n_runTaskBasedTest@chrome://mochikit/content/browser-test.js:1211:18\nasync*Tester_execTest@chrome://mochikit/content/browser-test.js:1353:14\nnextTest/<@chrome://mochikit/content/browser-test.js:1128:14\nSimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1058:13\n","nativeSavedFrame":{}},"caller":null,"formattedStack":"simpleUI@chrome://mochitests/content/browser/browser/components/urlbar/tests/quicksuggest/browser/browser_weather.js:467:12\nasync*newTaskFn@chrome://mochitests/content/browser/browser/components/urlbar/tests/quicksuggest/browser/head.js:668:20\nasync*handleTask@chrome://mochikit/content/browser-test.js:1139:26\n_runTaskBasedTest@chrome://mochikit/content/browser-test.js:1211:18\nasync*Tester_execTest@chrome://mochikit/content/browser-test.js:1353:14\nnextTest/<@chrome://mochikit/content/browser-test.js:1128:14\nSimpleTest.waitForFocus/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:1058:13\n","nativeSavedFrame":{}}
[task 2024-03-04T00:15:08.862Z] 00:15:08 INFO - Stack trace:
[task 2024-03-04T00:15:08.862Z] 00:15:08 INFO - chrome://mochitests/content/browser/browser/components/urlbar/tests/quicksuggest/browser/browser_weather.js:simpleUI:467
[task 2024-03-04T00:15:08.862Z] 00:15:08 INFO - chrome://mochitests/content/browser/browser/components/urlbar/tests/quicksuggest/browser/head.js:newTaskFn:668
[task 2024-03-04T00:15:08.862Z] 00:15:08 INFO - chrome://mochikit/content/browser-test.js:handleTask:1139
[task 2024-03-04T00:15:08.862Z] 00:15:08 INFO - chrome://mochikit/content/browser-test.js:_runTaskBasedTest:1211
[task 2024-03-04T00:15:08.862Z] 00:15:08 INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1353
[task 2024-03-04T00:15:08.862Z] 00:15:08 INFO - chrome://mochikit/content/browser-test.js:nextTest/<:1128
[task 2024-03-04T00:15:08.862Z] 00:15:08 INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/<:1058
[task 2024-03-04T00:15:08.863Z] 00:15:08 INFO - Closing the view directly
[task 2024-03-04T00:15:08.863Z] 00:15:08 INFO - Waiting for the view to close
[task 2024-03-04T00:15:08.864Z] 00:15:08 INFO - Urlbar view closed
[task 2024-03-04T00:15:08.864Z] 00:15:08 INFO - initNimbusFeature awaiting ExperimentManager.onStartup
[task 2024-03-04T00:15:08.865Z] 00:15:08 INFO - initNimbusFeature awaiting ExperimentAPI.ready
[task 2024-03-04T00:15:08.866Z] 00:15:08 INFO - initNimbusFeature awaiting ExperimentFakes.enrollWithRollout
[task 2024-03-04T00:15:08.866Z] 00:15:08 INFO - initNimbusFeature done
[task 2024-03-04T00:15:08.867Z] 00:15:08 INFO - Waiting for the urlbar view to open
[task 2024-03-04T00:15:08.867Z] 00:15:08 INFO - Urlbar view opened
[task 2024-03-04T00:15:08.868Z] 00:15:08 INFO - TEST-PASS | browser/components/urlbar/tests/quicksuggest/browser/browser_weather.js | Result should be from a weather provider - "UrlbarProviderQuickSuggest" == "UrlbarProviderQuickSuggest" -
Comment 34•4 months ago
|
||
Hi Drew! Can you please take a look at this? Maybe you can help us assign this to someone.
Thank you!
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Assignee | ||
Comment 37•4 months ago
|
||
I'll take a look.
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 40•4 months ago
|
||
bumping up priority as it's quite frequent (top 5 last week)
Assignee | ||
Comment 41•4 months ago
|
||
It looks like the recent failures are with the new simple UI, which was added in bug 1882220, so I'll mark that as regressing. However, less frequent failures in this test go way back before that, so there are multiple causes here.
Comment 42•4 months ago
|
||
Set release status flags based on info from the regressing bug 1882220
Assignee | ||
Updated•4 months ago
|
Assignee | ||
Comment 43•4 months ago
|
||
I found several problems:
Problem 1:
getViewUpdate()
is allowed to be async and UrlbarView
awaits it even though
the Weather
implementation is not async. That means the summary text content
will be updated asyncly, so browser_weather.js
needs to wait for it.
This is the cause of the recent frequent failures.
Problem 2:
This has to do with add_tasks_with_rust()
. When it disables the Rust backend
and forces sync, the JS backend will sync Weather
with remote settings. Since
keywords are present in remote settings at that point, Weather
will then start
fetching. Each task that uses add_tasks_with_rust()
needs to wait for this
fetch to finish. Otherwise weather.suggestion
may be null. To fix this, I
added a way for tests to register a setup function that will run each time
add_tasks_with_rust()
calls an original task.
This is the cause of infrequent failures that go back to at least when Rust was
enabled by default. I think this might be the cause of recent failures in
test_weather.js
and test_weather_keywords.js
too so I did the same thing
there.
Problem 3:
browser_weather.js
sometimes times out in verify mode, so I requested a longer
timeout. It looks like the test finishes, it just takes a long time sometimes.
Problem 4:
test_weather_keywords.js
sometimes times out in verify mode. This test takes
forever to run, especially now that it uses add_tasks_with_rust()
. There's no
way to request a longer timeout for xpcshell tests (?), so I added a skip-if
for verify mode. It's fine to skip verify mode for this test. Once we remove the
JS backend, we can probably remove the skip-if
. If it still times out, we
could split it up.
Comment 44•4 months ago
|
||
(In reply to Drew Willcoxon :adw from comment #43)
There's no way to request a longer timeout for xpcshell tests (?), so I added a
skip-if
I think you can do this https://searchfox.org/mozilla-central/rev/a0ebb2a2c286c1d98d7ae93d043f65ed9970108b/dom/localstorage/test/unit/xpcshell.toml#85
Comment hidden (Intermittent Failures Robot) |
Assignee | ||
Comment 46•4 months ago
•
|
||
(In reply to Marco Bonardo [:mak] from comment #44)
I think you can do this https://searchfox.org/mozilla-central/rev/a0ebb2a2c286c1d98d7ae93d043f65ed9970108b/dom/localstorage/test/unit/xpcshell.toml#85
Thank you, that's great to know!
Here's what that link points to, for posterity and making bug searching easier. requesttimeoutfactor
is an xpcshell.toml option:
["test_snapshotting.js"]
skip-if = ["tsan"] # Unreasonably slow, bug 1612707
requesttimeoutfactor = 4
Comment 47•4 months ago
|
||
Pushed by dwillcoxon@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/45447fcb0116 Fix failures in urlbar weather tests. r=daisuke
Comment hidden (Intermittent Failures Robot) |
Comment 49•4 months ago
|
||
bugherder |
Updated•4 months ago
|
Updated•4 months ago
|
Updated•4 months ago
|
Comment hidden (Intermittent Failures Robot) |
Description
•