1691389 - High Frequency browser/components/urlbar/tests/browser/<testName>.js | leaked 1 window(s) until shutdown [url = about:blank] | leaked 1 window(s) until shutdown [url = chrome://browser/content/browser.xhtml]

Status: RESOLVED FIXED

(Firefox :: Address Bar, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: btara [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=329221837&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/WtnJ9hSOQu-C8Fxg0qs1Ew/runs/0/artifacts/public/logs/live_backing.log

---

...
[task 2021-02-08T12:51:49.569Z] 12:51:49     INFO - TEST-OK | browser/components/urlbar/tests/browser/browser_whereToOpen.js | took 5394ms
[task 2021-02-08T12:51:49.589Z] 12:51:49     INFO - GECKO(3260) | [Child 3414: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 5 (0x7f2bb4b94200) [pid = 3414] [serial = 487] [outer = (nil)] [url = about:blank]
[task 2021-02-08T12:51:49.590Z] 12:51:49     INFO - GECKO(3260) | [Child 3414: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 4 (0x7f2bb4b94040) [pid = 3414] [serial = 484] [outer = (nil)] [url = about:blank]
[task 2021-02-08T12:51:49.590Z] 12:51:49     INFO - GECKO(3260) | [Child 3414: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7f2bb4b16400 == 1 [pid = 3414] [id = 193]
[task 2021-02-08T12:51:49.591Z] 12:51:49     INFO - GECKO(3260) | [Child 3414: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 5 (0x7f2bb6458040) [pid = 3414] [serial = 490] [outer = (nil)]
[task 2021-02-08T12:51:49.593Z] 12:51:49     INFO - GECKO(3260) | [Child 3414: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 6 (0x7f2bb4b17000) [pid = 3414] [serial = 491] [outer = 0x7f2bb6458040]
[task 2021-02-08T12:51:49.649Z] 12:51:49     INFO - GECKO(3260) | [Child 9096: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7ff1ea703400 == 0 [pid = 9096] [id = 0] [url = http://example.com/non-empty]
[task 2021-02-08T12:51:49.656Z] 12:51:49     INFO - checking window state
[task 2021-02-08T12:51:49.713Z] 12:51:49     INFO - GECKO(3260) | [Child 9096: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (0x7ff206e62e40) [pid = 9096] [serial = 1] [outer = (nil)] [url = http://example.com/non-empty]
[task 2021-02-08T12:51:49.714Z] 12:51:49     INFO - GECKO(3260) | [Child 9096: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 1 (0x7ff1ea709800) [pid = 9096] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2021-02-08T12:51:49.715Z] 12:51:49     INFO - GECKO(3260) | [Child 9096: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 0 (0x7ff1ea711000) [pid = 9096] [serial = 3] [outer = (nil)] [url = http://example.com/non-empty]
[task 2021-02-08T12:51:49.757Z] 12:51:49     INFO - GECKO(3260) | [Child 9096, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3365
[task 2021-02-08T12:51:49.772Z] 12:51:49     INFO - GECKO(3260) | [Parent 3260: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 20 (0x7fedfc7ae000) [pid = 3260] [serial = 451] [outer = 0x7fee10ee2900]
[task 2021-02-08T12:51:49.803Z] 12:51:49     INFO - GECKO(3260) | [Child 9096, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4381
[task 2021-02-08T12:51:49.826Z] 12:51:49     INFO - GECKO(3260) | [Child 3314: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f9078903000 == 2 [pid = 3314] [id = 164] [url = about:blank]
[task 2021-02-08T12:51:49.827Z] 12:51:49     INFO - GECKO(3260) | [Child 3314: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f907890b800 == 1 [pid = 3314] [id = 166] [url = about:blank]
[task 2021-02-08T12:51:49.828Z] 12:51:49     INFO - GECKO(3260) | [Child 3314: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f907890a800 == 0 [pid = 3314] [id = 165] [url = about:blank]
[task 2021-02-08T12:51:49.842Z] 12:51:49     INFO - GECKO(3260) | [Parent 3260, Main Thread] WARNING: NS_ENSURE_TRUE(presShell) failed: file /builds/worker/checkouts/gecko/dom/base/nsGlobalWindowOuter.cpp:4256
[task 2021-02-08T12:51:49.887Z] 12:51:49     INFO - GECKO(3260) | [Parent 3260, Main Thread] WARNING: This lives in the child process: file /builds/worker/checkouts/gecko/docshell/shistory/SessionHistoryEntry.cpp:551
...
[task 2021-02-08T12:51:51.704Z] 12:51:51     INFO - GECKO(3260) | [Parent 3260: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 19 (0x7fedfd69c000) [pid = 3260] [serial = 450] [outer = (nil)] [url = about:mozilla]
[task 2021-02-08T12:51:51.705Z] 12:51:51     INFO - GECKO(3260) | [Parent 3260: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 18 (0x7fedfccc2000) [pid = 3260] [serial = 449] [outer = (nil)] [url = about:blank]
[task 2021-02-08T12:51:52.623Z] 12:51:52     INFO - GECKO(3260) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-02-08T12:51:52.840Z] 12:51:52     INFO - GECKO(3260) | [Child 9122, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3365
[task 2021-02-08T12:51:52.921Z] 12:51:52     INFO - GECKO(3260) | [Child 9122, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4381
[task 2021-02-08T12:51:53.847Z] 12:51:53     INFO - GECKO(3260) | [Child 3388: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f5f1bc1e400 == 0 [pid = 3388] [id = 37] [url = about:newtab]
[task 2021-02-08T12:51:53.849Z] 12:51:53     INFO - GECKO(3260) | [Child 3388: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 1 (0x7f5f1d132040) [pid = 3388] [serial = 110] [outer = (nil)] [url = about:newtab]
[task 2021-02-08T12:51:53.850Z] 12:51:53     INFO - GECKO(3260) | [Child 3388: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 0 (0x7f5f1c426c00) [pid = 3388] [serial = 113] [outer = (nil)] [url = about:newtab]
[task 2021-02-08T12:51:54.266Z] 12:51:54     INFO - GECKO(3260) | Completed ShutdownLeaks collections in process 7376
[task 2021-02-08T12:51:54.383Z] 12:51:54     INFO - GECKO(3260) | Completed ShutdownLeaks collections in process 3418
[task 2021-02-08T12:51:54.419Z] 12:51:54     INFO - GECKO(3260) | Completed ShutdownLeaks collections in process 7213
[task 2021-02-08T12:51:54.475Z] 12:51:54     INFO - GECKO(3260) | Completed ShutdownLeaks collections in process 7396
[task 2021-02-08T12:51:54.476Z] 12:51:54     INFO - GECKO(3260) | Completed ShutdownLeaks collections in process 7421
[task 2021-02-08T12:51:54.476Z] 12:51:54     INFO - GECKO(3260) | Completed ShutdownLeaks collections in process 7448
[task 2021-02-08T12:51:54.558Z] 12:51:54     INFO - GECKO(3260) | Completed ShutdownLeaks collections in process 3314
[task 2021-02-08T12:51:54.626Z] 12:51:54     INFO - GECKO(3260) | Completed ShutdownLeaks collections in process 3414
[task 2021-02-08T12:51:55.065Z] 12:51:55     INFO - GECKO(3260) | Completed ShutdownLeaks collections in process 3333
[task 2021-02-08T12:51:55.112Z] 12:51:55     INFO - GECKO(3260) | Completed ShutdownLeaks collections in process 3388
[task 2021-02-08T12:51:55.395Z] 12:51:55     INFO - GECKO(3260) | [Parent 3260: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7fedfca76c00 == 5 [pid = 3260] [id = 195] [url = about:mozilla]
[task 2021-02-08T12:51:55.396Z] 12:51:55     INFO - GECKO(3260) | [Parent 3260: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 17 (0x7fedfe35a800) [pid = 3260] [serial = 422] [outer = (nil)] [url = about:preferences#search]
[task 2021-02-08T12:51:55.397Z] 12:51:55     INFO - GECKO(3260) | [Parent 3260: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 16 (0x7fedfe9db000) [pid = 3260] [serial = 338] [outer = (nil)] [url = about:preferences#search]
[task 2021-02-08T12:51:55.398Z] 12:51:55     INFO - GECKO(3260) | [Parent 3260: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 15 (0x7fedfcae8000) [pid = 3260] [serial = 427] [outer = (nil)] [url = about:preferences#search]
[task 2021-02-08T12:51:56.274Z] 12:51:56     INFO - GECKO(3260) | [Parent 3260: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 14 (0x7fedd6d3f040) [pid = 3260] [serial = 444] [outer = (nil)] [url = chrome://browser/content/browser.xhtml]
[task 2021-02-08T12:51:56.275Z] 12:51:56     INFO - GECKO(3260) | [Parent 3260: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 13 (0x7fedfccc6000) [pid = 3260] [serial = 445] [outer = (nil)] [url = about:blank]
[task 2021-02-08T12:51:56.275Z] 12:51:56     INFO - GECKO(3260) | [Parent 3260: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 12 (0x7fee0cf85800) [pid = 3260] [serial = 6] [outer = (nil)] [url = about:blank]
[task 2021-02-08T12:51:57.081Z] 12:51:57     INFO - GECKO(3260) | [Parent 3260: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 13 (0x7fedd6d2cc00) [pid = 3260] [serial = 452] [outer = 0x7fee10ee2900]
[task 2021-02-08T12:51:57.259Z] 12:51:57     INFO - GECKO(3260) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmp9I5ipG.mozrunner/runtests_leaks_tab_pid9159.log
[task 2021-02-08T12:51:57.260Z] 12:51:57     INFO - GECKO(3260) | [9159, Main Thread] WARNING: XPCOM_MEM_BLOAT_LOG is set, disabling native allocations.: file /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:251
[task 2021-02-08T12:51:57.281Z] 12:51:57     INFO - GECKO(3260) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmp9I5ipG.mozrunner/runtests_leaks_tab_pid9157.log
[task 2021-02-08T12:51:57.282Z] 12:51:57     INFO - GECKO(3260) | [9157, Main Thread] WARNING: XPCOM_MEM_BLOAT_LOG is set, disabling native allocations.: file /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:251
[task 2021-02-08T12:51:57.370Z] 12:51:57     INFO - GECKO(3260) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmp9I5ipG.mozrunner/runtests_leaks_tab_pid9165.log
[task 2021-02-08T12:51:57.370Z] 12:51:57     INFO - GECKO(3260) | [9165, Main Thread] WARNING: XPCOM_MEM_BLOAT_LOG is set, disabling native allocations.: file /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:251
[task 2021-02-08T12:51:57.394Z] 12:51:57     INFO - GECKO(3260) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmp9I5ipG.mozrunner/runtests_leaks_tab_pid9169.log
[task 2021-02-08T12:51:57.394Z] 12:51:57     INFO - GECKO(3260) | [9169, Main Thread] WARNING: XPCOM_MEM_BLOAT_LOG is set, disabling native allocations.: file /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:251
[task 2021-02-08T12:51:57.455Z] 12:51:57     INFO - GECKO(3260) | [Child 9159, Main Thread] WARNING: could not set real-time limit in CubebUtils::InitLibrary: file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:619
[task 2021-02-08T12:51:57.531Z] 12:51:57     INFO - GECKO(3260) | [Child 9157, Main Thread] WARNING: could not set real-time limit in CubebUtils::InitLibrary: file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:619
[task 2021-02-08T12:51:57.538Z] 12:51:57     INFO - GECKO(3260) | [Child 9165, Main Thread] WARNING: could not set real-time limit in CubebUtils::InitLibrary: file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:619
[task 2021-02-08T12:51:57.634Z] 12:51:57     INFO - GECKO(3260) | [Child 9169, Main Thread] WARNING: could not set real-time limit in CubebUtils::InitLibrary: file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:619
[task 2021-02-08T12:51:57.876Z] 12:51:57     INFO - GECKO(3260) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-02-08T12:51:57.897Z] 12:51:57     INFO - GECKO(3260) | [Child 9169, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3365
[task 2021-02-08T12:51:57.904Z] 12:51:57     INFO - GECKO(3260) | [Child 9169, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4381
[task 2021-02-08T12:52:00.299Z] 12:52:00     INFO - GECKO(3260) | [Parent 3260: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 12 (0x7fedfc7ae000) [pid = 3260] [serial = 451] [outer = (nil)] [url = about:blank]
[task 2021-02-08T12:52:01.104Z] 12:52:01     INFO - GECKO(3260) | Completed ShutdownLeaks collections in process 3260
[task 2021-02-08T12:52:01.105Z] 12:52:01     INFO - TEST-START | Shutdown
[task 2021-02-08T12:52:01.105Z] 12:52:01     INFO - Browser Chrome Test Summary
[task 2021-02-08T12:52:01.105Z] 12:52:01     INFO - Passed:  12080
[task 2021-02-08T12:52:01.105Z] 12:52:01     INFO - Failed:  0
[task 2021-02-08T12:52:01.105Z] 12:52:01     INFO - Todo:    1
[task 2021-02-08T12:52:01.105Z] 12:52:01     INFO - Mode:    e10s
[task 2021-02-08T12:52:01.105Z] 12:52:01     INFO - *** End BrowserChrome Test Results ***
[task 2021-02-08T12:52:01.187Z] 12:52:01     INFO - GECKO(3260) | [Child 3333, Main Thread] WARNING: '!CanSend() || !mManager || !mManager->CanSend()', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:40
...
[task 2021-02-08T12:52:04.751Z] 12:52:04     INFO - GECKO(3260) | [Parent 3260: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 1 (0x7fedd6d2cc00) [pid = 3260] [serial = 452] [outer = (nil)] [url = about:blank]
[task 2021-02-08T12:52:04.758Z] 12:52:04     INFO - GECKO(3260) | [Parent 3260: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 0 (0x7fee09d88400) [pid = 3260] [serial = 9] [outer = (nil)] [url = resource://gre-resources/hiddenWindow.html]
[task 2021-02-08T12:52:04.812Z] 12:52:04     INFO - GECKO(3260) | [Parent 3260, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3365
[task 2021-02-08T12:52:04.943Z] 12:52:04     INFO - GECKO(3260) | [Parent 3260, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4381
[task 2021-02-08T12:52:04.968Z] 12:52:04     INFO - TEST-INFO | Main app process: exit 0
[task 2021-02-08T12:52:04.968Z] 12:52:04     INFO - TEST-INFO | Confirming we saw 959 DOCSHELL created and 959 destroyed log strings.
[task 2021-02-08T12:52:04.968Z] 12:52:04     INFO - TEST-INFO | Confirming we saw 2612 DOMWINDOW created and 2612 destroyed log strings.
[task 2021-02-08T12:52:04.968Z] 12:52:04    ERROR - TEST-UNEXPECTED-FAIL | browser/components/urlbar/tests/browser/browser_speculative_connect.js | leaked 1 window(s) until shutdown [url = about:blank]
[task 2021-02-08T12:52:04.969Z] 12:52:04    ERROR - TEST-UNEXPECTED-FAIL | browser/components/urlbar/tests/browser/browser_speculative_connect.js | leaked 1 window(s) until shutdown [url = chrome://browser/content/browser.xhtml]
[task 2021-02-08T12:52:04.970Z] 12:52:04     INFO - TEST-INFO | browser/components/urlbar/tests/browser/browser_speculative_connect.js | windows(s) leaked: [pid = 3260] [serial = 358], [pid = 3260] [serial = 357]
[task 2021-02-08T12:52:04.970Z] 12:52:04     INFO - TEST-INFO | browser/components/urlbar/tests/browser/browser_speculative_connect.js | This test created 1 hidden window(s)
[task 2021-02-08T12:52:04.971Z] 12:52:04     INFO - TEST-INFO | browser/components/urlbar/tests/browser/browser_speculative_connect.js | This test created 1 hidden docshell(s)
[task 2021-02-08T12:52:04.971Z] 12:52:04     INFO - TEST-INFO | browser/components/urlbar/tests/browser/browser_UrlbarInput_hiddenFocus.js | This test created 1 hidden window(s)
...```

Comment 1

[Bogdan Tara[:bogdan_tara | bogdant]]

Marco, could you, please, take a look?

This intermittent seems to start with your changes.

https://treeherder.mozilla.org/jobs?repo=autoland&group_state=expanded&fromchange=ed0ab9078607e373de6cc25ff31c28fc1c0e0120&tochange=6e5caabf4c1fc44de3afcb2ffa565127d40ebb28&searchStr=linux%2C18.04%2Cx64%2Cdebug%2Cmochitests%2Cwith%2Cfission%2Cenabled%2Ctest-linux1804-64%2Fdebug-mochitest-browser-chrome-fis-e10s%2Cbc10&selectedTaskRun=WtnJ9hSOQu-C8Fxg0qs1Ew.0

Comment 2

[Marco Bonardo [:mak]]

I'm relanding the patch with a modification, basically the pref the test was modifying has a global listener in browser.js, and it looks like that was being executed in a closed window, causing this leak.
Let's call this fixed by backout for now.

Comment 3

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

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

Comment 4

[Intermittent Failures Robot]

13 failures in 4322 pushes (0.003 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 13

Platform and build breakdown:

• linux1804-64: 13
  • debug: 13

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