1679481 - Intermittent dom/media/mediacontrol/tests/browser/browser_media_control_before_media_starts.js | Uncaught exception - Video is being cloned visually. - timed out after 50 tries.

Status: RESOLVED INCOMPLETE

(Core :: Audio/Video, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: nerli [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=322844401&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/IppPSYSuS7GSK7eiDaKg4Q/runs/0/artifacts/public/logs/live_backing.log

---

[task 2020-11-26T23:07:26.427Z] 23:07:26     INFO - TEST-START | dom/media/mediacontrol/tests/browser/browser_media_control_before_media_starts.js
[task 2020-11-26T23:07:26.796Z] 23:07:26     INFO - GECKO(10051) | 1606432046792	Marionette	TRACE	Received observer notification toplevel-window-ready
[task 2020-11-26T23:07:27.460Z] 23:07:27     INFO - GECKO(10051) | 1606432047455	Marionette	TRACE	Received observer notification toplevel-window-ready
[task 2020-11-26T23:07:27.678Z] 23:07:27     INFO - GECKO(10051) | IPDL protocol error: Handler returned error code!
[task 2020-11-26T23:07:27.679Z] 23:07:27     INFO - GECKO(10051) | ###!!! [Parent][DispatchAsyncMessage] Error: PLayerTransaction::Msg_ReleaseLayer Processing error: message was deserialized, but the handler returned false (indicating failure)
[task 2020-11-26T23:07:27.679Z] 23:07:27     INFO - GECKO(10051) | IPDL protocol error: Handler returned error code!
[task 2020-11-26T23:07:27.680Z] 23:07:27     INFO - GECKO(10051) | ###!!! [Parent][DispatchAsyncMessage] Error: PLayerTransaction::Msg_ReleaseLayer Processing error: message was deserialized, but the handler returned false (indicating failure)
[task 2020-11-26T23:07:27.681Z] 23:07:27     INFO - GECKO(10051) | IPDL protocol error: Handler returned error code!
[task 2020-11-26T23:07:27.681Z] 23:07:27     INFO - GECKO(10051) | ###!!! [Parent][DispatchAsyncMessage] Error: PLayerTransaction::Msg_ReleaseLayer Processing error: message was deserialized, but the handler returned false (indicating failure)
[task 2020-11-26T23:07:27.681Z] 23:07:27     INFO - GECKO(10051) | IPDL protocol error: Handler returned error code!
[task 2020-11-26T23:07:27.681Z] 23:07:27     INFO - GECKO(10051) | ###!!! [Parent][DispatchAsyncMessage] Error: PLayerTransaction::Msg_ReleaseLayer Processing error: message was deserialized, but the handler returned false (indicating failure)
[task 2020-11-26T23:07:27.681Z] 23:07:27     INFO - GECKO(10051) | IPDL protocol error: Handler returned error code!
[task 2020-11-26T23:07:27.681Z] 23:07:27     INFO - GECKO(10051) | ###!!! [Parent][DispatchAsyncMessage] Error: PLayerTransaction::Msg_ReleaseLayer Processing error: message was deserialized, but the handler returned false (indicating failure)
[task 2020-11-26T23:07:32.584Z] 23:07:32     INFO - TEST-INFO | started process screentopng
[task 2020-11-26T23:07:32.807Z] 23:07:32     INFO - TEST-INFO | screentopng: exit 0
[task 2020-11-26T23:07:32.808Z] 23:07:32     INFO - Buffered messages logged at 23:07:26
[task 2020-11-26T23:07:32.808Z] 23:07:32     INFO - Entering test bound setupTestingPref
[task 2020-11-26T23:07:32.808Z] 23:07:32     INFO - Leaving test bound setupTestingPref
[task 2020-11-26T23:07:32.809Z] 23:07:32     INFO - Entering test bound testMediaEntersPIPMode
[task 2020-11-26T23:07:32.809Z] 23:07:32     INFO - open media page
[task 2020-11-26T23:07:32.810Z] 23:07:32     INFO - Console message: [JavaScript Error: "The character encoding of the HTML document was not declared. The document will render with garbled text in some browser configurations if the document contains characters from outside the US-ASCII range. The character encoding of the page must be declared in the document or in the transfer protocol." {file: "https://example.com/browser/dom/media/mediacontrol/tests/browser/file_non_autoplay.html" line: 0}]
[task 2020-11-26T23:07:32.811Z] 23:07:32     INFO - trigger PIP mode
[task 2020-11-26T23:07:32.812Z] 23:07:32     INFO - Buffered messages logged at 23:07:27
[task 2020-11-26T23:07:32.812Z] 23:07:32     INFO - handle event=activated
[task 2020-11-26T23:07:32.812Z] 23:07:32     INFO - press 'play' and wait until media starts
[task 2020-11-26T23:07:32.813Z] 23:07:32     INFO - handle event=playbackstatechange
[task 2020-11-26T23:07:32.813Z] 23:07:32     INFO - TEST-PASS | dom/media/mediacontrol/tests/browser/browser_media_control_before_media_starts.js | media started playing - true == true - 
[task 2020-11-26T23:07:32.813Z] 23:07:32     INFO - remove tab
[task 2020-11-26T23:07:32.814Z] 23:07:32     INFO - wait until finishing close tab wrapper
[task 2020-11-26T23:07:32.814Z] 23:07:32     INFO - handle event=deactivated
[task 2020-11-26T23:07:32.815Z] 23:07:32     INFO - TEST-PASS | dom/media/mediacontrol/tests/browser/browser_media_control_before_media_starts.js | First event should be 'activated' - 
[task 2020-11-26T23:07:32.816Z] 23:07:32     INFO - TEST-PASS | dom/media/mediacontrol/tests/browser/browser_media_control_before_media_starts.js | Last event should be 'deactivated' - 
[task 2020-11-26T23:07:32.816Z] 23:07:32     INFO - Leaving test bound testMediaEntersPIPMode
[task 2020-11-26T23:07:32.816Z] 23:07:32     INFO - Entering test bound testMutedMediaEntersPIPMode
[task 2020-11-26T23:07:32.816Z] 23:07:32     INFO - open media page and mute video
[task 2020-11-26T23:07:32.817Z] 23:07:32     INFO - Console message: [JavaScript Warning: "Cannot play media. No decoders for requested formats: video/mp4" {file: "https://example.com/browser/dom/media/mediacontrol/tests/browser/file_iframe_media.html" line: 0}]
[task 2020-11-26T23:07:32.818Z] 23:07:32     INFO - Console message: [JavaScript Error: "The character encoding of the HTML document was not declared. The document will render with garbled text in some browser configurations if the document contains characters from outside the US-ASCII range. The character encoding of the page must be declared in the document or in the transfer protocol." {file: "https://example.com/browser/dom/media/mediacontrol/tests/browser/file_non_autoplay.html" line: 0}]
[task 2020-11-26T23:07:32.818Z] 23:07:32     INFO - trigger PIP mode
[task 2020-11-26T23:07:32.819Z] 23:07:32     INFO - handle event=activated
[task 2020-11-26T23:07:32.819Z] 23:07:32     INFO - Console message: [JavaScript Warning: "Cannot play media. No decoders for requested formats: video/mp4" {file: "https://example.com/browser/dom/media/mediacontrol/tests/browser/file_non_autoplay.html" line: 0}]
[task 2020-11-26T23:07:32.819Z] 23:07:32     INFO - Buffered messages finished
[task 2020-11-26T23:07:32.820Z] 23:07:32     INFO - TEST-UNEXPECTED-FAIL | dom/media/mediacontrol/tests/browser/browser_media_control_before_media_starts.js | Uncaught exception - Video is being cloned visually. - timed out after 50 tries.
[task 2020-11-26T23:07:32.820Z] 23:07:32     INFO - Leaving test bound testMutedMediaEntersPIPMode
[task 2020-11-26T23:07:32.820Z] 23:07:32     INFO - Entering test bound testMediaEntersFullScreen
[task 2020-11-26T23:07:32.821Z] 23:07:32     INFO - open media page
[task 2020-11-26T23:07:32.821Z] 23:07:32     INFO - Console message: [JavaScript Error: "The character encoding of the HTML document was not declared. The document will render with garbled text in some browser configurations if the document contains characters from outside the US-ASCII range. The character encoding of the page must be declared in the document or in the transfer protocol." {file: "https://example.com/browser/dom/media/mediacontrol/tests/browser/file_non_autoplay.html" line: 0}]
[task 2020-11-26T23:07:32.908Z] 23:07:32     INFO - make video fullscreen
[task 2020-11-26T23:07:33.087Z] 23:07:33     INFO - handle event=activated
[task 2020-11-26T23:07:33.087Z] 23:07:33     INFO - press 'play' and wait until media starts
[task 2020-11-26T23:07:33.128Z] 23:07:33     INFO - handle event=playbackstatechange
[task 2020-11-26T23:07:33.132Z] 23:07:33     INFO - TEST-PASS | dom/media/mediacontrol/tests/browser/browser_media_control_before_media_starts.js | media started playing - true == true - 
[task 2020-11-26T23:07:33.139Z] 23:07:33     INFO - remove tab
[task 2020-11-26T23:07:33.139Z] 23:07:33     INFO - wait until finishing close tab wrapper
[task 2020-11-26T23:07:33.163Z] 23:07:33     INFO - Console message: [JavaScript Warning: "Exited fullscreen because fullscreen element was removed from document." {file: "chrome://browser/content/tabbrowser.js" line: 3726}]
[task 2020-11-26T23:07:33.163Z] 23:07:33     INFO - handle event=deactivated
[task 2020-11-26T23:07:33.163Z] 23:07:33     INFO - TEST-PASS | dom/media/mediacontrol/tests/browser/browser_media_control_before_media_starts.js | First event should be 'activated' - 
[task 2020-11-26T23:07:33.171Z] 23:07:33     INFO - TEST-PASS | dom/media/mediacontrol/tests/browser/browser_media_control_before_media_starts.js | Last event should be 'deactivated' - 
[task 2020-11-26T23:07:33.171Z] 23:07:33     INFO - Leaving test bound testMediaEntersFullScreen
[task 2020-11-26T23:07:33.171Z] 23:07:33     INFO - Entering test bound testMutedMediaEntersFullScreen
[task 2020-11-26T23:07:33.172Z] 23:07:33     INFO - open media page and mute video
[task 2020-11-26T23:07:33.415Z] 23:07:33     INFO - Console message: [JavaScript Error: "The character encoding of the HTML document was not declared. The document will render with garbled text in some browser configurations if the document contains characters from outside the US-ASCII range. The character encoding of the page must be declared in the document or in the transfer protocol." {file: "https://example.com/browser/dom/media/mediacontrol/tests/browser/file_non_autoplay.html" line: 0}]
[task 2020-11-26T23:07:33.511Z] 23:07:33     INFO - make video fullscreen
[task 2020-11-26T23:07:33.547Z] 23:07:33     INFO - GECKO(10051) | JavaScript error: resource:///actors/DOMFullscreenParent.jsm, line 130: Error: TelemetryStopwatch: key "FULLSCREEN_CHANGE_MS" was already initialized
[task 2020-11-26T23:07:33.603Z] 23:07:33     INFO - Console message: [JavaScript Error: "Error: TelemetryStopwatch: key "FULLSCREEN_CHANGE_MS" was already initialized" {file: "resource:///actors/DOMFullscreenParent.jsm" line: 130}]
[task 2020-11-26T23:07:33.603Z] 23:07:33     INFO - handleEvent@resource:///actors/DOMFullscreenParent.jsm:130:28
[task 2020-11-26T23:07:33.603Z] 23:07:33     INFO - 
[task 2020-11-26T23:07:33.604Z] 23:07:33     INFO - handle event=activated
[task 2020-11-26T23:07:33.620Z] 23:07:33     INFO - press 'play' and wait until media starts
[task 2020-11-26T23:07:33.723Z] 23:07:33     INFO - handle event=playbackstatechange
[task 2020-11-26T23:07:33.731Z] 23:07:33     INFO - TEST-PASS | dom/media/mediacontrol/tests/browser/browser_media_control_before_media_starts.js | media started playing - true == true - 
[task 2020-11-26T23:07:33.732Z] 23:07:33     INFO - remove tab
[task 2020-11-26T23:07:33.733Z] 23:07:33     INFO - wait until finishing close tab wrapper
[task 2020-11-26T23:07:33.774Z] 23:07:33     INFO - Console message: [JavaScript Warning: "Exited fullscreen because fullscreen element was removed from document." {file: "chrome://browser/content/tabbrowser.js" line: 3726}]
[task 2020-11-26T23:07:33.774Z] 23:07:33     INFO - handle event=deactivated```

Comment 1

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 2

Platform breakdown:

• linux1804-64-ccov: 2

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

Comment 2

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 1

Platform breakdown:

• linux1804-64-ccov: 1

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

Comment 3

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 1

Platform breakdown:

• linux1804-64-ccov: 1

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

Comment 4

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 1

Platform breakdown:

• linux1804-64-ccov: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1679481&startday=2020-12-28&endday=2021-01-03&tree=all

Comment 5

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 1

Platform breakdown:

• linux1804-64-ccov: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1679481&startday=2021-01-04&endday=2021-01-10&tree=all

Comment 6

[BugBot [:suhaib / :marco]]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.