Closed Bug 1407003 Opened 7 years ago Closed 4 years ago

Intermittent dom/media/test/test_play_events.html | Test timed out!

Categories

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

Product:
Core
Component:
Audio/Video: Playback
Platform:
x86_64
Windows 10
Type:
defect

Tracking

()

Status:
RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Depends on 1 open bug)

Details

(Keywords: intermittent-failure) 

Filed by: archaeopteryx [at] coole-files.de

https://treeherder.mozilla.org/logviewer.html#?job_id=135724168&repo=mozilla-inbound

https://queue.taskcluster.net/v1/task/G8Lq3ZjaQRWMC75e0M93tw/runs/0/artifacts/public/test_info/mochitest-media_errorsummary.log

16:28:01     INFO -  580 INFO TEST-PASS | dom/media/test/test_play_events.html | Check expected event got playing at canplay for http://mochi.test:8888/tests/dom/media/test/flac-s24.flac uneval(event.type)="playing" typeof(event.type)=string uneval(v._state)="canplay" typeof(v._state)=string tokens[canplay]=playing tokens[canplay].indexOf(event.type)=0
16:28:01     INFO -  581 INFO [finished gizmo-short.mp4-10] remaining= flac-s24.flac-11
16:28:01     INFO -  582 INFO TEST-PASS | dom/media/test/test_play_events.html | [finished gizmo-short.mp4-10 t=1.783] Length of array should match number of running tests
16:28:01     INFO -  583 INFO TEST-PASS | dom/media/test/test_play_events.html | Check expected event got canplaythrough at playing for http://mochi.test:8888/tests/dom/media/test/flac-s24.flac uneval(event.type)="canplaythrough" typeof(event.type)=string uneval(v._state)="playing" typeof(v._state)=string tokens[playing]=canplay,canplaythrough tokens[playing].indexOf(event.type)=1
16:28:01     INFO -  Buffered messages finished
16:28:01    ERROR -  584 INFO TEST-UNEXPECTED-FAIL | dom/media/test/test_play_events.html | Test timed out!
16:28:01     INFO -      onTimeout@dom/media/test/manifest.js:1693:7
16:28:01     INFO -      setTimeout handler*MediaTestManager/this.started@dom/media/test/manifest.js:1699:26
16:28:01     INFO -      initTest@dom/media/test/test_play_events.html:44:3
16:28:01     INFO -      MediaTestManager/this.nextTest@dom/media/test/manifest.js:1748:7
16:28:01     INFO -      MediaTestManager/this.finished@dom/media/test/manifest.js:1727:7
16:28:01     INFO -      ended@dom/media/test/test_play_events.html:38:3
16:28:01     INFO -      EventListener.handleEvent*initTest@dom/media/test/test_play_events.html:51:3
16:28:01     INFO -      MediaTestManager/this.nextTest@dom/media/test/manifest.js:1748:7
16:28:01     INFO -      MediaTestManager/this.finished@dom/media/test/manifest.js:1727:7
16:28:01     INFO -      EventListener.handleEvent*initTest@dom/media/test/test_play_events.html:51:3
16:28:01     INFO -      MediaTestManager/this.nextTest@dom/media/test/manifest.js:1748:7
16:28:01     INFO -      MediaTestManager/this.finished@dom/media/test/manifest.js:1727:7
16:28:01     INFO -      EventListener.handleEvent*initTest@dom/media/test/test_play_events.html:51:3
16:28:01     INFO -      MediaTestManager/this.nextTest@dom/media/test/manifest.js:1748:7
16:28:01     INFO -      MediaTestManager/this.finished@dom/media/test/manifest.js:1727:7
16:28:01     INFO -      EventListener.handleEvent*initTest@dom/media/test/test_play_events.html:51:3
16:28:01     INFO -      EventListener.handleEvent*initTest@dom/media/test/test_play_events.html:51:3
16:28:01     INFO -      EventListener.handleEvent*initTest@dom/media/test/test_play_events.html:51:3
16:28:01     INFO -      MediaTestManager/this.nextTest@dom/media/test/manifest.js:1748:7
16:28:01     INFO -      MediaTestManager/this.runTests/<@dom/media/test/manifest.js:1668:7
16:28:01     INFO -  585 INFO flac-s24.flac-11 timed out!
(In reply to OrangeFactor Robot from comment #1)
> 7 failures in 947 pushes (0.007 failures/push) were associated with this bug
> in the last 7 days.    
> 
> Repository breakdown:
> * mozilla-inbound: 6
> * autoland: 1
> 
> Platform breakdown:
> * windows10-64-stylo-disabled: 4
> * windows10-64: 3
> 
> For more details, see:
> https://brasstacks.mozilla.com/orangefactor/
> ?display=Bug&bugid=1407003&startday=2017-10-09&endday=2017-10-15&tree=all

Windows 10 timeout.
Depends on: 1407553
OS: Unspecified → Windows 10
Hardware: Unspecified → x86_64

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup

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

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup

Status: REOPENED → RESOLVED
Closed: 5 years ago → 5 years ago
Resolution: --- → INCOMPLETE

Recent log failure: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=266843095&repo=autoland&lineNumber=7629

Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---

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

Status: REOPENED → RESOLVED
Closed: 5 years ago → 5 years ago
Resolution: --- → INCOMPLETE

Recent failure log:
https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=273171270&repo=autoland&lineNumber=2739

[task 2019-10-27T21:13:12.707Z] 21:13:12 INFO - TEST-PASS | dom/media/test/test_play_events.html | Check expected event got canplaythrough at playing for http://mochi.test:8888/tests/dom/media/test/flac-s24.flac uneval(event.type)="canplaythrough" typeof(event.type)=string uneval(v._state)="playing" typeof(v._state)=string tokens[playing]=canplay,canplaythrough tokens[playing].indexOf(event.type)=1
[task 2019-10-27T21:13:12.707Z] 21:13:12 INFO - Buffered messages finished
[task 2019-10-27T21:13:12.707Z] 21:13:12 INFO - TEST-UNEXPECTED-FAIL | dom/media/test/test_play_events.html | Test timed out!
[task 2019-10-27T21:13:12.707Z] 21:13:12 INFO - SimpleTest.ok@SimpleTest/SimpleTest.js:277:18
[task 2019-10-27T21:13:12.707Z] 21:13:12 INFO - onTimeout@dom/media/test/manifest.js:2086:9
[task 2019-10-27T21:13:12.707Z] 21:13:12 INFO - setTimeout handlerMediaTestManager/this.started@dom/media/test/manifest.js:2093:57
[task 2019-10-27T21:13:12.707Z] 21:13:12 INFO - initTest@dom/media/test/test_play_events.html:44:11
[task 2019-10-27T21:13:12.707Z] 21:13:12 INFO - MediaTestManager/this.nextTest@dom/media/test/manifest.js:2167:12
[task 2019-10-27T21:13:12.707Z] 21:13:12 INFO - MediaTestManager/this.finished@dom/media/test/manifest.js:2139:12
[task 2019-10-27T21:13:12.708Z] 21:13:12 INFO - ended@dom/media/test/test_play_events.html:38:11
[task 2019-10-27T21:13:12.708Z] 21:13:12 INFO - EventListener.handleEventinitTest@dom/media/test/test_play_events.html:51:5
[task 2019-10-27T21:13:12.708Z] 21:13:12 INFO - MediaTestManager/this.nextTest@dom/media/test/manifest.js:2167:12
[task 2019-10-27T21:13:12.708Z] 21:13:12 INFO - MediaTestManager/this.finished@dom/media/test/manifest.js:2139:12
[task 2019-10-27T21:13:12.708Z] 21:13:12 INFO - ended@dom/media/test/test_play_events.html:38:11
[task 2019-10-27T21:13:12.708Z] 21:13:12 INFO - EventListener.handleEventinitTest@dom/media/test/test_play_events.html:51:5
[task 2019-10-27T21:13:12.708Z] 21:13:12 INFO - MediaTestManager/this.nextTest@dom/media/test/manifest.js:2167:12
[task 2019-10-27T21:13:12.708Z] 21:13:12 INFO - MediaTestManager/this.finished@dom/media/test/manifest.js:2139:12
[task 2019-10-27T21:13:12.708Z] 21:13:12 INFO - ended@dom/media/test/test_play_events.html:38:11
[task 2019-10-27T21:13:12.708Z] 21:13:12 INFO - EventListener.handleEventinitTest@dom/media/test/test_play_events.html:51:5
[task 2019-10-27T21:13:12.708Z] 21:13:12 INFO - MediaTestManager/this.nextTest@dom/media/test/manifest.js:2167:12
[task 2019-10-27T21:13:12.709Z] 21:13:12 INFO - MediaTestManager/this.finished@dom/media/test/manifest.js:2139:12
[task 2019-10-27T21:13:12.709Z] 21:13:12 INFO - ended@dom/media/test/test_play_events.html:38:11
[task 2019-10-27T21:13:12.709Z] 21:13:12 INFO - EventListener.handleEventinitTest@dom/media/test/test_play_events.html:51:5
[task 2019-10-27T21:13:12.709Z] 21:13:12 INFO - MediaTestManager/this.nextTest@dom/media/test/manifest.js:2167:12
[task 2019-10-27T21:13:12.709Z] 21:13:12 INFO - MediaTestManager/this.finished@dom/media/test/manifest.js:2139:12
[task 2019-10-27T21:13:12.709Z] 21:13:12 INFO - ended@dom/media/test/test_play_events.html:38:11
[task 2019-10-27T21:13:12.709Z] 21:13:12 INFO - EventListener.handleEventinitTest@dom/media/test/test_play_events.html:51:5
[task 2019-10-27T21:13:12.709Z] 21:13:12 INFO - MediaTestManager/this.nextTest@dom/media/test/manifest.js:2167:12
[task 2019-10-27T21:13:12.709Z] 21:13:12 INFO - MediaTestManager/this.runTests/<@dom/media/test/manifest.js:2062:12
[task 2019-10-27T21:13:12.709Z] 21:13:12 INFO - Async*MediaTestManager/this.runTests@dom/media/test/manifest.js:2061:19
[task 2019-10-27T21:13:12.709Z] 21:13:12 INFO - @dom/media/test/test_play_events.html:58:9
[task 2019-10-27T21:13:12.709Z] 21:13:12 INFO - flac-s24.flac-11 timed out!
[task 2019-10-27T21:13:12.710Z] 21:13:12 INFO - {"EMEInfo":{"keySystem":"","sessionsInfo":""},"compositorDroppedFrames":0,"decoder":{"PlayState":"PLAYING","channels":2,"containerType":"audio/flac","hasAudio":true,"hasVideo":false,"instance":"1c1c83a9800","rate":88200,"reader":{"audioChannels":2,"audioDecoderName":"ffmpeg audio decoder","audioFramesDecoded":29,"audioRate":88.19999694824219,"audioState":{"demuxEOS":0,"demuxQueueSize":0,"drainState":0,"hasDecoder":false,"hasDemuxRequest":false,"hasPromise":false,"lastStreamSourceID":-1,"needInput":false,"numSamplesInput":29,"numSamplesOutput":29,"pending":0,"queueSize":0,"timeTreshold":-1,"timeTresholdHasSeeked":false,"waitingForData":0,"waitingForKey":0,"waitingPromise":false},"audioType":"audio/flac","frameStats":{"droppedCompositorFrames":0,"droppedDecodedFrames":0,"droppedSinkFrames":0},"videoDecoderName":"unavailable","videoHardwareAccelerated":false,"videoHeight":0,"videoNumSamplesOutputTotal":0,"videoNumSamplesSkippedTotal":0,"videoRate":0,"videoState":{"demuxEOS":-437918235,"demuxQueueSize":-437918235,"drainState":-437918235,"hasDecoder":true,"hasDemuxRequest":true,"hasPromise":true,"lastStreamSourceID":-437918235,"needInput":true,"numSamplesInput":-1880844493789993500,"numSamplesOutput":-1880844493789993500,"pending":-437918235,"queueSize":-437918235,"timeTreshold":-7.269300372276537e+182,"timeTresholdHasSeeked":true,"waitingForData":-437918235,"waitingForKey":-437918235,"waitingPromise":true},"videoType":"none","videoWidth":0},"resource":{"cacheStream":{"cacheSuspended":true,"channelEnded":true,"channelOffset":-1880844493789993500,"loadID":-437918235,"streamLength":-1880844493789993500}},"stateMachine":{"audioCompleted":false,"audioRequestStatus":"idle","clock":2040000,"decodedAudioEndTime":2693513,"decodedVideoEndTime":0,"duration":4040272,"isPlaying":true,"mediaSink":{"audioSinkWrapper":{"audioEnded":false,"audioSink":{"audioEnded":true,"hasErrored":false,"isPlaying":true,"isStarted":true,"lastGoodPosition":2040000,"outputRate":48000,"playbackComplete":false,"startTime":0,"written":102720},"isPlaying":true,"isStarted":true},"decodedStream":{"audioQueueFinished":true,"audioQueueSize":-437918235,"data":{"audioFramesWritten":-1880844493789993500,"haveSentFinishAudio":true,"haveSentFinishVideo":true,"instance":"","lastVideoEndTime":-1880844493789993500,"lastVideoStartTime":-1880844493789993500,"nextAudioTime":-1880844493789993500,"streamAudioWritten":-1880844493789993500,"streamVideoWritten":-1880844493789993500},"instance":"","lastAudio":-1880844493789993500,"lastOutputTime":-1880844493789993500,"playing":-437918235,"startTime":-1880844493789993500},"videoSink":{"endPromiseHolderIsEmpty":true,"finished":false,"hasVideo":false,"isPlaying":true,"isStarted":true,"size":0,"videoFrameEndTime":0,"videoSinkEndRequestExists":false}},"mediaTime":2040000,"playState":3,"sentFirstFrameLoadedEvent":true,"state":"","stateObj":{"isPrerolling":false},"videoCompleted":false,"videoRequestStatus":"idle"}}}
[task 2019-10-27T21:13:12.710Z] 21:13:12 INFO - [finished flac-s24.flac-11] remaining=
[task 2019-10-27T21:13:12.710Z] 21:13:12 INFO - TEST-PASS | dom/media/test/test_play_events.html | [finished flac-s24.flac-11 t=181.767] Length of array should match number of running tests
[task 2019-10-27T21:13:12.710Z] 21:13:12 INFO - Finished at Sun Oct 27 2019 21:13:12 GMT+0000 (Greenwich Mean Time) (1572210792.666s)
[task 2019-10-27T21:13:12.710Z] 21:13:12 INFO - Running time: 181.847s
[task 2019-10-27T21:13:12.711Z] 21:13:12 INFO - GECKO(7460) | MEMORY STAT | vsize 2103930MB | vsizeMaxContiguous 68944685MB | residentFast 128MB | heapAllocated 16MB

Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---

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

Status: REOPENED → RESOLVED
Closed: 5 years ago → 4 years ago
Resolution: --- → INCOMPLETE

Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=284638282&repo=mozilla-central&lineNumber=2627

Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---

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

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