1820456 - Intermittent dom/media/test/test_seek-5.html | single tracking bug

Status: RESOLVED INCOMPLETE

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

Description

[Treeherder Bug Filer]

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

---

[task 2023-03-06T06:08:18.473Z] 06:08:18     INFO - TEST-PASS | dom/media/test/test_seek-5.html | [started split.webm-7-seek5.js t=4.957] Length of array should match number of running tests 
[task 2023-03-06T06:08:18.473Z] 06:08:18     INFO - Buffered messages finished
[task 2023-03-06T06:08:18.474Z] 06:08:18     INFO - TEST-UNEXPECTED-FAIL | dom/media/test/test_seek-5.html | Test timed out! 
[task 2023-03-06T06:08:18.474Z] 06:08:18     INFO -     SimpleTest.ok@SimpleTest/SimpleTest.js:421:16
[task 2023-03-06T06:08:18.474Z] 06:08:18     INFO -     onTimeout@dom/media/test/manifest.js:2367:9
[task 2023-03-06T06:08:18.474Z] 06:08:18     INFO - bug516323.indexed.ogv-6-seek5.js timed out!
[task 2023-03-06T06:08:18.479Z] 06:08:18     INFO - {"EMEInfo":{"keySystem":"","sessionsInfo":""},"compositorDroppedFrames":0,"decoder":{"PlayState":"LOADING","channels":0,"containerType":"application/ogg","hasAudio":false,"hasVideo":false,"instance":"c514200","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":"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":-1,"decodedAudioEndTime":0,"decodedVideoEndTime":0,"duration":-1,"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":0,"sentFirstFrameLoadedEvent":false,"state":"","stateObj":{"isPrerolling":false},"videoCompleted":false,"videoRequestStatus":"idle"}}}
[task 2023-03-06T06:08:18.480Z] 06:08:18     INFO - [finished bug516323.indexed.ogv-6-seek5.js] remaining= split.webm-7-seek5.js
[task 2023-03-06T06:08:18.480Z] 06:08:18     INFO - TEST-PASS | dom/media/test/test_seek-5.html | [finished bug516323.indexed.ogv-6-seek5.js t=183.434] Length of array should match number of running tests 
[task 2023-03-06T06:08:18.480Z] 06:08:18     INFO - TEST-PASS | dom/media/test/test_seek-5.html | [started detodos.opus-8-seek5.js t=183.435] Length of array should match number of running tests 
[task 2023-03-06T06:08:18.481Z] 06:08:18     INFO - GECKO(1392) | SEEK-TEST: Started detodos.opus seek test 5
[task 2023-03-06T06:08:18.481Z] 06:08:18     INFO - TEST-PASS | dom/media/test/test_seek-5.html | detodos.opus seek test 5: Video currentTime should be around 1.45675: 1.45675 
[task 2023-03-06T06:08:18.482Z] 06:08:18     INFO - GECKO(1392) | [Child 1380, MediaDecoderStateMachine #1] WARNING: c538390 Could not set cubeb stream name.: file /builds/worker/checkouts/gecko/dom/media/AudioStream.cpp:321
[task 2023-03-06T06:08:19.476Z] 06:08:19     INFO - Not taking screenshot here: see the one that was previously logged
[task 2023-03-06T06:08:19.477Z] 06:08:19     INFO - TEST-UNEXPECTED-FAIL | dom/media/test/test_seek-5.html | Test timed out! 
[task 2023-03-06T06:08:19.477Z] 06:08:19     INFO -     SimpleTest.ok@SimpleTest/SimpleTest.js:421:16
[task 2023-03-06T06:08:19.477Z] 06:08:19     INFO -     onTimeout@dom/media/test/manifest.js:2367:9
[task 2023-03-06T06:08:19.478Z] 06:08:19     INFO - split.webm-7-seek5.js timed out!
[task 2023-03-06T06:08:19.539Z] 06:08:19     INFO - {"EMEInfo":{"keySystem":"","sessionsInfo":""},"compositorDroppedFrames":0,"decoder":{"PlayState":"LOADING","channels":0,"containerType":"video/webm","hasAudio":false,"hasVideo":false,"instance":"c5145c0","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":"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":-1,"decodedAudioEndTime":0,"decodedVideoEndTime":0,"duration":-1,"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":0,"sentFirstFrameLoadedEvent":false,"state":"","stateObj":{"isPrerolling":false},"videoCompleted":false,"videoRequestStatus":"idle"}}}
[task 2023-03-06T06:08:19.540Z] 06:08:19     INFO - [finished split.webm-7-seek5.js] remaining= detodos.opus-8-seek5.js
[task 2023-03-06T06:08:19.541Z] 06:08:19     INFO - TEST-PASS | dom/media/test/test_seek-5.html | [finished split.webm-7-seek5.js t=185.014] Length of array should match number of running tests 
[task 2023-03-06T06:08:19.541Z] 06:08:19     INFO - TEST-PASS | dom/media/test/test_seek-5.html | [started gizmo.mp4-9-seek5.js t=185.014] Length of array should match number of running tests 
[task 2023-03-06T06:08:19.542Z] 06:08:19     INFO - GECKO(1392) | SEEK-TEST: Started gizmo.mp4 seek test 5
[task 2023-03-06T06:08:19.622Z] 06:08:19     INFO - TEST-PASS | dom/media/test/test_seek-5.html | detodos.opus seek test 5: Got seeking event 
[task 2023-03-06T06:08:19.626Z] 06:08:19     INFO - TEST-PASS | dom/media/test/test_seek-5.html | detodos.opus seek test 5: Got seeked event 
[task 2023-03-06T06:08:19.626Z] 06:08:19     INFO - GECKO(1392) | SEEK-TEST: Finished detodos.opus seek test 5 token: detodos.opus-8-seek5.js
[task 2023-03-06T06:08:19.628Z] 06:08:19     INFO - [finished detodos.opus-8-seek5.js] remaining= gizmo.mp4-9-seek5.js
[task 2023-03-06T06:08:19.629Z] 06:08:19     INFO - TEST-PASS | dom/media/test/test_seek-5.html | [finished detodos.opus-8-seek5.js t=185.109] Length of array should match number of running tests 
[task 2023-03-06T06:08:19.631Z] 06:08:19     INFO - TEST-PASS | dom/media/test/test_seek-5.html | [started owl.mp3-10-seek5.js t=185.111] Length of array should match number of running tests 
[task 2023-03-06T06:08:19.634Z] 06:08:19     INFO - GECKO(1392) | SEEK-TEST: Started owl.mp3 seek test 5
[task 2023-03-06T06:08:30.841Z] 06:08:30     INFO - GECKO(1392) | [Parent 2700, Cache2 I/O] WARNING: 'NS_FAILED(aResult)', file /builds/worker/checkouts/gecko/netwerk/cache2/CacheFile.cpp:661
[task 2023-03-06T06:09:08.012Z] 06:09:08     INFO - GECKO(1392) | [Parent 2700, Cache2 I/O] WARNING: 'NS_FAILED(aResult)', file /builds/worker/checkouts/gecko/netwerk/cache2/CacheFile.cpp:661
[task 2023-03-06T06:09:08.028Z] 06:09:08     INFO - GECKO(1392) | [Parent 2700, Cache2 I/O] WARNING: 'NS_FAILED(aResult)', file /builds/worker/checkouts/gecko/netwerk/cache2/CacheFile.cpp:661
[task 2023-03-06T06:09:45.138Z] 06:09:45     INFO - GECKO(1392) | [Parent 2700, Cache2 I/O] WARNING: 'NS_FAILED(aResult)', file /builds/worker/checkouts/gecko/netwerk/cache2/CacheFile.cpp:661
[task 2023-03-06T06:09:45.139Z] 06:09:45     INFO - GECKO(1392) | [Parent 2700, Cache2 I/O] WARNING: 'NS_FAILED(aResult)', file /builds/worker/checkouts/gecko/netwerk/cache2/CacheFile.cpp:661
[task 2023-03-06T06:09:55.242Z] 06:09:55     INFO - GECKO(1392) | [Parent 2700, Cache2 I/O] WARNING: 'NS_FAILED(aResult)', file /builds/worker/checkouts/gecko/netwerk/cache2/CacheFile.cpp:661
[task 2023-03-06T06:09:57.203Z] 06:09:57     INFO -  [Parent 9056, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005 (NS_ERROR_FAILURE): file /builds/worker/checkouts/gecko/toolkit/components/places/Database.cpp:519
[task 2023-03-06T06:09:57.208Z] 06:09:57     INFO -  [Parent 9056, Main Thread] WARNING: Unable to get a connection to vacuum database: file /builds/worker/checkouts/gecko/storage/VacuumManager.cpp:130
[task 2023-03-06T06:09:57.313Z] 06:09:57     INFO -  console.error: (new TypeError("connection not specified or invalid.", "resource://gre/modules/Sqlite.sys.mjs", 1363))
[task 2023-03-06T06:09:57.331Z] 06:09:57     INFO -  [Parent 9056, IPDL Background] WARNING: QM_TRY failure (ERROR): 'OkIf(gBasePath)', file dom/quota/ActorsParent.cpp:2816
[task 2023-03-06T06:09:57.331Z] 06:09:57     INFO -  [Parent 9056, IPDL Background] WARNING: Trying to create QuotaManager before profile-do-change! Forgot to call do_get_profile()?: file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:2815
[task 2023-03-06T06:09:57.332Z] 06:09:57     INFO -  [Parent 9056, IPDL Background] WARNING: QM_TRY failure (ERROR): 'GetOrCreate().map([](const auto& res) { return Ok{}; }) failed with resultCode 0x80004005, resultName NS_ERROR_FAILURE', file dom/quota/ActorsParent.cpp:2835
[task 2023-03-06T06:09:57.332Z] 06:09:57     INFO -  [Parent 9056, IPDL Background] WARNING: QM_TRY failure (ERROR): 'QuotaManager::EnsureCreated() failed with resultCode 0x80004005, resultName NS_ERROR_FAILURE', file dom/quota/ActorsParent.cpp:7797
[task 2023-03-06T06:10:28.666Z] 06:10:28     INFO - GECKO(1392) | [WARN  rkv::backend::impl_safe::environment] `load_ratio()` is irrelevant for this storage backend.
[task 2023-03-06T06:10:28.680Z] 06:10:28     INFO - GECKO(1392) | console.error: (new Error("Polling for changes failed: Unexpected content-type \"text/plain;charset=US-ASCII\".", "resource://services-settings/remote-settings.sys.mjs", 325))
[task 2023-03-06T06:11:19.546Z] 06:11:19     INFO - Not taking screenshot here: see the one that was previously logged
[task 2023-03-06T06:11:19.550Z] 06:11:19     INFO - TEST-UNEXPECTED-FAIL | dom/media/test/test_seek-5.html | Test timed out! 
[task 2023-03-06T06:11:19.550Z] 06:11:19     INFO -     SimpleTest.ok@SimpleTest/SimpleTest.js:421:16
[task 2023-03-06T06:11:19.550Z] 06:11:19     INFO -     onTimeout@dom/media/test/manifest.js:2367:9
[task 2023-03-06T06:11:19.551Z] 06:11:19     INFO - gizmo.mp4-9-seek5.js timed out!
[task 2023-03-06T06:11:19.609Z] 06:11:19     INFO - {"EMEInfo":{"keySystem":"","sessionsInfo":""},"compositorDroppedFrames":0,"decoder":{"PlayState":"LOADING","channels":0,"containerType":"video/mp4","hasAudio":false,"hasVideo":false,"instance":"c514b60","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":"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":-1,"decodedAudioEndTime":0,"decodedVideoEndTime":0,"duration":-1,"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":0,"sentFirstFrameLoadedEvent":false,"state":"","stateObj":{"isPrerolling":false},"videoCompleted":false,"videoRequestStatus":"idle"}}}
[task 2023-03-06T06:11:19.615Z] 06:11:19     INFO - [finished gizmo.mp4-9-seek5.js] remaining= owl.mp3-10-seek5.js
[task 2023-03-06T06:11:19.615Z] 06:11:19     INFO - TEST-PASS | dom/media/test/test_seek-5.html | [finished gizmo.mp4-9-seek5.js t=365.086] Length of array should match number of running tests 
[task 2023-03-06T06:11:19.616Z] 06:11:19     INFO - TEST-PASS | dom/media/test/test_seek-5.html | [started bug482461-theora.ogv-11-seek5.js t=365.087] Length of array should match number of running tests 
[task 2023-03-06T06:11:19.618Z] 06:11:19     INFO - GECKO(1392) | SEEK-TEST: Started bug482461-theora.ogv seek test 5
[task 2023-03-06T06:11:19.641Z] 06:11:19     INFO - Not taking screenshot here: see the one that was previously logged
[task 2023-03-06T06:11:19.644Z] 06:11:19     INFO - TEST-UNEXPECTED-FAIL | dom/media/test/test_seek-5.html | Test timed out! 
[task 2023-03-06T06:11:19.644Z] 06:11:19     INFO -     SimpleTest.ok@SimpleTest/SimpleTest.js:421:16
[task 2023-03-06T06:11:19.644Z] 06:11:19     INFO -     onTimeout@dom/media/test/manifest.js:2367:9
[task 2023-03-06T06:11:19.644Z] 06:11:19     INFO - owl.mp3-10-seek5.js timed out!
[task 2023-03-06T06:11:19.687Z] 06:11:19     INFO - {"EMEInfo":{"keySystem":"","sessionsInfo":""},"compositorDroppedFrames":0,"decoder":{"PlayState":"LOADING","channels":0,"containerType":"audio/mpeg","hasAudio":false,"hasVideo":false,"instance":"c5156a0","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":"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":-1,"decodedAudioEndTime":0,"decodedVideoEndTime":0,"duration":-1,"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":0,"sentFirstFrameLoadedEvent":false,"state":"","stateObj":{"isPrerolling":false},"videoCompleted":false,"videoRequestStatus":"idle"}}}
[task 2023-03-06T06:11:19.698Z] 06:11:19     INFO - [finished owl.mp3-10-seek5.js] remaining= bug482461-theora.ogv-11-seek5.js
[task 2023-03-06T06:11:19.699Z] 06:11:19     INFO - TEST-PASS | dom/media/test/test_seek-5.html | [finished owl.mp3-10-seek5.js t=365.174] Length of array should match number of running tests 
[task 2023-03-06T06:11:23.971Z] 06:11:23     INFO - GECKO(1392) | [Parent 2700, Cache2 I/O] WARNING: 'NS_FAILED(aResult)', file /builds/worker/checkouts/gecko/netwerk/cache2/CacheFile.cpp:661
[task 2023-03-06T06:11:23.978Z] 06:11:23     INFO - GECKO(1392) | [Parent 2700, Cache2 I/O] WARNING: 'NS_FAILED(aResult)', file /builds/worker/checkouts/gecko/netwerk/cache2/CacheFile.cpp:661
[task 2023-03-06T06:11:35.558Z] 06:11:35     INFO - GECKO(1392) | [Parent 2700, Cache2 I/O] WARNING: 'NS_FAILED(aResult)', file /builds/worker/checkouts/gecko/netwerk/cache2/CacheFile.cpp:661
[task 2023-03-06T06:11:35.563Z] 06:11:35     INFO - GECKO(1392) | [Parent 2700, Cache2 I/O] WARNING: 'NS_FAILED(aResult)', file /builds/worker/checkouts/gecko/netwerk/cache2/CacheFile.cpp:661
[task 2023-03-06T06:12:29.354Z] 06:12:29     INFO - GECKO(1392) | 1678083149359	addons.xpi	ERROR	System addon update list error Error: got node name: html, expected: updates
[task 2023-03-06T06:14:19.611Z] 06:14:19     INFO - Not taking screenshot here: see the one that was previously logged
[task 2023-03-06T06:14:19.614Z] 06:14:19     INFO - TEST-UNEXPECTED-FAIL | dom/media/test/test_seek-5.html | Test timed out! 
[task 2023-03-06T06:14:19.614Z] 06:14:19     INFO -     SimpleTest.ok@SimpleTest/SimpleTest.js:421:16
[task 2023-03-06T06:14:19.614Z] 06:14:19     INFO -     onTimeout@dom/media/test/manifest.js:2367:9
[task 2023-03-06T06:14:19.615Z] 06:14:19     INFO - bug482461-theora.ogv-11-seek5.js timed out!
[task 2023-03-06T06:14:19.674Z] 06:14:19     INFO - {"EMEInfo":{"keySystem":"","sessionsInfo":""},"compositorDroppedFrames":0,"decoder":{"PlayState":"LOADING","channels":0,"containerType":"application/ogg","hasAudio":false,"hasVideo":false,"instance":"c515a60","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":"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":-1,"decodedAudioEndTime":0,"decodedVideoEndTime":0,"duration":-1,"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":0,"sentFirstFrameLoadedEvent":false,"state":"","stateObj":{"isPrerolling":false},"videoCompleted":false,"videoRequestStatus":"idle"}}}
[task 2023-03-06T06:14:19.674Z] 06:14:19     INFO - [finished bug482461-theora.ogv-11-seek5.js] remaining= 
[task 2023-03-06T06:14:19.678Z] 06:14:19     INFO - TEST-PASS | dom/media/test/test_seek-5.html | [finished bug482461-theora.ogv-11-seek5.js t=545.149] Length of array should match number of running tests 
[task 2023-03-06T06:14:19.679Z] 06:14:19     INFO - GECKO(1392) | [Child 1380, MediaDecoderStateMachine #1] WARNING: Decoder=c514200 state=DECODING_METADATA Decode metadata failed, shutting down decoder: file /builds/worker/checkouts/gecko/dom/media/MediaDecoderStateMachine.cpp:372
[task 2023-03-06T06:14:19.680Z] 06:14:19     INFO - GECKO(1392) | [Child 1380, MediaDecoderStateMachine #1] WARNING: Decoder=c514200 Decode error: NS_ERROR_DOM_MEDIA_METADATA_ERR (0x806e0006): file /builds/worker/checkouts/gecko/dom/media/MediaDecoderStateMachineBase.cpp:164
[task 2023-03-06T06:14:19.681Z] 06:14:19     INFO - GECKO(1392) | [Child 1380, MediaDecoderStateMachine #1] WARNING: Decoder=c514b60 state=DECODING_METADATA Decode metadata failed, shutting down decoder: file /builds/worker/checkouts/gecko/dom/media/MediaDecoderStateMachine.cpp:372
[task 2023-03-06T06:14:19.681Z] 06:14:19     INFO - GECKO(1392) | [Child 1380, MediaDecoderStateMachine #1] WARNING: Decoder=c514b60 Decode error: NS_ERROR_DOM_MEDIA_METADATA_ERR (0x806e0006) - static MP4Metadata::ResultAndByteBuffer __cdecl mozilla::MP4Metadata::Metadata(mozilla::ByteStream *): Cannot parse metadata: file /builds/worker/checkouts/gecko/dom/media/MediaDecoderStateMachineBase.cpp:164
[task 2023-03-06T06:14:19.682Z] 06:14:19     INFO - GECKO(1392) | [Child 1380, MediaDecoderStateMachine #1] WARNING: Decoder=c515a60 state=DECODING_METADATA Decode metadata failed, shutting down decoder: file /builds/worker/checkouts/gecko/dom/media/MediaDecoderStateMachine.cpp:372
[task 2023-03-06T06:14:19.682Z] 06:14:19     INFO - GECKO(1392) | [Child 1380, MediaDecoderStateMachine #1] WARNING: Decoder=c515a60 Decode error: NS_ERROR_DOM_MEDIA_METADATA_ERR (0x806e0006): file /builds/worker/checkouts/gecko/dom/media/MediaDecoderStateMachineBase.cpp:164
[task 2023-03-06T06:14:19.815Z] 06:14:19     INFO - Finished at Mon Mar 06 2023 06:14:19 GMT+0000 (Greenwich Mean Time) (1678083259.815s)
[task 2023-03-06T06:14:19.817Z] 06:14:19     INFO - Running time: 545.298s
[task 2023-03-06T06:14:19.831Z] 06:14:19     INFO - GECKO(1392) | MEMORY STAT | vsize 605MB | vsizeMaxContiguous 1806MB | residentFast 76MB | heapAllocated 6MB
[task 2023-03-06T06:14:19.847Z] 06:14:19     INFO - TEST-OK | dom/media/test/test_seek-5.html | took 545419ms
[task 2023-03-06T06:14:19.910Z] 06:14:19     INFO - TEST-START | dom/media/test/test_seek-6.html

Comment 1

[Intermittent Failures Robot]

1 failures in 3966 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• windows11-32-2009-qr: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1820456&startday=2023-03-06&endday=2023-03-12&tree=all

Comment 2

[Intermittent Failures Robot]

2 failures in 4161 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 2

Platform and build breakdown:

• windows11-64-2009-qr: 1
  • debug: 1
• windows11-64-2009-asan-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1820456&startday=2023-03-20&endday=2023-03-26&tree=all

Comment 3

[BugBot [:suhaib / :marco]]

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

Comment 4

[Treeherder Bug Filer]

New failure instance: https://treeherder.mozilla.org/logviewer?job_id=413529552&repo=autoland

Comment 5

[Intermittent Failures Robot]

3 failures in 3177 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1
• mozilla-central: 1
• mozilla-beta: 1

Platform and build breakdown:

• windows11-64-2009-asan-qr: 3
  • opt: 3

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1820456&startday=2023-04-24&endday=2023-04-30&tree=all

Comment 6

[Intermittent Failures Robot]

1 failures in 3411 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 1

Platform and build breakdown:

• windows11-64-2009-asan-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1820456&startday=2023-05-01&endday=2023-05-07&tree=all

Comment 7

[Intermittent Failures Robot]

1 failures in 3946 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• windows11-64-2009-asan-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1820456&startday=2023-05-22&endday=2023-05-28&tree=all

Comment 8

[Intermittent Failures Robot]

1 failures in 3885 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• windows11-64-2009-qr: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1820456&startday=2023-06-05&endday=2023-06-11&tree=all

Comment 9

[Intermittent Failures Robot]

1 failures in 3594 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 1

Platform and build breakdown:

• windows11-64-2009-qr: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1820456&startday=2023-06-26&endday=2023-07-02&tree=all

Comment 10

[Intermittent Failures Robot]

2 failures in 2956 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 2

Platform and build breakdown:

• windows11-64-2009-asan-qr: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1820456&startday=2023-07-03&endday=2023-07-09&tree=all

Comment 11

[Intermittent Failures Robot]

2 failures in 3076 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 1
• try: 1

Platform and build breakdown:

• windows11-32-2009-qr: 2
  • debug: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1820456&startday=2023-08-14&endday=2023-08-20&tree=all

Comment 12

[Intermittent Failures Robot]

1 failures in 2218 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• try: 1

Platform and build breakdown:

• windows11-64-2009-qr: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1820456&startday=2023-08-21&endday=2023-08-27&tree=all

Comment 13

[BugBot [:suhaib / :marco]]

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

Comment 14

[Treeherder Bug Filer]

New failure instance: https://treeherder.mozilla.org/logviewer?job_id=430972578&repo=mozilla-beta

Comment 15

[Intermittent Failures Robot]

4 failures in 4018 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-beta: 4

Platform and build breakdown:

• windows11-32-2009-qr: 1
  • debug: 1
• windows11-64-2009-asan-qr: 2
  • opt: 2
• windows11-64-2009-qr: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1820456&startday=2023-10-02&endday=2023-10-08&tree=all

Comment 16

[BugBot [:suhaib / :marco]]

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

Comment 17

[Treeherder Bug Filer]

New failure instance: https://treeherder.mozilla.org/logviewer?job_id=447051258&repo=autoland

Comment 18

[Intermittent Failures Robot]

1 failures in 3125 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 1

Platform and build breakdown:

• windows11-64-2009-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1820456&startday=2024-02-12&endday=2024-02-18&tree=all

Comment 19

[BugBot [:suhaib / :marco]]

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