Closed Bug 1603192 Opened 5 years ago Closed 3 years ago

Intermittent dom/media/test/test_fastSeek-forwards.html | Test timed out!

Categories

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

defect

Tracking

()

RESOLVED DUPLICATE of bug 1787032

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: intermittent-failure)

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


[task 2019-12-11T17:39:05.424Z] 17:36:05     INFO -  222 INFO TEST-START | dom/media/test/test_fastSeek-forwards.html
[task 2019-12-11T17:39:05.424Z] 17:39:05     INFO -  Buffered messages logged at 17:35:55
[task 2019-12-11T17:39:05.424Z] 17:39:05     INFO -  223 INFO TEST-PASS | dom/media/test/test_fastSeek-forwards.html | A valid string reason is expected
[task 2019-12-11T17:39:05.424Z] 17:39:05     INFO -  224 INFO TEST-PASS | dom/media/test/test_fastSeek-forwards.html | Reason cannot be empty
[task 2019-12-11T17:39:05.424Z] 17:39:05     INFO -  225 INFO Started Wed Dec 11 2019 17:35:55 GMT+0000 (Coordinated Universal Time) (1576085755.776s)
[task 2019-12-11T17:39:05.424Z] 17:39:05     INFO -  226 INFO TEST-PASS | dom/media/test/test_fastSeek-forwards.html | [started gizmo.mp4-0 t=0.009] Length of array should match number of running tests
[task 2019-12-11T17:39:05.424Z] 17:39:05     INFO -  227 INFO TEST-PASS | dom/media/test/test_fastSeek-forwards.html | gizmo.mp4 - video should have at least two sync points
[task 2019-12-11T17:39:05.424Z] 17:39:05     INFO -  228 INFO TEST-PASS | dom/media/test/test_fastSeek-forwards.html | [started seek.webm-1 t=0.015] Length of array should match number of running tests
[task 2019-12-11T17:39:05.424Z] 17:39:05     INFO -  229 INFO TEST-PASS | dom/media/test/test_fastSeek-forwards.html | seek.webm - video should have at least two sync points
[task 2019-12-11T17:39:05.424Z] 17:39:05     INFO -  Buffered messages logged at 17:35:56
[task 2019-12-11T17:39:05.424Z] 17:39:05     INFO -  230 INFO TEST-PASS | dom/media/test/test_fastSeek-forwards.html | gizmo.mp4 seek never go backwards. time=0.75 firstSeekTarget=0.5 secondSeekTarget=0.75
[task 2019-12-11T17:39:05.424Z] 17:39:05     INFO -  231 INFO [finished gizmo.mp4-0] remaining= seek.webm-1
[task 2019-12-11T17:39:05.424Z] 17:39:05     INFO -  232 INFO TEST-PASS | dom/media/test/test_fastSeek-forwards.html | [finished gizmo.mp4-0 t=0.535] Length of array should match number of running tests
[task 2019-12-11T17:39:05.424Z] 17:39:05     INFO -  233 INFO TEST-PASS | dom/media/test/test_fastSeek-forwards.html | [started bug516323.indexed.ogv-2 t=0.535] Length of array should match number of running tests
[task 2019-12-11T17:39:05.424Z] 17:39:05     INFO -  234 INFO TEST-PASS | dom/media/test/test_fastSeek-forwards.html | bug516323.indexed.ogv - video should have at least two sync points
[task 2019-12-11T17:39:05.424Z] 17:39:05     INFO -  235 INFO TEST-PASS | dom/media/test/test_fastSeek-forwards.html | bug516323.indexed.ogv seek never go backwards. time=0.345 firstSeekTarget=0.23 secondSeekTarget=0.34500000000000003
[task 2019-12-11T17:39:05.424Z] 17:39:05     INFO -  236 INFO [finished bug516323.indexed.ogv-2] remaining= seek.webm-1
[task 2019-12-11T17:39:05.424Z] 17:39:05     INFO -  237 INFO TEST-PASS | dom/media/test/test_fastSeek-forwards.html | [finished bug516323.indexed.ogv-2 t=0.681] Length of array should match number of running tests
[task 2019-12-11T17:39:05.424Z] 17:39:05     INFO -  Buffered messages finished
[task 2019-12-11T17:39:05.424Z] 17:39:05  WARNING -  238 INFO TEST-UNEXPECTED-FAIL | dom/media/test/test_fastSeek-forwards.html | Test timed out!
[task 2019-12-11T17:39:05.424Z] 17:39:05     INFO -      SimpleTest.ok@SimpleTest/SimpleTest.js:277:18
[task 2019-12-11T17:39:05.424Z] 17:39:05     INFO -      onTimeout@dom/media/test/manifest.js:2086:9
[task 2019-12-11T17:39:05.424Z] 17:39:05     INFO -  239 INFO seek.webm-1 timed out!
[task 2019-12-11T17:40:38.965Z] 17:39:05     INFO -  240 INFO {"EMEInfo":{"keySystem":"","sessionsInfo":""},"compositorDroppedFrames":0,"decoder":{"PlayState":"LOADING","channels":0,"containerType":"video/webm","hasAudio":false,"hasVideo":true,"instance":"d279de60","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},"videoDecoderName":"shutdown","videoHardwareAccelerated":false,"videoHeight":240,"videoNumSamplesOutputTotal":0,"videoNumSamplesSkippedTotal":0,"videoRate":30.303030014038086,"videoState":{"demuxEOS":0,"demuxQueueSize":1,"drainState":0,"hasDecoder":false,"hasDemuxRequest":false,"hasPromise":false,"lastStreamSourceID":-1,"needInput":false,"numSamplesInput":0,"numSamplesOutput":0,"pending":0,"queueSize":0,"timeTreshold":-1,"timeTresholdHasSeeked":false,"waitingForData":false,"waitingForKey":false,"waitingPromise":false},"videoType":"video/vp8","videoWidth":320},"resource":{"cacheStream":{"cacheSuspended":false,"channelEnded":false,"channelOffset":0,"loadID":0,"streamLength":0}},"stateMachine":{"audioCompleted":false,"audioRequestStatus":"idle","clock":-1,"decodedAudioEndTime":0,"decodedVideoEndTime":0,"duration":4000000,"isPlaying":false,"mediaSink":{"audioSinkWrapper":{"audioEnded":true,"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":true,"finished":false,"hasVideo":false,"isPlaying":false,"isStarted":false,"size":0,"videoFrameEndTime":0,"videoSinkEndRequestExists":false}},"mediaTime":0,"playState":1,"sentFirstFrameLoadedEvent":false,"state":"","stateObj":{"isPrerolling":false},"videoCompleted":false,"videoRequestStatus":"idle"}}}
[task 2019-12-11T17:40:38.965Z] 17:39:05     INFO -  241 INFO [finished seek.webm-1] remaining=
[task 2019-12-11T17:40:38.965Z] 17:39:05     INFO -  242 INFO TEST-PASS | dom/media/test/test_fastSeek-forwards.html | [finished seek.webm-1 t=180.027] Length of array should match number of running tests
[task 2019-12-11T17:40:38.965Z] 17:39:05     INFO -  243 INFO Finished at Wed Dec 11 2019 17:38:55 GMT+0000 (Coordinated Universal Time) (1576085935.952s)
[task 2019-12-11T17:40:38.965Z] 17:39:05     INFO -  244 INFO Running time: 180.178s
Status: NEW → RESOLVED
Closed: 5 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 5 years ago5 years ago
Resolution: --- → INCOMPLETE

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=347873578&repo=autoland&lineNumber=2159

[task 2021-08-09T19:49:48.160Z] 19:49:48     INFO -  TEST-START | dom/media/test/test_fastSeek-forwards.html
[task 2021-08-09T19:52:50.246Z] 19:52:50     INFO -  Buffered messages logged at 19:49:39
[task 2021-08-09T19:52:50.246Z] 19:52:50     INFO -  TEST-PASS | dom/media/test/test_fastSeek-forwards.html | A valid string reason is expected
[task 2021-08-09T19:52:50.246Z] 19:52:50     INFO -  TEST-PASS | dom/media/test/test_fastSeek-forwards.html | Reason cannot be empty
[task 2021-08-09T19:52:50.246Z] 19:52:50     INFO -  Started Mon Aug 09 2021 19:49:39 GMT+0000 (Coordinated Universal Time) (1628538579.837s)
[task 2021-08-09T19:52:50.247Z] 19:52:50     INFO -  TEST-PASS | dom/media/test/test_fastSeek-forwards.html | [started gizmo.mp4-0 t=0.009] Length of array should match number of running tests
[task 2021-08-09T19:52:50.247Z] 19:52:50     INFO -  TEST-PASS | dom/media/test/test_fastSeek-forwards.html | gizmo.mp4 - video should have at least two sync points
[task 2021-08-09T19:52:50.247Z] 19:52:50     INFO -  TEST-PASS | dom/media/test/test_fastSeek-forwards.html | [started seek.webm-1 t=0.015] Length of array should match number of running tests
[task 2021-08-09T19:52:50.247Z] 19:52:50     INFO -  TEST-PASS | dom/media/test/test_fastSeek-forwards.html | seek.webm - video should have at least two sync points
[task 2021-08-09T19:52:50.247Z] 19:52:50     INFO -  Buffered messages logged at 19:49:40
[task 2021-08-09T19:52:50.248Z] 19:52:50     INFO -  TEST-PASS | dom/media/test/test_fastSeek-forwards.html | seek.webm seek never go backwards. time=0.6 firstSeekTarget=0.4 secondSeekTarget=0.6000000000000001
[task 2021-08-09T19:52:50.248Z] 19:52:50     INFO -  [finished seek.webm-1] remaining= gizmo.mp4-0
[task 2021-08-09T19:52:50.248Z] 19:52:50     INFO -  TEST-PASS | dom/media/test/test_fastSeek-forwards.html | [finished seek.webm-1 t=0.515] Length of array should match number of running tests
[task 2021-08-09T19:52:50.248Z] 19:52:50     INFO -  TEST-PASS | dom/media/test/test_fastSeek-forwards.html | [started bug516323.indexed.ogv-2 t=0.516] Length of array should match number of running tests
[task 2021-08-09T19:52:50.249Z] 19:52:50     INFO -  TEST-PASS | dom/media/test/test_fastSeek-forwards.html | bug516323.indexed.ogv - video should have at least two sync points
[task 2021-08-09T19:52:50.249Z] 19:52:50     INFO -  TEST-PASS | dom/media/test/test_fastSeek-forwards.html | bug516323.indexed.ogv seek never go backwards. time=0.345 firstSeekTarget=0.23 secondSeekTarget=0.34500000000000003
[task 2021-08-09T19:52:50.249Z] 19:52:50     INFO -  [finished bug516323.indexed.ogv-2] remaining= gizmo.mp4-0
[task 2021-08-09T19:52:50.249Z] 19:52:50     INFO -  TEST-PASS | dom/media/test/test_fastSeek-forwards.html | [finished bug516323.indexed.ogv-2 t=0.624] Length of array should match number of running tests
[task 2021-08-09T19:52:50.249Z] 19:52:50     INFO -  Buffered messages finished
[task 2021-08-09T19:52:50.250Z] 19:52:50  WARNING -  TEST-UNEXPECTED-FAIL | dom/media/test/test_fastSeek-forwards.html | Test timed out!
[task 2021-08-09T19:52:50.250Z] 19:52:50     INFO -      SimpleTest.ok@SimpleTest/SimpleTest.js:417:16
[task 2021-08-09T19:52:50.250Z] 19:52:50     INFO -      onTimeout@dom/media/test/manifest.js:2211:9
[task 2021-08-09T19:52:50.250Z] 19:52:50     INFO -  gizmo.mp4-0 timed out!
[task 2021-08-09T19:52:50.253Z] 19:52:50     INFO -  {"EMEInfo":{"keySystem":"","sessionsInfo":""},"compositorDroppedFrames":0,"decoder":{"PlayState":"PAUSED","channels":1,"containerType":"video/mp4","hasAudio":true,"hasVideo":true,"instance":"7d2c46fb7000","rate":48000,"reader":{"audioChannels":1,"audioDecoderName":"android decoder (remote)","audioFramesDecoded":1,"audioRate":48,"audioState":{"demuxEOS":0,"demuxQueueSize":0,"drainState":0,"hasDecoder":false,"hasDemuxRequest":false,"hasPromise":false,"lastStreamSourceID":-1,"needInput":false,"numSamplesInput":1,"numSamplesOutput":0,"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},"videoDecoderName":"android decoder (remote)","videoHardwareAccelerated":false,"videoHeight":320,"videoNumSamplesOutputTotal":1,"videoNumSamplesSkippedTotal":0,"videoRate":30.000093460083008,"videoState":{"demuxEOS":0,"demuxQueueSize":0,"drainState":0,"hasDecoder":false,"hasDemuxRequest":false,"hasPromise":false,"lastStreamSourceID":-1,"needInput":false,"numSamplesInput":1,"numSamplesOutput":0,"pending":0,"queueSize":1,"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":"idle","clock":-1,"decodedAudioEndTime":0,"decodedVideoEndTime":0,"duration":5589333,"isPlaying":false,"mediaSink":{"audioSinkWrapper":{"audioEnded":true,"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":true,"finished":false,"hasVideo":false,"isPlaying":false,"isStarted":false,"size":0,"videoFrameEndTime":0,"videoSinkEndRequestExists":false}},"mediaTime":500000,"playState":1,"sentFirstFrameLoadedEvent":true,"state":"","stateObj":{"isPrerolling":false},"videoCompleted":false,"videoRequestStatus":"idle"}}}
[task 2021-08-09T19:52:50.253Z] 19:52:50     INFO -  [finished gizmo.mp4-0] remaining=
[task 2021-08-09T19:52:50.254Z] 19:52:50     INFO -  TEST-PASS | dom/media/test/test_fastSeek-forwards.html | [finished gizmo.mp4-0 t=180.124] Length of array should match number of running tests
[task 2021-08-09T19:52:50.254Z] 19:52:50     INFO -  Finished at Mon Aug 09 2021 19:52:40 GMT+0000 (Coordinated Universal Time) (1628538760.056s)
[task 2021-08-09T19:52:50.254Z] 19:52:50     INFO -  Running time: 180.22s
[task 2021-08-09T19:52:50.254Z] 19:52:50     INFO -  TEST-OK | dom/media/test/test_fastSeek-forwards.html | took 180344ms
[task 2021-08-09T19:52:50.254Z] 19:52:50     INFO -  TEST-START | dom/media/test/test_fastSeek.html
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 5 years ago4 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 4 years ago3 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 3 years ago3 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 3 years ago3 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 3 years ago3 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 3 years ago3 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 3 years ago3 years ago
Resolution: --- → DUPLICATE
You need to log in before you can comment on or make changes to this bug.