Closed Bug 1900460 Opened 2 years ago Closed 2 years ago

Perma [tier 2] TEST-UNEXPECTED-FAIL | dom/media/test/test_background_video_cancel_suspend_taint.html | Test timed out!

Categories

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

Product:
Core
Component:
Audio/Video: Playback
Type:
defect

Tracking

()

Status:
RESOLVED FIXED

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: intermittent-failure, intermittent-testcase)

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

[task 2024-06-03T16:56:53.020Z] 16:56:53     INFO - TEST-PASS | dom/media/test/test_background_video_cancel_suspend_taint.html | gizmo.mp4-0 is visible. 
[task 2024-06-03T16:56:53.021Z] 16:56:53     INFO - Buffered messages finished
[task 2024-06-03T16:56:53.022Z] 16:56:53     INFO - TEST-UNEXPECTED-FAIL | dom/media/test/test_background_video_cancel_suspend_taint.html | Test timed out! 
[task 2024-06-03T16:56:53.022Z] 16:56:53     INFO -     SimpleTest.ok@SimpleTest/SimpleTest.js:426:16
[task 2024-06-03T16:56:53.023Z] 16:56:53     INFO -     onTimeout@dom/media/test/manifest.js:2174:9
[task 2024-06-03T16:56:53.023Z] 16:56:53     INFO -     setTimeout handler*MediaTestManager/this.started@dom/media/test/manifest.js:2181:57
[task 2024-06-03T16:56:53.023Z] 16:56:53     INFO -     runTest@dom/media/test/test_background_video_cancel_suspend_taint.html:61:13
[task 2024-06-03T16:56:53.023Z] 16:56:53     INFO -     MediaTestManager/this.nextTest@dom/media/test/manifest.js:2255:12
[task 2024-06-03T16:56:53.023Z] 16:56:53     INFO -     MediaTestManager/this.runTests/<@dom/media/test/manifest.js:2150:12
[task 2024-06-03T16:56:53.023Z] 16:56:53     INFO -     Async*MediaTestManager/this.runTests@dom/media/test/manifest.js:2149:19
[task 2024-06-03T16:56:53.023Z] 16:56:53     INFO -     startTest/<@dom/media/test/background_video.js:15:13
[task 2024-06-03T16:56:53.023Z] 16:56:53     INFO -     Async*startTest@dom/media/test/background_video.js:14:17
[task 2024-06-03T16:56:53.023Z] 16:56:53     INFO -     @dom/media/test/test_background_video_cancel_suspend_taint.html:51:10
[task 2024-06-03T16:56:53.024Z] 16:56:53     INFO - gizmo.mp4-0 timed out!
[task 2024-06-03T16:56:53.028Z] 16:56:53     INFO - {"EMEInfo":{"keySystem":"","sessionsInfo":""},"compositorDroppedFrames":0,"decoder":{"PlayState":"ENDED","channels":1,"containerType":"video/mp4","hasAudio":true,"hasVideo":true,"instance":"123fa01bb880","rate":48000,"reader":{"audioChannels":1,"audioDecoderName":"media engine audio stream (Utility MF Media Engine CDM remote)","audioFramesDecoded":261,"audioRate":48000,"audioState":{"demuxEOS":1,"demuxQueueSize":0,"drainState":0,"hasDecoder":false,"hasDemuxRequest":false,"hasPromise":false,"lastStreamSourceID":4294967295,"needInput":false,"numSamplesInput":262,"numSamplesOutput":261,"pending":0,"queueSize":1,"timeTreshold":-1,"timeTresholdHasSeeked":false,"waitingForData":false,"waitingForKey":false,"waitingPromise":false},"audioType":"audio/mp4a-latm","frameStats":{"droppedCompositorFrames":0,"droppedDecodedFrames":0,"droppedSinkFrames":0},"totalReadMetadataTimeMs":182.0607,"totalWaitingForVideoDataTimeMs":0,"videoDecoderName":"media engine video stream (Utility MF Media Engine CDM remote)","videoHardwareAccelerated":false,"videoHeight":320,"videoNumSamplesOutputTotal":166,"videoNumSamplesSkippedTotal":0,"videoRate":30,"videoState":{"demuxEOS":1,"demuxQueueSize":0,"drainState":0,"hasDecoder":false,"hasDemuxRequest":false,"hasPromise":false,"lastStreamSourceID":4294967295,"needInput":false,"numSamplesInput":166,"numSamplesOutput":166,"pending":0,"queueSize":0,"timeTreshold":-1,"timeTresholdHasSeeked":false,"waitingForData":false,"waitingForKey":false,"waitingPromise":false},"videoType":"video/avc","videoWidth":560},"resource":{"cacheStream":{"cacheSuspended":false,"channelEnded":false,"channelOffset":0,"loadID":0,"streamLength":0}},"stateMachine":{"audioCompleted":false,"audioRequestStatus":"","clock":0,"decodedAudioEndTime":0,"decodedVideoEndTime":0,"duration":0,"isPlaying":false,"mediaSink":{"audioSinkWrapper":{"audioEnded":false,"audioSink":{"audioEnded":false,"hasErrored":false,"isPlaying":false,"isStarted":false,"lastGoodPosition":0,"outputRate":0,"playbackComplete":false,"startTime":0,"written":0},"isPlaying":false,"isStarted":false},"decodedStream":{"audioQueueFinished":false,"audioQueueSize":0,"data":{"audioFramesWritten":0,"haveSentFinishAudio":false,"haveSentFinishVideo":false,"instance":"","lastVideoEndTime":0,"lastVideoStartTime":0,"nextAudioTime":0,"streamAudioWritten":0,"streamVideoWritten":0},"instance":"","lastAudio":0,"lastOutputTime":0,"playing":0,"startTime":0},"videoSink":{"endPromiseHolderIsEmpty":false,"finished":false,"hasVideo":false,"isPlaying":false,"isStarted":false,"size":0,"videoFrameEndTime":0,"videoSinkEndRequestExists":false}},"mediaTime":0,"playState":0,"sentFirstFrameLoadedEvent":false,"state":"","stateObj":{"isPrerolling":false},"totalBufferingTimeMs":0,"videoCompleted":false,"videoRequestStatus":""}}}
[task 2024-06-03T16:56:53.028Z] 16:56:53     INFO - [finished gizmo.mp4-0] remaining= 
[task 2024-06-03T16:56:53.029Z] 16:56:53     INFO - TEST-PASS | dom/media/test/test_background_video_cancel_suspend_taint.html | [finished gizmo.mp4-0 t=182.609] Length of array should match number of running tests 
[task 2024-06-03T16:56:53.029Z] 16:56:53     INFO - TEST-PASS | dom/media/test/test_background_video_cancel_suspend_taint.html | [started gizmo-noaudio.mp4-1 t=182.622] Length of array should match number of running tests 
[task 2024-06-03T16:56:53.030Z] 16:56:53     INFO - TEST-PASS | dom/media/test/test_background_video_cancel_suspend_taint.html | gizmo-noaudio.mp4-1 is visible. 
[task 2024-06-03T16:56:53.031Z] 16:56:53     INFO - [16:56:52.877] gizmo-noaudio.mp4-1 Start playing
[task 2024-06-03T16:56:53.205Z] 16:56:53     INFO - TEST-PASS | dom/media/test/test_background_video_cancel_suspend_taint.html | gizmo-noaudio.mp4-1 played. 
[task 2024-06-03T16:56:53.206Z] 16:56:53     INFO - [16:56:53.205] gizmo-noaudio.mp4-1 Set Hidden
[task 2024-06-03T16:59:33.292Z] 16:59:33     INFO -  console.trace: Places - FrecencyRecalculator: "Initializing Frecency Recalculator"
[task 2024-06-03T16:59:33.292Z] 16:59:33     INFO -  resource://gre/modules/PlacesFrecencyRecalculator.sys.mjs 110 PlacesFrecencyRecalculator
[task 2024-06-03T16:59:33.293Z] 16:59:33     INFO -  D:\task_171743284657296\build\tests\mochitest\server.js 178 runServer
[task 2024-06-03T16:59:33.293Z] 16:59:33     INFO -  D:\task_171743284657296\build\tests\mochitest\server.js 71
[task 2024-06-03T16:59:33.305Z] 16:59:33     INFO -  console.trace: Places - FrecencyRecalculator: "Arm frecency recalculation"
[task 2024-06-03T16:59:33.305Z] 16:59:33     INFO -  resource://gre/modules/PlacesFrecencyRecalculator.sys.mjs 366 maybeStartFrecencyRecalculation
[task 2024-06-03T16:59:33.305Z] 16:59:33     INFO -  resource://gre/modules/PlacesFrecencyRecalculator.sys.mjs 149 PlacesFrecencyRecalculator
[task 2024-06-03T16:59:33.305Z] 16:59:33     INFO -  D:\task_171743284657296\build\tests\mochitest\server.js 178 runServer
[task 2024-06-03T16:59:33.306Z] 16:59:33     INFO -  D:\task_171743284657296\build\tests\mochitest\server.js 71
[task 2024-06-03T16:59:33.309Z] 16:59:33     INFO -  console.trace: Places - FrecencyRecalculator: "Got places-init-complete topic"
[task 2024-06-03T16:59:33.309Z] 16:59:33     INFO -  resource://gre/modules/PlacesFrecencyRecalculator.sys.mjs 422 observe
[task 2024-06-03T16:59:33.310Z] 16:59:33     INFO -  D:\task_171743284657296\build\tests\mochitest\server.js 178 runServer
[task 2024-06-03T16:59:33.310Z] 16:59:33     INFO -  D:\task_171743284657296\build\tests\mochitest\server.js 71
[task 2024-06-03T16:59:33.310Z] 16:59:33     INFO -  console.error: (new TypeError("connection not specified or invalid.", "resource://gre/modules/Sqlite.sys.mjs", 1560))
[task 2024-06-03T16:59:33.311Z] 16:59:33     INFO -  console.error: (new TypeError("can't access property \"executeBeforeShutdown\", db is undefined", "resource://gre/modules/PlacesUtils.sys.mjs", 1469))
[task 2024-06-03T16:59:52.870Z] 16:59:52     INFO - Not taking screenshot here: see the one that was previously logged
[task 2024-06-03T16:59:52.871Z] 16:59:52     INFO - TEST-UNEXPECTED-FAIL | dom/media/test/test_background_video_cancel_suspend_taint.html | Test timed out! 
[task 2024-06-03T16:59:52.871Z] 16:59:52     INFO -     SimpleTest.ok@SimpleTest/SimpleTest.js:426:16
[task 2024-06-03T16:59:52.871Z] 16:59:52     INFO -     onTimeout@dom/media/test/manifest.js:2174:9
[task 2024-06-03T16:59:52.871Z] 16:59:52     INFO -     setTimeout handler*MediaTestManager/this.started@dom/media/test/manifest.js:2181:57
[task 2024-06-03T16:59:52.871Z] 16:59:52     INFO -     runTest@dom/media/test/test_background_video_cancel_suspend_taint.html:61:13
[task 2024-06-03T16:59:52.871Z] 16:59:52     INFO -     MediaTestManager/this.nextTest@dom/media/test/manifest.js:2255:12
[task 2024-06-03T16:59:52.871Z] 16:59:52     INFO -     MediaTestManager/this.finished@dom/media/test/manifest.js:2227:12
[task 2024-06-03T16:59:52.872Z] 16:59:52     INFO -     onTimeout@dom/media/test/manifest.js:2177:12
[task 2024-06-03T16:59:52.872Z] 16:59:52     INFO -     async*MediaTestManager/this.started@dom/media/test/manifest.js:2181:57
[task 2024-06-03T16:59:52.872Z] 16:59:52     INFO -     runTest@dom/media/test/test_background_video_cancel_suspend_taint.html:61:13
[task 2024-06-03T16:59:52.872Z] 16:59:52     INFO -     MediaTestManager/this.nextTest@dom/media/test/manifest.js:2255:12
[task 2024-06-03T16:59:52.872Z] 16:59:52     INFO -     MediaTestManager/this.runTests/<@dom/media/test/manifest.js:2150:12
[task 2024-06-03T16:59:52.872Z] 16:59:52     INFO -     Async*MediaTestManager/this.runTests@dom/media/test/manifest.js:2149:19
[task 2024-06-03T16:59:52.872Z] 16:59:52     INFO -     startTest/<@dom/media/test/background_video.js:15:13
[task 2024-06-03T16:59:52.872Z] 16:59:52     INFO -     Async*startTest@dom/media/test/background_video.js:14:17
[task 2024-06-03T16:59:52.872Z] 16:59:52     INFO -     @dom/media/test/test_background_video_cancel_suspend_taint.html:51:10
[task 2024-06-03T16:59:52.873Z] 16:59:52     INFO - gizmo-noaudio.mp4-1 timed out!
[task 2024-06-03T16:59:52.913Z] 16:59:52     INFO - {"EMEInfo":{"keySystem":"","sessionsInfo":""},"compositorDroppedFrames":0,"decoder":{"PlayState":"ENDED","channels":0,"containerType":"video/mp4","hasAudio":false,"hasVideo":true,"instance":"123fa0220480","rate":0,"reader":{"audioChannels":0,"audioDecoderName":"unavailable","audioFramesDecoded":0,"audioRate":0,"audioState":{"demuxEOS":0,"demuxQueueSize":0,"drainState":0,"hasDecoder":false,"hasDemuxRequest":false,"hasPromise":false,"lastStreamSourceID":0,"needInput":false,"numSamplesInput":0,"numSamplesOutput":0,"pending":0,"queueSize":0,"timeTreshold":0,"timeTresholdHasSeeked":false,"waitingForData":false,"waitingForKey":false,"waitingPromise":false},"audioType":"none","frameStats":{"droppedCompositorFrames":0,"droppedDecodedFrames":0,"droppedSinkFrames":0},"totalReadMetadataTimeMs":124.3245,"totalWaitingForVideoDataTimeMs":0,"videoDecoderName":"media engine video stream (Utility MF Media Engine CDM remote)","videoHardwareAccelerated":false,"videoHeight":320,"videoNumSamplesOutputTotal":166,"videoNumSamplesSkippedTotal":0,"videoRate":30,"videoState":{"demuxEOS":1,"demuxQueueSize":0,"drainState":0,"hasDecoder":false,"hasDemuxRequest":false,"hasPromise":false,"lastStreamSourceID":4294967295,"needInput":false,"numSamplesInput":166,"numSamplesOutput":166,"pending":0,"queueSize":0,"timeTreshold":-1,"timeTresholdHasSeeked":false,"waitingForData":false,"waitingForKey":false,"waitingPromise":false},"videoType":"video/avc","videoWidth":560},"resource":{"cacheStream":{"cacheSuspended":false,"channelEnded":false,"channelOffset":0,"loadID":0,"streamLength":0}},"stateMachine":{"audioCompleted":false,"audioRequestStatus":"","clock":0,"decodedAudioEndTime":0,"decodedVideoEndTime":0,"duration":0,"isPlaying":false,"mediaSink":{"audioSinkWrapper":{"audioEnded":false,"audioSink":{"audioEnded":false,"hasErrored":false,"isPlaying":false,"isStarted":false,"lastGoodPosition":0,"outputRate":0,"playbackComplete":false,"startTime":0,"written":0},"isPlaying":false,"isStarted":false},"decodedStream":{"audioQueueFinished":false,"audioQueueSize":0,"data":{"audioFramesWritten":0,"haveSentFinishAudio":false,"haveSentFinishVideo":false,"instance":"","lastVideoEndTime":0,"lastVideoStartTime":0,"nextAudioTime":0,"streamAudioWritten":0,"streamVideoWritten":0},"instance":"","lastAudio":0,"lastOutputTime":0,"playing":0,"startTime":0},"videoSink":{"endPromiseHolderIsEmpty":false,"finished":false,"hasVideo":false,"isPlaying":false,"isStarted":false,"size":0,"videoFrameEndTime":0,"videoSinkEndRequestExists":false}},"mediaTime":0,"playState":0,"sentFirstFrameLoadedEvent":false,"state":"","stateObj":{"isPrerolling":false},"totalBufferingTimeMs":0,"videoCompleted":false,"videoRequestStatus":""}}}
[task 2024-06-03T16:59:52.914Z] 16:59:52     INFO - [finished gizmo-noaudio.mp4-1] remaining= 
[task 2024-06-03T16:59:52.915Z] 16:59:52     INFO - TEST-PASS | dom/media/test/test_background_video_cancel_suspend_taint.html | [finished gizmo-noaudio.mp4-1 t=362.663] Length of array should match number of running tests

This failure didn't reproduced since bug 1898051 got backed out,most likely it was the culprit

Status: NEW → RESOLVED
Closed: 2 years ago
Resolution: --- → FIXED
You need to log in before you can comment on or make changes to this bug.