1900167 - Perma [tier 2] dom/media/autoplay/test/mochitest/test_streams_autoplay.html | Test timed out. -

Status: RESOLVED FIXED

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

Description

[Treeherder Bug Filer]

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

---

[task 2024-06-01T04:23:22.651Z] 04:23:22     INFO - TEST-PASS | dom/media/autoplay/test/mochitest/test_streams_autoplay.html | Reason cannot be empty 
[task 2024-06-01T04:23:22.652Z] 04:23:22     INFO - Buffered messages finished
[task 2024-06-01T04:23:22.653Z] 04:23:22     INFO - TEST-UNEXPECTED-FAIL | dom/media/autoplay/test/mochitest/test_streams_autoplay.html | Test timed out. - 
[task 2024-06-01T04:23:22.653Z] 04:23:22     INFO - GECKO(4120) | [WARN  webrender::renderer] Invalid ext-image
[task 2024-06-01T04:23:23.479Z] 04:23:23     INFO - {"EMEInfo":{"keySystem":"","sessionsInfo":""},"compositorDroppedFrames":0,"decoder":{"PlayState":"ENDED","channels":0,"containerType":"video/webm","hasAudio":false,"hasVideo":true,"instance":"2a36dbf9800","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},"totalReadMetadataTimeMs":0.6611,"totalWaitingForVideoDataTimeMs":0,"videoDecoderName":"media engine video stream (Utility MF Media Engine CDM remote)","videoHardwareAccelerated":false,"videoHeight":240,"videoNumSamplesOutputTotal":8,"videoNumSamplesSkippedTotal":0,"videoRate":30.104970932006836,"videoState":{"demuxEOS":1,"demuxQueueSize":0,"drainState":0,"hasDecoder":false,"hasDemuxRequest":false,"hasPromise":false,"lastStreamSourceID":4294967295,"needInput":false,"numSamplesInput":8,"numSamplesOutput":8,"pending":0,"queueSize":0,"timeTreshold":-1,"timeTresholdHasSeeked":false,"waitingForData":false,"waitingForKey":false,"waitingPromise":false},"videoType":"video/vp8","videoWidth":320},"resource":{"cacheStream":{"cacheSuspended":false,"channelEnded":false,"channelOffset":0,"loadID":0,"streamLength":0}},"stateMachine":{"audioCompleted":false,"audioRequestStatus":"","clock":0,"decodedAudioEndTime":0,"decodedVideoEndTime":0,"duration":0,"isPlaying":false,"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":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":false,"finished":false,"hasVideo":false,"isPlaying":false,"isStarted":false,"size":0,"videoFrameEndTime":0,"videoSinkEndRequestExists":false}},"mediaTime":0,"playState":0,"sentFirstFrameLoadedEvent":false,"state":"","stateObj":{"isPrerolling":false},"totalBufferingTimeMs":0,"videoCompleted":false,"videoRequestStatus":""}}}
[task 2024-06-01T04:23:23.569Z] 04:23:23     INFO - {"EMEInfo":{"keySystem":"","sessionsInfo":""},"compositorDroppedFrames":0,"decoder":{"PlayState":"","channels":0,"containerType":"","hasAudio":false,"hasVideo":false,"instance":"","rate":0,"reader":{"audioChannels":0,"audioDecoderName":"","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":"","frameStats":{"droppedCompositorFrames":0,"droppedDecodedFrames":0,"droppedSinkFrames":0},"totalReadMetadataTimeMs":0,"totalWaitingForVideoDataTimeMs":0,"videoDecoderName":"","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":"","videoWidth":0},"resource":{"cacheStream":{"cacheSuspended":false,"channelEnded":false,"channelOffset":0,"loadID":0,"streamLength":0}},"stateMachine":{"audioCompleted":false,"audioRequestStatus":"","clock":0,"decodedAudioEndTime":0,"decodedVideoEndTime":0,"duration":0,"isPlaying":false,"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":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":false,"finished":false,"hasVideo":false,"isPlaying":false,"isStarted":false,"size":0,"videoFrameEndTime":0,"videoSinkEndRequestExists":false}},"mediaTime":0,"playState":0,"sentFirstFrameLoadedEvent":false,"state":"","stateObj":{"isPrerolling":false},"totalBufferingTimeMs":0,"videoCompleted":false,"videoRequestStatus":""}}}
[task 2024-06-01T04:23:23.574Z] 04:23:23     INFO - GECKO(4120) | MEMORY STAT | vsize 2103885MB | vsizeMaxContiguous 67424614MB | residentFast 114MB | heapAllocated 11MB
[task 2024-06-01T04:23:23.610Z] 04:23:23     INFO - GECKO(4120) | [WARN  webrender::renderer] Invalid ext-image
[task 2024-06-01T04:23:23.667Z] 04:23:23     INFO - TEST-OK | dom/media/autoplay/test/mochitest/test_streams_autoplay.html | took 305294ms

Comment 1

[Cristian Tuns]

Hi, not sure about the cause of this, the backfills got me to this range: https://treeherder.mozilla.org/jobs?repo=autoland&group_state=expanded&fromchange=11b5fa2ce9366465ca604a4fce00176a807bdeb6&searchStr=windows%2C11%2Cx64%2C22h2%2Cwebrender%2Cdebug%2Cmochitests%2Cwith%2Cwindows%2Cmedia%2Cfoundation%2Cmedia%2Cengine%2Cenabled%2Ctest-windows11-64-2009-qr%2Fdebug-mochitest-media-wmfme%2Cmda&tochange=f13505d68177f3c036a59413c202629c451f3172&selectedTaskRun=fYTqpxM9Sq2lYtjNhsnx9g.0, might be fixed by commit, will update it later.

Comment 2

[BugBot [:suhaib / :marco/ :calixte]]

Set release status flags based on info from the regressing bug 1898051

Comment 3

[Joel Maher ( :jmaher ) (UTC -8)]

I am pretty sure this isn't related to bug 1898051: https://treeherder.mozilla.org/jobs?repo=try&tier=1%2C2%2C3&revision=440278876e7ea368a0d8647cdd0df635abd3b7ba

Comment 4

[Intermittent Failures Robot]

17 failures in 166 pushes (0.102 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 11
• mozilla-central: 6

Platform and build breakdown:

• windows11-64-2009-qr: 7
  • opt: 3
  • debug: 4
• windows11-64-2009-shippable-qr: 5
  • opt: 5
• windows11-64-2009-asan-qr: 5
  • opt: 5

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1900167&startday=2024-06-01&endday=2024-06-01&tree=all

Comment 5

[Intermittent Failures Robot]

42 failures in 4202 pushes (0.01 failures/push) were associated with this bug in the last 7 days.

This is the #41 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• autoland: 31
• mozilla-central: 11

Platform and build breakdown:

• windows11-64-2009-qr: 19
  • opt: 8
  • debug: 11
• windows11-64-2009-shippable-qr: 12
  • opt: 12
• windows11-64-2009-asan-qr: 11
  • opt: 11

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1900167&startday=2024-05-27&endday=2024-06-02&tree=all

Comment 6

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

This failed initially when bug 1899867 - and permanently. Backfills only failed intermittently, maybe if executed on machines which had run such a failed task before?

Alastor, could you check or redirect this request?

Comment 7

[Intermittent Failures Robot]

28 failures in 591 pushes (0.047 failures/push) were associated with this bug yesterday.

Repository breakdown:

• mozilla-central: 5
• autoland: 23

Platform and build breakdown:

• windows11-64-2009-qr: 12
  • debug: 7
  • opt: 5
• windows11-64-2009-asan-qr: 9
  • opt: 9
• windows11-64-2009-shippable-qr: 7
  • opt: 7

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

Comment 8

[Intermittent Failures Robot]

30 failures in 809 pushes (0.037 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 24
• mozilla-central: 6

Platform and build breakdown:

• windows11-64-2009-qr: 15
  • debug: 8
  • opt: 7
• windows11-64-2009-shippable-qr: 8
  • opt: 8
• windows11-64-2009-asan-qr: 7
  • opt: 7

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1900167&startday=2024-06-04&endday=2024-06-04&tree=all

Comment 9

[Sandor Molnar[:smolnar]]

This failure didn't reproduced since bug 1898051 got backed out,most likely it was the culprit

Comment 10

[Intermittent Failures Robot]

58 failures in 3649 pushes (0.016 failures/push) were associated with this bug in the last 7 days.

This is the #17 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• autoland: 47
• mozilla-central: 11

Platform and build breakdown:

• windows11-64-2009-qr: 27
  • debug: 15
  • opt: 12
• windows11-64-2009-shippable-qr: 15
  • opt: 15
• windows11-64-2009-asan-qr: 16
  • opt: 16

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