Closed Bug 1404373 Opened 8 years ago Closed 3 years ago

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

Categories

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

defect

Tracking

()

RESOLVED DUPLICATE of bug 1781567

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: intermittent-failure, Whiteboard: [stockwell unknown][stockwell disabled])

Attachments

(2 files)

Filed by: archaeopteryx [at] coole-files.de https://treeherder.mozilla.org/logviewer.html#?job_id=134073546&repo=autoland https://queue.taskcluster.net/v1/task/E8EYvm1KSw2xQ2b-8PhYvQ/runs/0/artifacts/public/test_info//mochitest-media_errorsummary.log [task 2017-09-29T15:14:16.421Z] 15:14:16 INFO - TEST-PASS | dom/media/test/test_bug495145.html | Playing after pause while ended works for gizmo-short.mp4#1 [task 2017-09-29T15:14:16.421Z] 15:14:16 INFO - [finished gizmo-short.mp4-10a] remaining= flac-s24.flac-11a,flac-s24.flac-11b [task 2017-09-29T15:14:16.422Z] 15:14:16 INFO - TEST-PASS | dom/media/test/test_bug495145.html | [finished gizmo-short.mp4-10a t=14.337] Length of array should match number of running tests [task 2017-09-29T15:14:16.423Z] 15:14:16 INFO - Buffered messages logged at 15:11:22 [task 2017-09-29T15:14:16.424Z] 15:14:16 INFO - TEST-PASS | dom/media/test/test_bug495145.html | Paused after seek after pause while ended for flac-s24.flac#2 [task 2017-09-29T15:14:16.425Z] 15:14:16 INFO - [finished flac-s24.flac-11b] remaining= flac-s24.flac-11a [task 2017-09-29T15:14:16.426Z] 15:14:16 INFO - TEST-PASS | dom/media/test/test_bug495145.html | [finished flac-s24.flac-11b t=18.366] Length of array should match number of running tests [task 2017-09-29T15:14:16.426Z] 15:14:16 INFO - Buffered messages finished [task 2017-09-29T15:14:16.427Z] 15:14:16 INFO - TEST-UNEXPECTED-FAIL | dom/media/test/test_bug495145.html | Test timed out! [task 2017-09-29T15:14:16.428Z] 15:14:16 INFO - onTimeout@dom/media/test/manifest.js:1693:7 [task 2017-09-29T15:14:16.429Z] 15:14:16 INFO - setTimeout handler*MediaTestManager/this.started@dom/media/test/manifest.js:1699:26 [task 2017-09-29T15:14:16.430Z] 15:14:16 INFO - createVideo@dom/media/test/test_bug495145.html:72:3 [task 2017-09-29T15:14:16.431Z] 15:14:16 INFO - startTest@dom/media/test/test_bug495145.html:85:3 [task 2017-09-29T15:14:16.431Z] 15:14:16 INFO - MediaTestManager/this.nextTest@dom/media/test/manifest.js:1748:7 [task 2017-09-29T15:14:16.432Z] 15:14:16 INFO - MediaTestManager/this.finished@dom/media/test/manifest.js:1727:7 [task 2017-09-29T15:14:16.432Z] 15:14:16 INFO - seeked2@dom/media/test/test_bug495145.html:65:3 [task 2017-09-29T15:14:16.433Z] 15:14:16 INFO - EventListener.handleEvent*createVideo@dom/media/test/test_bug495145.html:80:5 [task 2017-09-29T15:14:16.434Z] 15:14:16 INFO - EventListener.handleEvent*createVideo@dom/media/test/test_bug495145.html:78:3 [task 2017-09-29T15:14:16.434Z] 15:14:16 INFO - startTest@dom/media/test/test_bug495145.html:85:3 [task 2017-09-29T15:14:16.435Z] 15:14:16 INFO - MediaTestManager/this.nextTest@dom/media/test/manifest.js:1748:7 [task 2017-09-29T15:14:16.436Z] 15:14:16 INFO - MediaTestManager/this.finished@dom/media/test/manifest.js:1727:7 [task 2017-09-29T15:14:16.436Z] 15:14:16 INFO - EventListener.handleEvent*createVideo@dom/media/test/test_bug495145.html:80:5 [task 2017-09-29T15:14:16.437Z] 15:14:16 INFO - startTest@dom/media/test/test_bug495145.html:86:3 [task 2017-09-29T15:14:16.437Z] 15:14:16 INFO - MediaTestManager/this.nextTest@dom/media/test/manifest.js:1748:7 [task 2017-09-29T15:14:16.438Z] 15:14:16 INFO - MediaTestManager/this.finished@dom/media/test/manifest.js:1727:7 [task 2017-09-29T15:14:16.438Z] 15:14:16 INFO - EventListener.handleEvent*createVideo@dom/media/test/test_bug495145.html:80:5 [task 2017-09-29T15:14:16.439Z] 15:14:16 INFO - startTest@dom/media/test/test_bug495145.html:86:3 [task 2017-09-29T15:14:16.440Z] 15:14:16 INFO - MediaTestManager/this.nextTest@dom/media/test/manifest.js:1748:7 [task 2017-09-29T15:14:16.440Z] 15:14:16 INFO - MediaTestManager/this.finished@dom/media/test/manifest.js:1727:7 [task 2017-09-29T15:14:16.441Z] 15:14:16 INFO - EventListener.handleEvent*createVideo@dom/media/test/test_bug495145.html:78:3 [task 2017-09-29T15:14:16.441Z] 15:14:16 INFO - EventListener.handleEvent*createVideo@dom/media/test/test_bug495145.html:80:5 [task 2017-09-29T15:14:16.442Z] 15:14:16 INFO - startTest@dom/media/test/test_bug495145.html:86:3 [task 2017-09-29T15:14:16.443Z] 15:14:16 INFO - MediaTestManager/this.nextTest@dom/media/test/manifest.js:1748:7 [task 2017-09-29T15:14:16.443Z] 15:14:16 INFO - MediaTestManager/this.runTests/<@dom/media/test/manifest.js:1668:7 [task 2017-09-29T15:14:16.446Z] 15:14:16 INFO - flac-s24.flac-11a timed out!
The failure rate has increased in the last 2 weeks- majority of failures are on non-debug configurations for linux and windows. here is a recent linux failure: https://treeherder.mozilla.org/logviewer.html#?repo=autoland&job_id=138513768&lineNumber=2578 and the screenshot (doesn't appear useful): https://public-artifacts.taskcluster.net/PdXyJqQaQ9KBqlOAJ-QHZA/0/public/test_info//mozilla-test-fail-screenshot_m6wRX3.png and related data from the above failure: [task 2017-10-20T15:43:53.941Z] 15:43:53 INFO - [finished detodos-short.opus-9a] remaining= gizmo-short.mp4-10a [task 2017-10-20T15:43:53.942Z] 15:43:53 INFO - TEST-PASS | dom/media/test/test_bug495145.html | [finished detodos-short.opus-9a t=12.146] Length of array should match number of running tests [task 2017-10-20T15:43:53.945Z] 15:43:53 INFO - TEST-PASS | dom/media/test/test_bug495145.html | [started flac-s24.flac-11a t=12.149] Length of array should match number of running tests [task 2017-10-20T15:43:53.947Z] 15:43:53 INFO - TEST-PASS | dom/media/test/test_bug495145.html | [started flac-s24.flac-11b t=12.149] Length of array should match number of running tests [task 2017-10-20T15:43:53.948Z] 15:43:53 INFO - Buffered messages logged at 15:40:55 [task 2017-10-20T15:43:53.949Z] 15:43:53 INFO - TEST-PASS | dom/media/test/test_bug495145.html | Playing after pause while ended works for gizmo-short.mp4#1 [task 2017-10-20T15:43:53.950Z] 15:43:53 INFO - [finished gizmo-short.mp4-10a] remaining= flac-s24.flac-11a,flac-s24.flac-11b [task 2017-10-20T15:43:53.951Z] 15:43:53 INFO - TEST-PASS | dom/media/test/test_bug495145.html | [finished gizmo-short.mp4-10a t=14.666] Length of array should match number of running tests [task 2017-10-20T15:43:53.953Z] 15:43:53 INFO - Buffered messages logged at 15:40:59 [task 2017-10-20T15:43:53.954Z] 15:43:53 INFO - TEST-PASS | dom/media/test/test_bug495145.html | Paused after seek after pause while ended for flac-s24.flac#2 [task 2017-10-20T15:43:53.955Z] 15:43:53 INFO - [finished flac-s24.flac-11b] remaining= flac-s24.flac-11a [task 2017-10-20T15:43:53.958Z] 15:43:53 INFO - TEST-PASS | dom/media/test/test_bug495145.html | [finished flac-s24.flac-11b t=18.501] Length of array should match number of running tests [task 2017-10-20T15:43:53.959Z] 15:43:53 INFO - Buffered messages finished [task 2017-10-20T15:43:53.961Z] 15:43:53 INFO - TEST-UNEXPECTED-FAIL | dom/media/test/test_bug495145.html | Test timed out! [task 2017-10-20T15:43:53.962Z] 15:43:53 INFO - onTimeout@dom/media/test/manifest.js:1688:7 [task 2017-10-20T15:43:53.964Z] 15:43:53 INFO - setTimeout handler*MediaTestManager/this.started@dom/media/test/manifest.js:1694:26 [task 2017-10-20T15:43:53.964Z] 15:43:53 INFO - createVideo@dom/media/test/test_bug495145.html:72:3 [task 2017-10-20T15:43:53.965Z] 15:43:53 INFO - startTest@dom/media/test/test_bug495145.html:85:3 [task 2017-10-20T15:43:53.965Z] 15:43:53 INFO - MediaTestManager/this.nextTest@dom/media/test/manifest.js:1743:7 [task 2017-10-20T15:43:53.966Z] 15:43:53 INFO - MediaTestManager/this.finished@dom/media/test/manifest.js:1722:7 [task 2017-10-20T15:43:53.967Z] 15:43:53 INFO - ended1@dom/media/test/test_bug495145.html:37:5 [task 2017-10-20T15:43:53.967Z] 15:43:53 INFO - EventListener.handleEvent*createVideo@dom/media/test/test_bug495145.html:78:3 [task 2017-10-20T15:43:53.968Z] 15:43:53 INFO - startTest@dom/media/test/test_bug495145.html:85:3 [task 2017-10-20T15:43:53.969Z] 15:43:53 INFO - MediaTestManager/this.nextTest@dom/media/test/manifest.js:1743:7 [task 2017-10-20T15:43:53.970Z] 15:43:53 INFO - MediaTestManager/this.finished@dom/media/test/manifest.js:1722:7 [task 2017-10-20T15:43:53.971Z] 15:43:53 INFO - seeked2@dom/media/test/test_bug495145.html:65:3 [task 2017-10-20T15:43:53.971Z] 15:43:53 INFO - EventListener.handleEvent*createVideo@dom/media/test/test_bug495145.html:80:5 [task 2017-10-20T15:43:53.972Z] 15:43:53 INFO - startTest@dom/media/test/test_bug495145.html:86:3 [task 2017-10-20T15:43:53.973Z] 15:43:53 INFO - MediaTestManager/this.nextTest@dom/media/test/manifest.js:1743:7 [task 2017-10-20T15:43:53.974Z] 15:43:53 INFO - MediaTestManager/this.finished@dom/media/test/manifest.js:1722:7 [task 2017-10-20T15:43:53.975Z] 15:43:53 INFO - seeked2@dom/media/test/test_bug495145.html:65:3 [task 2017-10-20T15:43:53.975Z] 15:43:53 INFO - EventListener.handleEvent*createVideo@dom/media/test/test_bug495145.html:80:5 [task 2017-10-20T15:43:53.976Z] 15:43:53 INFO - startTest@dom/media/test/test_bug495145.html:86:3 [task 2017-10-20T15:43:53.977Z] 15:43:53 INFO - MediaTestManager/this.nextTest@dom/media/test/manifest.js:1743:7 [task 2017-10-20T15:43:53.977Z] 15:43:53 INFO - MediaTestManager/this.finished@dom/media/test/manifest.js:1722:7 [task 2017-10-20T15:43:53.978Z] 15:43:53 INFO - ended1@dom/media/test/test_bug495145.html:37:5 [task 2017-10-20T15:43:53.979Z] 15:43:53 INFO - EventListener.handleEvent*createVideo@dom/media/test/test_bug495145.html:78:3 [task 2017-10-20T15:43:53.980Z] 15:43:53 INFO - startTest@dom/media/test/test_bug495145.html:85:3 [task 2017-10-20T15:43:53.980Z] 15:43:53 INFO - MediaTestManager/this.nextTest@dom/media/test/manifest.js:1743:7 [task 2017-10-20T15:43:53.981Z] 15:43:53 INFO - MediaTestManager/this.finished@dom/media/test/manifest.js:1722:7 [task 2017-10-20T15:43:53.982Z] 15:43:53 INFO - EventListener.handleEvent*createVideo@dom/media/test/test_bug495145.html:78:3 [task 2017-10-20T15:43:53.982Z] 15:43:53 INFO - startTest@dom/media/test/test_bug495145.html:85:3 [task 2017-10-20T15:43:53.983Z] 15:43:53 INFO - MediaTestManager/this.nextTest@dom/media/test/manifest.js:1743:7 [task 2017-10-20T15:43:53.983Z] 15:43:53 INFO - MediaTestManager/this.finished@dom/media/test/manifest.js:1722:7 [task 2017-10-20T15:43:53.984Z] 15:43:53 INFO - ended1@dom/media/test/test_bug495145.html:37:5 [task 2017-10-20T15:43:53.985Z] 15:43:53 INFO - EventListener.handleEvent*createVideo@dom/media/test/test_bug495145.html:78:3 [task 2017-10-20T15:43:53.985Z] 15:43:53 INFO - EventListener.handleEvent*createVideo@dom/media/test/test_bug495145.html:80:5 [task 2017-10-20T15:43:53.986Z] 15:43:53 INFO - startTest@dom/media/test/test_bug495145.html:86:3 [task 2017-10-20T15:43:53.987Z] 15:43:53 INFO - MediaTestManager/this.nextTest@dom/media/test/manifest.js:1743:7 [task 2017-10-20T15:43:53.988Z] 15:43:53 INFO - MediaTestManager/this.runTests/<@dom/media/test/manifest.js:1663:7 [task 2017-10-20T15:43:53.989Z] 15:43:53 INFO - flac-s24.flac-11a timed out! [task 2017-10-20T15:43:53.989Z] 15:43:53 INFO - [finished flac-s24.flac-11a] remaining= [task 2017-10-20T15:43:53.990Z] 15:43:53 INFO - TEST-PASS | dom/media/test/test_bug495145.html | [finished flac-s24.flac-11a t=192.152] Length of array should match number of running tests [task 2017-10-20T15:43:53.991Z] 15:43:53 INFO - GECKO(1563) | Decoder=e33ef6c0 MediaDecoder State: channels=2 rate=88200 hasAudio=1 hasVideo=0 mPlayState=PLAYING mdsm=e128b800 [task 2017-10-20T15:43:53.992Z] 15:43:53 INFO - GECKO(1563) | reader data: [task 2017-10-20T15:43:53.993Z] 15:43:53 INFO - GECKO(1563) | Container Type: audio/flac [task 2017-10-20T15:43:53.994Z] 15:43:53 INFO - GECKO(1563) | Audio Decoder(audio/flac): ffmpeg audio decoder [task 2017-10-20T15:43:53.995Z] 15:43:53 INFO - GECKO(1563) | Audio Frames Decoded: 41 [task 2017-10-20T15:43:53.996Z] 15:43:53 INFO - GECKO(1563) | Audio State: ni=0 no=0 wp=0 demuxr=0 demuxq=0 decoder=0 tt=-1.0 tths=-1 in=41 out=40 qs=1 pending=0 wfd=0 eos=0 ds=0 wfk=0 sid=4294967295 [task 2017-10-20T15:43:53.997Z] 15:43:53 INFO - GECKO(1563) | Video Decoder(none, 0x0 @ 0.00): unavailable [task 2017-10-20T15:43:53.998Z] 15:43:53 INFO - GECKO(1563) | Hardware Video Decoding: disabled [task 2017-10-20T15:43:53.999Z] 15:43:53 INFO - GECKO(1563) | Video Frames Decoded: 0 (skipped=0) [task 2017-10-20T15:43:54.000Z] 15:43:53 INFO - GECKO(1563) | Decoder=e33ef6c0 MediaDecoderStateMachine State: GetMediaTime=3714467 GetClock=3714467 mMediaSink=e8b3b5f0 state=DECODING mPlayState=3 mSentFirstFrameLoadedEvent=1 IsPlaying=1 mAudioStatus=idle mVideoStatus=idle mDecodedAudioEndTime=3715191 mDecodedVideoEndTime=0mAudioCompleted=0 mVideoCompleted=0mIsPrerolling=0 [task 2017-10-20T15:43:54.001Z] 15:43:54 INFO - GECKO(1563) | VideoSink Status: IsStarted=1 IsPlaying=1 VideoQueue(finished=0 size=0) mVideoFrameEndTime=0 mHasVideo=0 mVideoSinkEndRequest.Exists()=0 mEndPromiseHolder.IsEmpty()=1 [task 2017-10-20T15:43:54.003Z] 15:43:54 INFO - Finished at Fri Oct 20 2017 15:43:53 GMT+0000 (UTC) (1508514233.36s) [task 2017-10-20T15:43:54.004Z] 15:43:54 INFO - Running time: 192.202s [task 2017-10-20T15:43:54.006Z] 15:43:54 INFO - GECKO(1563) | MEMORY STAT | vsize 575MB | residentFast 98MB | heapAllocated 12MB [task 2017-10-20T15:43:54.007Z] 15:43:54 INFO - TEST-OK | dom/media/test/test_bug495145.html | took 192382ms [task 2017-10-20T15:43:54.009Z] 15:43:54 INFO - TEST-START | dom/media/test/test_bug495300.html :k17e, can you help get this bug in front of the right developer?
Flags: needinfo?(ajones)
Whiteboard: [stockwell needswork]
Blake - can you get someone to take a looksee at this?
Flags: needinfo?(ajones) → needinfo?(bwu)
JW, Would this be related to Bug 1407553?
Flags: needinfo?(bwu) → needinfo?(jwwang)
No, I don't think so for the failure happens on Linux also.
Flags: needinfo?(jwwang)
https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=138433062&lineNumber=2447 [flac @ 0xe11db400] illegal residual coding method 2 [flac @ 0xe11db400] decode_frame() failed [Child 1706, MediaPlayback #3] WARNING: Decoder=e21f51a0 Decode error: file /builds/worker/workspace/build/src/dom/media/MediaDecoderStateMachine.cpp, line 3350 It looks like a decode error in flac decoder which prevents playback from reaching the end and causes the timeout. I will add more logs to diagnose the issue.
Depends on: 1411476
Hope bug 1406503 fix the decode errors in flac decoder.
Depends on: 1406503
https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-inbound&job_id=142085213&lineNumber=6135 WARNING: FFmpeg audio decoder error.: file /builds/worker/workspace/build/src/dom/media/platforms/ffmpeg/FFmpegAudioDecoder.cpp, line 154 Tons of audio decode error... Let's add some logs to figure out what these errors are about.
(In reply to JW Wang [:jwwang] [:jw_wang] from comment #14) > https://treeherder.mozilla.org/logviewer.html#?repo=mozilla- > inbound&job_id=142085213&lineNumber=6135 > > WARNING: FFmpeg audio decoder error.: file > /builds/worker/workspace/build/src/dom/media/platforms/ffmpeg/ > FFmpegAudioDecoder.cpp, line 154 > > Tons of audio decode error... > > Let's add some logs to figure out what these errors are about. Bug 1420324 might be the cause.
Depends on: 1420324
Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → INCOMPLETE

There are 24 failures in the last 7 days windows10-64-shippable-qr and windows10-64-shippable opt, windows10-64-qr and windows10-64 opt, windows10-64 debug, macosx1014-64-shippable opt:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?startday=2019-08-30&endday=2019-09-06&tree=trunk&bug=1404373

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

[task 2019-09-06T01:20:38.811Z] 01:20:38 INFO - TEST-UNEXPECTED-FAIL | dom/media/test/test_bug495145.html | Test timed out!
[task 2019-09-06T01:20:38.811Z] 01:20:38 INFO - SimpleTest.ok@SimpleTest/SimpleTest.js:277:18
[task 2019-09-06T01:20:38.811Z] 01:20:38 INFO - onTimeout@dom/media/test/manifest.js:1760:9
[task 2019-09-06T01:20:38.812Z] 01:20:38 INFO - setTimeout handlerMediaTestManager/this.started@dom/media/test/manifest.js:1767:57
[task 2019-09-06T01:20:38.812Z] 01:20:38 INFO - createVideo@dom/media/test/test_bug495145.html:72:11
[task 2019-09-06T01:20:38.812Z] 01:20:38 INFO - startTest@dom/media/test/test_bug495145.html:86:14
[task 2019-09-06T01:20:38.812Z] 01:20:38 INFO - MediaTestManager/this.nextTest@dom/media/test/manifest.js:1816:12
[task 2019-09-06T01:20:38.812Z] 01:20:38 INFO - MediaTestManager/this.finished@dom/media/test/manifest.js:1795:12
[task 2019-09-06T01:20:38.812Z] 01:20:38 INFO - seeked2@dom/media/test/test_bug495145.html:65:11
[task 2019-09-06T01:20:38.812Z] 01:20:38 INFO - EventListener.handleEvent
createVideo@dom/media/test/test_bug495145.html:80:7

Nils, can you redirect this to someone who can look into it?

Flags: needinfo?(drno)
Whiteboard: [stockwell unknown] → [stockwell unknown][stockwell needswork:owner]

In the last 7 days there were 29 failures associated with this bug: https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?startday=2019-09-13&endday=2019-09-20&tree=all&bug=1404373
Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=267624752&repo=mozilla-central&lineNumber=1980
Occurs on windows10-64, windows10-64-devedition, windows10-64-qr, windows10-64-shippable opt and debug build types.

There are 30 total failures in the last 7 days and 94 total failures in the lat 30 days on windows10-64, windows10-64-qr and windows10-64-shippable all opt builds.

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

[task 2019-10-10T20:16:55.999Z] 20:16:55 INFO - TEST-START | dom/media/test/test_bug495145.html
[task 2019-10-10T20:17:01.424Z] 20:17:01 INFO - GECKO(10656) | [Child 2608, MediaDecoderStateMachine #1] WARNING: Decoder=1d8e5b0e000 Decode error: NS_ERROR_DOM_MEDIA_DECODE_ERR (0x806e0004) - virtual mozilla::MediaResult __cdecl mozilla::FFmpegAudioDecoder<46465650>::DoDecode(mozilla::MediaRawData *, uint8_t *, int, bool *, mozilla::MediaDataDecoder::DecodedData &): FFmpeg audio error:-1094995529: file z:/task_1570727179/build/src/dom/media/MediaDecoderStateMachine.cpp, line 3308
[task 2019-10-10T20:20:00.042Z] 20:20:00 INFO - TEST-INFO | started process screenshot
[task 2019-10-10T20:20:00.108Z] 20:20:00 INFO - TEST-INFO | screenshot: exit 0
[task 2019-10-10T20:20:00.109Z] 20:20:00 INFO - Buffered messages logged at 20:16:56
[task 2019-10-10T20:20:00.109Z] 20:20:00 INFO - TEST-PASS | dom/media/test/test_bug495145.html | A valid string reason is expected
[task 2019-10-10T20:20:00.109Z] 20:20:00 INFO - TEST-PASS | dom/media/test/test_bug495145.html | Reason cannot be empty
[task 2019-10-10T20:20:00.110Z] 20:20:00 INFO - Started Thu Oct 10 2019 20:16:56 GMT+0000 (Greenwich Mean Time) (1570738616.028s)
[task 2019-10-10T20:20:00.110Z] 20:20:00 INFO - TEST-PASS | dom/media/test/test_bug495145.html | [started small-shot.ogg-0a t=0.005] Length of array should match number of running tests
[task 2019-10-10T20:20:00.111Z] 20:20:00 INFO - TEST-PASS | dom/media/test/test_bug495145.html | [started small-shot.ogg-0b t=0.015] Length of array should match number of running tests
[task 2019-10-10T20:20:00.111Z] 20:20:00 INFO - TEST-PASS | dom/media/test/test_bug495145.html | Paused after seek after pause while ended for small-shot.ogg#2
[task 2019-10-10T20:20:00.111Z] 20:20:00 INFO - [finished small-shot.ogg-0b] remaining= small-shot.ogg-0a

task 2019-10-10T20:20:00.140Z] 20:20:00 INFO - TEST-PASS | dom/media/test/test_bug495145.html | [finished flac-s24.flac-11a t=7.144] Length of array should match number of running tests
[task 2019-10-10T20:20:00.140Z] 20:20:00 INFO - Buffered messages finished
[task 2019-10-10T20:20:00.140Z] 20:20:00 INFO - TEST-UNEXPECTED-FAIL | dom/media/test/test_bug495145.html | Test timed out!
[task 2019-10-10T20:20:00.140Z] 20:20:00 INFO - SimpleTest.ok@SimpleTest/SimpleTest.js:277:18
[task 2019-10-10T20:20:00.140Z] 20:20:00 INFO - onTimeout@dom/media/test/manifest.js:1760:9
[task 2019-10-10T20:20:00.140Z] 20:20:00 INFO - setTimeout handlerMediaTestManager/this.started@dom/media/test/manifest.js:1767:57
[task 2019-10-10T20:20:00.140Z] 20:20:00 INFO - createVideo@dom/media/test/test_bug495145.html:72:11
[task 2019-10-10T20:20:00.140Z] 20:20:00 INFO - startTest@dom/media/test/test_bug495145.html:86:14
[task 2019-10-10T20:20:00.140Z] 20:20:00 INFO - MediaTestManager/this.nextTest@dom/media/test/manifest.js:1816:12
[task 2019-10-10T20:20:00.140Z] 20:20:00 INFO - MediaTestManager/this.finished@dom/media/test/manifest.js:1795:12
[task 2019-10-10T20:20:00.140Z] 20:20:00 INFO - seeked2@dom/media/test/test_bug495145.html:65:11
[task 2019-10-10T20:20:00.140Z] 20:20:00 INFO - EventListener.handleEvent
createVideo@dom/media/test/test_bug495145.html:80:7
[task 2019-10-10T20:20:00.140Z] 20:20:00 INFO - startTest@dom/media/test/test_bug495145.html:86:14
[task 2019-10-10T20:20:00.140Z] 20:20:00 INFO - MediaTestManager/this.nextTest@dom/media/test/manifest.js:1816:12
[task 2019-10-10T20:20:00.140Z] 20:20:00 INFO - MediaTestManager/this.finished@dom/media/test/manifest.js:1795:12
[task 2019-10-10T20:20:00.140Z] 20:20:00 INFO - seeked2@dom/media/test/test_bug495145.html:65:11
[task 2019-10-10T20:20:00.141Z] 20:20:00 INFO - EventListener.handleEventcreateVideo@dom/media/test/test_bug495145.html:80:7
[task 2019-10-10T20:20:00.141Z] 20:20:00 INFO - startTest@dom/media/test/test_bug495145.html:86:14
[task 2019-10-10T20:20:00.141Z] 20:20:00 INFO - MediaTestManager/this.nextTest@dom/media/test/manifest.js:1816:12
[task 2019-10-10T20:20:00.141Z] 20:20:00 INFO - MediaTestManager/this.finished@dom/media/test/manifest.js:1795:12
[task 2019-10-10T20:20:00.141Z] 20:20:00 INFO - ended1@dom/media/test/test_bug495145.html:37:13
[task 2019-10-10T20:20:00.141Z] 20:20:00 INFO - EventListener.handleEvent
createVideo@dom/media/test/test_bug495145.html:78:5
[task 2019-10-10T20:20:00.141Z] 20:20:00 INFO - startTest@dom/media/test/test_bug495145.html:85:14
[task 2019-10-10T20:20:00.141Z] 20:20:00 INFO - MediaTestManager/this.nextTest@dom/media/test/manifest.js:1816:12
[task 2019-10-10T20:20:00.141Z] 20:20:00 INFO - MediaTestManager/this.finished@dom/media/test/manifest.js:1795:12
[task 2019-10-10T20:20:00.141Z] 20:20:00 INFO - ended1@dom/media/test/test_bug495145.html:37:13
[task 2019-10-10T20:20:00.141Z] 20:20:00 INFO - EventListener.handleEventcreateVideo@dom/media/test/test_bug495145.html:78:5
[task 2019-10-10T20:20:00.141Z] 20:20:00 INFO - startTest@dom/media/test/test_bug495145.html:85:14
[task 2019-10-10T20:20:00.141Z] 20:20:00 INFO - MediaTestManager/this.nextTest@dom/media/test/manifest.js:1816:12
[task 2019-10-10T20:20:00.141Z] 20:20:00 INFO - MediaTestManager/this.finished@dom/media/test/manifest.js:1795:12
[task 2019-10-10T20:20:00.141Z] 20:20:00 INFO - ended1@dom/media/test/test_bug495145.html:37:13
[task 2019-10-10T20:20:00.141Z] 20:20:00 INFO - EventListener.handleEvent
createVideo@dom/media/test/test_bug495145.html:78:5
[task 2019-10-10T20:20:00.141Z] 20:20:00 INFO - startTest@dom/media/test/test_bug495145.html:85:14
[task 2019-10-10T20:20:00.141Z] 20:20:00 INFO - MediaTestManager/this.nextTest@dom/media/test/manifest.js:1816:12
[task 2019-10-10T20:20:00.141Z] 20:20:00 INFO - MediaTestManager/this.finished@dom/media/test/manifest.js:1795:12
[task 2019-10-10T20:20:00.141Z] 20:20:00 INFO - seeked2@dom/media/test/test_bug495145.html:65:11
[task 2019-10-10T20:20:00.141Z] 20:20:00 INFO - EventListener.handleEventcreateVideo@dom/media/test/test_bug495145.html:80:7
[task 2019-10-10T20:20:00.141Z] 20:20:00 INFO - startTest@dom/media/test/test_bug495145.html:86:14
[task 2019-10-10T20:20:00.141Z] 20:20:00 INFO - MediaTestManager/this.nextTest@dom/media/test/manifest.js:1816:12
[task 2019-10-10T20:20:00.141Z] 20:20:00 INFO - MediaTestManager/this.finished@dom/media/test/manifest.js:1795:12
[task 2019-10-10T20:20:00.142Z] 20:20:00 INFO - seeked2@dom/media/test/test_bug495145.html:65:11
[task 2019-10-10T20:20:00.142Z] 20:20:00 INFO - EventListener.handleEvent
createVideo@dom/media/test/test_bug495145.html:80:7
[task 2019-10-10T20:20:00.142Z] 20:20:00 INFO - startTest@dom/media/test/test_bug495145.html:86:14
[task 2019-10-10T20:20:00.142Z] 20:20:00 INFO - MediaTestManager/this.nextTest@dom/media/test/manifest.js:1816:12
[task 2019-10-10T20:20:00.142Z] 20:20:00 INFO - MediaTestManager/this.finished@dom/media/test/manifest.js:1795:12
[task 2019-10-10T20:20:00.142Z] 20:20:00 INFO - seeked2@dom/media/test/test_bug495145.html:65:11
[task 2019-10-10T20:20:00.142Z] 20:20:00 INFO - EventListener.handleEventcreateVideo@dom/media/test/test_bug495145.html:80:7
[task 2019-10-10T20:20:00.142Z] 20:20:00 INFO - startTest@dom/media/test/test_bug495145.html:86:14
[task 2019-10-10T20:20:00.142Z] 20:20:00 INFO - MediaTestManager/this.nextTest@dom/media/test/manifest.js:1816:12
[task 2019-10-10T20:20:00.142Z] 20:20:00 INFO - MediaTestManager/this.runTests/<@dom/media/test/manifest.js:1736:12
[task 2019-10-10T20:20:00.142Z] 20:20:00 INFO - Async
MediaTestManager/this.runTests@dom/media/test/manifest.js:1735:19
[task 2019-10-10T20:20:00.142Z] 20:20:00 INFO - @dom/media/test/test_bug495145.html:89:9
[task 2019-10-10T20:20:00.143Z] 20:20:00 INFO - flac-s24.flac-11b timed out!
[task 2019-10-10T20:20:00.143Z] 20:20:00 INFO - {"EMEInfo":{"keySystem":"","sessionsInfo":""},"compositorDroppedFrames":0,"decoder":{"PlayState":"PLAYING","channels":2,"containerType":"audio/flac","hasAudio":true,"hasVideo":false,"instance":"1d8e5b0e000","rate":88200,"reader":{"audioChannels":2,"audioDecoderName":"ffmpeg audio decoder","audioFramesDecoded":41,"audioRate":88.19999694824219,"audioState":{"demuxEOS":0,"demuxQueueSize":0,"drainState":0,"hasDecoder":false,"hasDemuxRequest":false,"hasPromise":false,"lastStreamSourceID":-1,"needInput":false,"numSamplesInput":41,"numSamplesOutput":40,"pending":0,"queueSize":1,"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":3714520,"decodedAudioEndTime":3715191,"decodedVideoEndTime":0,"duration":4040272,"isPlaying":true,"mediaSink":{"audioSinkWrapper":{"audioEnded":false,"audioSink":{"audioEnded":true,"hasErrored":false,"isPlaying":true,"isStarted":true,"lastGoodPosition":3714520,"outputRate":48000,"playbackComplete":false,"startTime":0,"written":178297},"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":3714520,"playState":3,"sentFirstFrameLoadedEvent":true,"state":"","stateObj":{"isPrerolling":false},"videoCompleted":false,"videoRequestStatus":"idle"}}}
[task 2019-10-10T20:20:00.143Z] 20:20:00 INFO - [finished flac-s24.flac-11b] remaining=
[task 2019-10-10T20:20:00.143Z] 20:20:00 INFO - TEST-PASS | dom/media/test/test_bug495145.html | [finished flac-s24.flac-11b t=184.006] Length of array should match number of running tests
[task 2019-10-10T20:20:00.143Z] 20:20:00 INFO - Finished at Thu Oct 10 2019 20:20:00 GMT+0000 (Greenwich Mean Time) (1570738800.098s)
[task 2019-10-10T20:20:00.143Z] 20:20:00 INFO - Running time: 184.07s
[task 2019-10-10T20:20:00.143Z] 20:20:00 INFO - GECKO(10656) | MEMORY STAT | vsize 2103855MB | vsizeMaxContiguous 67291758MB | residentFast 143MB | heapAllocated 15MB
[task 2019-10-10T20:20:00.144Z] 20:20:00 INFO - TEST-OK | dom/media/test/test_bug495145.html | took 184131ms

Geoff since the triage owner did not reply should we disable the test until someone is available to fix it?

Flags: needinfo?(gbrown)

Yes, I think that's reasonable.

The test is already skipped on android and win/aarch64. I think that could be expanded to android or all windows.

Flags: needinfo?(gbrown)
Keywords: leave-open
Whiteboard: [stockwell unknown][stockwell needswork:owner] → [stockwell unknown][stockwell disabled]
Pushed by apavel@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/7bf98679fda4 disabled test_bug495145.html on win r=gbrown
Severity: normal → S4
Flags: needinfo?(drno)
Status: REOPENED → RESOLVED
Closed: 6 years ago3 years ago
Resolution: --- → DUPLICATE
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: