Closed Bug 1691892 Opened 3 years ago Closed 3 years ago

Intermittent 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, P3)

Product:
Core
Component:
DOM: Core & HTML
Type:
defect

Tracking

()

Status:
RESOLVED FIXED
Milestone:
88 Branch
Project Flags:
Fission Milestone M7
Tracking Flags:
Tracking Status
firefox87 --- wontfix
firefox88 --- fixed

People

(Reporter: hsivonen, Assigned: hsivonen)

References

(Blocks 1 open bug)

Details

(Keywords: intermittent-failure, Whiteboard: [stockwell unknown])

Attachments

(1 file)

Bug 1691892 - Reject stale active browsing context setting attempts by action id in content processes.
48 bytes, text/x-phabricator-request
Details | Review 
[task 2021-02-10T03:52:56.430Z] 03:52:56     INFO - GECKO(2571) | [Parent 2571: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 18 (0x7f2e3bc4bac0) [pid = 2571] [serial = 18] [outer = (nil)] [url = about:blank]
[task 2021-02-10T03:52:57.069Z] 03:52:57     INFO - GECKO(2571) | [Child 2628: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 0 (0x7f320d9bc800) [pid = 2628] [serial = 11] [outer = (nil)] [url = about:blank]
[task 2021-02-10T03:52:59.098Z] 03:52:59     INFO - GECKO(2571) | [Child 3147: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f5e6a110800 == 1 [pid = 3147] [id = 1] [url = about:blank]
[task 2021-02-10T03:52:59.126Z] 03:52:59     INFO - GECKO(2571) | [Child 3147: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 5 (0x7f5e6a161200) [pid = 3147] [serial = 4] [outer = (nil)] [url = about:blank]
[task 2021-02-10T03:53:00.407Z] 03:53:00     INFO - GECKO(2571) | [Parent 2571: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 17 (0x7f2e32ee6c00) [pid = 2571] [serial = 17] [outer = (nil)] [url = about:blank]
[task 2021-02-10T03:53:00.407Z] 03:53:00     INFO - GECKO(2571) | [Parent 2571: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 16 (0x7f2e32d2d800) [pid = 2571] [serial = 19] [outer = (nil)] [url = about:blank]
[task 2021-02-10T03:53:00.408Z] 03:53:00     INFO - GECKO(2571) | [Parent 2571: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 15 (0x7f2e401f2c00) [pid = 2571] [serial = 12] [outer = (nil)] [url = about:blank]
[task 2021-02-10T03:53:00.408Z] 03:53:00     INFO - GECKO(2571) | [Parent 2571: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 14 (0x7f2e401f5000) [pid = 2571] [serial = 13] [outer = (nil)] [url = about:blank]
[task 2021-02-10T03:53:03.197Z] 03:53:03     INFO - GECKO(2571) | [Child 3147: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 4 (0x7f5e6a109800) [pid = 3147] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2021-02-10T03:53:03.199Z] 03:53:03     INFO - GECKO(2571) | [Child 3147: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 3 (0x7f5e6a111c00) [pid = 3147] [serial = 5] [outer = (nil)] [url = about:blank]
[task 2021-02-10T03:53:03.200Z] 03:53:03     INFO - GECKO(2571) | [Child 3147: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (0x7f5e6a1e4800) [pid = 3147] [serial = 6] [outer = (nil)] [url = about:blank]
[task 2021-02-10T03:53:04.875Z] 03:53:04     INFO - GECKO(2571) | [Child 3164: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (0x7f3a6c409c00) [pid = 3164] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2021-02-10T03:54:17.274Z] 03:54:17     INFO - TEST-INFO | started process screentopng
[task 2021-02-10T03:54:17.597Z] 03:54:17     INFO - TEST-INFO | screentopng: exit 0
[task 2021-02-10T03:54:17.598Z] 03:54:17     INFO - Buffered messages logged at 03:52:47
[task 2021-02-10T03:54:17.599Z] 03:54:17     INFO - Entering test bound setup
[task 2021-02-10T03:54:17.600Z] 03:54:17     INFO - Leaving test bound setup
[task 2021-02-10T03:54:17.601Z] 03:54:17     INFO - Entering test bound test_parentWindowFocus
[task 2021-02-10T03:54:17.601Z] 03:54:17     INFO - Calling window.open()
[task 2021-02-10T03:54:17.602Z] 03:54:17     INFO - Buffered messages logged at 03:52:48
[task 2021-02-10T03:54:17.603Z] 03:54:17     INFO - re-focusing main window
[task 2021-02-10T03:54:17.603Z] 03:54:17     INFO - must wait for focus
[task 2021-02-10T03:54:17.604Z] 03:54:17     INFO - Entering full-screen
[task 2021-02-10T03:54:17.605Z] 03:54:17     INFO - Buffered messages logged at 03:52:49
[task 2021-02-10T03:54:17.605Z] 03:54:17     INFO - Calling window.focus()
[task 2021-02-10T03:54:17.606Z] 03:54:17     INFO - Console message: [JavaScript Warning: "Exited fullscreen because a window was focused." {file: "http://example.com/browser/browser/base/content/test/fullscreen/open_and_focus_helper.html" line: 0}]
[task 2021-02-10T03:54:17.606Z] 03:54:17     INFO - Buffered messages logged at 03:52:50
[task 2021-02-10T03:54:17.607Z] 03:54:17     INFO - TEST-PASS | browser/base/content/test/fullscreen/browser_fullscreen_window_focus.js | Should leave full-screen - 
[task 2021-02-10T03:54:17.608Z] 03:54:17     INFO - Leaving test bound test_parentWindowFocus
[task 2021-02-10T03:54:17.608Z] 03:54:17     INFO - Entering test bound test_iframeWindowFocus
[task 2021-02-10T03:54:17.609Z] 03:54:17     INFO - Calling window.open()
[task 2021-02-10T03:54:17.610Z] 03:54:17     INFO - Buffered messages logged at 03:52:52
[task 2021-02-10T03:54:17.610Z] 03:54:17     INFO - re-focusing main window
[task 2021-02-10T03:54:17.611Z] 03:54:17     INFO - must wait for focus
[task 2021-02-10T03:54:17.611Z] 03:54:17     INFO - Entering full-screen
[task 2021-02-10T03:54:17.612Z] 03:54:17     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 2021-02-10T03:54:17.613Z] 03:54:17     INFO - Console message: [JavaScript Error: "TypeError: Fullscreen request denied"]
[task 2021-02-10T03:54:17.613Z] 03:54:17     INFO - Buffered messages finished
[task 2021-02-10T03:54:17.614Z] 03:54:17     INFO - TEST-UNEXPECTED-FAIL | browser/base/content/test/fullscreen/browser_fullscreen_window_focus.js | Test timed out - 
[task 2021-02-10T03:54:17.614Z] 03:54:17     INFO - GECKO(2571) | MEMORY STAT | vsize 3165MB | residentFast 346MB | heapAllocated 99MB
[task 2021-02-10T03:54:17.615Z] 03:54:17     INFO - TEST-OK | browser/base/content/test/fullscreen/browser_fullscreen_window_focus.js | took 90015ms
[task 2021-02-10T03:54:17.615Z] 03:54:17     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-02-10T03:54:17.616Z] 03:54:17     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 2021-02-10T03:54:17.616Z] 03:54:17     INFO - GECKO(2571) | [Child 2628: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7f320d9bbc00 == 1 [pid = 2628] [id = 4]
[task 2021-02-10T03:54:17.617Z] 03:54:17     INFO - GECKO(2571) | [Child 2628: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 1 (0x7f322a062ac0) [pid = 2628] [serial = 12] [outer = (nil)]
[task 2021-02-10T03:54:17.636Z] 03:54:17     INFO - GECKO(2571) | [Child 2628: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 2 (0x7f320d9bd000) [pid = 2628] [serial = 13] [outer = 0x7f322a062ac0]
[task 2021-02-10T03:54:17.636Z] 03:54:17     INFO - checking window state
[task 2021-02-10T03:54:17.636Z] 03:54:17     INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-02-10T03:54:17.636Z] 03:54:17     INFO - TEST-UNEXPECTED-FAIL | browser/base/content/test/fullscreen/browser_fullscreen_window_focus.js | Found a browser window after previous test timed out -

Tentatively tracking for Fission M7 Beta. If this test's intermittent failure rate is very low, then it might not need to block Fission.

Fission Milestone: --- → M7
status-firefox87: --- → affected
Priority: -- → P3

Making the focused browsing context changes ordered by action id does not fix this:
https://treeherder.mozilla.org/jobs?repo=try&revision=2da09cc906171884369624c0e02b4de566594fe9&selectedTaskRun=DyjyYTM8QSGcCEfiJOJscw.0

Now I don't have immediate ideas what would.

I thought I had an rr trace of this, but it was just a timeout happening right after the test had already pretty much passed.

The log in comment 0 shows the message from here:
https://searchfox.org/mozilla-central/rev/f47a4b67643b3048ef9a2e2ac0c34edf6d1ebff3/dom/base/Document.cpp#14241

This suggest that this is still about tab activeness despite the earlier fix to add actionIds to setting the active BrowsingContext.

Assignee: nobody → hsivonen
Status: NEW → ASSIGNED

With rebase, the test is now in bc12

Pushed by hsivonen@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/2217b5d0ed86
Reject stale active browsing context setting attempts by action id in content processes. r=nika

https://hg.mozilla.org/mozilla-central/rev/2217b5d0ed86

Status: ASSIGNED → RESOLVED
Closed: 3 years ago
status-firefox88: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → 88 Branch
See Also: → 1698036
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: