Open Bug 1978862 Opened 6 months ago Updated 8 days ago

Frequent dom/media/test/test_streams_element_capture_mediatrack.html | Test timed out!

Categories

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

Product:
Core
Component:
Audio/Video: Playback
Type:
defect

Tracking

()

Tracking Flags:
Tracking Status
firefox-esr128 --- unaffected
firefox-esr140 --- unaffected
firefox141 --- unaffected
firefox142 --- unaffected
firefox143 --- affected
firefox144 --- affected

People

(Reporter: intermittent-bug-filer, Unassigned, NeedInfo)

References

(Regression)

Details

(Keywords: intermittent-failure, intermittent-testcase, regression)

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

[task 2025-07-23T12:00:08.497+00:00] 11:59:58     INFO -  TEST-PASS | dom/media/test/test_streams_element_capture_mediatrack.html | Reason cannot be empty
[task 2025-07-23T12:00:08.497+00:00] 11:59:58     INFO -  Buffered messages finished
[task 2025-07-23T12:00:08.497+00:00] 11:59:58  WARNING -  TEST-UNEXPECTED-FAIL | dom/media/test/test_streams_element_capture_mediatrack.html | Test timed out!
[task 2025-07-23T12:00:08.497+00:00] 11:59:58     INFO -      SimpleTest.ok@SimpleTest/SimpleTest.js:426:16
[task 2025-07-23T12:00:08.497+00:00] 11:59:58     INFO -      onTimeout@dom/media/test/manifest.js:2201:9
[task 2025-07-23T12:00:08.497+00:00] 11:59:58     INFO -      setTimeout handler*MediaTestManager/this.started@dom/media/test/manifest.js:2208:57
[task 2025-07-23T12:00:08.497+00:00] 11:59:58     INFO -      startTest@dom/media/test/test_streams_element_capture_mediatrack.html:15:11
[task 2025-07-23T12:00:08.497+00:00] 11:59:58     INFO -      @dom/media/test/test_streams_element_capture_mediatrack.html:90:13
[task 2025-07-23T12:00:08.497+00:00] 11:59:58     INFO -      MediaTestManager/this.nextTest@dom/media/test/manifest.js:2282:12
[task 2025-07-23T12:00:08.497+00:00] 11:59:58     INFO -      MediaTestManager/this.finished@dom/media/test/manifest.js:2254:12
[task 2025-07-23T12:00:08.497+00:00] 11:59:58     INFO -      @dom/media/test/test_streams_element_capture_mediatrack.html:94:13
[task 2025-07-23T12:00:08.497+00:00] 11:59:58     INFO -      async*MediaTestManager/this.nextTest@dom/media/test/manifest.js:2282:12
[task 2025-07-23T12:00:08.497+00:00] 11:59:58     INFO -      MediaTestManager/this.finished@dom/media/test/manifest.js:2254:12
[task 2025-07-23T12:00:08.497+00:00] 11:59:58     INFO -      @dom/media/test/test_streams_element_capture_mediatrack.html:94:13
[task 2025-07-23T12:00:08.497+00:00] 11:59:58     INFO -      async*MediaTestManager/this.nextTest@dom/media/test/manifest.js:2282:12
[task 2025-07-23T12:00:08.497+00:00] 11:59:58     INFO -      MediaTestManager/this.finished@dom/media/test/manifest.js:2254:12
[task 2025-07-23T12:00:08.497+00:00] 11:59:58     INFO -      @dom/media/test/test_streams_element_capture_mediatrack.html:94:13
[task 2025-07-23T12:00:08.497+00:00] 11:59:58     INFO -      async*MediaTestManager/this.nextTest@dom/media/test/manifest.js:2282:12
[task 2025-07-23T12:00:08.497+00:00] 11:59:58     INFO -      MediaTestManager/this.finished@dom/media/test/manifest.js:2254:12
[task 2025-07-23T12:00:08.497+00:00] 11:59:58     INFO -      @dom/media/test/test_streams_element_capture_mediatrack.html:94:13
[task 2025-07-23T12:00:08.497+00:00] 11:59:58     INFO -      async*MediaTestManager/this.nextTest@dom/media/test/manifest.js:2282:12
[task 2025-07-23T12:00:08.497+00:00] 11:59:58     INFO -      MediaTestManager/this.finished@dom/media/test/manifest.js:2254:12
[task 2025-07-23T12:00:08.497+00:00] 11:59:58     INFO -      @dom/media/test/test_streams_element_capture_mediatrack.html:94:13
[task 2025-07-23T12:00:08.497+00:00] 11:59:58     INFO -      async*MediaTestManager/this.nextTest@dom/media/test/manifest.js:2282:12
[task 2025-07-23T12:00:08.497+00:00] 11:59:58     INFO -      MediaTestManager/this.finished@dom/media/test/manifest.js:2254:12
[task 2025-07-23T12:00:08.497+00:00] 11:59:58     INFO -      @dom/media/test/test_streams_element_capture_mediatrack.html:94:13
[task 2025-07-23T12:00:08.497+00:00] 11:59:58     INFO -      async*MediaTestManager/this.nextTest@dom/media/test/manifest.js:2282:12
[task 2025-07-23T12:00:08.497+00:00] 11:59:58     INFO -      MediaTestManager/this.finished@dom/media/test/manifest.js:2254:12
[task 2025-07-23T12:00:08.497+00:00] 11:59:58     INFO -      @dom/media/test/test_streams_element_capture_mediatrack.html:94:13
[task 2025-07-23T12:00:08.497+00:00] 11:59:58     INFO -      async*MediaTestManager/this.nextTest@dom/media/test/manifest.js:2282:12
[task 2025-07-23T12:00:08.497+00:00] 11:59:58     INFO -      MediaTestManager/this.finished@dom/media/test/manifest.js:2254:12
[task 2025-07-23T12:00:08.497+00:00] 11:59:58     INFO -      @dom/media/test/test_streams_element_capture_mediatrack.html:94:13
[task 2025-07-23T12:00:08.497+00:00] 11:59:58     INFO -      async*MediaTestManager/this.nextTest@dom/media/test/manifest.js:2282:12
[task 2025-07-23T12:00:08.497+00:00] 11:59:58     INFO -      MediaTestManager/this.finished@dom/media/test/manifest.js:2254:12
[task 2025-07-23T12:00:08.497+00:00] 11:59:58     INFO -      @dom/media/test/test_streams_element_capture_mediatrack.html:94:13
[task 2025-07-23T12:00:08.497+00:00] 11:59:58     INFO -      async*MediaTestManager/this.nextTest@dom/media/test/manifest.js:2282:12
[task 2025-07-23T12:00:08.497+00:00] 11:59:58     INFO -      MediaTestManager/this.finished@dom/media/test/manifest.js:2254:12
[task 2025-07-23T12:00:08.497+00:00] 11:59:58     INFO -      @dom/media/test/test_streams_element_capture_mediatrack.html:94:13
[task 2025-07-23T12:00:08.497+00:00] 11:59:58     INFO -      async*MediaTestManager/this.nextTest@dom/media/test/manifest.js:2282:12
[task 2025-07-23T12:00:08.497+00:00] 11:59:58     INFO -  sine-3s-xhe-aac-44khz-mono.mp4-64 timed out!
[task 2025-07-23T12:00:08.497+00:00] 11:59:58     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 2025-07-23T12:00:08.497+00:00] 11:59:58     INFO -  [finished sine-3s-xhe-aac-44khz-mono.mp4-64] remaining=
Flags: needinfo?(azebrowski)

