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)

defect

Tracking

()

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)
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

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

You need to log in before you can comment on or make changes to this bug.