Open Bug 1566173 Opened 9 months ago Updated 13 days ago

OSX Mojave (10.14) - toolkit/components/pictureinpicture/tests/browser_fullscreen.js | uncaught exception - Error: TelemetryStopwatch: key "FULLSCREEN_CHANGE_MS" was already initialized at handleEvent@chrome://browser/content/browser-fullScreenAndPointerL

Categories

(Toolkit :: General, defect, P5)

defect

Tracking

()

People

(Reporter: intermittent-bug-filer, Unassigned, NeedInfo)

References

(Blocks 1 open bug)

Details

(Keywords: intermittent-failure, leave-open, Whiteboard: [stockwell disabled])

Attachments

(1 file)

Filed by: egao [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=256301704&repo=try
Full log: https://queue.taskcluster.net/v1/task/COH6yW1-QxG7wnmh2_8kWQ/runs/0/artifacts/public/logs/live_backing.log


Platform: macosx1014/debug
Suite: mochitest-browser-chrome
Chunk: 9

Context:
01:42:53 INFO - TEST-START | toolkit/components/pictureinpicture/tests/browser_fullscreen.js
01:42:53 INFO - GECKO(2002) | ++DOCSHELL 0x1145e4000 == 2 [pid = 2004] [id = {aa4cadc1-2804-2a43-a3ea-a48b43b3affd}]
01:42:53 INFO - GECKO(2002) | ++DOMWINDOW == 5 (0x11a140020) [pid = 2004] [serial = 7] [outer = 0x0]
01:42:53 INFO - GECKO(2002) | [Child 2004, Main Thread] WARNING: No active window: file /builds/worker/workspace/build/src/js/xpconnect/src/XPCJSContext.cpp, line 662
01:42:53 INFO - GECKO(2002) | ++DOMWINDOW == 6 (0x11a3cd000) [pid = 2004] [serial = 8] [outer = 0x11a140020]
01:42:53 INFO - GECKO(2002) | [Parent 2002, Main Thread] WARNING: Constructing RangeBoundary with invalid value: 'mRef || aOffset == 0', file /builds/worker/workspace/build/src/obj-firefox/dist/include/mozilla/RangeBoundary.h, line 79
01:42:53 INFO - GECKO(2002) | [Parent 2002, Main Thread] WARNING: Constructing RangeBoundary with invalid value: 'mRef || aOffset == 0', file /builds/worker/workspace/build/src/obj-firefox/dist/include/mozilla/RangeBoundary.h, line 79
01:42:53 INFO - GECKO(2002) | ++DOMWINDOW == 7 (0x12fb54800) [pid = 2004] [serial = 9] [outer = 0x11a140020]
01:42:54 INFO - GECKO(2002) | --DOCSHELL 0x11a90f000 == 4 [pid = 2005] [id = {38c15c4d-4219-3640-a7b8-c89205ae9293}] [url = about:blank]
01:42:54 INFO - GECKO(2002) | --DOCSHELL 0x114ae5800 == 3 [pid = 2005] [id = {06881a68-0cee-1243-bb56-5c9cf7dd56b1}] [url = about:blank]
01:42:54 INFO - GECKO(2002) | --DOCSHELL 0x114afd000 == 2 [pid = 2005] [id = {ff6701e9-72d7-e641-80fa-d0a986f20e61}] [url = http://example.com/browser/toolkit/components/pictureinpicture/tests/test-page.html]
01:42:54 INFO - GECKO(2002) | --DOMWINDOW == 14 (0x122287000) [pid = 2003] [serial = 6] [outer = 0x0] [url = about:blank]
01:42:54 INFO - GECKO(2002) | --DOMWINDOW == 13 (0x122295800) [pid = 2003] [serial = 9] [outer = 0x0] [url = about:blank]
01:42:54 INFO - GECKO(2002) | --DOMWINDOW == 12 (0x122466800) [pid = 2003] [serial = 10] [outer = 0x0] [url = about:blank]
01:42:54 INFO - GECKO(2002) | --DOMWINDOW == 11 (0x122293400) [pid = 2003] [serial = 7] [outer = 0x0] [url = about:blank]
01:42:54 INFO - GECKO(2002) | --DOMWINDOW == 10 (0x122294800) [pid = 2003] [serial = 8] [outer = 0x0] [url = about:blank]
01:42:54 INFO - GECKO(2002) | [Parent 2002, Compositor] WARNING: Framebuffer not complete -- CheckFramebufferStatus returned 0x8219, GLContext=125343000, IsOffscreen()=0, mFBO=0, aFBOTextureTarget=0x0, aRect.width=1280, aRect.height=1009: file /builds/worker/workspace/build/src/gfx/layers/opengl/CompositingRenderTargetOGL.cpp, line 64
01:42:54 INFO - GECKO(2002) | [Parent 2002, Compositor] WARNING: Framebuffer not complete -- CheckFramebufferStatus returned 0x8219, GLContext=125343000, IsOffscreen()=0, mFBO=0, aFBOTextureTarget=0x0, aRect.width=1280, aRect.height=1009: file /builds/worker/workspace/build/src/gfx/layers/opengl/CompositingRenderTargetOGL.cpp, line 64
01:42:54 INFO - GECKO(2002) | --DOMWINDOW == 9 (0x12224c980) [pid = 2003] [serial = 5] [outer = 0x0] [url = moz-extension://404141c9-ffba-3d43-915a-98c28bc63fb3/_generated_background_page.html]
01:42:54 INFO - GECKO(2002) | --DOCSHELL 0x11e009000 == 1 [pid = 2009] [id = {9a08e4ba-44a9-e443-9e37-737468a2fa96}] [url = http://example.com/browser/toolkit/components/pictureinpicture/tests/test-page.html]
01:42:56 INFO - GECKO(2002) | --DOMWINDOW == 2 (0x121c32400) [pid = 2006] [serial = 2] [outer = 0x0] [url = about:blank]
01:42:56 INFO - GECKO(2002) | --DOCSHELL 0x11c1e3800 == 0 [pid = 2008] [id = {fd3fe60a-4aab-2a46-9f6a-400b794b94b1}] [url = about:blank]
01:42:56 INFO - GECKO(2002) | --DOCSHELL 0x127f09800 == 1 [pid = 2011] [id = {e2bc5ad3-87c1-ef48-b7cd-0d273670a0fc}] [url = http://example.com/browser/toolkit/components/pictureinpicture/tests/test-page.html]
01:42:56 INFO - GECKO(2002) | [Child 2005, Main Thread] WARNING: No active window: file /builds/worker/workspace/build/src/js/xpconnect/src/XPCJSContext.cpp, line 662
01:42:56 INFO - GECKO(2002) | [Parent 2002, Main Thread] WARNING: Constructing RangeBoundary with invalid value: 'mRef || aOffset == 0', file /builds/worker/workspace/build/src/obj-firefox/dist/include/mozilla/RangeBoundary.h, line 79
01:42:56 INFO - GECKO(2002) | [Parent 2002, Main Thread] WARNING: Constructing RangeBoundary with invalid value: 'mRef || aOffset == 0', file /builds/worker/workspace/build/src/obj-firefox/dist/include/mozilla/RangeBoundary.h, line 79
01:42:56 INFO - GECKO(2002) | ++DOCSHELL 0x126a7b000 == 3 [pid = 2007] [id = {4f3cf89e-5a0e-5644-b145-b22ac157eedd}]
01:42:56 INFO - GECKO(2002) | ++DOMWINDOW == 11 (0x12684e880) [pid = 2007] [serial = 11] [outer = 0x0]
01:42:56 INFO - GECKO(2002) | [Child 2007, Main Thread] WARNING: No active window: file /builds/worker/workspace/build/src/js/xpconnect/src/XPCJSContext.cpp, line 662
01:42:56 INFO - GECKO(2002) | ++DOMWINDOW == 12 (0x11fcebc00) [pid = 2007] [serial = 12] [outer = 0x12684e880]
01:42:56 INFO - GECKO(2002) | [Parent 2002, Main Thread] WARNING: Constructing RangeBoundary with invalid value: 'mRef || aOffset == 0', file /builds/worker/workspace/build/src/obj-firefox/dist/include/mozilla/RangeBoundary.h, line 79
01:42:56 INFO - GECKO(2002) | [Parent 2002, Main Thread] WARNING: Constructing RangeBoundary with invalid value: 'mRef || aOffset == 0', file /builds/worker/workspace/build/src/obj-firefox/dist/include/mozilla/RangeBoundary.h, line 79
01:42:56 INFO - GECKO(2002) | [Child 2007, Main Thread] WARNING: No active window: file /builds/worker/workspace/build/src/js/xpconnect/src/XPCJSContext.cpp, line 662
01:42:56 INFO - GECKO(2002) | ++DOMWINDOW == 13 (0x1294a2800) [pid = 2007] [serial = 13] [outer = 0x12684e880]
01:42:57 INFO - GECKO(2002) | --DOMWINDOW == 12 (0x12682fc00) [pid = 2007] [serial = 2] [outer = 0x0] [url = about:blank]
01:42:57 INFO - GECKO(2002) | --DOMWINDOW == 11 (0x12749fc00) [pid = 2007] [serial = 7] [outer = 0x0] [url = about:blank]
01:42:57 INFO - GECKO(2002) | JavaScript error: , line 0: TypeError: The expression cannot be converted to return the specified type.
01:42:57 INFO - GECKO(2002) | --DOCSHELL 0x126a77000 == 2 [pid = 2007] [id = {fd480a74-ca47-d041-b560-8a3c75c604eb}] [url = http://example.com/browser/toolkit/components/pictureinpicture/tests/test-page.html]
01:42:57 INFO - GECKO(2002) | --DOMWINDOW == 6 (0x10bf24400) [pid = 2004] [serial = 3] [outer = 0x0] [url = about:blank]
01:42:57 INFO - GECKO(2002) | --DOMWINDOW == 5 (0x11a3cec00) [pid = 2004] [serial = 4] [outer = 0x0] [url = about:blank]
01:42:57 INFO - GECKO(2002) | --DOCSHELL 0x1145e4800 == 1 [pid = 2004] [id = {08157967-431f-f947-a1bc-60da48ab3866}] [url = about:blank]
01:42:57 INFO - GECKO(2002) | --DOCSHELL 0x1145e4000 == 0 [pid = 2004] [id = {aa4cadc1-2804-2a43-a3ea-a48b43b3affd}] [url = http://example.com/browser/toolkit/components/pictureinpicture/tests/test-page.html]
01:42:57 INFO - GECKO(2002) | --DOMWINDOW == 10 (0x12684e100) [pid = 2007] [serial = 4] [outer = 0x0] [url = about:blank]
01:42:57 INFO - GECKO(2002) | --DOMWINDOW == 9 (0x12684d020) [pid = 2007] [serial = 1] [outer = 0x0] [url = http://example.com/browser/toolkit/components/pictureinpicture/tests/test-page.html]
01:42:57 INFO - GECKO(2002) | --DOMWINDOW == 0 (0x11eb4c020) [pid = 2010] [serial = 1] [outer = 0x0] [url = ]
01:42:58 INFO - TEST-INFO | started process screencapture
01:42:58 INFO - TEST-INFO | screencapture: exit 0
01:42:58 INFO - Buffered messages logged at 01:42:53
01:42:58 INFO - Entering test bound
01:42:58 INFO - Console message: [JavaScript Error: "uncaught exception: Object" {file: "resource://testing-common/PromiseTestUtils.jsm" line: 112}]
01:42:58 INFO - Buffered messages logged at 01:42:54
01:42:58 INFO - TEST-PASS | toolkit/components/pictureinpicture/tests/browser_fullscreen.js | Toggle should be hidden in fullscreen mode. - true == true -
01:42:58 INFO - Buffered messages logged at 01:42:56
01:42:58 INFO - TEST-PASS | toolkit/components/pictureinpicture/tests/browser_fullscreen.js | Toggle should be hidden in fullscreen mode. - true == true -
01:42:58 INFO - Leaving test bound
01:42:58 INFO - Entering test bound
01:42:58 INFO - Buffered messages logged at 01:42:57
01:42:58 INFO - Console message: [JavaScript Warning: "Request for fullscreen was denied because requesting element is not in the currently focused tab." {file: "resource:///actors/DOMFullscreenChild.jsm" line: 20}]
01:42:58 INFO - Console message: [JavaScript Error: "TypeError: The expression cannot be converted to return the specified type."]
01:42:58 INFO - Buffered messages finished
01:42:58 INFO - TEST-UNEXPECTED-FAIL | toolkit/components/pictureinpicture/tests/browser_fullscreen.js | uncaught exception - Error: TelemetryStopwatch: key "FULLSCREEN_CHANGE_MS" was already initialized at handleEvent@chrome://browser/content/browser-fullScreenAndPointerLock.js:392:28
01:42:58 INFO - EventListener.handleEventinit@chrome://browser/content/browser-fullScreenAndPointerLock.js:260:12
01:42:58 INFO - _delayedStartup@chrome://browser/content/browser.js:1986:16
01:42:58 INFO - EventListener.handleEvent
onLoad@chrome://browser/content/browser.js:1849:12
01:42:58 INFO - EventHandlerNonNull*@chrome://browser/content/browser.xhtml:114:39
01:42:58 INFO -
01:42:58 INFO - Stack trace:
01:42:58 INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:simpletestOnerror:1665
01:42:58 INFO - chrome://browser/content/browser-fullScreenAndPointerLock.js:handleEvent:392
01:42:58 INFO - EventListener.handleEventchrome://browser/content/browser-fullScreenAndPointerLock.js:init:260
01:42:58 INFO - chrome://browser/content/browser.js:_delayedStartup:1986
01:42:58 INFO - chrome://browser/content/browser.js:onLoad:1849
01:42:58 INFO - chrome://browser/content/browser.xhtml:null:114
01:42:58 INFO - GECKO(2002) | JavaScript error: chrome://browser/content/browser-fullScreenAndPointerLock.js, line 392: Error: TelemetryStopwatch: key "FULLSCREEN_CHANGE_MS" was already initialized
01:42:58 INFO - Console message: [JavaScript Error: "Error: TelemetryStopwatch: key "FULLSCREEN_CHANGE_MS" was already initialized" {file: "chrome://browser/content/browser-fullScreenAndPointerLock.js" line: 392}]
01:42:58 INFO - handleEvent@chrome://browser/content/browser-fullScreenAndPointerLock.js:392:28
01:42:58 INFO - EventListener.handleEvent
init@chrome://browser/content/browser-fullScreenAndPointerLock.js:260:12
01:42:58 INFO - _delayedStartup@chrome://browser/content/browser.js:1986:16
01:42:58 INFO - EventListener.handleEventonLoad@chrome://browser/content/browser.js:1849:12
01:42:58 INFO - EventHandlerNonNull
@chrome://browser/content/browser.xhtml:114:39
01:42:58 INFO -
01:42:58 INFO - Not taking screenshot here: see the one that was previously logged
01:42:58 INFO - TEST-UNEXPECTED-FAIL | toolkit/components/pictureinpicture/tests/browser_fullscreen.js | Uncaught exception - TypeError: Argument 1 of Window.getComputedStyle does not implement interface Element.
01:42:58 INFO - Leaving test bound
01:42:58 INFO - GECKO(2002) | --DOCSHELL 0x11eb09000 == 0 [pid = 2010] [id = {48e0ef1d-683f-f746-a25a-a949731752cd}] [url = ]
01:42:58 INFO - GECKO(2002) | MEMORY STAT | vsize 7695MB | residentFast 416MB | heapAllocated 154MB
01:42:58 INFO - TEST-OK | toolkit/components/pictureinpicture/tests/browser_fullscreen.js | took 4656ms
01:42:58 INFO - Not taking screenshot here: see the one that was previously logged
01:42:58 INFO - TEST-UNEXPECTED-FAIL | toolkit/components/pictureinpicture/tests/browser_fullscreen.js | Found an unexpected tab at the end of test run: http://example.com/browser/toolkit/components/pictureinpicture/tests/test-page.html -
01:42:58 INFO - GECKO(2002) | [Parent 2002, Main Thread] WARNING: Constructing RangeBoundary with invalid value: 'mRef || aOffset == 0', file /builds/worker/workspace/build/src/obj-firefox/dist/include/mozilla/RangeBoundary.h, line 79
01:42:58 INFO - GECKO(2002) | [Parent 2002, Main Thread] WARNING: Constructing RangeBoundary with invalid value: 'mRef || aOffset == 0', file /builds/worker/workspace/build/src/obj-firefox/dist/include/mozilla/RangeBoundary.h, line 79
01:42:58 INFO - GECKO(2002) | ++DOCSHELL 0x112878000 == 1 [pid = 2004] [id = {760b5ca5-9be9-324e-8802-b508866f5d4c}]

:dolske - this appears to be a new intermittent failure unique to macosx1014/debug in mochitest-browser-chrome. macosx1014 is currently not running mochitest-browser-chrome, so this failure is not currently observed regularly in CI.

Being a new failure blocking the migration of mochitest-browser-chrome to macosx1014, I'd like to request a review of this test and decide if test should be fixed or disabled, thanks!

Flags: needinfo?(dolske)

There are 22 failures in the last 7 days on macosx1014-64 debug: https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?startday=2019-09-10&endday=2019-09-17&tree=trunk&bug=1566173

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

[task 2019-09-16T23:13:30.110Z] 23:13:30 INFO - TEST-PASS | toolkit/components/pictureinpicture/tests/browser_fullscreen.js | Toggle should be hidden in fullscreen mode. - true == true -
[task 2019-09-16T23:13:30.110Z] 23:13:30 INFO - Buffered messages logged at 23:13:28
[task 2019-09-16T23:13:30.110Z] 23:13:30 INFO - Leaving test bound
[task 2019-09-16T23:13:30.110Z] 23:13:30 INFO - Entering test bound
[task 2019-09-16T23:13:30.110Z] 23:13:30 INFO - Buffered messages logged at 23:13:29
[task 2019-09-16T23:13:30.110Z] 23:13:30 INFO - Console message: [JavaScript Warning: "Request for fullscreen was denied because requesting element is not in the currently focused tab." {file: "resource:///actors/DOMFullscreenChild.jsm" line: 20}]
[task 2019-09-16T23:13:30.111Z] 23:13:30 INFO - Console message: [JavaScript Error: "TypeError: The expression cannot be converted to return the specified type."]
[task 2019-09-16T23:13:30.111Z] 23:13:30 INFO - Buffered messages finished
[task 2019-09-16T23:13:30.111Z] 23:13:30 INFO - TEST-UNEXPECTED-FAIL | toolkit/components/pictureinpicture/tests/browser_fullscreen.js | uncaught exception - Error: TelemetryStopwatch: key "FULLSCREEN_CHANGE_MS" was already initialized at handleEvent@chrome://browser/content/browser-fullScreenAndPointerLock.js:407:28
[task 2019-09-16T23:13:30.111Z] 23:13:30 INFO - EventListener.handleEventinit@chrome://browser/content/browser-fullScreenAndPointerLock.js:274:12
[task 2019-09-16T23:13:30.111Z] 23:13:30 INFO - _delayedStartup@chrome://browser/content/browser.js:2094:16
[task 2019-09-16T23:13:30.111Z] 23:13:30 INFO - EventListener.handleEvent
onLoad@chrome://browser/content/browser.js:1904:12
[task 2019-09-16T23:13:30.111Z] 23:13:30 INFO - EventHandlerNonNull*@chrome://browser/content/browser.xhtml:120:39
[task 2019-09-16T23:13:30.111Z] 23:13:30 INFO -
[task 2019-09-16T23:13:30.111Z] 23:13:30 INFO - Stack trace:
[task 2019-09-16T23:13:30.111Z] 23:13:30 INFO - chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:simpletestOnerror:1667
[task 2019-09-16T23:13:30.112Z] 23:13:30 INFO - chrome://browser/content/browser-fullScreenAndPointerLock.js:handleEvent:407
[task 2019-09-16T23:13:30.112Z] 23:13:30 INFO - EventListener.handleEventchrome://browser/content/browser-fullScreenAndPointerLock.js:init:274
[task 2019-09-16T23:13:30.112Z] 23:13:30 INFO - chrome://browser/content/browser.js:_delayedStartup:2094
[task 2019-09-16T23:13:30.112Z] 23:13:30 INFO - chrome://browser/content/browser.js:onLoad:1904
[task 2019-09-16T23:13:30.112Z] 23:13:30 INFO - chrome://browser/content/browser.xhtml:null:120
[task 2019-09-16T23:13:30.112Z] 23:13:30 INFO - GECKO(1923) | JavaScript error: chrome://browser/content/browser-fullScreenAndPointerLock.js, line 407: Error: TelemetryStopwatch: key "FULLSCREEN_CHANGE_MS" was already initialized
[task 2019-09-16T23:13:30.112Z] 23:13:30 INFO - Console message: [JavaScript Error: "Error: TelemetryStopwatch: key "FULLSCREEN_CHANGE_MS" was already initialized" {file: "chrome://browser/content/browser-fullScreenAndPointerLock.js" line: 407}]
[task 2019-09-16T23:13:30.112Z] 23:13:30 INFO - handleEvent@chrome://browser/content/browser-fullScreenAndPointerLock.js:407:28
[task 2019-09-16T23:13:30.112Z] 23:13:30 INFO - EventListener.handleEvent
init@chrome://browser/content/browser-fullScreenAndPointerLock.js:274:12
[task 2019-09-16T23:13:30.112Z] 23:13:30 INFO - _delayedStartup@chrome://browser/content/browser.js:2094:16
[task 2019-09-16T23:13:30.112Z] 23:13:30 INFO - EventListener.handleEventonLoad@chrome://browser/content/browser.js:1904:12
[task 2019-09-16T23:13:30.113Z] 23:13:30 INFO - EventHandlerNonNull
@chrome://browser/content/browser.xhtml:120:39
[task 2019-09-16T23:13:30.113Z] 23:13:30 INFO -
[task 2019-09-16T23:13:30.113Z] 23:13:30 INFO - GECKO(1923) | --DOMWINDOW == 6 (0x12059c800) [pid = 1924] [serial = 12] [outer = 0x0] [url = moz-extension://d9c86f6d-edb6-5845-8699-4a7e0222de89/_generated_background_page.html]
[task 2019-09-16T23:13:30.113Z] 23:13:30 INFO - Not taking screenshot here: see the one that was previously logged
[task 2019-09-16T23:13:30.113Z] 23:13:30 INFO - TEST-UNEXPECTED-FAIL | toolkit/components/pictureinpicture/tests/browser_fullscreen.js | Toggle should be hidden in fullscreen mode. - false == true -

Justin, any insight on this?

Keywords: leave-open
Whiteboard: [stockwell disabled]
Pushed by csabou@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/366b78b3f763
Disable browser_fullscreen.js on mac debug cause of frequent failures. r=gbrown

Looks like this is a PIP test, so forwarding NI to Mike for at least info.

Flags: needinfo?(dolske) → needinfo?(mconley)
You need to log in before you can comment on or make changes to this bug.