Closed Bug 1612228 Opened 4 years ago Closed 4 years ago

Intermittent browser/components/urlbar/tests/browser/browser_search_tips.js | Test timed out -

Categories

(Firefox :: Address Bar, defect, P5)

Product:
Firefox
Component:
Address Bar
Type:
defect
Points:
1

Tracking

()

Status:
RESOLVED FIXED
Milestone:
Firefox 74
Iteration:
74.2 - Jan 20 - Feb 09
Tracking Flags:
Tracking Status
firefox74 --- fixed

People

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

References

(Regression)

Details

(Keywords: intermittent-failure, regression, Whiteboard: [retriggered])

Attachments

(1 file)

Bug 1612228 - Reset UrlbarProviderSearchTips after each run of browser_search_tips.js. r?adw
47 bytes, text/x-phabricator-request
Details | Review

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

[task 2020-01-29T21:55:44.965Z] 21:55:44 INFO - TEST-PASS | browser/components/urlbar/tests/browser/browser_search_tips.js | Default engine should be Google. - "Google" == "Google" -
[task 2020-01-29T21:55:44.966Z] 21:55:44 INFO - Leaving test bound init
[task 2020-01-29T21:55:44.967Z] 21:55:44 INFO - Entering test bound newtab
[task 2020-01-29T21:55:44.968Z] 21:55:44 INFO - Buffered messages finished
[task 2020-01-29T21:55:44.970Z] 21:55:44 INFO - TEST-UNEXPECTED-FAIL | browser/components/urlbar/tests/browser/browser_search_tips.js | Test timed out -
[task 2020-01-29T21:55:44.972Z] 21:55:44 INFO - TEST-PASS | browser/components/urlbar/tests/browser/browser_search_tips.js | {"_name":"Google","_shortName":"google-b-1-d","_loadPath":"[other]addEngineWithDetails:google@search.mozilla.org","description":"Google Search","__searchForm":"https://www.google.com/search?client=firefox-b-1-d&q={searchTerms}","_iconURL":"moz-extension://aaeec68b-6e2b-4b41-9cb0-518c51e8d478/favicon.ico","_iconMapObj":{"{}":"moz-extension://aaeec68b-6e2b-4b41-9cb0-518c51e8d478/favicon.ico"},"_metaData":{"alias":null},"_urls":[{"params":[{"condition":"pref","mozparam":true,"name":"channel","pref":"google_channel_us"},{"name":"client","value":"firefox-b-1-d"},{"name":"q","value":"{searchTerms}"}],"rels":[],"resultDomain":"www.google.com","template":"https://www.google.com/search"},{"params":[],"rels":[],"resultDomain":"www.google.com","template":"https://www.google.com/complete/search?client=firefox&q={searchTerms}","type":"application/x-suggestions+json"}],"_isBuiltin":true,"queryCharset":"UTF-8","extensionID":"google@search.mozilla.org","extensionLocale":"b-1-d"} == true -
[task 2020-01-29T21:55:44.973Z] 21:55:44 INFO - GECKO(1240) | MEMORY STAT | vsize 3109MB | residentFast 379MB | heapAllocated 119MB
[task 2020-01-29T21:55:44.975Z] 21:55:44 INFO - TEST-OK | browser/components/urlbar/tests/browser/browser_search_tips.js | took 90062ms
[task 2020-01-29T21:55:44.975Z] 21:55:44 INFO - Not taking screenshot here: see the one that was previously logged
[task 2020-01-29T21:55:44.978Z] 21:55:44 INFO - TEST-UNEXPECTED-FAIL | browser/components/urlbar/tests/browser/browser_search_tips.js | Found a tab after previous test timed out: about:newtab -
[task 2020-01-29T21:55:44.979Z] 21:55:44 INFO - GECKO(1240) | [Child 1447: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7f9ad3f14800 == 1 [pid = 1447] [id = {5eab49b5-712a-429f-ad50-ecf2eff52203}]
[task 2020-01-29T21:55:44.979Z] 21:55:44 INFO - GECKO(1240) | [Child 1447: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 1 (0x7f9ad5d2b5c0) [pid = 1447] [serial = 15] [outer = (nil)]
[task 2020-01-29T21:55:44.980Z] 21:55:44 INFO - GECKO(1240) | [Child 1447, Main Thread] WARNING: NS_ENSURE_TRUE(mPresShell) failed: file /builds/worker/workspace/build/src/layout/base/nsPresContext.cpp, line 845
[task 2020-01-29T21:55:44.980Z] 21:55:44 INFO - GECKO(1240) | [Child 1447: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 2 (0x7f9ad3e61000) [pid = 1447] [serial = 16] [outer = 0x7f9ad5d2b5c0]
[task 2020-01-29T21:55:44.981Z] 21:55:44 INFO - GECKO(1240) | [Child 1447: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 3 (0x7f9ad3e66800) [pid = 1447] [serial = 17] [outer = 0x7f9ad5d2b5c0]
[task 2020-01-29T21:55:44.982Z] 21:55:44 INFO - checking window state
[task 2020-01-29T21:55:45.045Z] 21:55:45 INFO - GECKO(1240) | [Parent 1240, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005: file /builds/worker/workspace/build/src/dom/base/nsFrameLoader.cpp, line 665
[task 2020-01-29T21:55:45.046Z] 21:55:45 INFO - GECKO(1240) | [Parent 1240: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 11 (0x7f176d6d2800) [pid = 1240] [serial = 13] [outer = 0x7f17799c75c0]
[task 2020-01-29T21:55:45.082Z] 21:55:45 INFO - GECKO(1240) | [Parent 1240: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 12 (0x7f176d6de800) [pid = 1240] [serial = 14] [outer = 0x7f17799c75c0]
[task 2020-01-29T21:55:45.510Z] 21:55:45 INFO - GECKO(1240) | [Child 1326: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7efc45ccc000 == 0 [pid = 1326] [id = {793393f7-fe72-40ee-a53f-6f9a26a0d961}] [url = about:blank]
[task 2020-01-29T21:55:45.567Z] 21:55:45 INFO - GECKO(1240) | [Child 1447: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (0x7f9ad3e61000) [pid = 1447] [serial = 16] [outer = (nil)] [url = about:blank]
[task 2020-01-29T21:55:45.844Z] 21:55:45 INFO - GECKO(1240) | [Child 1390: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7fa2465c9000 == 0 [pid = 1390] [id = {1377083e-376a-4538-a657-f0ff94fbf29b}] [url = about:newtab]
[task 2020-01-29T21:55:45.845Z] 21:55:45 INFO - GECKO(1240) | [Child 1390: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 1 (0x7fa247929b60) [pid = 1390] [serial = 3] [outer = (nil)] [url = about:newtab]
[task 2020-01-29T21:55:45.846Z] 21:55:45 INFO - GECKO(1240) | [Child 1390: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 0 (0x7fa245a12800) [pid = 1390] [serial = 5] [outer = (nil)] [url = about:newtab]
[task 2020-01-29T21:55:45.945Z] 21:55:45 INFO - GECKO(1240) | [Child 1423: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 1 (0x7f0c491b9400) [pid = 1423] [serial = 117] [outer = (nil)] [url = about:newtab]
[task 2020-01-29T21:55:45.946Z] 21:55:45 INFO - GECKO(1240) | [Child 1423: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 0 (0x7f0c4a305a60) [pid = 1423] [serial = 115] [outer = (nil)] [url = about:newtab]
[task 2020-01-29T21:55:45.946Z] 21:55:45 INFO - GECKO(1240) | [Child 1423: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f0c49274800 == 0 [pid = 1423] [id = {806937cf-15db-4ce6-b1d4-84994374c3ee}] [url = about:newtab]
[task 2020-01-29T21:55:48.043Z] 21:55:48 INFO - GECKO(1240) | [Child 1326: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 1 (0x7efc45702b60) [pid = 1326] [serial = 17] [outer = (nil)] [url = about:blank]
[task 2020-01-29T21:55:48.044Z] 21:55:48 INFO - GECKO(1240) | [Child 1326: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 0 (0x7efc45cebc00) [pid = 1326] [serial = 19] [outer = (nil)] [url = about:blank]
[task 2020-01-29T21:55:48.871Z] 21:55:48 INFO - GECKO(1240) | Completed ShutdownLeaks collections in process 1516
[task 2020-01-29T21:55:48.980Z] 21:55:48 INFO - GECKO(1240) | Completed ShutdownLeaks collections in process 1569
[task 2020-01-29T21:55:49.145Z] 21:55:49 INFO - GECKO(1240) | Completed ShutdownLeaks collections in process 1483
[task 2020-01-29T21:55:49.161Z] 21:55:49 INFO - GECKO(1240) | Completed ShutdownLeaks collections in process 1545
[task 2020-01-29T21:55:49.238Z] 21:55:49 INFO - GECKO(1240) | Completed ShutdownLeaks collections in process 1447
[task 2020-01-29T21:55:49.294Z] 21:55:49 INFO - GECKO(1240) | Completed ShutdownLeaks collections in process 1390
[task 2020-01-29T21:55:49.309Z] 21:55:49 INFO - GECKO(1240) | Completed ShutdownLeaks collections in process 1423
[task 2020-01-29T21:55:49.377Z] 21:55:49 INFO - GECKO(1240) | Completed ShutdownLeaks collections in process 1326
[task 2020-01-29T21:55:49.680Z] 21:55:49 INFO - GECKO(1240) | Completed ShutdownLeaks collections in process 1302
[task 2020-01-29T21:55:50.052Z] 21:55:50 INFO - GECKO(1240) | [Parent 1240: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 11 (0x7f177f1e1000) [pid = 1240] [serial = 7] [outer = (nil)] [url = about:blank]
[task 2020-01-29T21:55:53.145Z] 21:55:53 INFO - GECKO(1240) | [Parent 1240: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 10 (0x7f176d6d2800) [pid = 1240] [serial = 13] [outer = (nil)] [url = about:blank]
[task 2020-01-29T21:55:53.724Z] 21:55:53 INFO - GECKO(1240) | Completed ShutdownLeaks collections in process 1240

Flags: needinfo?(htwyford)
Regressed by: 1610024
Summary: Intermittent browser/components/urlbar/tests/browser/browser_search_tips.js | Test timed out - → Intermittent TV browser/components/urlbar/tests/browser/browser_search_tips.js | Test timed out -
Whiteboard: [retriggered]
Has Regression Range: --- → yes
Keywords: regression

This test does a lot. We should probably split it up.

Although looking at the log, it looks like the test just sits there for 90 seconds right after it starts...?

When the test runs the second time, UrlbarProviderSearchTips.showedTipInCurrentEngagement is true, the tip isn't shown, and the test hangs on the very first subtest. This can be fixed by simply adding a call to resetProvider to the cleanup function.

We could also split it up, but a good portion of the test is helper functions, which would probably have to be added to their own head.js file with the tests in a new folder, like what you did with interventions_update. We could do this, but it might be overkill for a test that is (now) running fine. What do you think?

Assignee: nobody → htwyford
Status: NEW → ASSIGNED
Iteration: --- → 74.2 - Jan 20 - Feb 09
Points: --- → 1
Flags: needinfo?(htwyford) → needinfo?(adw)

Thanks for looking into this. I agree there's no need to split it up if the problem isn't just that the test takes too long.

Flags: needinfo?(adw)
Pushed by htwyford@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/03d54624d4f2
Reset UrlbarProviderSearchTips after each run of browser_search_tips.js. r=adw
Summary: Intermittent TV browser/components/urlbar/tests/browser/browser_search_tips.js | Test timed out - → Intermittent browser/components/urlbar/tests/browser/browser_search_tips.js | Test timed out -

This second backout is a result of my patch coming into conflict with bug 1611873, which landed at the same time. I've rebased my patch on top of it and fixed an issue in bug 1611873's addition to browser_search_tips.js that was causing the failure. Try run: https://treeherder.mozilla.org/#/jobs?repo=try&revision=9fd727b904567b88b941771670eaf1a03e500ce3

Flags: needinfo?(htwyford)
Pushed by htwyford@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/9ea66e2c59b2
Reset UrlbarProviderSearchTips after each run of browser_search_tips.js. r=adw

https://hg.mozilla.org/mozilla-central/rev/9ea66e2c59b2

Status: ASSIGNED → RESOLVED
Closed: 4 years ago
status-firefox74: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → Firefox 74
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: