Closed Bug 1663104 Opened 4 years ago Closed 2 years ago

Intermittent dom/media/mediacontrol/tests/browser/browser_default_action_handler.js | Test timed out -

Categories

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

defect

Tracking

()

RESOLVED DUPLICATE of bug 1775888
Tracking Status
firefox-esr68 --- unaffected
firefox-esr78 --- unaffected
firefox80 --- unaffected
firefox81 --- unaffected
firefox82 --- affected

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Blocks 1 open bug, Regression)

Details

(Keywords: intermittent-failure, regression)

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


[task 2020-09-04T04:41:38.795Z] 04:41:38 INFO - Console message: [JavaScript Warning: "Media resource https://example.org/browser/dom/media/mediacontrol/tests/gizmo.mp4 could not be decoded, error: Error Code: NS_ERROR_DOM_MEDIA_DECODE_ERR (0x806e0004)
[task 2020-09-04T04:41:38.795Z] 04:41:38 INFO - Details: virtual mozilla::MediaResult mozilla::FFmpegAudioDecoder<57>::DoDecode(mozilla::MediaRawData *, uint8_t *, int, bool *, mozilla::MediaDataDecoder::DecodedData &): FFmpeg audio error:-1094995529" {file: "https://example.org/browser/dom/media/mediacontrol/tests/file_iframe_media.html" line: 0}]
[task 2020-09-04T04:41:38.796Z] 04:41:38 INFO - Buffered messages finished
[task 2020-09-04T04:41:38.797Z] 04:41:38 INFO - TEST-UNEXPECTED-FAIL | dom/media/mediacontrol/tests/browser_default_action_handler.js | Test timed out -
[task 2020-09-04T04:41:38.797Z] 04:41:38 INFO - GECKO(5573) | MEMORY STAT | vsize 3331MB | residentFast 351MB | heapAllocated 77MB
[task 2020-09-04T04:41:38.798Z] 04:41:38 INFO - TEST-OK | dom/media/mediacontrol/tests/browser_default_action_handler.js | took 180035ms
[task 2020-09-04T04:41:38.798Z] 04:41:38 INFO - Not taking screenshot here: see the one that was previously logged
[task 2020-09-04T04:41:38.800Z] 04:41:38 INFO - TEST-UNEXPECTED-FAIL | dom/media/mediacontrol/tests/browser_default_action_handler.js | Found a tab after previous test timed out: https://example.com/browser/dom/media/mediacontrol/tests/file_main_frame_with_multiple_child_session_frames.html -
[task 2020-09-04T04:41:38.800Z] 04:41:38 INFO - GECKO(5573) | [Child 5683: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7f7a34050000 == 1 [pid = 5683] [id = {1b3b002c-3310-4464-818b-9d6042a23f34}]
[task 2020-09-04T04:41:38.801Z] 04:41:38 INFO - GECKO(5573) | [Child 5683: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 1 (0x7f7a5cd93180) [pid = 5683] [serial = 65] [outer = (nil)]
[task 2020-09-04T04:41:38.801Z] 04:41:38 INFO - GECKO(5573) | [Child 5683: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 2 (0x7f7a34051000) [pid = 5683] [serial = 66] [outer = 0x7f7a5cd93180]
[task 2020-09-04T04:41:38.802Z] 04:41:38 INFO - GECKO(5573) | [Child 5819: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f58f4b6fc00 == 2 [pid = 5819] [id = {569342a1-9037-4497-9d2c-6a8087f9919a}] [url = https://example.org/browser/dom/media/mediacontrol/tests/file_iframe_media.html]
[task 2020-09-04T04:41:38.802Z] 04:41:38 INFO - GECKO(5573) | [Child 5819: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f58f4b74c00 == 1 [pid = 5819] [id = {5a7a2311-bdf2-41ce-a9fe-eeaa88b2be72}] [url = https://test1.example.org/browser/dom/media/mediacontrol/tests/file_iframe_media.html]
[task 2020-09-04T04:41:38.803Z] 04:41:38 INFO - checking window state

Has Regression Range: --- → yes

Set release status flags based on info from the regressing bug 1634494

Status: NEW → RESOLVED
Closed: 3 years ago
Resolution: --- → INCOMPLETE

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=335322080&repo=mozilla-central&lineNumber=8500

[task 2021-04-02T23:48:29.818Z] 23:48:29 INFO - TEST-START | dom/media/mediacontrol/tests/browser/browser_default_action_handler.js
[task 2021-04-02T23:48:30.330Z] 23:48:30 INFO - GECKO(9868) | [Parent 7824, IPC I/O Parent] WARNING: file /builds/worker/checkouts/gecko/ipc/chromium/src/base/process_util_win.cc:167
[task 2021-04-02T23:48:31.041Z] 23:48:31 INFO - GECKO(9868) | JavaScript error: resource://gre/actors/AudioPlaybackParent.jsm, line 24: TypeError: can't access property "audioPlaybackStopped", browser is null
[task 2021-04-02T23:48:31.569Z] 23:48:31 INFO - GECKO(9868) | JavaScript error: resource://gre/actors/AudioPlaybackParent.jsm, line 24: TypeError: can't access property "audioPlaybackStopped", browser is null
[task 2021-04-02T23:49:14.842Z] 23:49:14 INFO - TEST-INFO | started process screenshot
[task 2021-04-02T23:49:14.926Z] 23:49:14 INFO - TEST-INFO | screenshot: exit 0
[task 2021-04-02T23:49:14.927Z] 23:49:14 INFO - <snipped 87 output lines - if you need more context, please use SimpleTest.requestCompleteLog() in your test>
[task 2021-04-02T23:49:14.927Z] 23:49:14 INFO - Buffered messages logged at 23:48:31
[task 2021-04-02T23:49:14.928Z] 23:49:14 INFO - load iframe with url 'https://example.com/browser/dom/media/mediacontrol/tests/browser/file_iframe_media.html'
[task 2021-04-02T23:49:14.928Z] 23:49:14 INFO - Console message: [JavaScript Warning: "The character encoding of a framed document was not declared. The document may appear different if viewed without the document framing it." {file: "https://example.com/browser/dom/media/mediacontrol/tests/browser/file_iframe_media.html" line: 0}]
[task 2021-04-02T23:49:14.929Z] 23:49:14 INFO - start media from iframe would make it become active session
[task 2021-04-02T23:49:14.929Z] 23:49:14 INFO - TEST-PASS | dom/media/mediacontrol/tests/browser/browser_default_action_handler.js | Received response played - true == true -
[task 2021-04-02T23:49:14.930Z] 23:49:14 INFO - handle event=activated
[task 2021-04-02T23:49:14.930Z] 23:49:14 INFO - press 'play' should trigger iframe's action handler
[task 2021-04-02T23:49:14.931Z] 23:49:14 INFO - handle event=playbackstatechange
[task 2021-04-02T23:49:14.931Z] 23:49:14 INFO - TEST-PASS | dom/media/mediacontrol/tests/browser/browser_default_action_handler.js | Received response setActionHandler-done - true == true -
[task 2021-04-02T23:49:14.932Z] 23:49:14 INFO - wait until 'play' action handler is triggered
[task 2021-04-02T23:49:14.932Z] 23:49:14 INFO - handle event=metadatachange
[task 2021-04-02T23:49:14.933Z] 23:49:14 INFO - TEST-PASS | dom/media/mediacontrol/tests/browser/browser_default_action_handler.js | Received response checkActionHandler-done - true == true -
[task 2021-04-02T23:49:14.933Z] 23:49:14 INFO - start media from main frame so iframe would become inactive
[task 2021-04-02T23:49:14.933Z] 23:49:14 INFO - pause media first in order to test 'play'
[task 2021-04-02T23:49:14.933Z] 23:49:14 INFO - handle event=metadatachange
[task 2021-04-02T23:49:14.933Z] 23:49:14 INFO - TEST-PASS | dom/media/mediacontrol/tests/browser/browser_default_action_handler.js | Received response paused - true == true -
[task 2021-04-02T23:49:14.933Z] 23:49:14 INFO - press 'play' would trigger default andler on main frame because it doesn't set action handler
[task 2021-04-02T23:49:14.934Z] 23:49:14 INFO - handle event=playbackstatechange
[task 2021-04-02T23:49:14.934Z] 23:49:14 INFO - handle event=playbackstatechange
[task 2021-04-02T23:49:14.935Z] 23:49:14 INFO - TEST-PASS | dom/media/mediacontrol/tests/browser/browser_default_action_handler.js | media is playing - true == true -
[task 2021-04-02T23:49:14.935Z] 23:49:14 INFO - default handler should also be triggered on inactive iframe, which would resume media
[task 2021-04-02T23:49:14.935Z] 23:49:14 INFO - handle event=metadatachange
[task 2021-04-02T23:49:14.936Z] 23:49:14 INFO - TEST-PASS | dom/media/mediacontrol/tests/browser/browser_default_action_handler.js | Received response checked-playing - true == true -
[task 2021-04-02T23:49:14.937Z] 23:49:14 INFO - remove tab
[task 2021-04-02T23:49:14.937Z] 23:49:14 INFO - wait until finishing close tab wrapper
[task 2021-04-02T23:49:14.938Z] 23:49:14 INFO - handle event=deactivated
[task 2021-04-02T23:49:14.938Z] 23:49:14 INFO - TEST-PASS | dom/media/mediacontrol/tests/browser/browser_default_action_handler.js | First event should be 'activated' -
[task 2021-04-02T23:49:14.938Z] 23:49:14 INFO - TEST-PASS | dom/media/mediacontrol/tests/browser/browser_default_action_handler.js | Last event should be 'deactivated' -
[task 2021-04-02T23:49:14.939Z] 23:49:14 INFO - open page and load iframe
[task 2021-04-02T23:49:14.939Z] 23:49:14 INFO - Console message: [JavaScript Error: "TypeError: can't access property "audioPlaybackStopped", browser is null" {file: "resource://gre/actors/AudioPlaybackParent.jsm" line: 24}]
[task 2021-04-02T23:49:14.940Z] 23:49:14 INFO - receiveMessage@resource://gre/actors/AudioPlaybackParent.jsm:24:9
[task 2021-04-02T23:49:14.940Z] 23:49:14 INFO -
[task 2021-04-02T23:49:14.940Z] 23:49:14 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 2021-04-02T23:49:14.941Z] 23:49:14 INFO - load iframe with url 'https://example.com/browser/dom/media/mediacontrol/tests/browser/file_iframe_media.html'
[task 2021-04-02T23:49:14.941Z] 23:49:14 INFO - Console message: [JavaScript Warning: "The character encoding of a framed document was not declared. The document may appear different if viewed without the document framing it." {file: "https://example.com/browser/dom/media/mediacontrol/tests/browser/file_iframe_media.html" line: 0}]
[task 2021-04-02T23:49:14.942Z] 23:49:14 INFO - start media from iframe would make it become active session
[task 2021-04-02T23:49:14.942Z] 23:49:14 INFO - TEST-PASS | dom/media/mediacontrol/tests/browser/browser_default_action_handler.js | Received response played - true == true -
[task 2021-04-02T23:49:14.943Z] 23:49:14 INFO - handle event=activated
[task 2021-04-02T23:49:14.943Z] 23:49:14 INFO - press 'pause' should trigger iframe's action handler
[task 2021-04-02T23:49:14.943Z] 23:49:14 INFO - handle event=playbackstatechange
[task 2021-04-02T23:49:14.944Z] 23:49:14 INFO - handle event=metadatachange
[task 2021-04-02T23:49:14.944Z] 23:49:14 INFO - TEST-PASS | dom/media/mediacontrol/tests/browser/browser_default_action_handler.js | Received response setActionHandler-done - true == true -
[task 2021-04-02T23:49:14.945Z] 23:49:14 INFO - wait until 'pause' action handler is triggered
[task 2021-04-02T23:49:14.945Z] 23:49:14 INFO - TEST-PASS | dom/media/mediacontrol/tests/browser/browser_default_action_handler.js | Received response checkActionHandler-done - true == true -
[task 2021-04-02T23:49:14.946Z] 23:49:14 INFO - start media from main frame so iframe would become inactive
[task 2021-04-02T23:49:14.946Z] 23:49:14 INFO - Buffered messages logged at 23:48:32
[task 2021-04-02T23:49:14.947Z] 23:49:14 INFO - press 'pause' would trigger default andler on main frame because it doesn't set action handler
[task 2021-04-02T23:49:14.947Z] 23:49:14 INFO - handle event=metadatachange
[task 2021-04-02T23:49:14.948Z] 23:49:14 INFO - handle event=metadatachange
[task 2021-04-02T23:49:14.948Z] 23:49:14 INFO - handle event=playbackstatechange
[task 2021-04-02T23:49:14.949Z] 23:49:14 INFO - TEST-PASS | dom/media/mediacontrol/tests/browser/browser_default_action_handler.js | media stopped playing - true == true -
[task 2021-04-02T23:49:14.949Z] 23:49:14 INFO - default handler should also be triggered on inactive iframe, which would pause media
[task 2021-04-02T23:49:14.950Z] 23:49:14 INFO - TEST-PASS | dom/media/mediacontrol/tests/browser/browser_default_action_handler.js | Received response checked-pause - true == true -
[task 2021-04-02T23:49:14.950Z] 23:49:14 INFO - remove tab
[task 2021-04-02T23:49:14.951Z] 23:49:14 INFO - wait until finishing close tab wrapper
[task 2021-04-02T23:49:14.951Z] 23:49:14 INFO - handle event=deactivated
[task 2021-04-02T23:49:14.952Z] 23:49:14 INFO - TEST-PASS | dom/media/mediacontrol/tests/browser/browser_default_action_handler.js | First event should be 'activated' -
[task 2021-04-02T23:49:14.952Z] 23:49:14 INFO - TEST-PASS | dom/media/mediacontrol/tests/browser/browser_default_action_handler.js | Last event should be 'deactivated' -
[task 2021-04-02T23:49:14.953Z] 23:49:14 INFO - open page and load iframe
[task 2021-04-02T23:49:14.953Z] 23:49:14 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 2021-04-02T23:49:14.954Z] 23:49:14 INFO - load iframe with url 'https://example.com/browser/dom/media/mediacontrol/tests/browser/file_iframe_media.html'
[task 2021-04-02T23:49:14.954Z] 23:49:14 INFO - Console message: [JavaScript Warning: "The character encoding of a framed document was not declared. The document may appear different if viewed without the document framing it." {file: "https://example.com/browser/dom/media/mediacontrol/tests/browser/file_iframe_media.html" line: 0}]
[task 2021-04-02T23:49:14.955Z] 23:49:14 INFO - start media from iframe would make it become active session
[task 2021-04-02T23:49:14.956Z] 23:49:14 INFO - TEST-PASS | dom/media/mediacontrol/tests/browser/browser_default_action_handler.js | Received response played - true == true -
[task 2021-04-02T23:49:14.956Z] 23:49:14 INFO - handle event=activated
[task 2021-04-02T23:49:14.957Z] 23:49:14 INFO - press 'stop' should trigger iframe's action handler
[task 2021-04-02T23:49:14.957Z] 23:49:14 INFO - handle event=playbackstatechange
[task 2021-04-02T23:49:14.958Z] 23:49:14 INFO - handle event=metadatachange
[task 2021-04-02T23:49:14.959Z] 23:49:14 INFO - TEST-PASS | dom/media/mediacontrol/tests/browser/browser_default_action_handler.js | Received response setActionHandler-done - true == true -
[task 2021-04-02T23:49:14.959Z] 23:49:14 INFO - wait until 'stop' action handler is triggered
[task 2021-04-02T23:49:14.959Z] 23:49:14 INFO - TEST-PASS | dom/media/mediacontrol/tests/browser/browser_default_action_handler.js | Received response checkActionHandler-done - true == true -
[task 2021-04-02T23:49:14.959Z] 23:49:14 INFO - start media from main frame so iframe would become inactive
[task 2021-04-02T23:49:14.960Z] 23:49:14 INFO - press 'stop' would trigger default andler on main frame because it doesn't set action handler
[task 2021-04-02T23:49:14.960Z] 23:49:14 INFO - handle event=metadatachange
[task 2021-04-02T23:49:14.960Z] 23:49:14 INFO - handle event=metadatachange
[task 2021-04-02T23:49:14.960Z] 23:49:14 INFO - TEST-PASS | dom/media/mediacontrol/tests/browser/browser_default_action_handler.js | media stopped playing - true == true -
[task 2021-04-02T23:49:14.960Z] 23:49:14 INFO - handle event=playbackstatechange
[task 2021-04-02T23:49:14.961Z] 23:49:14 INFO - default handler should also be triggered on inactive iframe, which would pause media
[task 2021-04-02T23:49:14.961Z] 23:49:14 INFO - TEST-PASS | dom/media/mediacontrol/tests/browser/browser_default_action_handler.js | Received response checked-pause - true == true -
[task 2021-04-02T23:49:14.961Z] 23:49:14 INFO - remove tab
[task 2021-04-02T23:49:14.961Z] 23:49:14 INFO - wait until finishing close tab wrapper
[task 2021-04-02T23:49:14.961Z] 23:49:14 INFO - handle event=deactivated
[task 2021-04-02T23:49:14.962Z] 23:49:14 INFO - TEST-PASS | dom/media/mediacontrol/tests/browser/browser_default_action_handler.js | First event should be 'activated' -
[task 2021-04-02T23:49:14.962Z] 23:49:14 INFO - TEST-PASS | dom/media/mediacontrol/tests/browser/browser_default_action_handler.js | Last event should be 'deactivated' -
[task 2021-04-02T23:49:14.962Z] 23:49:14 INFO - open page and load iframe
[task 2021-04-02T23:49:14.962Z] 23:49:14 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 2021-04-02T23:49:14.962Z] 23:49:14 INFO - load iframe with url 'https://example.org/browser/dom/media/mediacontrol/tests/browser/file_iframe_media.html'
[task 2021-04-02T23:49:14.962Z] 23:49:14 INFO - Buffered messages logged at 23:48:33
[task 2021-04-02T23:49:14.963Z] 23:49:14 INFO - start media from iframe would make it become active session
[task 2021-04-02T23:49:14.963Z] 23:49:14 INFO - TEST-PASS | dom/media/mediacontrol/tests/browser/browser_default_action_handler.js | Received response played - true == true -
[task 2021-04-02T23:49:14.963Z] 23:49:14 INFO - handle event=activated
[task 2021-04-02T23:49:14.963Z] 23:49:14 INFO - press 'play' should trigger iframe's action handler
[task 2021-04-02T23:49:14.963Z] 23:49:14 INFO - handle event=playbackstatechange
[task 2021-04-02T23:49:14.963Z] 23:49:14 INFO - handle event=metadatachange
[task 2021-04-02T23:49:14.963Z] 23:49:14 INFO - TEST-PASS | dom/media/mediacontrol/tests/browser/browser_default_action_handler.js | Received response setActionHandler-done - true == true -
[task 2021-04-02T23:49:14.964Z] 23:49:14 INFO - wait until 'play' action handler is triggered
[task 2021-04-02T23:49:14.964Z] 23:49:14 INFO - TEST-PASS | dom/media/mediacontrol/tests/browser/browser_default_action_handler.js | Received response checkActionHandler-done - true == true -
[task 2021-04-02T23:49:14.964Z] 23:49:14 INFO - start media from main frame so iframe would become inactive
[task 2021-04-02T23:49:14.964Z] 23:49:14 INFO - pause media first in order to test 'play'
[task 2021-04-02T23:49:14.964Z] 23:49:14 INFO - handle event=metadatachange
[task 2021-04-02T23:49:14.964Z] 23:49:14 INFO - TEST-PASS | dom/media/mediacontrol/tests/browser/browser_default_action_handler.js | Received response paused - true == true -
[task 2021-04-02T23:49:14.964Z] 23:49:14 INFO - press 'play' would trigger default andler on main frame because it doesn't set action handler
[task 2021-04-02T23:49:14.965Z] 23:49:14 INFO - handle event=metadatachange
[task 2021-04-02T23:49:14.965Z] 23:49:14 INFO - handle event=playbackstatechange
[task 2021-04-02T23:49:14.965Z] 23:49:14 INFO - wait until media starts playing
[task 2021-04-02T23:49:14.965Z] 23:49:14 INFO - Buffered messages finished
[task 2021-04-02T23:49:14.965Z] 23:49:14 INFO - TEST-UNEXPECTED-FAIL | dom/media/mediacontrol/tests/browser/browser_default_action_handler.js | Test timed out -
[task 2021-04-02T23:49:14.965Z] 23:49:14 INFO - GECKO(9868) | MEMORY STAT | vsize 2104261MB | vsizeMaxContiguous 74818976MB | residentFast 237MB | heapAllocated 73MB
[task 2021-04-02T23:49:14.966Z] 23:49:14 INFO - TEST-OK | dom/media/mediacontrol/tests/browser/browser_default_action_handler.js | took 45061ms
[task 2021-04-02T23:49:14.966Z] 23:49:14 INFO - Not taking screenshot here: see the one that was previously logged
[task 2021-04-02T23:49:14.966Z] 23:49:14 INFO - TEST-UNEXPECTED-FAIL | dom/media/mediacontrol/tests/browser/browser_default_action_handler.js | Found a tab after previous test timed out: https://example.com/browser/dom/media/mediacontrol/tests/browser/file_non_autoplay.html -
[task 2021-04-02T23:49:14.966Z] 23:49:14 INFO - checking window state
[task 2021-04-02T23:49:14.966Z] 23:49:14 ERROR - GECKO(9868) | TEST-UNEXPECTED-FAIL | unknown test url | uncaught exception - ReferenceError: info is not defined at _handleEvent@chrome://mochitests/content/browser/dom/media/mediacontrol/tests/browser/head.js:52:7
[task 2021-04-02T23:49:14.967Z] 23:49:14 INFO - GECKO(9868) | JavaScript error: chrome://mochitests/content/browser/dom/media/mediacontrol/tests/browser/head.js, line 52: ReferenceError: info is not defined

Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 3 years ago3 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Summary: Intermittent dom/media/mediacontrol/tests/browser_default_action_handler.js | Test timed out - → Intermittent dom/media/mediacontrol/tests/browser/browser_default_action_handler.js | Test timed out -
Status: REOPENED → RESOLVED
Closed: 3 years ago2 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 2 years ago2 years ago
Resolution: --- → DUPLICATE
You need to log in before you can comment on or make changes to this bug.