Permafail browser/base/content/test/fullscreen/browser_fullscreen_window_focus.js | Test timed out - | Found a tab after previous test timed out: http://example.com/browser/browser/base/content/test/fullscreen/open_and_focus_helper.html
Categories
(Core :: DOM: Core & HTML, defect)
Tracking
()
People
(Reporter: intermittent-bug-filer, Assigned: hsivonen)
References
(Blocks 1 open bug)
Details
(Keywords: intermittent-failure, Whiteboard: [stockwell unknown])
Attachments
(3 files, 1 obsolete file)
Filed by: btara [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=322126689&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/AnncU67LRM2c3U5ahS-oRw/runs/0/artifacts/public/logs/live_backing.log
[task 2020-11-18T01:12:40.821Z] 01:12:40 INFO - TEST-START | browser/base/content/test/fullscreen/browser_fullscreen_window_focus.js
[task 2020-11-18T01:12:40.845Z] 01:12:40 INFO - GECKO(2246) | [Child 2812, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4287
[task 2020-11-18T01:12:40.904Z] 01:12:40 INFO - GECKO(2246) | [Child 2879: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7febe7f45400 == 1 [pid = 2879] [id = 0]
[task 2020-11-18T01:12:40.905Z] 01:12:40 INFO - GECKO(2246) | [Child 2879: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 1 (0x7fec044b0040) [pid = 2879] [serial = 1] [outer = (nil)]
[task 2020-11-18T01:12:40.906Z] 01:12:40 INFO - GECKO(2246) | [Child 2879: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 2 (0x7febe7f46800) [pid = 2879] [serial = 2] [outer = 0x7fec044b0040]
[task 2020-11-18T01:12:41.084Z] 01:12:41 INFO - GECKO(2246) | [Child 2879, Main Thread] WARNING: NS_ENSURE_TRUE(info) failed: file /builds/worker/checkouts/gecko/extensions/permissions/PermissionDelegateHandler.cpp:348
[task 2020-11-18T01:12:41.105Z] 01:12:41 INFO - GECKO(2246) | [Child 2879: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 3 (0x7febee34f800) [pid = 2879] [serial = 3] [outer = 0x7fec044b0040]
[task 2020-11-18T01:12:41.362Z] 01:12:41 INFO - GECKO(2246) | [Child 2879: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7febe7f99c00 == 2 [pid = 2879] [id = 1]
[task 2020-11-18T01:12:41.362Z] 01:12:41 INFO - GECKO(2246) | [Child 2879: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 4 (0x7fec04464ac0) [pid = 2879] [serial = 4] [outer = (nil)]
[task 2020-11-18T01:12:41.362Z] 01:12:41 INFO - GECKO(2246) | [Child 2879: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 5 (0x7febe7f9ac00) [pid = 2879] [serial = 5] [outer = 0x7fec04464ac0]
[task 2020-11-18T01:12:41.365Z] 01:12:41 INFO - GECKO(2246) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpNDkNYA.mozrunner/runtests_leaks_tab_pid2973.log
[task 2020-11-18T01:12:41.366Z] 01:12:41 INFO - GECKO(2246) | [2973, Main Thread] WARNING: XPCOM_MEM_BLOAT_LOG is set, disabling native allocations.: file /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:251
[task 2020-11-18T01:12:41.446Z] 01:12:41 INFO - GECKO(2246) | [Parent 2246: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7f2115a4ec00 == 8 [pid = 2246] [id = 7]
[task 2020-11-18T01:12:41.446Z] 01:12:41 INFO - GECKO(2246) | [Parent 2246: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 15 (0x7f210e864e40) [pid = 2246] [serial = 16] [outer = (nil)]
[task 2020-11-18T01:12:41.448Z] 01:12:41 INFO - GECKO(2246) | [Parent 2246: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 16 (0x7f2115a4f800) [pid = 2246] [serial = 17] [outer = 0x7f210e864e40]
[task 2020-11-18T01:12:41.471Z] 01:12:41 INFO - GECKO(2246) | [Child 2973, Main Thread] WARNING: could not set real-time limit in CubebUtils::InitLibrary: file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:629
[task 2020-11-18T01:12:41.479Z] 01:12:41 INFO - GECKO(2246) | [Parent 2246, Main Thread] WARNING: NS_ENSURE_TRUE(rootFrame) failed: file /builds/worker/checkouts/gecko/dom/base/nsGlobalWindowOuter.cpp:4289
[task 2020-11-18T01:12:41.782Z] 01:12:41 INFO - GECKO(2246) | [Parent 2246: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7f211cc88c00 == 9 [pid = 2246] [id = 8]
[task 2020-11-18T01:12:41.782Z] 01:12:41 INFO - GECKO(2246) | [Parent 2246: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 17 (0x7f2112a8c580) [pid = 2246] [serial = 18] [outer = (nil)]
[task 2020-11-18T01:12:41.979Z] 01:12:41 INFO - GECKO(2246) | [Parent 2246, Main Thread] WARNING: NS_ENSURE_TRUE(presShell) failed: file /builds/worker/checkouts/gecko/dom/base/nsGlobalWindowOuter.cpp:4287
[task 2020-11-18T01:12:41.994Z] 01:12:41 INFO - GECKO(2246) | [Parent 2246: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 18 (0x7f20fc203800) [pid = 2246] [serial = 19] [outer = 0x7f2112a8c580]
[task 2020-11-18T01:12:42.082Z] 01:12:42 INFO - GECKO(2246) | [Child 2879: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 6 (0x7febe7f9dc00) [pid = 2879] [serial = 6] [outer = 0x7fec04464ac0]
[task 2020-11-18T01:12:42.205Z] 01:12:42 INFO - GECKO(2246) | [Child 2487: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f272989e400 == 1 [pid = 2487] [id = 1] [url = about:blank]
[task 2020-11-18T01:12:42.490Z] 01:12:42 INFO - GECKO(2246) | [Child 2906: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7f9af5145c00 == 1 [pid = 2906] [id = 0]
[task 2020-11-18T01:12:42.492Z] 01:12:42 INFO - GECKO(2246) | [Child 2906: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 1 (0x7f9af51e9040) [pid = 2906] [serial = 1] [outer = (nil)]
[task 2020-11-18T01:12:42.493Z] 01:12:42 INFO - GECKO(2246) | [Child 2906: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 2 (0x7f9af5146c00) [pid = 2906] [serial = 2] [outer = 0x7f9af51e9040]
[task 2020-11-18T01:12:42.519Z] 01:12:42 INFO - GECKO(2246) | [Child 2487: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 5 (0x7f27298ba3c0) [pid = 2487] [serial = 3] [outer = (nil)] [url = about:blank]
[task 2020-11-18T01:12:42.524Z] 01:12:42 INFO - GECKO(2246) | [Child 2487: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 4 (0x7f27298ba200) [pid = 2487] [serial = 1] [outer = (nil)] [url = about:blank]
[task 2020-11-18T01:12:42.684Z] 01:12:42 INFO - GECKO(2246) | [Child 2906, Main Thread] WARNING: NS_ENSURE_TRUE(info) failed: file /builds/worker/checkouts/gecko/extensions/permissions/PermissionDelegateHandler.cpp:348
[task 2020-11-18T01:12:42.721Z] 01:12:42 INFO - GECKO(2246) | [Child 2906: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 3 (0x7f9af5467000) [pid = 2906] [serial = 3] [outer = 0x7f9af51e9040]
[task 2020-11-18T01:12:42.722Z] 01:12:42 INFO - GECKO(2246) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpNDkNYA.mozrunner/runtests_leaks_tab_pid2998.log
[task 2020-11-18T01:12:42.722Z] 01:12:42 INFO - GECKO(2246) | [2998, Main Thread] WARNING: XPCOM_MEM_BLOAT_LOG is set, disabling native allocations.: file /builds/worker/checkouts/gecko/tools/profiler/core/platform.cpp:251
[task 2020-11-18T01:12:42.806Z] 01:12:42 INFO - GECKO(2246) | JavaScript error: , line 0: TypeError: Fullscreen request denied
[task 2020-11-18T01:12:42.962Z] 01:12:42 INFO - GECKO(2246) | [Child 2998, Main Thread] WARNING: could not set real-time limit in CubebUtils::InitLibrary: file /builds/worker/checkouts/gecko/dom/media/CubebUtils.cpp:629
[task 2020-11-18T01:12:46.292Z] 01:12:46 INFO - GECKO(2246) | [Child 2487: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 3 (0x7f2729848800) [pid = 2487] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2020-11-18T01:12:46.293Z] 01:12:46 INFO - GECKO(2246) | [Child 2487: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (0x7f272989f800) [pid = 2487] [serial = 4] [outer = (nil)] [url = about:blank]
[task 2020-11-18T01:12:47.534Z] 01:12:47 INFO - GECKO(2246) | [Parent 2246: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f20fea9b000 == 8 [pid = 2246] [id = 4] [url = about:blank]
[task 2020-11-18T01:12:47.534Z] 01:12:47 INFO - GECKO(2246) | [Parent 2246: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f20fea9cc00 == 7 [pid = 2246] [id = 5] [url = about:blank]
[task 2020-11-18T01:12:48.062Z] 01:12:48 INFO - GECKO(2246) | [Parent 2246: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 17 (0x7f20feab6740) [pid = 2246] [serial = 10] [outer = (nil)] [url = about:blank]
[task 2020-11-18T01:12:48.063Z] 01:12:48 INFO - GECKO(2246) | [Parent 2246: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 16 (0x7f20feab6ac0) [pid = 2246] [serial = 11] [outer = (nil)] [url = about:blank]
[task 2020-11-18T01:12:48.801Z] 01:12:48 INFO - GECKO(2246) | [Child 2385: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f4216749c00 == 0 [pid = 2385] [id = 3] [url = about:blank]
[task 2020-11-18T01:12:49.137Z] 01:12:49 INFO - GECKO(2246) | [Child 2879: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7febe7f99c00 == 1 [pid = 2879] [id = 1] [url = about:blank]
[task 2020-11-18T01:12:51.864Z] 01:12:51 INFO - GECKO(2246) | [Parent 2246: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 15 (0x7f20feaa0000) [pid = 2246] [serial = 12] [outer = (nil)] [url = about:blank]
[task 2020-11-18T01:12:51.864Z] 01:12:51 INFO - GECKO(2246) | [Parent 2246: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 14 (0x7f20feaa0400) [pid = 2246] [serial = 13] [outer = (nil)] [url = about:blank]
[task 2020-11-18T01:12:52.872Z] 01:12:52 INFO - GECKO(2246) | [Child 2385: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 1 (0x7f42167c2040) [pid = 2385] [serial = 10] [outer = (nil)] [url = about:blank]
[task 2020-11-18T01:12:53.235Z] 01:12:53 INFO - GECKO(2246) | [Child 2879: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 5 (0x7febe7f46800) [pid = 2879] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2020-11-18T01:12:53.235Z] 01:12:53 INFO - GECKO(2246) | [Child 2879: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 4 (0x7febe7f9ac00) [pid = 2879] [serial = 5] [outer = (nil)] [url = about:blank]
[task 2020-11-18T01:12:53.255Z] 01:12:53 INFO - GECKO(2246) | [Child 2879: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 3 (0x7fec04464ac0) [pid = 2879] [serial = 4] [outer = (nil)] [url = about:blank]
[task 2020-11-18T01:12:54.796Z] 01:12:54 INFO - GECKO(2246) | [Child 2385: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 0 (0x7f4216794000) [pid = 2385] [serial = 11] [outer = (nil)] [url = about:blank]
[task 2020-11-18T01:12:54.864Z] 01:12:54 INFO - GECKO(2246) | [Child 2906: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (0x7f9af5146c00) [pid = 2906] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2020-11-18T01:12:56.145Z] 01:12:56 INFO - GECKO(2246) | [Parent 2246, Main Thread] WARNING: Not implemented in the parent process!: file /builds/worker/checkouts/gecko/docshell/shistory/SessionHistoryEntry.cpp:506
[task 2020-11-18T01:12:57.309Z] 01:12:57 INFO - GECKO(2246) | [Child 2879: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (0x7febe7f9dc00) [pid = 2879] [serial = 6] [outer = (nil)] [url = about:blank]
[task 2020-11-18T01:12:57.993Z] 01:12:57 INFO - GECKO(2246) | [Parent 2246, Main Thread] WARNING: Not implemented in the parent process!: file /builds/worker/checkouts/gecko/docshell/shistory/SessionHistoryEntry.cpp:506
[task 2020-11-18T01:14:10.837Z] 01:14:10 INFO - TEST-INFO | started process screentopng
[task 2020-11-18T01:14:11.062Z] 01:14:11 INFO - TEST-INFO | screentopng: exit 0
[task 2020-11-18T01:14:11.062Z] 01:14:11 INFO - Buffered messages logged at 01:12:40
[task 2020-11-18T01:14:11.062Z] 01:14:11 INFO - Entering test bound setup
[task 2020-11-18T01:14:11.063Z] 01:14:11 INFO - Leaving test bound setup
[task 2020-11-18T01:14:11.063Z] 01:14:11 INFO - Entering test bound test_parentWindowFocus
[task 2020-11-18T01:14:11.063Z] 01:14:11 INFO - Buffered messages logged at 01:12:41
[task 2020-11-18T01:14:11.063Z] 01:14:11 INFO - Calling window.open()
[task 2020-11-18T01:14:11.063Z] 01:14:11 INFO - Buffered messages logged at 01:12:42
[task 2020-11-18T01:14:11.063Z] 01:14:11 INFO - re-focusing main window
[task 2020-11-18T01:14:11.063Z] 01:14:11 INFO - must wait for focus
[task 2020-11-18T01:14:11.063Z] 01:14:11 INFO - Entering full-screen
[task 2020-11-18T01:14:11.063Z] 01:14:11 INFO - Console message: [JavaScript Warning: "Request for fullscreen was denied because requesting element is not in the currently focused tab." {file: "http://example.com/browser/browser/base/content/test/fullscreen/open_and_focus_helper.html" line: 0}]
[task 2020-11-18T01:14:11.063Z] 01:14:11 INFO - Console message: [JavaScript Error: "TypeError: Fullscreen request denied"]
[task 2020-11-18T01:14:11.064Z] 01:14:11 INFO - Buffered messages finished
[task 2020-11-18T01:14:11.066Z] 01:14:11 INFO - TEST-UNEXPECTED-FAIL | browser/base/content/test/fullscreen/browser_fullscreen_window_focus.js | Test timed out -
[task 2020-11-18T01:14:11.069Z] 01:14:11 INFO - GECKO(2246) | MEMORY STAT | vsize 3310MB | residentFast 349MB | heapAllocated 99MB
[task 2020-11-18T01:14:11.085Z] 01:14:11 INFO - TEST-OK | browser/base/content/test/fullscreen/browser_fullscreen_window_focus.js | took 90026ms
[task 2020-11-18T01:14:11.086Z] 01:14:11 INFO - Not taking screenshot here: see the one that was previously logged
[task 2020-11-18T01:14:11.087Z] 01:14:11 INFO - TEST-UNEXPECTED-FAIL | browser/base/content/test/fullscreen/browser_fullscreen_window_focus.js | Found a tab after previous test timed out: http://example.com/browser/browser/base/content/test/fullscreen/open_and_focus_helper.html -
[task 2020-11-18T01:14:11.088Z] 01:14:11 INFO - GECKO(2246) | [Child 2385: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7f4216746800 == 1 [pid = 2385] [id = 4]
[task 2020-11-18T01:14:11.089Z] 01:14:11 INFO - GECKO(2246) | [Child 2385: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 1 (0x7f42167c2040) [pid = 2385] [serial = 12] [outer = (nil)]
[task 2020-11-18T01:14:11.090Z] 01:14:11 INFO - GECKO(2246) | [Child 2385: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 2 (0x7f4216793c00) [pid = 2385] [serial = 13] [outer = 0x7f42167c2040]
[task 2020-11-18T01:14:11.092Z] 01:14:11 INFO - checking window state
[task 2020-11-18T01:14:11.093Z] 01:14:11 INFO - Not taking screenshot here: see the one that was previously logged
[task 2020-11-18T01:14:11.094Z] 01:14:11 INFO - TEST-UNEXPECTED-FAIL | browser/base/content/test/fullscreen/browser_fullscreen_window_focus.js | Found a browser window after previous test timed out -
Assignee | ||
Comment 2•4 years ago
|
||
Sigh. Let's see if at least the frequency gets lower, since at least it went from easily reproducible to not reproducing locally.
One thing to try would be to apply the mechanism that bug 1618386 applied to the active browsing context to focused browsing context as well. So far testing hasn't implicated focused browsing context, but reasoning suggests that it should get the same treatment.
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Assignee | ||
Comment 5•3 years ago
|
||
Assignee | ||
Comment 6•3 years ago
|
||
At least the failure rate is now very low. The attached patch implements the idea from comment 2. I have no idea if it fixes the problem. Let's see if breaks anything:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=f068766797ae0e4d3cdbd498aa0f0da9e2554fdc
Assignee | ||
Comment 7•3 years ago
|
||
The failure of dom/base/test/browser_bug1303838.js looks like it might be caused by the patch.
Assignee | ||
Comment 8•3 years ago
|
||
(In reply to Henri Sivonen (:hsivonen) from comment #7)
The failure of dom/base/test/browser_bug1303838.js looks like it might be caused by the patch.
Can't repro locally, but a respin on try repros.
Also, browser/extensions/formautofill/test/browser/browser_remoteiframe.js looks like it could be caused by this patch.
Assignee | ||
Comment 9•3 years ago
|
||
(In reply to Henri Sivonen (:hsivonen) from comment #8)
(In reply to Henri Sivonen (:hsivonen) from comment #7)
The failure of dom/base/test/browser_bug1303838.js looks like it might be caused by the patch.
Can't repro locally, but a respin on try repros.
Also, browser/extensions/formautofill/test/browser/browser_remoteiframe.js looks like it could be caused by this patch.
Sadly, the subject matter of the tests suggests that the breakage is related to what this patch is trying to do.
Relative to the situation without the patch, this patch makes racing content processes to take their place in the ordering at an earlier point than without the patch. The expected upside of the patch is that the ordering taken by active browsing context should be the same as the ordering taken by focused browsing context, which I hope to fix stuff.
Still unclear to me how exactly the breakage with the patch happens.
Assignee | ||
Comment 10•3 years ago
|
||
(In reply to Henri Sivonen (:hsivonen) from comment #7)
The failure of dom/base/test/browser_bug1303838.js looks like it might be caused by the patch.
Let's see if Pernosco can repro this in the cloud.
Updated•3 years ago
|
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 18•3 years ago
|
||
The current spike seems to have been caused by bug 1659383.
Comment 19•3 years ago
|
||
Failures started after bug 1659383 had landed.
Updated•3 years ago
|
Updated•3 years ago
|
Comment hidden (Intermittent Failures Robot) |
Updated•3 years ago
|
Comment hidden (Intermittent Failures Robot) |
Comment 22•3 years ago
|
||
Pushed by malexandru@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/ec74c1b52c53 disable browser_fullscreen_window_focus.js on Linux Fission as suggested by hsivonen. r=jmaher
Updated•3 years ago
|
Comment 23•3 years ago
|
||
bugherder |
Comment 24•3 years ago
|
||
Only runs on central, so got missed when autoland got checked.
Comment 25•3 years ago
|
||
Bug 1677899 - disable browser_fullscreen_window_focus.js on Linux Fission as suggested by hsivonen. r=jmaher
Henri, this test is now disabled on macOS and Fission Linux. Do you think we need to debug and re-enable this test before we ship Fission MVP?
Comment hidden (Intermittent Failures Robot) |
Assignee | ||
Comment 27•3 years ago
|
||
(In reply to Chris Peterson [:cpeterson] from comment #25)
Bug 1677899 - disable browser_fullscreen_window_focus.js on Linux Fission as suggested by hsivonen. r=jmaher
Henri, this test is now disabled on macOS and Fission Linux. Do you think we need to debug and re-enable this test before we ship Fission MVP?
Neha already targeted this to M7. I'm starting the trace collection now.
Assignee | ||
Comment 28•3 years ago
|
||
(In reply to Sebastian Hengst [:aryx] (needinfo on intermittent or backout) from comment #19)
Created attachment 9197872 [details]
Bug 1677899 - disable browser_fullscreen_window_focus.js on Linux Fission as suggested by hsivonen. r=jmaherFailures started after bug 1659383 had landed.
Notably, the permission check added in that bug does not block anything when this test case runs.
Also, it looks like the two windows that leak are an inner window and an outer window that were created together even though the log shows different URLs for them.
Comment 29•3 years ago
|
||
Pushed by archaeopteryx@coole-files.de: https://hg.mozilla.org/integration/autoland/rev/1bf076c3f271 disable browser_fullscreen_window_focus.js also on Windows Fission. r=jmaher DONTBUILD
Comment 30•3 years ago
|
||
bugherder |
Comment hidden (Intermittent Failures Robot) |
Assignee | ||
Comment 32•3 years ago
|
||
This is what I get out of the CC log:
known edges:
0x7fc537e1d910 [Promise] --[mGlobal]--> 0x7fc533743000
0x7fc5339e3100 [AnimationTimeline] --[mWindow]--> 0x7fc533743000
0x7fc51b8d3c40 [Promise] --[mGlobal]--> 0x7fc533743000
0x7fc533755c70 [Promise] --[mGlobal]--> 0x7fc533743000
0x7fc51c483c60 [CustomElementRegistry] --[mWindow]--> 0x7fc533743000
0x8945927c880 [JS Object (Window)] --[UnwrapDOMObject(obj)]--> 0x7fc533743000
0x7fc528c6ee80 [Promise] --[mGlobal]--> 0x7fc533743000
0x7fc53396f460 [DOMParser] --[mOwner]--> 0x7fc533743000
0x7fc533480180 [PerformanceEntry] --[mParent]--> 0x7fc533743000
0x7fc533743000 [nsGlobalWindowInner # 44 inner ] --[mTopInnerWindow]--> 0x7fc533743000
0x7fc51b8d3280 [Promise] --[mGlobal]--> 0x7fc533743000
0x7fc528ca2850 [Promise] --[mGlobal]--> 0x7fc533743000
0x7fc51b871280 [Location] --[mInnerWindow]--> 0x7fc533743000
0x7fc53375b3d0 [Localization] --[mGlobal]--> 0x7fc533743000
0x7fc50f7b63c0 [PerformanceEntry] --[mParent]--> 0x7fc533743000
0x7fc528c6e8b0 [Promise] --[mGlobal]--> 0x7fc533743000
0x7fc51b8a9b80 [Promise] --[mGlobal]--> 0x7fc533743000
Comment 33•3 years ago
•
|
||
is that concise or verbose log?
It is a tiny bit surprising to see all those promises. Why do we have them all alive?
Hmm, perhaps the log was concise and the relevant JS side is alive because they just are in the same page, which hasn't been GCed.
Or does FocusManager just keep stuff alive too long? It does explicitly clean up stuff during xpcom-shutdown.
Assignee | ||
Comment 34•3 years ago
|
||
(In reply to Olli Pettay [:smaug] from comment #33)
is that concise or verbose log?
Whatever MOZ_CC_LOG_SHUTDOWN=1 MOZ_CC_ALL_TRACES=shutdown
does.
It is a tiny bit surprising to see all those promises. Why do we have them all alive?
I'll try to see what I can find in Pernosco.
Or does FocusManager just keep stuff alive too long? It does explicitly clean up stuff during xpcom-shutdown.
These fields are all nullptr
by the time of xpcom-shutdown
, so it's not nsFocusManager
keeping them alive until then.
Assignee | ||
Comment 35•3 years ago
|
||
(In reply to Henri Sivonen (:hsivonen) from comment #32)
This is what I get out of the CC log:
known edges: 0x7fc537e1d910 [Promise] --[mGlobal]--> 0x7fc533743000
From DocumentL10n::Init()
0x7fc51b8d3c40 [Promise] --[mGlobal]--> 0x7fc533743000
From Document::GetDocumentReadyForIdle
(from Document::EndLoad
of a DOMParser
-created doc.)
0x7fc533755c70 [Promise] --[mGlobal]--> 0x7fc533743000
Likewise.
0x7fc528c6ee80 [Promise] --[mGlobal]--> 0x7fc533743000
Likewise.
0x7fc51b8d3280 [Promise] --[mGlobal]--> 0x7fc533743000
Likewise.
0x7fc528ca2850 [Promise] --[mGlobal]--> 0x7fc533743000
Likewise.
0x7fc528c6e8b0 [Promise] --[mGlobal]--> 0x7fc533743000
Likewise.
0x7fc51b8a9b80 [Promise] --[mGlobal]--> 0x7fc533743000
Likewise.
Clearly, the next step is to figure out what's going on with that localization promise (which stays alive until shutdown), but I'm surprised that parsing something with DOMParser
can spawn promises.
Assignee | ||
Comment 36•3 years ago
|
||
Random remark:
The Promise
created here: https://searchfox.org/mozilla-central/rev/0dfbe5a699cc6c73cf8c14d1aa10ba10ef3ec8fa/dom/l10n/DocumentL10n.cpp#151
...gets dropped here: https://searchfox.org/mozilla-central/rev/0dfbe5a699cc6c73cf8c14d1aa10ba10ef3ec8fa/dom/l10n/DocumentL10n.cpp#227
...but doesn't appear to destruct immediately but destructs later from cycle collection.
Assignee | ||
Comment 37•3 years ago
|
||
(In reply to Henri Sivonen (:hsivonen) from comment #35)
(In reply to Henri Sivonen (:hsivonen) from comment #32)
This is what I get out of the CC log:
known edges: 0x7fc537e1d910 [Promise] --[mGlobal]--> 0x7fc533743000
From
DocumentL10n::Init()
This promise does get resolved by the l10n code.
Assignee | ||
Comment 38•3 years ago
|
||
(In reply to Henri Sivonen (:hsivonen) from comment #37)
(In reply to Henri Sivonen (:hsivonen) from comment #35)
(In reply to Henri Sivonen (:hsivonen) from comment #32)
This is what I get out of the CC log:
known edges: 0x7fc537e1d910 [Promise] --[mGlobal]--> 0x7fc533743000
From
DocumentL10n::Init()
This promise does get resolved by the l10n code.
But DocumentL10n::mReady
holds onto the Promise
for the life time of DocumentL10n
.
mReady
is used here:
https://searchfox.org/mozilla-central/rev/0dfbe5a699cc6c73cf8c14d1aa10ba10ef3ec8fa/xpfe/appshell/AppWindow.cpp#3145
It gets used here: https://searchfox.org/mozilla-central/rev/0dfbe5a699cc6c73cf8c14d1aa10ba10ef3ec8fa/xpfe/appshell/AppWindow.cpp#3145
But that case is ifdef
ed out in the scenario that I'm debugging. (Still, what if that code runs later than the Promise
is resolved?)
Assignee | ||
Comment 39•3 years ago
|
||
(In reply to Henri Sivonen (:hsivonen) from comment #38)
But
DocumentL10n::mReady
holds onto thePromise
for the life time ofDocumentL10n
.
This is not the problem.
Assignee | ||
Comment 40•3 years ago
|
||
The most interesting finding so far is that a Document
holds a weak ref to its scope object, but via Document::mDocumentL10n
the ref is strong, which defeats the purpose of the weak ref, whatever the original design idea was relative to CC.
Assignee | ||
Comment 41•3 years ago
|
||
Zibi, is a window leak due to DocumentL10n
a known pattern with a known cure?
Comment 43•3 years ago
|
||
Each event listener on Document would keep a strong pointer to the scope object too, and I assume some other member variables too.
It seems like it is some missed edge which is the interesting piece here. Something which CC doesn't know about and thus it isn't in the log.
Assignee | ||
Comment 44•3 years ago
|
||
(In reply to Olli Pettay [:smaug] from comment #43)
It seems like it is some missed edge which is the interesting piece here. Something which CC doesn't know about and thus it isn't in the log.
Yeah. Unfortunately, the custom elements cause so much refcount spam that it's hard to notice what else is going on.
Assignee | ||
Comment 45•3 years ago
|
||
Without bug 1659383, the test relies on a hack that checks that the caller isn't JS (because the JS was in the other process) and the test passes that way.
Assignee | ||
Comment 46•3 years ago
|
||
Assignee | ||
Comment 47•3 years ago
|
||
Updated•3 years ago
|
Comment 48•3 years ago
|
||
Pushed by hsivonen@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/8f5274b317cc Trust the process where where focus() is called for focusability. r=nika
Assignee | ||
Comment 49•3 years ago
|
||
Note to sheriff: The patch fixes the permafail. If this test comes back yet again as a low-frequency intermittent, let's mint yet another bug number for that.
Comment 50•3 years ago
|
||
bugherder |
Comment 51•3 years ago
|
||
Still failing: https://treeherder.mozilla.org/logviewer?job_id=329454042&repo=autoland&lineNumber=4754
Assignee | ||
Comment 52•3 years ago
|
||
(In reply to Natalia Csoregi [:nataliaCs] from comment #51)
Still failing: https://treeherder.mozilla.org/logviewer?job_id=329454042&repo=autoland&lineNumber=4754
Per comment 22, filed as bug 1691892. Let's close this one as fixing the permafail.
Comment hidden (Intermittent Failures Robot) |
Updated•3 years ago
|
Description
•