This passed when run in confirm failure mode (rerun the test 4x in the same session).

This indicates that the test is probably a lower frequency intermittent and harder to reproduce/debug.

this did reproduce frequently on a full retrigger, this indicates another test that ran prior could be affecting the state of the browser.

Whiteboard: [collect_confirm_failure]

Ashley will take a look on Monday.

Summary: Intermittent dom/media/test/test_streams_element_capture_mediatrack.html | Test timed out! → Frequent dom/media/test/test_streams_element_capture_mediatrack.html | Test timed out!

I'm not sure what the issue is here - interesting it seems to be happening mostly on actual hardware, though. :padenot, would you have any ideas?

Flags: needinfo?(azebrowski) → needinfo?(padenot)

I'd start by looking at the range and attempt to find anything there: https://treeherder.mozilla.org/intermittent-failures/bugdetails?startday=2025-06-30&endday=2025-07-30&tree=all&failurehash=all&bug=1978862

Flags: needinfo?(padenot)

I narrowed it down to that range and it looks like this might be related to Bug 1711882 - Firefox doesn't play xHE-AAC content (mp4a.40.42). In it, we add support for AAC codec string mp4a-40-42. If we check the audio file where the timeouts are occurring we can see it's a new file introduced using AAC codec string mp4a-40-42. I'll mark it as a regression from that work - let me know if you'd like me to take a deeper look or collect more details.

$ mediainfo ./dom/media/test/sine-3s-xhe-aac-44khz-mono.mp4
General
Complete name                            : ./dom/media/test/sine-3s-xhe-aac-44khz-mono.mp4
Format                                   : MPEG-4
Format profile                           : Base Media / Version 2
Codec ID                                 : mp42 (mp42/isom)
File size                                : 6.74 KiB
Duration                                 : 3 s 0 ms
Overall bit rate mode                    : Variable
Overall bit rate                         : 18.4 kb/s
Encoded date                             : 2025-07-24 15:17:30 UTC
Tagged date                              : 2025-07-24 15:17:30 UTC
Writing application                      : exhale 1.2.1

Audio
ID                                       : 1
Format                                   : USAC
Format/Info                              : Unified Speech and Audio Coding
Codec ID                                 : mp4a-40-42
Duration                                 : 3 s 0 ms
Duration_LastFrame                       : -19 ms
Bit rate mode                            : Variable
Bit rate                                 : 14.6 kb/s
Nominal bit rate                         : 16.0 kb/s
Maximum bit rate                         : 72.7 kb/s
Channel(s)                               : 1 channel
Channel layout                           : M
Sampling rate                            : 44.1 kHz
Frame rate                               : 43.066 FPS (1024 SPF)
Compression mode                         : Lossy
Stream size                              : 5.35 KiB (79%)
Title                                    : crh
Encoded date                             : 2025-07-24 15:17:30 UTC
Tagged date                              : 2025-07-24 15:17:30 UTC
Sample peak level                        : -3.031 dBFS
Program loudness                         : -6.75 LKFS
Flags: needinfo?(padenot)
Keywords: regression
Regressed by: 1711882

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

status-firefox141: --- → unaffected
status-firefox142: --- → unaffected
status-firefox143: --- → affected
status-firefox-esr128: --- → unaffected
status-firefox-esr140: --- → unaffected

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

status-firefox144: --- → affected
You need to log in before you can comment on or make changes to this bug.