1592835 - Intermittent toolkit/components/pictureinpicture/tests/browser_toggleSimple.js | Uncaught exception - [Exception... "Component is not available" nsresult: "0x80040111 (NS_ERROR_NOT_AVAILABLE)" location: "<unknown>" data: no]

Status: RESOLVED WORKSFORME

(Toolkit :: General, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: apavel [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=273778736&repo=autoland
Full log: https://queue.taskcluster.net/v1/task/JK8zC5dfT7Gkrdf-N26gtg/runs/0/artifacts/public/logs/live_backing.log

---

[task 2019-10-30T22:36:16.153Z] 22:36:16 INFO - TEST-START | toolkit/components/pictureinpicture/tests/browser_toggleSimple.js
[task 2019-10-30T22:36:16.173Z] 22:36:16 INFO - GECKO(1942) | ++DOCSHELL 0x114625000 == 3 [pid = 1945] [id = {013ec09e-935f-9e4f-bfe3-7edb5d07b65c}]
[task 2019-10-30T22:36:16.173Z] 22:36:16 INFO - GECKO(1942) | ++DOMWINDOW == 12 (0x11c4523e0) [pid = 1945] [serial = 50] [outer = 0x0]
[task 2019-10-30T22:36:16.173Z] 22:36:16 INFO - GECKO(1942) | ++DOMWINDOW == 13 (0x114837800) [pid = 1945] [serial = 51] [outer = 0x11c4523e0]
[task 2019-10-30T22:36:16.310Z] 22:36:16 INFO - GECKO(1942) | ++DOMWINDOW == 14 (0x114951000) [pid = 1945] [serial = 52] [outer = 0x11c4523e0]
[task 2019-10-30T22:36:17.120Z] 22:36:17 INFO - GECKO(1942) | --DOMWINDOW == 29 (0x11e5494c0) [pid = 1942] [serial = 44] [outer = 0x0] [url = about:blank]
[task 2019-10-30T22:36:17.120Z] 22:36:17 INFO - GECKO(1942) | --DOMWINDOW == 28 (0x13103cd40) [pid = 1942] [serial = 42] [outer = 0x0] [url = about:blank]
[task 2019-10-30T22:36:17.121Z] 22:36:17 INFO - GECKO(1942) | --DOMWINDOW == 27 (0x11e548f20) [pid = 1942] [serial = 40] [outer = 0x0] [url = about:blank]
[task 2019-10-30T22:36:17.121Z] 22:36:17 INFO - GECKO(1942) | --DOMWINDOW == 26 (0x11e548d40) [pid = 1942] [serial = 36] [outer = 0x0] [url = chrome://global/content/pictureinpicture/player.xhtml]
[task 2019-10-30T22:36:17.485Z] 22:36:17 INFO - GECKO(1942) | --DOCSHELL 0x112249000 == 0 [pid = 1948] [id = {011a474d-f98e-674d-85a1-0201c48ee16a}] [url = about:blank]
[task 2019-10-30T22:36:17.552Z] 22:36:17 INFO - GECKO(1942) | --DOMWINDOW == 2 (0x120d51020) [pid = 1948] [serial = 7] [outer = 0x0] [url = about:blank]
[task 2019-10-30T22:36:17.867Z] 22:36:17 INFO - GECKO(1942) | --DOMWINDOW == 10 (0x11d811000) [pid = 1946] [serial = 31] [outer = 0x0] [url = about:blank]
[task 2019-10-30T22:36:17.868Z] 22:36:17 INFO - GECKO(1942) | --DOMWINDOW == 9 (0x11d75d400) [pid = 1946] [serial = 39] [outer = 0x0] [url = about:blank]
[task 2019-10-30T22:36:17.868Z] 22:36:17 INFO - GECKO(1942) | --DOMWINDOW == 8 (0x11d75b400) [pid = 1946] [serial = 41] [outer = 0x0] [url = about:blank]
[task 2019-10-30T22:36:17.868Z] 22:36:17 INFO - GECKO(1942) | --DOMWINDOW == 7 (0x11d817800) [pid = 1946] [serial = 34] [outer = 0x0] [url = about:blank]
[task 2019-10-30T22:36:17.868Z] 22:36:17 INFO - GECKO(1942) | --DOCSHELL 0x11d8a1000 == 1 [pid = 1946] [id = {f80d6e3f-272e-a345-8513-89b4ffb1e80c}] [url = about:blank]
[task 2019-10-30T22:36:18.033Z] 22:36:18 INFO - GECKO(1942) | --DOMWINDOW == 6 (0x12524c020) [pid = 1946] [serial = 35] [outer = 0x0] [url = http://example.com/browser/toolkit/components/pictureinpicture/tests/test-page.html]
[task 2019-10-30T22:36:18.266Z] 22:36:18 INFO - GECKO(1942) | [Parent 1942, Main Thread] WARNING: IPC message discarded: actor cannot send: file /builds/worker/workspace/build/src/ipc/glue/ProtocolUtils.cpp, line 481
[task 2019-10-30T22:36:18.267Z] 22:36:18 INFO - GECKO(1942) | [Parent 1942, Main Thread] WARNING: IPC message discarded: actor cannot send: file /builds/worker/workspace/build/src/ipc/glue/ProtocolUtils.cpp, line 481
[task 2019-10-30T22:36:18.267Z] 22:36:18 INFO - TEST-INFO | started process screencapture
[task 2019-10-30T22:36:18.453Z] 22:36:18 INFO - TEST-INFO | screencapture: exit 0
[task 2019-10-30T22:36:18.461Z] 22:36:18 INFO - Buffered messages logged at 22:36:16
[task 2019-10-30T22:36:18.461Z] 22:36:18 INFO - Entering test bound
[task 2019-10-30T22:36:18.463Z] 22:36:18 INFO - Waiting for videos to be ready
[task 2019-10-30T22:36:18.463Z] 22:36:18 INFO - Testing video with id: with-controls
[task 2019-10-30T22:36:18.463Z] 22:36:18 INFO - Waiting for toggle to become visible
[task 2019-10-30T22:36:18.463Z] 22:36:18 INFO - Buffered messages logged at 22:36:17
[task 2019-10-30T22:36:18.464Z] 22:36:18 INFO - TEST-PASS | toolkit/components/pictureinpicture/tests/browser_toggleSimple.js | Toggle reached target opacity. - true == true -
[task 2019-10-30T22:36:18.464Z] 22:36:18 INFO - Hovering the toggle rect now.
[task 2019-10-30T22:36:18.467Z] 22:36:18 INFO - TEST-PASS | toolkit/components/pictureinpicture/tests/browser_toggleSimple.js | Toggle reached target opacity. - true == true -
[task 2019-10-30T22:36:18.468Z] 22:36:18 INFO - Right-clicking on toggle.
[task 2019-10-30T22:36:18.468Z] 22:36:18 INFO - TEST-PASS | toolkit/components/pictureinpicture/tests/browser_toggleSimple.js | Expected to get the right mouse events. - [] deepEqual [] -
[task 2019-10-30T22:36:18.468Z] 22:36:18 INFO - TEST-PASS | toolkit/components/pictureinpicture/tests/browser_toggleSimple.js | No Picture-in-Picture window found. -
[task 2019-10-30T22:36:18.469Z] 22:36:18 INFO - Clicking on toggle, and expecting a Picture-in-Picture window to open
[task 2019-10-30T22:36:18.469Z] 22:36:18 INFO - Buffered messages finished
[task 2019-10-30T22:36:18.469Z] 22:36:18 INFO - TEST-UNEXPECTED-FAIL | toolkit/components/pictureinpicture/tests/browser_toggleSimple.js | Uncaught exception - [Exception... "Component is not available" nsresult: "0x80040111 (NS_ERROR_NOT_AVAILABLE)" location: "<unknown>" data: no]
[task 2019-10-30T22:36:18.469Z] 22:36:18 INFO - Leaving test bound
[task 2019-10-30T22:36:18.469Z] 22:36:18 INFO - GECKO(1942) | ++DOCSHELL 0x11bf1b000 == 9 [pid = 1942] [id = {13a75d29-9dfa-c341-a2bd-ece0c2363b07}]
[task 2019-10-30T22:36:18.469Z] 22:36:18 INFO - GECKO(1942) | ++DOMWINDOW == 27 (0x11e548020) [pid = 1942] [serial = 56] [outer = 0x0]
[task 2019-10-30T22:36:18.469Z] 22:36:18 INFO - GECKO(1942) | ++DOMWINDOW == 28 (0x11bf31400) [pid = 1942] [serial = 57] [outer = 0x11e548020]
[task 2019-10-30T22:36:18.471Z] 22:36:18 INFO - Console message: [JavaScript Error: "remote browser crashed while on http://example.com/browser/toolkit/components/pictureinpicture/tests/test-page.html
[task 2019-10-30T22:36:18.471Z] 22:36:18 INFO - " {file: "chrome://mochikit/content/mochitest-e10s-utils.js" line: 10}]
[task 2019-10-30T22:36:18.471Z] 22:36:18 INFO - e10s_init/<@chrome://mochikit/content/mochitest-e10s-utils.js:10:10
[task 2019-10-30T22:36:18.471Z] 22:36:18 INFO - EventListener.handleEvente10s_init@chrome://mochikit/content/mochitest-e10s-utils.js:6:10
[task 2019-10-30T22:36:18.471Z] 22:36:18 INFO - testInit@chrome://mochikit/content/browser-test.js:130:5
[task 2019-10-30T22:36:18.471Z] 22:36:18 INFO - setTimeout handler@chrome://mochikit/content/browser-test.js:40:11
[task 2019-10-30T22:36:18.472Z] 22:36:18 INFO - loadChromeScripts@jar:file:///var/folders/46/7l78jpwn6pg7v1b63gq7p834000017/T/tmpRKsvIv.mozrunner/extensions/[e-mail]!/api.js:21:25
[task 2019-10-30T22:36:18.472Z] 22:36:18 INFO - loadMochitest@jar:file:///var/folders/46/7l78jpwn6pg7v1b63gq7p834000017/T/tmpRKsvIv.mozrunner/extensions/[e-mail]!/api.js:143:20
[task 2019-10-30T22:36:18.472Z] 22:36:18 INFO - @tests/mochitest/runtests.py:1794:5
[task 2019-10-30T22:36:18.472Z] 22:36:18 INFO - @tests/mochitest/runtests.py:1795:8
[task 2019-10-30T22:36:18.472Z] 22:36:18 INFO - evaluate.sandbox/promise<@chrome://marionette/content/evaluate.js:138:10
[task 2019-10-30T22:36:18.472Z] 22:36:18 INFO - evaluate.sandbox@chrome://marionette/content/evaluate.js:114:17
[task 2019-10-30T22:36:18.472Z] 22:36:18 INFO - GeckoDriver.prototype.execute_@chrome://marionette/content/driver.js:1068:28
[task 2019-10-30T22:36:18.472Z] 22:36:18 INFO - async*GeckoDriver.prototype.executeScript@chrome://marionette/content/driver.js:943:30
[task 2019-10-30T22:36:18.472Z] 22:36:18 INFO - despatch@chrome://marionette/content/server.js:305:40
[task 2019-10-30T22:36:18.472Z] 22:36:18 INFO - execute@chrome://marionette/content/server.js:275:16
[task 2019-10-30T22:36:18.472Z] 22:36:18 INFO - onPacket/<@chrome://marionette/content/server.js:248:20
[task 2019-10-30T22:36:18.472Z] 22:36:18 INFO - onPacket@chrome://marionette/content/server.js:249:9
[task 2019-10-30T22:36:18.472Z] 22:36:18 INFO - _onJSONObjectReady/<@chrome://marionette/content/transport.js:501:20
[task 2019-10-30T22:36:18.473Z] 22:36:18 INFO -
[task 2019-10-30T22:36:18.473Z] 22:36:18 INFO - GECKO(1942) | ++DOMWINDOW == 29 (0x116faf800) [pid = 1942] [serial = 58] [outer = 0x11e548020]
[task 2019-10-30T22:36:18.474Z] 22:36:18 INFO - GECKO(1942) | MEMORY STAT | vsize 7618MB | residentFast 351MB | heapAllocated 129MB
[task 2019-10-30T22:36:18.474Z] 22:36:18 INFO - TEST-OK | toolkit/components/pictureinpicture/tests/browser_toggleSimple.js | took 2272ms
[task 2019-10-30T22:36:18.474Z] 22:36:18 INFO - Not taking screenshot here: see the one that was previously logged
[task 2019-10-30T22:36:18.475Z] 22:36:18 INFO - TEST-UNEXPECTED-FAIL | toolkit/components/pictureinpicture/tests/browser_toggleSimple.js | Found an unexpected tab at the end of test run: http://example.com/browser/toolkit/components/pictureinpicture/tests/test-page.html -
[task 2019-10-30T22:36:18.475Z] 22:36:18 INFO - GECKO(1942) | [Parent 1942, Main Thread] WARNING: '!inner', file /builds/worker/workspace/build/src/dom/ipc/JSWindowActorService.cpp, line 172
[task 2019-10-30T22:36:18.535Z] 22:36:18 INFO - GECKO(1942) | [1956, MainThread] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file /builds/worker/workspace/build/src/xpcom/base/nsTraceRefcnt.cpp, line 198
[task 2019-10-30T22:36:18.535Z] 22:36:18 INFO - GECKO(1942) | [1956, MainThread] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file /builds/worker/workspace/build/src/xpcom/base/nsTraceRefcnt.cpp, line 198
[task 2019-10-30T22:36:18.535Z] 22:36:18 INFO - GECKO(1942) | ### XPCOM_MEM_BLOAT_LOG defined -- logging bloat/leaks to /var/folders/46/7l78jpwn6pg7v1b63gq7p834000017/T/tmpRKsvIv.mozrunner/runtests_leaks_tab_pid1956.log
[task 2019-10-30T22:36:18.537Z] 22:36:18 INFO - GECKO(1942) | [1956, MainThread] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file /builds/worker/workspace/build/src/xpcom/base/nsTraceRefcnt.cpp, line 198
[task 2019-10-30T22:36:18.537Z] 22:36:18 INFO - GECKO(1942) | [1956, MainThread] WARNING: XPCOM objects created/destroyed from static ctor/dtor: file /builds/worker/workspace/build/src/xpcom/base/nsTraceRefcnt.cpp, line 198
[task 2019-10-30T22:36:18.568Z] 22:36:18 INFO - checking window state
[task 2019-10-30T22:36:18.646Z] 22:36:18 INFO - GECKO(1942) | [Child 1956, Main Thread] WARNING: No CID found when attempting to map contract ID: file /builds/worker/workspace/build/src/xpcom/components/nsComponentManager.cpp, line 729

Comment 1

[Andreea Pavel [:apavel]]

Hi Ting-Yu, there has been an increase in failures of this sort: https://bugzilla.mozilla.org/buglist.cgi?quicksearch=toggle%20Exception...%20%22Component%20is%20not%20available%22%20nsresu&list_id=14967948

or: https://bugzilla.mozilla.org/buglist.cgi?quicksearch=toolkit%2Fcomponents%2Fpictureinpicture%2Ftests%2Fbrowser_toggle&list_id=14967960

Could that be due to bug 1590185?

Comment 2

[Ting-Yu Lin [:TYLin] (PDT, UTC-7)]

Could that be due to bug 1590185?

It is unlikely that bug 1590185 can cause this kind of failures, because it added a functionality that is available only when a developer running ./mach run --layoutdebug in debug build.

Comment 3

[Andreea Pavel [:apavel]]

Fixed by backout: https://bugzilla.mozilla.org/show_bug.cgi?id=1588220#c4

Comment 4

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 1

Platform breakdown:

• macosx1014-64: 1

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