[task 2020-12-01T11:22:25.987Z] 11:22:25 INFO - TEST-START | dom/media/test/test_seamless_looping.html
[task 2020-12-01T11:27:51.939Z] 11:27:51 INFO - TEST-INFO | started process screenshot
[task 2020-12-01T11:27:52.019Z] 11:27:52 INFO - TEST-INFO | screenshot: exit 0
[task 2020-12-01T11:27:52.019Z] 11:27:52 INFO - Buffered messages logged at 11:22:26
[task 2020-12-01T11:27:52.019Z] 11:27:52 INFO - TEST-PASS | dom/media/test/test_seamless_looping.html | A valid string reason is expected
[task 2020-12-01T11:27:52.019Z] 11:27:52 INFO - TEST-PASS | dom/media/test/test_seamless_looping.html | Reason cannot be empty
[task 2020-12-01T11:27:52.019Z] 11:27:52 INFO - - create looping audio element -
[task 2020-12-01T11:27:52.019Z] 11:27:52 INFO - - start audio and analyze audio wave data to ensure looping audio without any silence or noise -
[task 2020-12-01T11:27:52.019Z] 11:27:52 INFO - TEST-PASS | dom/media/test/test_seamless_looping.html | audio can start playing.
[task 2020-12-01T11:27:52.019Z] 11:27:52 INFO - TEST-PASS | dom/media/test/test_seamless_looping.html | audio started playing successfully.
[task 2020-12-01T11:27:52.019Z] 11:27:52 INFO - - test seamless looping multiples times -
[task 2020-12-01T11:27:52.019Z] 11:27:52 INFO - Buffered messages finished
[task 2020-12-01T11:27:52.019Z] 11:27:52 INFO - TEST-UNEXPECTED-FAIL | dom/media/test/test_seamless_looping.html | Test timed out.
[task 2020-12-01T11:27:52.019Z] 11:27:52 INFO - SimpleTest.ok@SimpleTest/SimpleTest.js:417:16
[task 2020-12-01T11:27:52.019Z] 11:27:52 INFO - reportError@SimpleTest/TestRunner.js:143:22
[task 2020-12-01T11:27:52.019Z] 11:27:52 INFO - TestRunner._checkForHangs@SimpleTest/TestRunner.js:165:18
[task 2020-12-01T11:27:52.965Z] 11:27:52 INFO - {"EMEInfo":{"keySystem":"","sessionsInfo":""},"compositorDroppedFrames":0,"decoder":{"PlayState":"PLAYING","channels":1,"containerType":"audio/x-wav","hasAudio":true,"hasVideo":false,"instance":"14b003ed800","rate":44100,"reader":{"audioChannels":1,"audioDecoderName":"wave audio decoder (RDD remote)","audioFramesDecoded":200,"audioRate":44.099998474121094,"audioState":{"demuxEOS":0,"demuxQueueSize":0,"drainState":0,"hasDecoder":false,"hasDemuxRequest":false,"hasPromise":false,"lastStreamSourceID":-1,"needInput":false,"numSamplesInput":84,"numSamplesOutput":84,"pending":0,"queueSize":0,"timeTreshold":-1,"timeTresholdHasSeeked":false,"waitingForData":false,"waitingForKey":false,"waitingPromise":false},"audioType":"audio/wave; codecs=1","frameStats":{"droppedCompositorFrames":0,"droppedDecodedFrames":0,"droppedSinkFrames":0},"videoDecoderName":"unavailable","videoHardwareAccelerated":false,"videoHeight":0,"videoNumSamplesOutputTotal":0,"videoNumSamplesSkippedTotal":0,"videoRate":0,"videoState":{"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},"videoType":"none","videoWidth":0},"resource":{"cacheStream":{"cacheSuspended":false,"channelEnded":false,"channelOffset":0,"loadID":0,"streamLength":0}},"stateMachine":{"audioCompleted":false,"audioRequestStatus":"idle","clock":728000,"decodedAudioEndTime":1731427,"decodedVideoEndTime":0,"duration":1000000,"isPlaying":true,"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":116,"data":{"audioFramesWritten":76356,"haveSentFinishAudio":false,"haveSentFinishVideo":false,"instance":"14b019d8120","lastVideoEndTime":-1,"lastVideoStartTime":-1,"nextAudioTime":1731427,"streamAudioWritten":83109,"streamVideoWritten":0},"instance":"14b003f2000","lastAudio":1731427,"lastOutputTime":728000,"playing":1,"startTime":0},"videoSink":{"endPromiseHolderIsEmpty":true,"finished":false,"hasVideo":false,"isPlaying":true,"isStarted":true,"size":0,"videoFrameEndTime":0,"videoSinkEndRequestExists":false}},"mediaTime":728000,"playState":3,"sentFirstFrameLoadedEvent":true,"state":"","stateObj":{"isPrerolling":false},"videoCompleted":false,"videoRequestStatus":"idle"}}}
[task 2020-12-01T11:27:52.984Z] 11:27:52 INFO - GECKO(3432) | MEMORY STAT | vsize 2103864MB | vsizeMaxContiguous 71411695MB | residentFast 101MB | heapAllocated 13MB
[task 2020-12-01T11:27:52.984Z] 11:27:52 INFO - TEST-OK | dom/media/test/test_seamless_looping.html | took 326999ms
[task 2020-12-01T11:27:53.002Z] 11:27:53 INFO - TEST-START | dom/media/test/test_seek-1.html
[task 2020-12-01T11:27:53.049Z] 11:27:53 INFO - GECKO(3432) | SEEK-TEST: Started r11025_s16_c1.wav seek test 1
[task 2020-12-01T11:27:53.049Z] 11:27:53 INFO - GECKO(3432) | SEEK-TEST: Started audio.wav seek test 1
[task 2020-12-01T11:30:53.076Z] 11:30:53 INFO - Not taking screenshot here: see the one that was previously logged
[task 2020-12-01T11:30:53.076Z] 11:30:53 INFO - Buffered messages logged at 11:27:53
[task 2020-12-01T11:30:53.076Z] 11:30:53 INFO - TEST-PASS | dom/media/test/test_seek-1.html | A valid string reason is expected
[task 2020-12-01T11:30:53.076Z] 11:30:53 INFO - TEST-PASS | dom/media/test/test_seek-1.html | Reason cannot be empty
[task 2020-12-01T11:30:53.076Z] 11:30:53 INFO - Started Tue Dec 01 2020 11:27:53 GMT+0000 (Greenwich Mean Time) (1606822073.038s)
[task 2020-12-01T11:30:53.076Z] 11:30:53 INFO - TEST-PASS | dom/media/test/test_seek-1.html | [started r11025_s16_c1.wav-0-seek1.js t=0.003] Length of array should match number of running tests
[task 2020-12-01T11:30:53.077Z] 11:30:53 INFO - TEST-PASS | dom/media/test/test_seek-1.html | [started audio.wav-1-seek1.js t=0.006] Length of array should match number of running tests
[task 2020-12-01T11:30:53.077Z] 11:30:53 INFO - TEST-PASS | dom/media/test/test_seek-1.html | audio.wav seek test 1: Should not be completed yet
[task 2020-12-01T11:30:53.077Z] 11:30:53 INFO - TEST-PASS | dom/media/test/test_seek-1.html | audio.wav seek test 1: seeking should default to false
[task 2020-12-01T11:30:53.077Z] 11:30:53 INFO - TEST-PASS | dom/media/test/test_seek-1.html | audio.wav seek test 1: seeking should be readonly
[task 2020-12-01T11:30:53.077Z] 11:30:53 INFO - TEST-PASS | dom/media/test/test_seek-1.html | r11025_s16_c1.wav seek test 1: Should not be completed yet
[task 2020-12-01T11:30:53.077Z] 11:30:53 INFO - TEST-PASS | dom/media/test/test_seek-1.html | r11025_s16_c1.wav seek test 1: seeking should default to false
[task 2020-12-01T11:30:53.077Z] 11:30:53 INFO - TEST-PASS | dom/media/test/test_seek-1.html | r11025_s16_c1.wav seek test 1: seeking should be readonly
[task 2020-12-01T11:30:53.077Z] 11:30:53 INFO - TEST-PASS | dom/media/test/test_seek-1.html | audio.wav seek test 1: should not be completed yet
[task 2020-12-01T11:30:53.077Z] 11:30:53 INFO - TEST-PASS | dom/media/test/test_seek-1.html | audio.wav seek test 1: Video currentTime should be around 0.0156235: 0.0156235 (seeking)
[task 2020-12-01T11:30:53.077Z] 11:30:53 INFO - TEST-PASS | dom/media/test/test_seek-1.html | audio.wav seek test 1: shuld not be completed yet
[task 2020-12-01T11:30:53.078Z] 11:30:53 INFO - TEST-PASS | dom/media/test/test_seek-1.html | audio.wav seek test 1: Video currentTime should be around 0.0156235: 0.015624 (seeked)
[task 2020-12-01T11:30:53.078Z] 11:30:53 INFO - TEST-PASS | dom/media/test/test_seek-1.html | r11025_s16_c1.wav seek test 1: should not be completed yet
[task 2020-12-01T11:30:53.078Z] 11:30:53 INFO - TEST-PASS | dom/media/test/test_seek-1.html | r11025_s16_c1.wav seek test 1: Video currentTime should be around 0.5: 0.5 (seeking)
[task 2020-12-01T11:30:53.078Z] 11:30:53 INFO - TEST-PASS | dom/media/test/test_seek-1.html | r11025_s16_c1.wav seek test 1: shuld not be completed yet
[task 2020-12-01T11:30:53.078Z] 11:30:53 INFO - TEST-PASS | dom/media/test/test_seek-1.html | r11025_s16_c1.wav seek test 1: Video currentTime should be around 0.5: 0.5 (seeked)
[task 2020-12-01T11:30:53.078Z] 11:30:53 INFO - Buffered messages finished
[task 2020-12-01T11:30:53.078Z] 11:30:53 INFO - TEST-UNEXPECTED-FAIL | dom/media/test/test_seek-1.html | Test timed out!
[task 2020-12-01T11:30:53.078Z] 11:30:53 INFO - SimpleTest.ok@SimpleTest/SimpleTest.js:417:16
[task 2020-12-01T11:30:53.078Z] 11:30:53 INFO - onTimeout@dom/media/test/manifest.js:2109:9
[task 2020-12-01T11:30:53.078Z] 11:30:53 INFO - r11025_s16_c1.wav-0-seek1.js timed out!
[task 2020-12-01T11:30:53.078Z] 11:30:53 INFO - Not taking screenshot here: see the one that was previously logged
[task 2020-12-01T11:30:53.078Z] 11:30:53 INFO - TEST-UNEXPECTED-FAIL | dom/media/test/test_seek-1.html | Test timed out!
[task 2020-12-01T11:30:53.079Z] 11:30:53 INFO - SimpleTest.ok@SimpleTest/SimpleTest.js:417:16
[task 2020-12-01T11:30:53.079Z] 11:30:53 INFO - onTimeout@dom/media/test/manifest.js:2109:9
[task 2020-12-01T11:30:53.079Z] 11:30:53 INFO - audio.wav-1-seek1.js timed out!
[task 2020-12-01T11:30:53.097Z] 11:30:53 INFO - {"EMEInfo":{"keySystem":"","sessionsInfo":""},"compositorDroppedFrames":0,"decoder":{"PlayState":"PLAYING","channels":1,"containerType":"audio/x-wav","hasAudio":true,"hasVideo":false,"instance":"14b0012ac00","rate":11025,"reader":{"audioChannels":1,"audioDecoderName":"shutdown","audioFramesDecoded":19,"audioRate":11.024999618530273,"audioState":{"demuxEOS":1,"demuxQueueSize":0,"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},"audioType":"audio/wave; codecs=1","frameStats":{"droppedCompositorFrames":0,"droppedDecodedFrames":0,"droppedSinkFrames":0},"videoDecoderName":"unavailable","videoHardwareAccelerated":false,"videoHeight":0,"videoNumSamplesOutputTotal":0,"videoNumSamplesSkippedTotal":0,"videoRate":0,"videoState":{"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},"videoType":"none","videoWidth":0},"resource":{"cacheStream":{"cacheSuspended":false,"channelEnded":false,"channelOffset":0,"loadID":0,"streamLength":0}},"stateMachine":{"audioCompleted":false,"audioRequestStatus":"idle","clock":500000,"decodedAudioEndTime":999999,"decodedVideoEndTime":0,"duration":1000000,"isPlaying":true,"mediaSink":{"audioSinkWrapper":{"audioEnded":false,"audioSink":{"audioEnded":false,"hasErrored":false,"isPlaying":true,"isStarted":false,"lastGoodPosition":0,"outputRate":48000,"playbackComplete":false,"startTime":500000,"written":4800},"isPlaying":true,"isStarted":true},"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":true,"isStarted":true,"size":0,"videoFrameEndTime":0,"videoSinkEndRequestExists":false}},"mediaTime":500000,"playState":3,"sentFirstFrameLoadedEvent":true,"state":"","stateObj":{"isPrerolling":false},"videoCompleted":false,"videoRequestStatus":"idle"}}}
[task 2020-12-01T11:30:53.097Z] 11:30:53 INFO - [finished r11025_s16_c1.wav-0-seek1.js] remaining= audio.wav-1-seek1.js
[task 2020-12-01T11:30:53.098Z] 11:30:53 INFO - TEST-PASS | dom/media/test/test_seek-1.html | [finished r11025_s16_c1.wav-0-seek1.js t=180.052] Length of array should match number of running tests
[task 2020-12-01T11:30:53.098Z] 11:30:53 INFO - TEST-PASS | dom/media/test/test_seek-1.html | [started seek.ogv-2-seek1.js t=180.052] Length of array should match number of running tests
[task 2020-12-01T11:30:53.098Z] 11:30:53 INFO - GECKO(3432) | SEEK-TEST: Started seek.ogv seek test 1
[task 2020-12-01T11:30:53.117Z] 11:30:53 INFO - {"EMEInfo":{"keySystem":"","sessionsInfo":""},"compositorDroppedFrames":0,"decoder":{"PlayState":"PLAYING","channels":1,"containerType":"audio/x-wav","hasAudio":true,"hasVideo":false,"instance":"14b003cd400","rate":44100,"reader":{"audioChannels":1,"audioDecoderName":"shutdown","audioFramesDecoded":4,"audioRate":44.099998474121094,"audioState":{"demuxEOS":1,"demuxQueueSize":0,"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},"audioType":"audio/wave; codecs=1","frameStats":{"droppedCompositorFrames":0,"droppedDecodedFrames":0,"droppedSinkFrames":0},"videoDecoderName":"unavailable","videoHardwareAccelerated":false,"videoHeight":0,"videoNumSamplesOutputTotal":0,"videoNumSamplesSkippedTotal":0,"videoRate":0,"videoState":{"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},"videoType":"none","videoWidth":0},"resource":{"cacheStream":{"cacheSuspended":false,"channelEnded":false,"channelOffset":0,"loadID":0,"streamLength":0}},"stateMachine":{"audioCompleted":false,"audioRequestStatus":"idle","clock":15624,"decodedAudioEndTime":31246,"decodedVideoEndTime":0,"duration":31247,"isPlaying":true,"mediaSink":{"audioSinkWrapper":{"audioEnded":false,"audioSink":{"audioEnded":false,"hasErrored":false,"isPlaying":true,"isStarted":false,"lastGoodPosition":0,"outputRate":44100,"playbackComplete":false,"startTime":15624,"written":689},"isPlaying":true,"isStarted":true},"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":true,"isStarted":true,"size":0,"videoFrameEndTime":0,"videoSinkEndRequestExists":false}},"mediaTime":15624,"playState":3,"sentFirstFrameLoadedEvent":true,"state":"","stateObj":{"isPrerolling":false},"videoCompleted":false,"videoRequestStatus":"idle"}}}
[task 2020-12-01T11:30:53.117Z] 11:30:53 INFO - [finished audio.wav-1-seek1.js] remaining= seek.ogv-2-seek1.js
[task 2020-12-01T11:30:53.117Z] 11:30:53 INFO - TEST-PASS | dom/media/test/test_seek-1.html | [finished audio.wav-1-seek1.js t=180.072] Length of array should match number of running tests
[task 2020-12-01T11:30:53.118Z] 11:30:53 INFO - TEST-PASS | dom/media/test/test_seek-1.html | [started 320x240.ogv-3-seek1.js t=180.072] Length of array should match number of running tests
[task 2020-12-01T11:30:53.118Z] 11:30:53 INFO - GECKO(3432) | SEEK-TEST: Started 320x240.ogv seek test 1
[task 2020-12-01T11:30:53.157Z] 11:30:53 INFO - TEST-PASS | dom/media/test/test_seek-1.html | 320x240.ogv seek test 1: Should not be completed yet
[task 2020-12-01T11:30:53.157Z] 11:30:53 INFO - TEST-PASS | dom/media/test/test_seek-1.html | 320x240.ogv seek test 1: seeking should default to false
[task 2020-12-01T11:30:53.158Z] 11:30:53 INFO - TEST-PASS | dom/media/test/test_seek-1.html | 320x240.ogv seek test 1: seeking should be readonly
[task 2020-12-01T11:30:53.158Z] 11:30:53 INFO - TEST-PASS | dom/media/test/test_seek-1.html | 320x240.ogv seek test 1: should not be completed yet
[task 2020-12-01T11:30:53.158Z] 11:30:53 INFO - TEST-PASS | dom/media/test/test_seek-1.html | 320x240.ogv seek test 1: Video currentTime should be around 0.133: 0.133 (seeking)
[task 2020-12-01T11:30:53.158Z] 11:30:53 INFO - TEST-PASS | dom/media/test/test_seek-1.html | 320x240.ogv seek test 1: shuld not be completed yet
[task 2020-12-01T11:30:53.158Z] 11:30:53 INFO - TEST-PASS | dom/media/test/test_seek-1.html | 320x240.ogv seek test 1: Video currentTime should be around 0.133: 0.133 (seeked)
[task 2020-12-01T11:30:53.177Z] 11:30:53 INFO - TEST-PASS | dom/media/test/test_seek-1.html | seek.ogv seek test 1: Should not be completed yet
[task 2020-12-01T11:30:53.177Z] 11:30:53 INFO - TEST-PASS | dom/media/test/test_seek-1.html | seek.ogv seek test 1: seeking should default to false
[task 2020-12-01T11:30:53.179Z] 11:30:53 INFO - TEST-PASS | dom/media/test/test_seek-1.html | seek.ogv seek test 1: seeking should be readonly
[task 2020-12-01T11:30:53.179Z] 11:30:53 INFO - TEST-PASS | dom/media/test/test_seek-1.html | seek.ogv seek test 1: should not be completed yet
[task 2020-12-01T11:30:53.179Z] 11:30:53 INFO - TEST-PASS | dom/media/test/test_seek-1.html | seek.ogv seek test 1: Video currentTime should be around 1.983: 1.983 (seeking)
[task 2020-12-01T11:30:53.223Z] 11:30:53 INFO - TEST-PASS | dom/media/test/test_seek-1.html | seek.ogv seek test 1: shuld not be completed yet
[task 2020-12-01T11:30:53.223Z] 11:30:53 INFO - TEST-PASS | dom/media/test/test_seek-1.html | seek.ogv seek test 1: Video currentTime should be around 1.983: 1.983 (seeked)
[task 2020-12-01T11:30:53.304Z] 11:30:53 INFO - TEST-PASS | dom/media/test/test_seek-1.html | 320x240.ogv seek test 1: should not be completed yet
[task 2020-12-01T11:30:53.304Z] 11:30:53 INFO - TEST-PASS | dom/media/test/test_seek-1.html | 320x240.ogv seek test 1: seeking event
[task 2020-12-01T11:30:53.304Z] 11:30:53 INFO - TEST-PASS | dom/media/test/test_seek-1.html | 320x240.ogv seek test 1: seeked event
[task 2020-12-01T11:30:53.305Z] 11:30:53 INFO - TEST-PASS | dom/media/test/test_seek-1.html | 320x240.ogv seek test 1: seeking flag on start should be true
[task 2020-12-01T11:30:53.305Z] 11:30:53 INFO - TEST-PASS | dom/media/test/test_seek-1.html | 320x240.ogv seek test 1: seeking flag on end should be false
[task 2020-12-01T11:30:53.305Z] 11:30:53 INFO - GECKO(3432) | SEEK-TEST: Finished 320x240.ogv seek test 1 token: 320x240.ogv-3-seek1.js
Description
•