1618386 - 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 -

Status: RESOLVED FIXED

(Core :: DOM: Core & HTML, defect, P2)

Description

[Treeherder Bug Filer]

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

---

[task 2020-02-26T22:44:13.244Z] 22:44:13     INFO - TEST-START | browser/base/content/test/fullscreen/browser_fullscreen_window_focus.js
[task 2020-02-26T22:44:13.300Z] 22:44:13     INFO - GECKO(1779) | [Child 2277: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (0x7fc71b093520) [pid = 2277] [serial = 1] [outer = (nil)] [url = https://example.com/]
[task 2020-02-26T22:44:13.301Z] 22:44:13     INFO - GECKO(1779) | [Child 2277: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 1 (0x7fc7009bd000) [pid = 2277] [serial = 3] [outer = (nil)] [url = https://example.com/]
[task 2020-02-26T22:44:13.302Z] 22:44:13     INFO - GECKO(1779) | [Child 2277: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 0 (0x7fc7000be800) [pid = 2277] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2020-02-26T22:44:13.323Z] 22:44:13     INFO - GECKO(1779) | [Child 2277, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/workspace/build/src/xpcom/base/nsCycleCollector.cpp, line 3362
[task 2020-02-26T22:44:13.380Z] 22:44:13     INFO - GECKO(1779) | nsStringStats
[task 2020-02-26T22:44:13.380Z] 22:44:13     INFO - GECKO(1779) |  => mAllocCount:           8797
[task 2020-02-26T22:44:13.380Z] 22:44:13     INFO - GECKO(1779) |  => mReallocCount:            0
[task 2020-02-26T22:44:13.381Z] 22:44:13     INFO - GECKO(1779) |  => mFreeCount:            8797
[task 2020-02-26T22:44:13.381Z] 22:44:13     INFO - GECKO(1779) |  => mShareCount:           7622
[task 2020-02-26T22:44:13.382Z] 22:44:13     INFO - GECKO(1779) |  => mAdoptCount:            532
[task 2020-02-26T22:44:13.382Z] 22:44:13     INFO - GECKO(1779) |  => mAdoptFreeCount:        536
[task 2020-02-26T22:44:13.383Z] 22:44:13     INFO - GECKO(1779) |  => Process ID: 2277, Thread ID: 140493153281920
[task 2020-02-26T22:44:13.398Z] 22:44:13     INFO - GECKO(1779) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpajDLRk.mozrunner/runtests_leaks_tab_pid2304.log
[task 2020-02-26T22:44:13.496Z] 22:44:13     INFO - GECKO(1779) | [Child 2304, Main Thread] WARNING: No CID found when attempting to map contract ID: file /builds/worker/workspace/build/src/xpcom/components/nsComponentManager.cpp, line 721
[task 2020-02-26T22:44:13.632Z] 22:44:13     INFO - GECKO(1779) | Couldn't convert chrome URL: chrome://branding/locale/brand.properties
[task 2020-02-26T22:44:13.794Z] 22:44:13     INFO - GECKO(1779) | [Child 2304, Main Thread] WARNING: could not set real-time limit at process startup: file /builds/worker/workspace/build/src/dom/ipc/ContentChild.cpp, line 1825
[task 2020-02-26T22:44:13.814Z] 22:44:13     INFO - GECKO(1779) | [Child 2304: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7f0badb1f800 == 1 [pid = 2304] [id = {d8a7eb4c-aecd-4071-886a-d4c7f05a2a4d}]
[task 2020-02-26T22:44:13.851Z] 22:44:13     INFO - GECKO(1779) | [Child 2304: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 1 (0x7f0bc8d93520) [pid = 2304] [serial = 1] [outer = (nil)]
[task 2020-02-26T22:44:13.851Z] 22:44:13     INFO - GECKO(1779) | [Child 2304, Main Thread] WARNING: NS_ENSURE_TRUE(mPresShell) failed: file /builds/worker/workspace/build/src/layout/base/nsPresContext.cpp, line 848
[task 2020-02-26T22:44:13.851Z] 22:44:13     INFO - GECKO(1779) | [Child 2304: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 2 (0x7f0badd9bc00) [pid = 2304] [serial = 2] [outer = 0x7f0bc8d93520]
[task 2020-02-26T22:44:13.968Z] 22:44:13     INFO - GECKO(1779) | [Child 2304, Main Thread] WARNING: Trying to request nsIHttpChannel from DocumentChannel, this is likely broken: file /builds/worker/workspace/build/src/netwerk/ipc/DocumentChannel.cpp, line 64
[task 2020-02-26T22:44:13.992Z] 22:44:13     INFO - GECKO(1779) | [Child 2304: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 3 (0x7f0bb3c61400) [pid = 2304] [serial = 3] [outer = 0x7f0bc8d93520]
[task 2020-02-26T22:44:14.255Z] 22:44:14     INFO - GECKO(1779) | [Child 2304: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7f0bae699000 == 2 [pid = 2304] [id = {bb1c1888-a12b-42da-92e6-59e3138fec2a}]
[task 2020-02-26T22:44:14.255Z] 22:44:14     INFO - GECKO(1779) | [Child 2304: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 4 (0x7f0bc8d936f0) [pid = 2304] [serial = 4] [outer = (nil)]
[task 2020-02-26T22:44:14.255Z] 22:44:14     INFO - GECKO(1779) | [Child 2304: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 5 (0x7f0bb3bb9800) [pid = 2304] [serial = 5] [outer = 0x7f0bc8d936f0]
[task 2020-02-26T22:44:14.316Z] 22:44:14     INFO - GECKO(1779) | [Parent 1779: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7f63b0acb800 == 6 [pid = 1779] [id = {a1002cba-3bdf-41a3-9a33-b95664534f4e}]
[task 2020-02-26T22:44:14.318Z] 22:44:14     INFO - GECKO(1779) | [Parent 1779: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 11 (0x7f63acedb430) [pid = 1779] [serial = 12] [outer = (nil)]
[task 2020-02-26T22:44:14.319Z] 22:44:14     INFO - GECKO(1779) | [Parent 1779: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 12 (0x7f63abe89400) [pid = 1779] [serial = 13] [outer = 0x7f63acedb430]
[task 2020-02-26T22:44:14.341Z] 22:44:14     INFO - GECKO(1779) | [Parent 1779, Main Thread] WARNING: Attempting to get a displayport from a content with no primary frame!: file /builds/worker/workspace/build/src/layout/base/nsLayoutUtils.cpp, line 791
[task 2020-02-26T22:44:14.499Z] 22:44:14     INFO - GECKO(1779) | [Child 2166: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f1e673eb800 == 0 [pid = 2166] [id = {ffc5964f-4f77-41cf-87dc-d8090873aeeb}] [url = about:blank]
[task 2020-02-26T22:44:14.635Z] 22:44:14     INFO - GECKO(1779) | [Parent 1779: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7f63b4a75000 == 7 [pid = 1779] [id = {934f80c2-7891-4c09-93e6-0650fd1c04d6}]
...
...
[task 2020-02-26T22:44:20.954Z] 22:44:20     INFO - GECKO(1779) | [Child 2419: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 3 (0x7f4130619c00) [pid = 2419] [serial = 3] [outer = 0x7f414b693520]
[task 2020-02-26T22:44:21.035Z] 22:44:21     INFO - GECKO(1779) | JavaScript error: , line 0: TypeError: Fullscreen request denied
[task 2020-02-26T22:44:21.373Z] 22:44:21     INFO - GECKO(1779) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpajDLRk.mozrunner/runtests_leaks_tab_pid2446.log
[task 2020-02-26T22:44:21.451Z] 22:44:21     INFO - GECKO(1779) | [Child 2446, Main Thread] WARNING: No CID found when attempting to map contract ID: file /builds/worker/workspace/build/src/xpcom/components/nsComponentManager.cpp, line 721
[task 2020-02-26T22:44:21.533Z] 22:44:21     INFO - GECKO(1779) | Couldn't convert chrome URL: chrome://branding/locale/brand.properties
[task 2020-02-26T22:44:21.634Z] 22:44:21     INFO - GECKO(1779) | [Child 2446, Main Thread] WARNING: could not set real-time limit at process startup: file /builds/worker/workspace/build/src/dom/ipc/ContentChild.cpp, line 1825
[task 2020-02-26T22:44:22.092Z] 22:44:22     INFO - GECKO(1779) | [Child 1991: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 0 (0x7f678dc5e400) [pid = 1991] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2020-02-26T22:44:22.630Z] 22:44:22     INFO - GECKO(1779) | [Child 2166: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 0 (0x7f1e6d139400) [pid = 2166] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2020-02-26T22:44:22.693Z] 22:44:22     INFO - GECKO(1779) | [Child 2364: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f85c31cd800 == 1 [pid = 2364] [id = {0db45169-25df-462b-bac2-d7de4e34e79e}] [url = ]
[task 2020-02-26T22:44:22.694Z] 22:44:22     INFO - GECKO(1779) | [Child 2364: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (0x7f85c28b6800) [pid = 2364] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2020-02-26T22:44:24.992Z] 22:44:24     INFO - GECKO(1779) | [Parent 1779: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f63b0acb800 == 7 [pid = 1779] [id = {a1002cba-3bdf-41a3-9a33-b95664534f4e}] [url = chrome://browser/content/browser.xhtml]
[task 2020-02-26T22:44:25.414Z] 22:44:25     INFO - GECKO(1779) | [Parent 1779: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 17 (0x7f63acedb600) [pid = 1779] [serial = 14] [outer = (nil)] [url = about:blank]
[task 2020-02-26T22:44:26.857Z] 22:44:26     INFO - GECKO(1779) | [Child 2391: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f4a598a4800 == 1 [pid = 2391] [id = {18c25b7a-e295-4f21-8183-0d4c3535f2fe}] [url = about:blank]
[task 2020-02-26T22:44:29.084Z] 22:44:29     INFO - GECKO(1779) | [Parent 1779: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 16 (0x7f63acedb430) [pid = 1779] [serial = 12] [outer = (nil)] [url = chrome://browser/content/browser.xhtml]
[task 2020-02-26T22:44:29.422Z] 22:44:29     INFO - GECKO(1779) | [Parent 1779: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 15 (0x7f63abe89400) [pid = 1779] [serial = 13] [outer = (nil)] [url = about:blank]
[task 2020-02-26T22:44:29.438Z] 22:44:29     INFO - GECKO(1779) | [Parent 1779: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 14 (0x7f63adb83800) [pid = 1779] [serial = 15] [outer = (nil)] [url = about:blank]
[task 2020-02-26T22:44:30.942Z] 22:44:30     INFO - GECKO(1779) | [Child 2391: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 5 (0x7f4a58fadc00) [pid = 2391] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2020-02-26T22:44:30.943Z] 22:44:30     INFO - GECKO(1779) | [Child 2391: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 4 (0x7f4a5ed5b800) [pid = 2391] [serial = 5] [outer = (nil)] [url = about:blank]
[task 2020-02-26T22:44:30.964Z] 22:44:30     INFO - GECKO(1779) | [Child 2391: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 3 (0x7f4a73f936f0) [pid = 2391] [serial = 4] [outer = (nil)] [url = about:blank]
[task 2020-02-26T22:44:33.114Z] 22:44:33     INFO - GECKO(1779) | [Child 2419: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (0x7f413653f400) [pid = 2419] [serial = 2] [outer = (nil)] [url = about:blank]
[task 2020-02-26T22:44:35.006Z] 22:44:35     INFO - GECKO(1779) | [Child 2391: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (0x7f4a5ed5fc00) [pid = 2391] [serial = 6] [outer = (nil)] [url = about:blank]
[task 2020-02-26T22:45:43.259Z] 22:45:43     INFO - TEST-INFO | started process screentopng
[task 2020-02-26T22:45:43.471Z] 22:45:43     INFO - TEST-INFO | screentopng: exit 0
[task 2020-02-26T22:45:43.472Z] 22:45:43     INFO - Buffered messages logged at 22:44:13
[task 2020-02-26T22:45:43.473Z] 22:45:43     INFO - Entering test bound setup
[task 2020-02-26T22:45:43.473Z] 22:45:43     INFO - Leaving test bound setup
[task 2020-02-26T22:45:43.474Z] 22:45:43     INFO - Entering test bound test_parentWindowFocus
[task 2020-02-26T22:45:43.475Z] 22:45:43     INFO - Buffered messages logged at 22:44:14
[task 2020-02-26T22:45:43.476Z] 22:45:43     INFO - Calling window.open()
[task 2020-02-26T22:45:43.476Z] 22:45:43     INFO - Buffered messages logged at 22:44:15
[task 2020-02-26T22:45:43.477Z] 22:45:43     INFO - re-focusing main window
[task 2020-02-26T22:45:43.478Z] 22:45:43     INFO - must wait for focus
[task 2020-02-26T22:45:43.484Z] 22:45:43     INFO - Entering full-screen
[task 2020-02-26T22:45:43.485Z] 22:45:43     INFO - Calling window.focus()
[task 2020-02-26T22:45:43.486Z] 22:45:43     INFO - Buffered messages logged at 22:44:16
[task 2020-02-26T22:45:43.487Z] 22:45:43     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 2020-02-26T22:45:43.488Z] 22:45:43     INFO - TEST-PASS | browser/base/content/test/fullscreen/browser_fullscreen_window_focus.js | Should leave full-screen - 
[task 2020-02-26T22:45:43.488Z] 22:45:43     INFO - Leaving test bound test_parentWindowFocus
[task 2020-02-26T22:45:43.489Z] 22:45:43     INFO - Entering test bound test_iframeWindowFocus
[task 2020-02-26T22:45:43.490Z] 22:45:43     INFO - Buffered messages logged at 22:44:17
[task 2020-02-26T22:45:43.491Z] 22:45:43     INFO - Calling window.open()
[task 2020-02-26T22:45:43.492Z] 22:45:43     INFO - Buffered messages logged at 22:44:20
[task 2020-02-26T22:45:43.493Z] 22:45:43     INFO - re-focusing main window
[task 2020-02-26T22:45:43.494Z] 22:45:43     INFO - must wait for focus
[task 2020-02-26T22:45:43.498Z] 22:45:43     INFO - Entering full-screen
[task 2020-02-26T22:45:43.500Z] 22:45:43     INFO - Buffered messages logged at 22:44:21
[task 2020-02-26T22:45:43.501Z] 22:45:43     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-02-26T22:45:43.502Z] 22:45:43     INFO - Console message: [JavaScript Error: "TypeError: Fullscreen request denied"]
[task 2020-02-26T22:45:43.503Z] 22:45:43     INFO - Buffered messages finished
[task 2020-02-26T22:45:43.504Z] 22:45:43     INFO - TEST-UNEXPECTED-FAIL | browser/base/content/test/fullscreen/browser_fullscreen_window_focus.js | Test timed out - 
[task 2020-02-26T22:45:43.505Z] 22:45:43     INFO - GECKO(1779) | MEMORY STAT | vsize 3329MB | residentFast 360MB | heapAllocated 108MB
[task 2020-02-26T22:45:43.506Z] 22:45:43     INFO - TEST-OK | browser/base/content/test/fullscreen/browser_fullscreen_window_focus.js | took 90036ms
[task 2020-02-26T22:45:43.507Z] 22:45:43     INFO - Not taking screenshot here: see the one that was previously logged
[task 2020-02-26T22:45:43.508Z] 22:45:43     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-02-26T22:45:43.509Z] 22:45:43     INFO - GECKO(1779) | [Child 2364, Main Thread] WARNING: NS_ENSURE_TRUE(aWindow) failed: file /builds/worker/workspace/build/src/dom/base/nsFocusManager.cpp, line 551
[task 2020-02-26T22:45:43.510Z] 22:45:43     INFO - GECKO(1779) | [Child 2446: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7fab3c61c800 == 1 [pid = 2446] [id = {8c2b68ac-b210-4167-904c-2f29e70740f3}]
[task 2020-02-26T22:45:43.512Z] 22:45:43     INFO - GECKO(1779) | [Child 2446: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 1 (0x7fab57893520) [pid = 2446] [serial = 1] [outer = (nil)]
[task 2020-02-26T22:45:43.513Z] 22:45:43     INFO - GECKO(1779) | [Child 2446, Main Thread] WARNING: NS_ENSURE_TRUE(mPresShell) failed: file /builds/worker/workspace/build/src/layout/base/nsPresContext.cpp, line 848
[task 2020-02-26T22:45:43.514Z] 22:45:43     INFO - GECKO(1779) | [Child 2446: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 2 (0x7fab3c8b1000) [pid = 2446] [serial = 2] [outer = 0x7fab57893520]
[task 2020-02-26T22:45:43.516Z] 22:45:43     INFO - checking window state
[task 2020-02-26T22:45:43.517Z] 22:45:43     INFO - Not taking screenshot here: see the one that was previously logged
[task 2020-02-26T22:45:43.518Z] 22:45:43     INFO - TEST-UNEXPECTED-FAIL | browser/base/content/test/fullscreen/browser_fullscreen_window_focus.js | Found a browser window after previous test timed out - 
[task 2020-02-26T22:45:43.584Z] 22:45:43     INFO - GECKO(1779) | [Parent 1779, Main Thread] WARNING: NS_ENSURE_TRUE(GetWrapper()) failed: file /builds/worker/workspace/build/src/dom/ipc/JSWindowActor.cpp, line 66
...
[task 2020-02-26T22:45:43.660Z] 22:45:43     INFO - TEST-START | browser/base/content/test/fullscreen/browser_fullscreen_window_open.js
[task 2020-02-26T22:45:43.717Z] 22:45:43     INFO - GECKO(1779) | [Parent 1779, Main Thread] WARNING: NS_ENSURE_TRUE(GetWrapper()) failed: file /builds/worker/workspace/build/src/dom/ipc/JSWindowActor.cpp, line 66
[task 2020-02-26T22:45:43.761Z] 22:45:43     INFO - GECKO(1779) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2020-02-26T22:45:43.779Z] 22:45:43     INFO - GECKO(1779) | [Child 2391: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f4a590ee800 == 0 [pid = 2391] [id = {0db45169-25df-462b-bac2-d7de4e34e79e}] [url = https://example.org/browser/browser/base/content/test/fullscreen/open_and_focus_helper.html]
[task 2020-02-26T22:45:43.915Z] 22:45:43     INFO - GECKO(1779) | [Child 2364: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f85c251f800 == 0 [pid = 2364] [id = {5f13689d-3158-4855-a140-7a6d921188ba}] [url = http://example.com/browser/browser/base/content/test/fullscreen/open_and_focus_helper.html]
[task 2020-02-26T22:45:43.936Z] 22:45:43     INFO - GECKO(1779) | [Child 2419: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f41307d1800 == 0 [pid = 2419] [id = {18c25b7a-e295-4f21-8183-0d4c3535f2fe}] [url = https://example.com/]
[task 2020-02-26T22:45:43.957Z] 22:45:43     INFO - GECKO(1779) | [Child 2391: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 1 (0x7f4a73f93520) [pid = 2391] [serial = 1] [outer = (nil)] [url = https://example.org/browser/browser/base/content/test/fullscreen/open_and_focus_helper.html]
[task 2020-02-26T22:45:43.960Z] 22:45:43     INFO - GECKO(1779) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpajDLRk.mozrunner/runtests_leaks_tab_pid2470.log
[task 2020-02-26T22:45:43.969Z] 22:45:43     INFO - GECKO(1779) | [Child 2391: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 0 (0x7f4a5eea2c00) [pid = 2391] [serial = 3] [outer = (nil)] [url = https://example.org/browser/browser/base/content/test/fullscreen/open_and_focus_helper.html]
[task 2020-02-26T22:45:44.030Z] 22:45:44     INFO - GECKO(1779) | [Child 2391, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/workspace/build/src/xpcom/base/nsCycleCollector.cpp, line 3362
[task 2020-02-26T22:45:44.030Z] 22:45:44     INFO - GECKO(1779) | [Child 2364: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 1 (0x7f85dd893520) [pid = 2364] [serial = 1] [outer = (nil)] [url = http://example.com/browser/browser/base/content/test/fullscreen/open_and_focus_helper.html]
[task 2020-02-26T22:45:44.030Z] 22:45:44     INFO - GECKO(1779) | [Child 2364: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 0 (0x7f85c2807c00) [pid = 2364] [serial = 3] [outer = (nil)] [url = http://example.com/browser/browser/base/content/test/fullscreen/open_and_focus_helper.html]
[task 2020-02-26T22:45:44.070Z] 22:45:44     INFO - GECKO(1779) | [Child 2364, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/workspace/build/src/xpcom/base/nsCycleCollector.cpp, line 3362
[task 2020-02-26T22:45:44.070Z] 22:45:44     INFO - GECKO(1779) | [Child 2419: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 1 (0x7f414b693520) [pid = 2419] [serial = 1] [outer = (nil)] [url = https://example.com/]
[task 2020-02-26T22:45:44.070Z] 22:45:44     INFO - GECKO(1779) | [Child 2419: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 0 (0x7f4130619c00) [pid = 2419] [serial = 3] [outer = (nil)] [url = https://example.com/]
[task 2020-02-26T22:45:44.127Z] 22:45:44     INFO - GECKO(1779) | nsStringStats
[task 2020-02-26T22:45:44.127Z] 22:45:44     INFO - GECKO(1779) |  => mAllocCount:           8139
[task 2020-02-26T22:45:44.127Z] 22:45:44     INFO - GECKO(1779) |  => mReallocCount:            0
[task 2020-02-26T22:45:44.127Z] 22:45:44     INFO - GECKO(1779) |  => mFreeCount:            8139
[task 2020-02-26T22:45:44.127Z] 22:45:44     INFO - GECKO(1779) |  => mShareCount:           6232
[task 2020-02-26T22:45:44.127Z] 22:45:44     INFO - GECKO(1779) | nsStringStats
[task 2020-02-26T22:45:44.127Z] 22:45:44     INFO - GECKO(1779) |  => mAllocCount:           8218
[task 2020-02-26T22:45:44.127Z] 22:45:44     INFO - GECKO(1779) |  => mReallocCount:            0
[task 2020-02-26T22:45:44.127Z] 22:45:44     INFO - GECKO(1779) |  => mFreeCount:            8218
[task 2020-02-26T22:45:44.127Z] 22:45:44     INFO - GECKO(1779) |  => mShareCount:           5848
[task 2020-02-26T22:45:44.128Z] 22:45:44     INFO - GECKO(1779) |  => mAdoptCount:            379
[task 2020-02-26T22:45:44.128Z] 22:45:44     INFO - GECKO(1779) |  => mAdoptFreeCount:        387
[task 2020-02-26T22:45:44.128Z] 22:45:44     INFO - GECKO(1779) |  => Process ID: 2391, Thread ID: 139957773850496
[task 2020-02-26T22:45:44.128Z] 22:45:44     INFO - GECKO(1779) |  => mAdoptCount:            486
[task 2020-02-26T22:45:44.128Z] 22:45:44     INFO - GECKO(1779) |  => mAdoptFreeCount:        494
[task 2020-02-26T22:45:44.129Z] 22:45:44     INFO - GECKO(1779) |  => Process ID: 2364, Thread ID: 140212947834752
[task 2020-02-26T22:45:44.144Z] 22:45:44     INFO - GECKO(1779) | [Child 2419, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/workspace/build/src/xpcom/base/nsCycleCollector.cpp, line 3362
[task 2020-02-26T22:45:44.160Z] 22:45:44     INFO - GECKO(1779) | [Child 2470, Main Thread] WARNING: No CID found when attempting to map contract ID: file /builds/worker/workspace/build/src/xpcom/components/nsComponentManager.cpp, line 721
[task 2020-02-26T22:45:44.201Z] 22:45:44     INFO - GECKO(1779) | nsStringStats
[task 2020-02-26T22:45:44.201Z] 22:45:44     INFO - GECKO(1779) |  => mAllocCount:           9004
[task 2020-02-26T22:45:44.201Z] 22:45:44     INFO - GECKO(1779) |  => mReallocCount:            0
[task 2020-02-26T22:45:44.201Z] 22:45:44     INFO - GECKO(1779) |  => mFreeCount:            9004
[task 2020-02-26T22:45:44.201Z] 22:45:44     INFO - GECKO(1779) |  => mShareCount:           7663
[task 2020-02-26T22:45:44.201Z] 22:45:44     INFO - GECKO(1779) |  => mAdoptCount:            730
[task 2020-02-26T22:45:44.201Z] 22:45:44     INFO - GECKO(1779) |  => mAdoptFreeCount:        734
[task 2020-02-26T22:45:44.201Z] 22:45:44     INFO - GECKO(1779) |  => Process ID: 2419, Thread ID: 139918438926208
[task 2020-02-26T22:45:44.226Z] 22:45:44     INFO - GECKO(1779) | [Parent 1779: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f63b161e000 == 6 [pid = 1779] [id = {c1a80244-6994-461b-9937-0eaef2b21e0a}] [url = about:blank]
[task 2020-02-26T22:45:44.327Z] 22:45:44     INFO - GECKO(1779) | Couldn't convert chrome URL: chrome://branding/locale/brand.properties
[task 2020-02-26T22:45:44.485Z] 22:45:44     INFO - GECKO(1779) | [Child 2470, Main Thread] WARNING: could not set real-time limit at process startup: file /builds/worker/workspace/build/src/dom/ipc/ContentChild.cpp, line 1825
[task 2020-02-26T22:45:44.485Z] 22:45:44     INFO - GECKO(1779) | [Child 2470: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7f075f1cd800 == 1 [pid = 2470] [id = {4c06e348-caad-4f41-bed8-285dbabea875}]
[task 2020-02-26T22:45:44.521Z] 22:45:44     INFO - GECKO(1779) | [Child 2470: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 1 (0x7f077a093520) [pid = 2470] [serial = 1] [outer = (nil)]
[task 2020-02-26T22:45:44.522Z] 22:45:44     INFO - GECKO(1779) | [Child 2470, Main Thread] WARNING: NS_ENSURE_TRUE(mPresShell) failed: file /builds/worker/workspace/build/src/layout/base/nsPresContext.cpp, line 848
[task 2020-02-26T22:45:44.522Z] 22:45:44     INFO - GECKO(1779) | [Child 2470: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 2 (0x7f075f0bf800) [pid = 2470] [serial = 2] [outer = 0x7f077a093520]
[task 2020-02-26T22:45:44.920Z] 22:45:44     INFO - GECKO(1779) | [Child 2470, Main Thread] WARNING: Trying to request nsIHttpChannel from DocumentChannel, this is likely broken: file /builds/worker/workspace/build/src/netwerk/ipc/DocumentChannel.cpp, line 64
[task 2020-02-26T22:45:44.945Z] 22:45:44     INFO - GECKO(1779) | [Child 2470: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 3 (0x7f075f9bbc00) [pid = 2470] [serial = 3] [outer = 0x7f077a093520]
[task 2020-02-26T22:45:45.102Z] 22:45:45     INFO - GECKO(1779) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpajDLRk.mozrunner/runtests_leaks_tab_pid2493.log
[task 2020-02-26T22:45:45.211Z] 22:45:45     INFO - GECKO(1779) | [Child 2493, Main Thread] WARNING: No CID found when attempting to map contract ID: file /builds/worker/workspace/build/src/xpcom/components/nsComponentManager.cpp, line 721
[task 2020-02-26T22:45:45.313Z] 22:45:45     INFO - GECKO(1779) | Couldn't convert chrome URL: chrome://branding/locale/brand.properties
[task 2020-02-26T22:45:45.615Z] 22:45:45     INFO - Not taking screenshot here: see the one that was previously logged
[task 2020-02-26T22:45:45.615Z] 22:45:45     INFO - Buffered messages logged at 22:45:43
[task 2020-02-26T22:45:45.615Z] 22:45:45     INFO - Entering test bound setup
[task 2020-02-26T22:45:45.615Z] 22:45:45     INFO - Leaving test bound setup
[task 2020-02-26T22:45:45.615Z] 22:45:45     INFO - Entering test bound test_parentWindowOpen
[task 2020-02-26T22:45:45.615Z] 22:45:45     INFO - Buffered messages logged at 22:45:45
[task 2020-02-26T22:45:45.615Z] 22:45:45     INFO - Entering full-screen
[task 2020-02-26T22:45:45.616Z] 22:45:45     INFO - Calling window.open()
[task 2020-02-26T22:45:45.616Z] 22:45:45     INFO - Buffered messages finished
[task 2020-02-26T22:45:45.616Z] 22:45:45     INFO - TEST-UNEXPECTED-FAIL | browser/base/content/test/fullscreen/browser_fullscreen_window_focus.js | Uncaught exception received from previously timed out test - at chrome://mochitests/content/browser/browser/base/content/test/fullscreen/browser_fullscreen_window_focus.js:28 - ReferenceError: info is not defined
[task 2020-02-26T22:45:45.616Z] 22:45:45     INFO - Stack trace:
[task 2020-02-26T22:45:45.616Z] 22:45:45     INFO - testWindowFocus/<@chrome://mochitests/content/browser/browser/base/content/test/fullscreen/browser_fullscreen_window_focus.js:28:5
[task 2020-02-26T22:45:45.616Z] 22:45:45     INFO - testExpectFullScreenExit@chrome://mochitests/content/browser/browser/base/content/test/fullscreen/head.js:57:13
[task 2020-02-26T22:45:45.616Z] 22:45:45     INFO - testWindowFocus@chrome://mochitests/content/browser/browser/base/content/test/fullscreen/browser_fullscreen_window_focus.js:27:9
[task 2020-02-26T22:45:45.616Z] 22:45:45     INFO - async*test_iframeWindowFocus@chrome://mochitests/content/browser/browser/base/content/test/fullscreen/browser_fullscreen_window_focus.js:51:10
[task 2020-02-26T22:45:45.616Z] 22:45:45     INFO - Tester_execTest/<@chrome://mochikit/content/browser-test.js:1062:34
[task 2020-02-26T22:45:45.616Z] 22:45:45     INFO - async*Tester_execTest@chrome://mochikit/content/browser-test.js:1097:11
[task 2020-02-26T22:45:45.616Z] 22:45:45     INFO - nextTest/<@chrome://mochikit/content/browser-test.js:925:14
[task 2020-02-26T22:45:45.616Z] 22:45:45     INFO - SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:914:23
[task 2020-02-26T22:45:45.616Z] 22:45:45     INFO - GECKO(1779) | JavaScript error: chrome://mochitests/content/browser/browser/base/content/test/fullscreen/head.js, line 17: TypeError: can't access property "ownerGlobal", browser is null
[task 2020-02-26T22:45:45.617Z] 22:45:45     INFO - Console message: [JavaScript Error: "TypeError: can't access property "ownerGlobal", browser is null" {file: "chrome://mochitests/content/browser/browser/base/content/test/fullscreen/head.js" line: 17}]
[task 2020-02-26T22:45:45.617Z] 22:45:45     INFO - GECKO(1779) | [Child 2470: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7f075f9cf000 == 2 [pid = 2470] [id = {3de47cdb-51ac-42a4-8cce-617bbd66e447}]
[task 2020-02-26T22:45:45.617Z] 22:45:45     INFO - GECKO(1779) | [Child 2470: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 4 (0x7f077a0936f0) [pid = 2470] [serial = 4] [outer = (nil)]
[task 2020-02-26T22:45:45.617Z] 22:45:45     INFO - GECKO(1779) | [Child 2470: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 5 (0x7f0764f68c00) [pid = 2470] [serial = 5] [outer = 0x7f077a0936f0]
[task 2020-02-26T22:45:45.672Z] 22:45:45     INFO - GECKO(1779) | [Parent 1779: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7f63aa30f000 == 7 [pid = 1779] [id = {feb78b65-50c0-4236-b780-e19036cffe29}]
[task 2020-02-26T22:45:45.672Z] 22:45:45     INFO - GECKO(1779) | [Parent 1779: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 15 (0x7f63acedcd90) [pid = 1779] [serial = 20] [outer = (nil)]
[task 2020-02-26T22:45:45.672Z] 22:45:45     INFO - GECKO(1779) | [Parent 1779: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 16 (0x7f63abe88000) [pid = 1779] [serial = 21] [outer = 0x7f63acedcd90]
[task 2020-02-26T22:45:45.692Z] 22:45:45     INFO - GECKO(1779) | [Parent 1779, Main Thread] WARNING: Attempting to get a displayport from a content with no primary frame!: file /builds/worker/workspace/build/src/layout/base/nsLayoutUtils.cpp, line 791
[task 2020-02-26T22:45:45.728Z] 22:45:45     INFO - GECKO(1779) | [Child 2493, Main Thread] WARNING: could not set real-time limit at process startup: file /builds/worker/workspace/build/src/dom/ipc/ContentChild.cpp, line 1825
[task 2020-02-26T22:45:45.972Z] 22:45:45     INFO - GECKO(1779) | [Parent 1779: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7f63ad927000 == 8 [pid = 1779] [id = {de6501bb-07bd-43da-8b06-9fcbd0ca82d9}]
[task 2020-02-26T22:45:45.972Z] 22:45:45     INFO - GECKO(1779) | [Parent 1779: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 17 (0x7f63acedd4d0) [pid = 1779] [serial = 22] [outer = (nil)]
[task 2020-02-26T22:45:46.088Z] 22:45:46     INFO - GECKO(1779) | [Parent 1779: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 18 (0x7f63adb81800) [pid = 1779] [serial = 23] [outer = 0x7f63acedd4d0]
[task 2020-02-26T22:45:46.204Z] 22:45:46     INFO - GECKO(1779) | [Child 2470: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 6 (0x7f0764f6d800) [pid = 2470] [serial = 6] [outer = 0x7f077a0936f0]
[task 2020-02-26T22:45:46.305Z] 22:45:46     INFO - GECKO(1779) | [Parent 1779, Main Thread] WARNING: Ignoring duplicate observer.: file /builds/worker/workspace/build/src/modules/libpref/Preferences.cpp, line 2692
[task 2020-02-26T22:45:46.547Z] 22:45:46     INFO - GECKO(1779) | [Child 2470, Main Thread] WARNING: Trying to request nsIHttpChannel from DocumentChannel, this is likely broken: file /builds/worker/workspace/build/src/netwerk/ipc/DocumentChannel.cpp, line 64
[task 2020-02-26T22:45:46.548Z] 22:45:46     INFO - GECKO(1779) | [Child 2470, Main Thread] WARNING: Trying to request nsIHttpChannel from DocumentChannel, this is likely broken: file /builds/worker/workspace/build/src/netwerk/ipc/DocumentChannel.cpp, line 64
[task 2020-02-26T22:45:46.549Z] 22:45:46     INFO - GECKO(1779) | [Child 2470, Main Thread] WARNING: NS_ENSURE_TRUE(request) failed: file /builds/worker/workspace/build/src/netwerk/base/nsLoadGroup.cpp, line 584
[task 2020-02-26T22:45:46.593Z] 22:45:46     INFO - GECKO(1779) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /tmp/tmpajDLRk.mozrunner/runtests_leaks_tab_pid2525.log
[task 2020-02-26T22:45:46.729Z] 22:45:46     INFO - GECKO(1779) | [Child 2525, Main Thread] WARNING: No CID found when attempting to map contract ID: file /builds/worker/workspace/build/src/xpcom/components/nsComponentManager.cpp, line 721
[task 2020-02-26T22:45:46.838Z] 22:45:46     INFO - TEST-PASS | browser/base/content/test/fullscreen/browser_fullscreen_window_open.js | Should leave full-screen - 
[task 2020-02-26T22:45:46.939Z] 22:45:46     INFO - GECKO(1779) | Couldn't convert chrome URL: chrome://branding/locale/brand.properties
[task 2020-02-26T22:45:47.168Z] 22:45:47     INFO - GECKO(1779) | [Child 2525, Main Thread] WARNING: could not set real-time limit at process startup: file /builds/worker/workspace/build/src/dom/ipc/ContentChild.cpp, line 1825
[task 2020-02-26T22:45:47.176Z] 22:45:47     INFO - GECKO(1779) | [Child 2525: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7fb082b22800 == 1 [pid = 2525] [id = {3de47cdb-51ac-42a4-8cce-617bbd66e447}]
[task 2020-02-26T22:45:47.197Z] 22:45:47     INFO - GECKO(1779) | [Child 2525: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 1 (0x7fb09de93520) [pid = 2525] [serial = 1] [outer = (nil)]
[task 2020-02-26T22:45:47.198Z] 22:45:47     INFO - GECKO(1779) | [Child 2525, Main Thread] WARNING: NS_ENSURE_TRUE(mPresShell) failed: file /builds/worker/workspace/build/src/layout/base/nsPresContext.cpp, line 848
[task 2020-02-26T22:45:47.199Z] 22:45:47     INFO - GECKO(1779) | [Child 2525: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 2 (0x7fb083768000) [pid = 2525] [serial = 2] [outer = 0x7fb09de93520]
[task 2020-02-26T22:45:47.234Z] 22:45:47     INFO - GECKO(1779) | [Parent 1779, Compositor] WARNING: Created child without a matching parent?: file /builds/worker/workspace/build/src/gfx/layers/ipc/ContentCompositorBridgeParent.cpp, line 110
[task 2020-02-26T22:45:47.235Z] 22:45:47     INFO - GECKO(1779) | [Child 2525, Main Thread] WARNING: failed to allocate layer transaction: file /builds/worker/workspace/build/src/dom/ipc/BrowserChild.cpp, line 2803
[task 2020-02-26T22:45:47.235Z] 22:45:47     INFO - GECKO(1779) | [Child 2525, Main Thread] WARNING: Fallback to BasicLayerManager: file /builds/worker/workspace/build/src/dom/ipc/BrowserChild.cpp, line 2755
[task 2020-02-26T22:45:47.337Z] 22:45:47     INFO - Not taking screenshot here: see the one that was previously logged
[task 2020-02-26T22:45:47.338Z] 22:45:47     INFO - TEST-UNEXPECTED-FAIL | browser/base/content/test/fullscreen/browser_fullscreen_window_open.js | A promise chain failed to handle a rejection: can't access property "ownerGlobal", browser is null - stack: waitForFullScreenState/<@chrome://mochitests/content/browser/browser/base/content/test/fullscreen/head.js:17:5
[task 2020-02-26T22:45:47.338Z] 22:45:47     INFO - waitForFullScreenState@chrome://mochitests/content/browser/browser/base/content/test/fullscreen/head.js:5:10
[task 2020-02-26T22:45:47.338Z] 22:45:47     INFO - testExpectFullScreenExit@chrome://mochitests/content/browser/browser/base/content/test/fullscreen/head.js:54:41
[task 2020-02-26T22:45:47.339Z] 22:45:47     INFO - testWindowFocus@chrome://mochitests/content/browser/browser/base/content/test/fullscreen/browser_fullscreen_window_focus.js:27:9
[task 2020-02-26T22:45:47.339Z] 22:45:47     INFO - async*test_iframeWindowFocus@chrome://mochitests/content/browser/browser/base/content/test/fullscreen/browser_fullscreen_window_focus.js:51:10
[task 2020-02-26T22:45:47.339Z] 22:45:47     INFO - Tester_execTest/<@chrome://mochikit/content/browser-test.js:1062:34
[task 2020-02-26T22:45:47.339Z] 22:45:47     INFO - async*Tester_execTest@chrome://mochikit/content/browser-test.js:1097:11
[task 2020-02-26T22:45:47.340Z] 22:45:47     INFO - nextTest/<@chrome://mochikit/content/browser-test.js:925:14
[task 2020-02-26T22:45:47.340Z] 22:45:47     INFO - SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:914:23
[task 2020-02-26T22:45:47.341Z] 22:45:47     INFO - Rejection date: Wed Feb 26 2020 22:45:45 GMT+0000 (Coordinated Universal Time) - false == true - JS frame :: resource://testing-common/PromiseTestUtils.jsm :: assertNoUncaughtRejections :: line 265
[task 2020-02-26T22:45:47.341Z] 22:45:47     INFO - Stack trace:
[task 2020-02-26T22:45:47.341Z] 22:45:47     INFO - resource://testing-common/PromiseTestUtils.jsm:assertNoUncaughtRejections:265
[task 2020-02-26T22:45:47.341Z] 22:45:47     INFO - chrome://mochikit/content/browser-test.js:Tester_execTest/<:1093
[task 2020-02-26T22:45:47.342Z] 22:45:47     INFO - chrome://mochikit/content/browser-test.js:Tester_execTest:1097
[task 2020-02-26T22:45:47.342Z] 22:45:47     INFO - chrome://mochikit/content/browser-test.js:nextTest/<:925
[task 2020-02-26T22:45:47.342Z] 22:45:47     INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<:914
[task 2020-02-26T22:45:47.342Z] 22:45:47     INFO - Leaving test bound test_parentWindowOpen
...

Comment 1

[Andreea Pavel [:apavel]]

Retriggers: https://treeherder.mozilla.org/#/jobs?repo=autoland&searchStr=Linux%2C18.04%2Cx64%2Cdebug%2CMochitests%2Cwith%2Cfission%2Cenabled%2Ctest-linux1804-64%2Fdebug-mochitest-browser-chrome-fis-e10s-2%2CM-fis%28bc2%29&fromchange=7bdea74790de1ab4734e1efaa373c7ffed9a01b0&tochange=a55fe811294d91e2c7d64e79344bfab96e2a7958&group_state=expanded&selectedJob=290665269

Henri please take a look.

Comment 2

[Intermittent Failures Robot]

11 failures in 5233 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 9
• mozilla-central: 2

Platform breakdown:

• linux1804-64: 11

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1618386&startday=2020-02-24&endday=2020-03-01&tree=all

Comment 3

[Henri Sivonen (:hsivonen)]

I believe this is an alternative manifestation of bug 1611355.

Comment 4

[Chris Peterson [:cpeterson]]

This intermittent test failure doesn't need to block Fission MVP unless it becomes more frequent.

Comment 5

[Intermittent Failures Robot]

28 failures in 5483 pushes (0.005 failures/push) were associated with this bug in the last 7 days.

This is the #47 most frequent failure this week.

Repository breakdown:

• autoland: 24
• try: 1
• mozilla-central: 3

Platform breakdown:

• linux1804-64: 28

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1618386&startday=2020-03-02&endday=2020-03-08&tree=all

Comment 6

[Razvan Maries]

There are 23 total failures in the last 7 days: https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?startday=2020-03-04&endday=2020-03-11&tree=trunk&bug=1618386

Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=292629267&repo=autoland&lineNumber=3152

Comment 7

[Andreea Pavel [:apavel]]

Henri are you working on this?

Comment 8

[Henri Sivonen (:hsivonen)]

I am in the sense that I expect this to be fixed by the fix for bug 1614268, and I'm working on the (transitive) blockers of that bug. (It might make sense to disable this test for now.)

Comment 9

[Andreea Pavel [:apavel]]

Attachment: Bug 1618386 - temporary disable browser_fullscreen_window_focus.js on linux fission r=hsivonen

Comment 10

[Andreea Pavel [:apavel]]

Andrew, as an fyi, this got disabled on linux fission.

Comment 11

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/b6887c96688f
temporary disable browser_fullscreen_window_focus.js on linux fission r=hsivonen

Comment 12

[Chris Peterson [:cpeterson]]

Since this test was failing often enough to get disabled, I'll track it for Fission's M4.1 mochitest milestone.

Comment 13

[Arthur Iakab [arthur_iakab]]

https://hg.mozilla.org/mozilla-central/rev/b6887c96688f

Comment 14

[Intermittent Failures Robot]

32 failures in 5336 pushes (0.006 failures/push) were associated with this bug in the last 7 days.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• autoland: 22
• mozilla-central: 5
• try: 5

Platform breakdown:

• linux1804-64: 32

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1618386&startday=2020-03-09&endday=2020-03-15&tree=all

Comment 15

[Chris Peterson [:cpeterson]]

(In reply to Arthur Iakab [arthur_iakab] from comment #13)

https://hg.mozilla.org/mozilla-central/rev/b6887c96688f

Andreea, I think there is a typo in your browser.ini code change:

skip-if = debug && (os == 'mac' && ( fission && os == "linux" && os_version == "18.04")) # Bug 1568570, 1618386

You probably mean (os == 'mac' || ... instead of (os == 'mac' && .... os can't be both 'mac' and 'linux'. :)

Comment 16

[Andreea Pavel [:apavel]]

Attachment: Bug 1618386 - correct disabling typo r=cpeterson

Comment 17

[Andreea Pavel [:apavel]]

Thanks for noticing. Please see the attached patch.

Comment 18

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/c4d2ca8f78b7
correct disabling typo r=cpeterson

Comment 19

[Stefan Hindli [:stefan_hindli]]

https://hg.mozilla.org/mozilla-central/rev/c4d2ca8f78b7

Comment 20

[Intermittent Failures Robot]

35 failures in 4955 pushes (0.007 failures/push) were associated with this bug in the last 7 days.

This is the #46 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• autoland: 22
• try: 4
• mozilla-central: 9

Platform breakdown:

• linux1804-64: 25
• macosx1014-64: 10

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1618386&startday=2020-03-16&endday=2020-03-22&tree=all

Comment 21

[Intermittent Failures Robot]

5 failures in 4773 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• try: 4
• autoland: 1

Platform breakdown:

• linux1804-64: 4
• macosx1014-64-shippable: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1618386&startday=2020-03-23&endday=2020-03-29&tree=all

Comment 22

[Intermittent Failures Robot]

3 failures in 5015 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• try: 1
• mozilla-central: 2

Platform breakdown:

• linux1804-64: 2
• macosx1014-64-shippable: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1618386&startday=2020-03-30&endday=2020-04-05&tree=all

Comment 23

[Intermittent Failures Robot]

2 failures in 4823 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 2

Platform breakdown:

• linux1804-64: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1618386&startday=2020-04-06&endday=2020-04-12&tree=all

Comment 24

[Intermittent Failures Robot]

3 failures in 4528 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 2
• try: 1

Platform breakdown:

• linux1804-64: 3

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1618386&startday=2020-04-13&endday=2020-04-19&tree=all

Comment 25

[Intermittent Failures Robot]

4 failures in 5423 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• try: 1
• mozilla-central: 1
• autoland: 2

Platform breakdown:

• linux1804-64: 2
• macosx1014-64-shippable: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1618386&startday=2020-04-27&endday=2020-05-03&tree=all

Comment 26

[Intermittent Failures Robot]

1 failures in 5276 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 1

Platform breakdown:

• linux1804-64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1618386&startday=2020-05-04&endday=2020-05-10&tree=all

Comment 27

[Intermittent Failures Robot]

19 failures in 1010 pushes (0.019 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 19

Platform breakdown:

• macosx1014-64-shippable: 19

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1618386&startday=2020-05-15&endday=2020-05-15&tree=all

Comment 28

[Narcis Beleuzu [:NarcisB]]

There are 22 failures in the last 2 days. All on macosx1014-64-shippable / opt
:xidorn , the failure started with the landing of Bug 1276537.
https://treeherder.mozilla.org/#/jobs?repo=autoland&searchStr=OS%2CX%2C10.14%2CShippable%2Copt%2CMochitests%2Ctest-macosx1014-64-shippable%2Fopt-mochitest-browser-chrome-e10s-2%2CM%28bc2%29&tochange=ea043dfff6a65516a1925efec246491ba4ec5182&selectedTaskRun=C5xVVJ3ESyqDTUhBozxrqw-0&fromchange=4266d097e223610178159331d3ffea2fbacf4ec7
Can you please take a look?

Comment 29

[Xidorn Quan [:xidorn] UTC+10]

I can... but it seems that this test has already been disabled for macOS debug? Does it make sense to just disable it for release as well?

Comment 30

[Xidorn Quan [:xidorn] UTC+10]

Looks like someone has opened another issue bug 1638499 for this, so cleaning my ni? here.

Comment 31

[Intermittent Failures Robot]

33 failures in 5488 pushes (0.006 failures/push) were associated with this bug in the last 7 days.

This is the #49 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• autoland: 29
• mozilla-central: 1
• try: 3

Platform breakdown:

• macosx1014-64-shippable: 31
• macosx1014-64-devedition: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1618386&startday=2020-05-11&endday=2020-05-17&tree=all

Comment 32

[Intermittent Failures Robot]

27 failures in 718 pushes (0.038 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 21
• mozilla-central: 3
• try: 3

Platform breakdown:

• macosx1014-64-shippable: 26
• linux1804-64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1618386&startday=2020-05-18&endday=2020-05-18&tree=all

Comment 33

[Intermittent Failures Robot]

20 failures in 1049 pushes (0.019 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 17
• mozilla-central: 2
• mozilla-beta: 1

Platform breakdown:

• macosx1014-64-shippable: 18
• linux1804-64: 1
• macosx1014-64-devedition: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1618386&startday=2020-05-19&endday=2020-05-19&tree=all

Comment 34

[Dorel Luca [:dluca]]

This bug failed 44 times in the last 7 days. Occurs on macosx1014-64-shippable, linux1804-64-shippable and linux1804-64 on opt.

Recent log:
https://treeherder.mozilla.org/logviewer.html#?job_id=302889790&repo=autoland

Comment 35

[Intermittent Failures Robot]

49 failures in 4727 pushes (0.01 failures/push) were associated with this bug in the last 7 days.

This is the #23 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• autoland: 39
• mozilla-central: 5
• try: 4
• mozilla-beta: 1

Platform breakdown:

• macosx1014-64-shippable: 45
• linux1804-64: 2
• macosx1014-64-devedition: 1
• linux1804-64-shippable: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1618386&startday=2020-05-18&endday=2020-05-24&tree=all

Comment 36

[Andreea Pavel [:apavel]]

Occurrences dropped when bug 1638499 got disabled.

Comment 37

[Chris Peterson [:cpeterson]]

Tentatively reassigning this bug to Alphan because Hsin-Yi says he will work on this Fission test bug after he finishes Fission YouTube bug 1620341.

Comment 38

[Intermittent Failures Robot]

4 failures in 5458 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 4

Platform breakdown:

• linux1804-64: 4

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1618386&startday=2020-05-25&endday=2020-05-31&tree=all

Comment 39

[Intermittent Failures Robot]

11 failures in 4949 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 8
• try: 3

Platform breakdown:

• linux1804-64: 11

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1618386&startday=2020-06-01&endday=2020-06-07&tree=all

Comment 40

[Alphan Chen [:alchen]]

I tried to enable this test on all platforms.
https://treeherder.mozilla.org/#/jobs?repo=try&revision=e0e13c86129e8439357dd2ebfd636aac85e9de93&selectedTaskRun=Ib7zQlVJTZCYTdOfgkhy2A.0

We can see the failures on OSX debug/opt and Linux debug/opt with fission enable.
They all failed due to the same reason as bug 1568570.
We disabled the test on OSX debug when introducing this test.

I think the problem is caused by the timing of popup.
https://searchfox.org/mozilla-central/rev/0e09b9191c02097034e46b193930f91c45b7885d/browser/base/content/test/fullscreen/browser_fullscreen_window_focus.js#20

Comment 41

[Chris Peterson [:cpeterson]]

(In reply to Alphan Chen [:alchen] from comment #40)

We can see the failures on OSX debug/opt and Linux debug/opt with fission enable.
They all failed due to the same reason as bug 1568570.
We disabled the test on OSX debug when introducing this test.

This test is currently disabled for all OSX debug/opt and Fission Linux debug. To make the sheriffs lives easier, perhaps we should also disable this test on Fission Linux opt until we have a fix? The recent intermittent failures in comment 38 and comment 39 are all Linux opt.

https://searchfox.org/mozilla-central/rev/0e09b9191c02097034e46b193930f91c45b7885d/browser/base/content/test/fullscreen/browser.ini#18-19

[browser_fullscreen_window_focus.js]
skip-if = os == 'mac' || (debug && fission && os == "linux" && os_version == "18.04") # Bug 1568570, 1618386

Comment 42

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 13
• try: 2

Platform breakdown:

• linux1804-64: 15

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1618386&startday=2020-06-08&endday=2020-06-14&tree=all

Comment 43

[Alphan Chen [:alchen]]

Summarize what I found recently.

First, I enabled the test on all platforms and simplify the test.
https://treeherder.mozilla.org/#/jobs?repo=try&revision=1cada551a63844c61c52ca41f00a60caaa54469c
We can get the same result as I said before.
Found failures on OSX, Fission Linux.
The logs are all the same. ("Request for fullscreen was denied because requesting element is not in the currently focused tab.")
The message is from Document::FullscreenElementReadyCheck().
https://searchfox.org/mozilla-central/rev/2c1092dc68c63f7bad6da6a03c5883a5ab5ff2ca/dom/base/Document.cpp#13650

Second, I add some logs for classifying the reason for the failures.
https://treeherder.mozilla.org/#/jobs?repo=try&revision=85b971b1bc9a4838f601a99c36b5a39523a52845
When the failures happen, IsInActiveTab() is false.
However, there are not caused by the same reason.
(Mac) docshell said it is not active from "docshell->GetIsActive()"
https://searchfox.org/mozilla-central/rev/2c1092dc68c63f7bad6da6a03c5883a5ab5ff2ca/dom/base/Document.cpp#13516
(Linux with fission) There is no ActiveBrowsingContext from "nsFocusManager->GetActiveBrowsingContext()".
https://searchfox.org/mozilla-central/rev/2c1092dc68c63f7bad6da6a03c5883a5ab5ff2ca/dom/base/Document.cpp#13554

Comment 44

[Alphan Chen [:alchen]]

(In reply to Alphan Chen [:alchen] from comment #43)

(Mac) docshell said it is not active from "docshell->GetIsActive()"
https://searchfox.org/mozilla-central/rev/2c1092dc68c63f7bad6da6a03c5883a5ab5ff2ca/dom/base/Document.cpp#13516

For this failure, I found we can eliminate the failure on OSX by setting preference( "full-screen-api.transition-duration.enter" and ".leave") before the tests. (OS X 10.14 debug 99 times and OS X 10.14 Shippable opt 83 times.)
However, it won't fix the failures on fission Linux.

(Detail explaining)
I double-check the preferences we have in other fullscreen tests.
The problem won't happen again when adding the preference of "full-screen-api.transition-duration".
https://treeherder.mozilla.org/#/jobs?repo=try&revision=ad2291722c28e282a9e6dc50cf8e6aab48c64c9a
OS X 10.14 debug 43 times and OS X 10.14 Shippable opt 35 times.
https://treeherder.mozilla.org/#/jobs?repo=try&revision=bfe701bbc2c78d17a163ab60fb0dd4760818388f
OS X 10.14 debug 32 times and OS X 10.14 Shippable opt 37 times.

The preference only affects on FullscreenTransitionDuration
.IsSuppressed(). So I trigger another try to make sure the result.
https://treeherder.mozilla.org/#/jobs?repo=try&revision=f3d20c73dd7366894affd12652acf0f3601400cf
OS X 10.14 debug 24 times and OS X 10.14 Shippable opt 11 times.

I think we can discuss this more in bug 1568570.

Comment 45

[Alphan Chen [:alchen]]

(In reply to Alphan Chen [:alchen] from comment #43)

(Linux with fission) There is no ActiveBrowsingContext from "nsFocusManager->GetActiveBrowsingContext()".
https://searchfox.org/mozilla-central/rev/2c1092dc68c63f7bad6da6a03c5883a5ab5ff2ca/dom/base/Document.cpp#13554

In this case, the docshell said it is active.
However, the activeBrowsingContext from nsFocusManager is null.

Hi Henri, does this make sense to you?
In the test, we will wait until "docShell.isActive && content.document.hasFocus()" is true before requesting fullscreen.
Is there any check we should add before requesting fullscreen to prevent this problem?

Comment 46

[Henri Sivonen (:hsivonen)]

(In reply to Alphan Chen [:alchen] from comment #45)

(In reply to Alphan Chen [:alchen] from comment #43)

(Linux with fission) There is no ActiveBrowsingContext from "nsFocusManager->GetActiveBrowsingContext()".
https://searchfox.org/mozilla-central/rev/2c1092dc68c63f7bad6da6a03c5883a5ab5ff2ca/dom/base/Document.cpp#13554

In this case, the docshell said it is active.
However, the activeBrowsingContext from nsFocusManager is null.

Hi Henri, does this make sense to you?

I assume it takes a while for IPC to catch up with the window having become the frontmost one? Can that apply given the test?

In the test, we will wait until "docShell.isActive && content.document.hasFocus()" is true before requesting fullscreen.
Is there any check we should add before requesting fullscreen to prevent this problem?

I suggest adding && Services.focus.activeBrowsingContext to the condition and seeing if that helps.

Comment 47

[Intermittent Failures Robot]

8 failures in 4035 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 6
• try: 2

Platform breakdown:

• linux1804-64: 8

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1618386&startday=2020-06-15&endday=2020-06-21&tree=all

Comment 48

[Chris Peterson [:cpeterson]]

Hsin-Yi recommends moving this bug to Fission's M6 Nightly milestone. The test failure appears to be caused by a focus message race condition that will need more investigation.

Comment 49

[Alphan Chen [:alchen]]

Here is a description of the mochitest.

1. Open a tab. (browser/browser/base/content/test/fullscreen/open_and_focus_helper.html)
2. Calling window.open(). It sends a message("open") to the tab which is opened in the step 1. The tab will open a new window called popup.
3. Re-focusing main window by "await waitForFocus()".
4. Entering full-screen by "await changeFullscreen()".
5. Calling window.focus(). It will send a message("focus") to the tab which is opened in the first step. The tab will call "popup.focus()".
6. Then we expect to exit from the fullscreen.

The failure happens in step 4.
The Service.focus.activeBrowsingContext is null or wrong when the failure happens.

(In reply to Henri Sivonen (:hsivonen) from comment #46)

I assume it takes a while for IPC to catch up with the window having become the frontmost one? Can that apply given the test?
I suggest adding && Services.focus.activeBrowsingContext to the condition and seeing if that helps.

I still see failures after adding "&& Service.focus.activeBrowsingContext" to the condition.
After investigation, I found there are unexpected behaviors that overwrite the expected "activeBrowsingContext".
I will summarize the finding in the next comment.

Comment 50

[Alphan Chen [:alchen]]

Here is the normal behaviour.

Here is a description of the mochitest.

1. Open a tab. (browser/browser/base/content/test/fullscreen/open_and_focus_helper.html)

0:05.47 GECKO(30550) nsFocusManager.cpp::Focus() call ActivateRemoteFrameIfNeeded()
0:05.47 GECKO(30550) nsFocusManager.cpp::ActivateRemoteFrameIfNeeded() Remote browser activated 0x7f652afd1800
0:05.47 GECKO(30550) @BrowserParent::Activate(), SetTopLevelWebFocus(this) and call SendActivate()
0:05.51 GECKO(30550) @BrowserChild.cpp::RecvActivate()call mWebBrowser->FocusActivate()
0:05.51 GECKO(30550) nsWebBrowser::FocusActivate() 0x7f09bdce2a00 about:blank
0:05.51 GECKO(30550) call fm->WindowRaised(window)
0:05.51 GECKO(30550) @nsFocusManager(0x7f09bead93a0)::WindowRaised Window 0x7f09bdcb37a0 Raised [Currently: (nil) (nil)]
0:05.52 GECKO(30550) @nsFocusManager::WindowRaised before return Window 0x7f09bdcb37a0 Raised [Currently: (nil) 0x7f09bdcb37a0] activeBC(0x7f09bdce5c00) parent process?0

In the end of step1, the activeBC of nsFocusManager(0x7f09bead93a0) is 0x7f09bdce5c00. (the new opened tab)

2. Calling window.open(). It sends a message("open") to the tab which is opened in the step 1. The tab will open a new window called popup.

0:06.09 GECKO(30550) nsFocusManager.cpp::Focus() call ActivateRemoteFrameIfNeeded()
0:06.09 GECKO(30550) nsFocusManager.cpp::ActivateRemoteFrameIfNeeded() Remote browser activated 0x7f652afd8800
0:06.09 GECKO(30550) @BrowserParent.cpp::Activate(), SetTopLevelWebFocus(this) and call SendActivate()
0:06.10 GECKO(30550) @BrowserChild.cpp::RecvActivate()call mWebBrowser->FocusActivate()
0:06.10 GECKO(30550) nsWebBrowser::FocusActivate() 0x7f09bdce3aa0 about:blank
0:06.10 GECKO(30550) call fm->WindowRaised(window)
0:06.10 GECKO(30550) nsFocusManager(0x7f09bead93a0)::WindowRaised Window 0x7f09bdcb3cb0 Raised [Currently: (nil) (nil)] parent process?0
0:06.10 GECKO(30550) nsFocusManager::WindowRaised before return Window 0x7f09bdcb3cb0 Raised [Currently: (nil) 0x7f09bdcb3cb0] activeBC(0x7f09bab7b000) parent process?0

In the end of step2, the activeBC of nsFocusManager(0x7f09bead93a0) is 0x7f09bdce5c00. (popup)

3. Re-focusing main window by "await waitForFocus()".

0:06.12 GECKO(30550) @BrowserParent.cpp::Activate(), SetTopLevelWebFocus(this) and call SendActivate()
0:06.13 GECKO(30550) @BrowserChild.cpp Enter BrowserChild::RecvActivate()call mWebBrowser->FocusActivate()
0:06.13 GECKO(30550) nsWebBrowser::FocusActivate() 0x7f09bdce2a00 http://example.com/browser/browser/base/content/test/fullscreen/open_and_focus_helper.html
0:06.13 GECKO(30550) call fm->WindowRaised(window)
0:06.13 GECKO(30550) nsWebBrowser::FocusActivate() 0x7f09bdce2a00 http://example.com/browser/browser/base/content/test/fullscreen/open_and_focus_helper.html
0:06.13 GECKO(30550) call fm->WindowRaised(window)
0:06.13 GECKO(30550) nsFocusManager(0x7f09bead93a0)::WindowRaised Window 0x7f09bdcb37a0 Raised [Currently: (nil) (nil)] parent process?0
0:06.13 GECKO(30550) nsFocusManager::WindowRaised Raised Window: http://example.com/browser/browser/base/content/test/fullscreen/open_and_focus_helper.html
0:06.13 GECKO(30550) nsFocusManager::WindowRaised before return Window 0x7f09bdcb37a0 Raised [Currently: (nil) 0x7f09bdcb37a0] activeBC(0x7f09bdce5c00) parent process?0

In the end of step3, the activeBC of nsFocusManager(0x7f09bead93a0) is 0x7f09bdce5c00. (http://example.com/browser/browser/base/content/test/fullscreen/open_and_focus_helper.html)

4. Entering full-screen by "await changeFullscreen()".

We request fullscreen from the tab that we opened in the first step.
At that time, Service.focus.activeBrowsingContext is what we expect("0x7f09bdce5c00").

Comment 51

[Alphan Chen [:alchen]]

One of the unexpected behaviour.

Here is a description of the mochitest.

1. Open a tab. (browser/browser/base/content/test/fullscreen/open_and_focus_helper.html)

0:10.78 GECKO(27754) nsFocusManager.cpp 2490::Focus() call ActivateRemoteFrameIfNeeded()
0:10.78 GECKO(27754) nsFocusManager.cpp 2328::ActivateRemoteFrameIfNeeded() Remote browser activated 0x7f047bf03000
0:10.78 GECKO(27754) @BrowserParent.cpp Enter BrowserParent::Activate(), SetTopLevelWebFocus(this) and call SendActivate()
0:10.82 GECKO(27754) @BrowserChild.cpp Enter BrowserChild::RecvActivate()call mWebBrowser->FocusActivate()
0:10.82 GECKO(27754) nsWebBrowser::FocusActivate() 0x7f4366a1c7a0 about:blank
0:10.82 GECKO(27754) call fm->WindowRaised(window)
0:10.82 GECKO(27754) nsFocusManager(0x7f434f0d9310):663::WindowRaised Window 0x7f434e2b67a0 Raised [Currently: (nil) (nil)] parent process?0
0:10.82 GECKO(27754) nsFocusManager::WindowRaised Raised Window: about:blank
0:10.82 GECKO(27754) nsFocusManager::WindowRaised before return Window 0x7f434e2b67a0 Raised [Currently: (nil) 0x7f434e2b67a0] activeBC(0x7f434e2da800) parent process?0

In the end of step1, the activeBC of nsFocusManager(0x7f434f0d9310) is 0x7f434e2da800. (the new opened tab)

2. Calling window.open(). It sends a message("open") to the tab which is opened in the step 1. The tab will open a new window called popup.

0:11.44 GECKO(27754) nsFocusManager.cpp 2490::Focus() call ActivateRemoteFrameIfNeeded()
0:11.44 GECKO(27754) nsFocusManager.cpp 2328::ActivateRemoteFrameIfNeeded() Remote browser activated 0x7f047ca47800
0:11.44 GECKO(27754) @BrowserParent.cpp Enter BrowserParent::Activate(), SetTopLevelWebFocus(this) and call SendActivate()

There is no BrowserChild::RecvActivate() call in the step 2!!!!!!
So we don't have chance to set activeBrowsingContext as the browsingContext of popup.

3. Re-focusing main window by "await waitForFocus()".

0:11.45 GECKO(27754) nsFocusManager.cpp 2490::Focus() call ActivateRemoteFrameIfNeeded()
0:11.45 GECKO(27754) nsFocusManager.cpp 2328::ActivateRemoteFrameIfNeeded() Remote browser activated 0x7f047bf03000
0:11.45 GECKO(27754) @BrowserParent.cpp Enter BrowserParent::Activate(), SetTopLevelWebFocus(this) and call SendActivate()
0:11.45 GECKO(27754) @BrowserChild.cpp Enter BrowserChild::RecvActivate()call mWebBrowser->FocusActivate()
0:11.45 GECKO(27754) nsWebBrowser::FocusActivate() 0x7f4366a1c7a0 http://example.com/browser/browser/base/content/test/fullscreen/open_and_focus_helper.html
0:11.45 GECKO(27754) call fm->WindowRaised(window)
0:11.45 GECKO(27754) nsFocusManager(0x7f434f0d9310):663::WindowRaised Window 0x7f434e2b67a0 Raised [Currently: (nil) (nil)] parent process?0
0:11.45 GECKO(27754) nsFocusManager::WindowRaised Raised Window: http://example.com/browser/browser/base/content/test/fullscreen/open_and_focus_helper.html
0:11.45 GECKO(27754) nsFocusManager::WindowRaised before return Window 0x7f434e2b67a0 Raised [Currently: (nil) 0x7f434e2b67a0] activeBC(0x7f434e2da800) parent process?0

In the end of step3, the activeBC of nsFocusManager(0x7f434f0d9310) is 0x7f434e2da800. (http://example.com/browser/browser/base/content/test/fullscreen/open_and_focus_helper.html)

4. Entering full-screen by "await changeFullscreen()".

In step 4, there is "BrowserChild::RecvActivate()" call.
It is weird that there is no "BrowserParent->SendActivate()" in step 3 or step 4.
But we do have "BrowserParent->SendActivate()" in the end of step 2.

[4-1]
In the call of BrowserChild::RecvActivate(), we call nsFocusManager::WindowRaised().
The nsFocusManager(0x7fd3d90d9310) is different from the previous(0x7f434f0d9310).
i. Call SetActiveBrowsingContextInContent() in nsFocusManager::WindowRaised()
https://searchfox.org/mozilla-central/rev/a87a1c3b543475276e6d57a7a80cb02f3e42b6ed/dom/base/nsFocusManager.cpp#712
ii. Call "contentChild->SendSetActiveBrowsingContext(aContext)" in SetActiveBrowsingContextInContent()
https://searchfox.org/mozilla-central/rev/a87a1c3b543475276e6d57a7a80cb02f3e42b6ed/dom/base/nsFocusManager.cpp#4642
iii. ContentParent::RecvSetActiveBrowsingContext().
https://searchfox.org/mozilla-central/rev/a87a1c3b543475276e6d57a7a80cb02f3e42b6ed/dom/ipc/ContentParent.cpp#6534
iv. ContentChild::RecvSetActiveBrowsingContext().
https://searchfox.org/mozilla-central/rev/a87a1c3b543475276e6d57a7a80cb02f3e42b6ed/dom/ipc/ContentChild.cpp#3797
v. In the end, we set mActiveBrowsingContextInContent of previous nsFocusManager(0x7f434f0d9310) and mActiveBrowsingContextInContentSetFromOtherProcess.
https://searchfox.org/mozilla-central/rev/a87a1c3b543475276e6d57a7a80cb02f3e42b6ed/dom/base/nsFocusManager.cpp#4683

In step v, we overwrite the mActiveBrowsingContextInContent of nsFocusManager(0x7f434f0d9310) to new BC(0x7f434b176800).

0:11.47 GECKO(27754) ContentChild.cpp 3789::RecvSetActiveBrowsingContext-call fm->SetActiveBrowsingContextFromOtherProcess(0x7f434b176800)
0:11.47 GECKO(27754) nsFocusManager(0x7f434f0d9310).cpp 4779 ::SetActiveBrowsingContextFromOtherProcess = aContext(0x7f434b176800), mActiveBrowsingContextInContentSetFromOtherProcess=true

[4-2]
After "BrowserChild::RecvActivate()" call, we get "BrowserChild::RecvDeactivate()".
It just reverse the previous "BrowserChild::RecvActivate()".
I. Call SetActiveBrowsingContextInContent(nullptr) in nsFocusManager::WindowLowered().
https://searchfox.org/mozilla-central/rev/a87a1c3b543475276e6d57a7a80cb02f3e42b6ed/dom/base/nsFocusManager.cpp#830
II. Call contentChild->SendUnsetActiveBrowsingContext(mActiveBrowsingContextInContent) in SetActiveBrowsingContextInContent()
https://searchfox.org/mozilla-central/rev/a87a1c3b543475276e6d57a7a80cb02f3e42b6ed/dom/base/nsFocusManager.cpp#4657
III. ContentParent::RecvUnsetActiveBrowsingContext()
https://searchfox.org/mozilla-central/rev/a87a1c3b543475276e6d57a7a80cb02f3e42b6ed/dom/ipc/ContentParent.cpp#6558
IV. ContentChild::RecvUnsetActiveBrowsingContext()
https://searchfox.org/mozilla-central/rev/a87a1c3b543475276e6d57a7a80cb02f3e42b6ed/dom/ipc/ContentChild.cpp#3824
V. nsFocusManager::UnsetActiveBrowsingContextFromOtherProcess
https://searchfox.org/mozilla-central/rev/a87a1c3b543475276e6d57a7a80cb02f3e42b6ed/dom/base/nsFocusManager.cpp#4691

In step V, we set the mActiveBrowsingContextInContent of previous nsFocusManager(0x7f434f0d9310) as nullptr.
0:11.48 GECKO(27754) nsFocusManager(0x7f434f0d9310).cpp::UnsetActiveBrowsingContextFromOtherProcess. Set mActiveBrowsingContextInContent=nullptr. due to mActiveBrowsingContextInContent= aContext(0x7f434b176800),

[4-3]
Then we use "Document::FullscreenElementReadyCheck" before request fullscreen.
https://searchfox.org/mozilla-central/rev/a87a1c3b543475276e6d57a7a80cb02f3e42b6ed/dom/base/Document.cpp#13644
In this case, the mActiveBrowsingContextInContent of nsFocusManager(0x7f434f0d9310) is null.
The bc that we expected is the same as what we have in the end of step 3.

0:11.56 GECKO(27754) Document.cpp IsInActiveTab() fm(0x7f434f0d9310) bc->Top()=0x7f434e2da800

Comment 52

[Alphan Chen [:alchen]]

As bug 1618386 comment 51, the mActiveBrowsingContextInContent we get from nsFocusManager is null.
https://searchfox.org/mozilla-central/rev/a87a1c3b543475276e6d57a7a80cb02f3e42b6ed/dom/base/Document.cpp#13549

There are other possibilities.
If we request fullscreen before [4-2 in comment 51], Document::IsInActiveTab return false due to ActiveBrowsingContextInContent is wrong.
https://searchfox.org/mozilla-central/rev/a87a1c3b543475276e6d57a7a80cb02f3e42b6ed/dom/base/Document.cpp#13552

I think it is also possible that we request fullscreen before [4-1 and 4-2 in comment 51].
In this case, "Document::FullscreenElementReadyCheck" return true.

Based on my experiments, I find the same symptom[2 in comment 51] when meeting the failure.

2. Calling window.open(). It sends a message("open") to the tab which is opened in the step 1. The tab will open a new window called popup.

0:11.44 GECKO(27754) nsFocusManager.cpp 2490::Focus() call ActivateRemoteFrameIfNeeded()
0:11.44 GECKO(27754) nsFocusManager.cpp 2328::ActivateRemoteFrameIfNeeded() Remote browser activated 0x7f047ca47800
0:11.44 GECKO(27754) @BrowserParent.cpp Enter BrowserParent::Activate(), SetTopLevelWebFocus(this) and call SendActivate()

There is no BrowserChild::RecvActivate() call in the step 2!!!!!!
So we don't have chance to set activeBrowsingContext as the browsingContext of popup.

Comment 53

[Alphan Chen [:alchen]]

I trigger a try with a workaround for the problem I mentioned in comment 51.
From result, there is no failure until now.
https://treeherder.mozilla.org/#/jobs?repo=try&selectedTaskRun=QYKOlNxiSImSSepl258XEA.0&revision=1c27bbdd2e8e1cdf3ff44be97c0f35400f9fdb04

The workaround is just not do "contentChild->SendSetActiveBrowsingContext(aContext)" in SetActiveBrowsingContextInContent().
https://searchfox.org/mozilla-central/rev/a87a1c3b543475276e6d57a7a80cb02f3e42b6ed/dom/base/nsFocusManager.cpp#4642
Then we can prevent the mActiveBrowsingContextInContent overwriting of [4-1 in comment 51].
And the mActiveBrowsingContextInContent won't reset due to "mActiveBrowsingContextInContent != aContext" in [4-2 in comment 51]
https://searchfox.org/mozilla-central/rev/a87a1c3b543475276e6d57a7a80cb02f3e42b6ed/dom/base/nsFocusManager.cpp#4691

From my view, I think we can use a new added variable to record activeBC from other process and add some logic in GetFocusedBrowsingContext() and other related functions to fix this problem.

Comment 54

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 12
• try: 3

Platform breakdown:

• linux1804-64: 15

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1618386&startday=2020-06-22&endday=2020-06-28&tree=all

Comment 55

[Alphan Chen [:alchen]]

For the real fix, we should know why there are other "nsFocusManager::WindowRaised()" and "nsFocusManager::WindowLowered()" in step 4 before requesting fullscreen.

4. Entering full-screen by "await changeFullscreen()".

Since the calls are from "BrowserChild::RecvActivate()" and ""BrowserChild::RecvDeactivate()", I think there is a possibility that these two calls are sent before the following. Due to the wrong order, we reset the activeBC.

3. Re-focusing main window by "await waitForFocus()".
   0:11.45 GECKO(27754) nsFocusManager.cpp 2490::Focus() call ActivateRemoteFrameIfNeeded()
   0:11.45 GECKO(27754) nsFocusManager.cpp 2328::ActivateRemoteFrameIfNeeded() Remote browser activated 0x7f047bf03000
   0:11.45 GECKO(27754) @BrowserParent.cpp Enter BrowserParent::Activate(), SetTopLevelWebFocus(this) and call SendActivate()
   0:11.45 GECKO(27754) @BrowserChild.cpp Enter BrowserChild::RecvActivate()call mWebBrowser->FocusActivate()
   0:11.45 GECKO(27754) nsWebBrowser::FocusActivate() 0x7f4366a1c7a0 http://example.com/browser/browser/base/content/test/fullscreen/open_and_focus_helper.html
   0:11.45 GECKO(27754) call fm->WindowRaised(window)
   0:11.45 GECKO(27754) nsFocusManager(0x7f434f0d9310):663::WindowRaised Window 0x7f434e2b67a0 Raised [Currently: (nil) (nil)] parent process?0
   0:11.45 GECKO(27754) nsFocusManager::WindowRaised Raised Window: http://example.com/browser/browser/base/content/test/fullscreen/open_and_focus_helper.html
   0:11.45 GECKO(27754) nsFocusManager::WindowRaised before return Window 0x7f434e2b67a0 Raised [Currently: (nil) 0x7f434e2b67a0] activeBC(0x7f434e2da800) parent process?0

In the end of step3, the activeBC of nsFocusManager(0x7f434f0d9310) is 0x7f434e2da800. (http://example.com/browser/browser/base/content/test/fullscreen/open_and_focus_helper.html)

Do you have any idea about unexpected behaviors that overwrite the expected "activeBrowsingContext"?

Comment 56

[Henri Sivonen (:hsivonen)]

Do you have any idea about unexpected behaviors that overwrite the expected "activeBrowsingContext"?

Unfortunately, I don't have specific ideas of what's going on here. Sorry. Two thoughts:

1. A pre-existing questionable behavior was fixed by the introduction of mActiveBrowsingContextInContentSetFromOtherProcess in nsFocusManager. Perhaps there are more issues in the same area.
2. Do all the relevant IPC messages get sent through the same actor? (I'd be very surprised if postMessage went via a different actor than all the focus stuff, but it would be prudent to check.)

Comment 57

[Intermittent Failures Robot]

19 failures in 4516 pushes (0.004 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 7
• try: 12

Platform breakdown:

• linux1804-64: 19

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1618386&startday=2020-06-29&endday=2020-07-05&tree=all

Comment 58

[Alphan Chen [:alchen]]

(In reply to Henri Sivonen (:hsivonen) (not reading bugmail until 2020-08-03) from comment #56)

Do you have any idea about unexpected behaviors that overwrite the expected "activeBrowsingContext"?

Unfortunately, I don't have specific ideas of what's going on here. Sorry. Two thoughts:

1. A pre-existing questionable behavior was fixed by the introduction of mActiveBrowsingContextInContentSetFromOtherProcess in nsFocusManager. Perhaps there are more issues in the same area.

Yes, I think the reason for this bug is similar to what :tnikkel found in bug 1616373.

Comment 59

[Hsin-Yi Tsai (she/her) [:hsinyi]]

Unassigning Alphan from this as this reveals deeper focus problem and he has other Fission task on his plate. Will need further investigation and plan discussion with Henri on focus area.

Comment 60

[Intermittent Failures Robot]

9 failures in 5265 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 8
• try: 1

Platform breakdown:

• linux1804-64: 9

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1618386&startday=2020-07-06&endday=2020-07-12&tree=all

Comment 61

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 12
• try: 2

Platform breakdown:

• linux1804-64: 14

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1618386&startday=2020-07-13&endday=2020-07-19&tree=all

Comment 62

[Intermittent Failures Robot]

8 failures in 4310 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 7
• try: 1

Platform breakdown:

• linux1804-64: 8

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1618386&startday=2020-07-20&endday=2020-07-26&tree=all

Comment 63

[Neha Kochar [:neha]]

Henri, need your thoughts on fixing this.

Comment 64

[Intermittent Failures Robot]

7 failures in 4289 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 7

Platform breakdown:

• linux1804-64: 1
• linux1804-64-shippable: 6

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1618386&startday=2020-07-27&endday=2020-08-02&tree=all

Comment 65

[Intermittent Failures Robot]

7 failures in 4618 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 7

Platform breakdown:

• linux1804-64-shippable: 7

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1618386&startday=2020-08-03&endday=2020-08-09&tree=all

Comment 66

[Intermittent Failures Robot]

4 failures in 3601 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 4

Platform breakdown:

• linux1804-64-shippable: 4

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1618386&startday=2020-08-10&endday=2020-08-16&tree=all

Comment 67

[Neha Kochar [:neha]]

Henri says it's less likely for users to run into this, so moving to M6c.

Comment 68

[Intermittent Failures Robot]

4 failures in 4100 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 4

Platform breakdown:

• linux1804-64-shippable: 4

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1618386&startday=2020-08-17&endday=2020-08-23&tree=all

Comment 69

[Intermittent Failures Robot]

5 failures in 4046 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 5

Platform breakdown:

• linux1804-64-shippable: 5

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1618386&startday=2020-08-24&endday=2020-08-30&tree=all

Comment 70

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 10

Platform breakdown:

• linux1804-64-shippable: 10

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1618386&startday=2020-08-31&endday=2020-09-06&tree=all

Comment 71

[Natalia Csoregi [:nataliaCs]]

Update:

There have been 20 failures within the last 7 days, all of them on Linux 18.04 x64 shippable opt.

Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=315547154&repo=mozilla-central&lineNumber=2484

Comment 72

[Intermittent Failures Robot]

20 failures in 3410 pushes (0.006 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 20

Platform breakdown:

• linux1804-64-shippable: 20

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1618386&startday=2020-09-07&endday=2020-09-13&tree=all

Comment 73

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 13

Platform breakdown:

• linux1804-64-shippable: 13

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1618386&startday=2020-09-14&endday=2020-09-20&tree=all

Comment 74

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 12

Platform breakdown:

• linux1804-64-shippable: 12

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1618386&startday=2020-09-21&endday=2020-09-27&tree=all

Comment 75

[Intermittent Failures Robot]

7 failures in 4195 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 7

Platform breakdown:

• linux1804-64-shippable: 7

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1618386&startday=2020-09-28&endday=2020-10-04&tree=all

Comment 76

[Intermittent Failures Robot]

8 failures in 4130 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 8

Platform breakdown:

• linux1804-64-shippable: 8

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1618386&startday=2020-10-05&endday=2020-10-11&tree=all

Comment 77

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 10

Platform breakdown:

• linux1804-64-shippable: 10

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1618386&startday=2020-10-12&endday=2020-10-18&tree=all

Comment 78

[Neha Kochar [:neha]]

Assigning to Henri to debug this further.

Comment 79

[Intermittent Failures Robot]

4 failures in 4230 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 4

Platform breakdown:

• linux1804-64-shippable: 4

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1618386&startday=2020-10-19&endday=2020-10-25&tree=all

Comment 80

[Henri Sivonen (:hsivonen)]

AFAICT, when this fails, a native window gets unfocused and another native window gets focused. In the unfocused native window, every content process gets a broadcast of deactivation. This in turn causes a broadcast back of unsetting the active browsing context. In the native window that gets focused, every content process gets a broadcast of activation. This in turn causes a broadcast back of setting the active browsing context.

In the process where things go wrong, not only do these broadcasts arrive too late relative to what that process itself is doing, but they also arrive out of order relative to each other.

The most obvious thing is that the design can deal with focus moving from one browsing context to another at a time, but it's really bad at dealing with these native window-level events causing a flurry of activity at one. Even worse when it's not about switching from another app to Firefox or from Firefox to another app but when switching between two native windows inside Firefox.

I don't yet have a good idea of how to fix this. One idea would be to make the parent process assign some kind of sequence number to changes triggered from there, but passing those sequence numbers through the whole chain of calls and IPC is a pretty big change.

Another idea worth pursuing is detecting the case of a native window switch between two Firefox windows and suppressing the active browsing context unsetting broadcasts in that case. (Not sure how to do that concretely.) That doesn't fix the issue of the native window focus broadcast also arriving late.

Comment 81

[Henri Sivonen (:hsivonen)]

Attachment: Bug 1618386 - Add action ids to filter out stale active browsing context updates.

Comment 82

[Henri Sivonen (:hsivonen)]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=e10acf789bb865abf8caeb98dcdc11458e0576a1

At this point, I'm not actually sure if there are remaining failures or if in some cases the test just runs extremely slowly in a debug build or in a debug build in rr.

I do see a failure in PrivateBrowsingUtils.jsm where the JS expect a non-null docshell but the docshell can be null. I'm not sure if it's something I broke or something I unmasked. When I try to paper over it in JS, the test appears to get stuck in the full-screen mode.

At present, I think it would make sense to land what I now have sooner than later, because what I have so far may unbreak other test cases.

Comment 83

[Henri Sivonen (:hsivonen)]

(In reply to Henri Sivonen (:hsivonen) from comment #82)

https://treeherder.mozilla.org/#/jobs?repo=try&revision=e10acf789bb865abf8caeb98dcdc11458e0576a1

Sigh. Pretty much everything goes orange.

Comment 84

[Henri Sivonen (:hsivonen)]

With a bug fixed and with more logging:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=8aa7290988c178f5c295dbaab069b86e04ef8534

Comment 85

[Intermittent Failures Robot]

7 failures in 4275 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 7

Platform breakdown:

• linux1804-64-shippable: 7

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1618386&startday=2020-10-26&endday=2020-11-01&tree=all

Comment 86

[Henri Sivonen (:hsivonen)]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=661df2c7c9b63712c23ae646a72fc299c32775b0

Comment 87

[Henri Sivonen (:hsivonen)]

With the latest patch the situation starts to look OK-ish, but now there is a failure with

can't access property "QueryInterface", aWindow.docShell is null - stack: pbu_privacyContextFromWindow@resource://gre/modules/PrivateBrowsingUtils.jsm:54:5

Comment 88

[Henri Sivonen (:hsivonen)]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=f120a13981ccd0f63eb487412de4bfdc9667f3f6

Comment 89

[Intermittent Failures Robot]

15 failures in 4128 pushes (0.004 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 15

Platform breakdown:

• linux1804-64-shippable: 15

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1618386&startday=2020-11-02&endday=2020-11-08&tree=all

Comment 90

[Henri Sivonen (:hsivonen)]

Removed sequence number set on detachment:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=34cc70bd47f5be0cee4e22085e9c655e60397ae1

Comment 91

[Henri Sivonen (:hsivonen)]

Try run with a rewritten patch based on discussion with Nika:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=254b81634ac82bdf39c7835c9604cdfb0c0cd6af

Comment 92

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 14

Platform breakdown:

• linux1804-64-shippable: 14

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1618386&startday=2020-11-09&endday=2020-11-15&tree=all

Comment 93

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/d66f803de161
Add action ids to filter out stale active browsing context updates. r=nika

Comment 94

[Alexandru Michis [:malexandru]]

https://hg.mozilla.org/mozilla-central/rev/d66f803de161

Comment 95

[Intermittent Failures Robot]

1 failures in 4810 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform breakdown:

• linux1804-64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1618386&startday=2020-11-16&endday=2020-11-22&tree=all