1713410 - Intermittent dom/media/test/test_bug1113600.html | assertion count 1 is more than expected 0 assertions | ASSERTION: Dropping samples: '(UINT32_MAX - aInRate + 1) / c.mDuration >= aOutRate', file /builds/worker/checkouts/gecko/dom/media/AudioSegment.h

Status: RESOLVED FIXED

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

Description

[Treeherder Bug Filer]

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

---

[task 2021-05-28T23:04:46.869Z] 23:04:46     INFO - TEST-START | dom/media/test/test_bug1113600.html
[task 2021-05-28T23:04:46.877Z] 23:04:46     INFO - GECKO(9716) | [Child 9788, Main Thread] WARNING: early callback, or time went backwards: '!aAllowIdleDispatch', file /builds/worker/checkouts/gecko/xpcom/threads/IdleTaskRunner.cpp:179
[task 2021-05-28T23:04:46.890Z] 23:04:46     INFO - GECKO(9716) | [Child 9788, Main Thread] WARNING: early callback, or time went backwards: '!aAllowIdleDispatch', file /builds/worker/checkouts/gecko/xpcom/threads/IdleTaskRunner.cpp:179
[task 2021-05-28T23:04:46.909Z] 23:04:46     INFO - GECKO(9716) | [Child 9788, Main Thread] WARNING: early callback, or time went backwards: '!aAllowIdleDispatch', file /builds/worker/checkouts/gecko/xpcom/threads/IdleTaskRunner.cpp:179
[task 2021-05-28T23:04:46.974Z] 23:04:46     INFO - Started Fri May 28 2021 23:04:46 GMT+0000 (Greenwich Mean Time) (1622243086.974s)
[task 2021-05-28T23:04:46.983Z] 23:04:46     INFO - TEST-PASS | dom/media/test/test_bug1113600.html | [started small-shot.ogg-0 t=0.009] Length of array should match number of running tests 
[task 2021-05-28T23:04:47.082Z] 23:04:47     INFO - GECKO(9716) | [Child 9788, MediaDecoderStateMachine #1] WARNING: 175e5613570 Could not set cubeb stream name.: file /builds/worker/checkouts/gecko/dom/media/AudioStream.cpp:367
[task 2021-05-28T23:04:47.371Z] 23:04:47     INFO - small-shot.ogg capture started at 0.276085. Duration=0.276
[task 2021-05-28T23:04:47.373Z] 23:04:47     INFO - TEST-PASS | dom/media/test/test_bug1113600.html | small-shot.ogg ended 
<...>
[task 2021-05-28T23:04:50.486Z] 23:04:50     INFO - GECKO(9716) | [Child 9788, MediaDecoderStateMachine #1] WARNING: 175e5613ce0 Could not set cubeb stream name.: file /builds/worker/checkouts/gecko/dom/media/AudioStream.cpp:367
[task 2021-05-28T23:04:50.805Z] 23:04:50     INFO - gizmo-short.mp4 capture started at 0.266666. Duration=0.27
[task 2021-05-28T23:04:50.806Z] 23:04:50     INFO - TEST-PASS | dom/media/test/test_bug1113600.html | gizmo-short.mp4 ended 
[task 2021-05-28T23:04:50.808Z] 23:04:50     INFO - [finished gizmo-short.mp4-10] remaining= 
[task 2021-05-28T23:04:50.808Z] 23:04:50     INFO - TEST-PASS | dom/media/test/test_bug1113600.html | [finished gizmo-short.mp4-10 t=3.834] Length of array should match number of running tests 
[task 2021-05-28T23:04:50.809Z] 23:04:50     INFO - TEST-PASS | dom/media/test/test_bug1113600.html | [started flac-s24.flac-11 t=3.835] Length of array should match number of running tests 
[task 2021-05-28T23:04:52.171Z] 23:04:52     INFO - GECKO(9716) | [Child 9788, MediaDecoderStateMachine #1] WARNING: 175e5613570 Could not set cubeb stream name.: file /builds/worker/checkouts/gecko/dom/media/AudioStream.cpp:367
[task 2021-05-28T23:04:53.367Z] 23:04:53     INFO - flac-s24.flac capture started at 1.184909. Duration=4.04
[task 2021-05-28T23:04:53.388Z] 23:04:53     INFO - GECKO(9716) | [Child 9788, MediaDecoderStateMachine #1] ###!!! ASSERTION: Dropping samples: '(UINT32_MAX - aInRate + 1) / c.mDuration >= aOutRate', file /builds/worker/checkouts/gecko/dom/media/AudioSegment.h:321
[task 2021-05-28T23:04:53.470Z] 23:04:53     INFO -  Initializing stack-fixing for the first stack frame, this may take a while...
[task 2021-05-28T23:05:03.496Z] 23:05:03     INFO - GECKO(9716) | #01: NS_DebugBreak(unsigned int, char const*, char const*, char const*, int) [xpcom/base/nsDebugImpl.cpp:431]
[task 2021-05-28T23:05:03.497Z] 23:05:03     INFO - GECKO(9716) | #02: mozilla::AudioSegment::Resample<float>(nsAutoRef<SpeexResamplerState_>&, unsigned int*, unsigned int, unsigned int) [dom/media/AudioSegment.h:322]
[task 2021-05-28T23:05:03.498Z] 23:05:03     INFO - GECKO(9716) | #03: mozilla::AudioSegment::ResampleChunks(nsAutoRef<SpeexResamplerState_>&, unsigned int*, unsigned int, unsigned int) [dom/media/AudioSegment.cpp:62]
[task 2021-05-28T23:05:03.499Z] 23:05:03     INFO - GECKO(9716) | #04: mozilla::AudioDecoderInputTrack::ConvertAudioDataToSegment(mozilla::AudioData*, mozilla::AudioSegment&, nsMainThreadPtrHandle<nsIPrincipal> const&) [dom/media/mediasink/AudioDecoderInputTrack.cpp:81]
[task 2021-05-28T23:05:03.500Z] 23:05:03     INFO - GECKO(9716) | #05: mozilla::AudioDecoderInputTrack::BatchData(mozilla::AudioData*, nsMainThreadPtrHandle<nsIPrincipal> const&) [dom/media/mediasink/AudioDecoderInputTrack.cpp:133]
[task 2021-05-28T23:05:03.500Z] 23:05:03     INFO - GECKO(9716) | #06: mozilla::AudioDecoderInputTrack::AppendData(nsTArray<RefPtr<mozilla::AudioData> >&, nsMainThreadPtrHandle<nsIPrincipal> const&) [dom/media/mediasink/AudioDecoderInputTrack.cpp:101]
[task 2021-05-28T23:05:03.501Z] 23:05:03     INFO - GECKO(9716) | #07: mozilla::DecodedStream::SendAudio(nsMainThreadPtrHandle<nsIPrincipal> const&) [dom/media/mediasink/DecodedStream.cpp:744]
[task 2021-05-28T23:05:03.501Z] 23:05:03     INFO - GECKO(9716) | #08: mozilla::DecodedStream::SendData() [dom/media/mediasink/DecodedStream.cpp:1036]
[task 2021-05-28T23:05:03.502Z] 23:05:03     INFO - GECKO(9716) | #09: mozilla::DecodedStream::Start(mozilla::media::TimeUnit const&, mozilla::MediaInfo const&) [dom/media/mediasink/DecodedStream.cpp:591]
[task 2021-05-28T23:05:03.503Z] 23:05:03     INFO - GECKO(9716) | #10: mozilla::VideoSink::Start(mozilla::media::TimeUnit const&, mozilla::MediaInfo const&) [dom/media/mediasink/VideoSink.cpp:217]
[task 2021-05-28T23:05:03.504Z] 23:05:03     INFO - GECKO(9716) | #11: mozilla::MediaDecoderStateMachine::StartMediaSink() [dom/media/MediaDecoderStateMachine.cpp:3394]
[task 2021-05-28T23:05:03.504Z] 23:05:03     INFO - GECKO(9716) | #12: mozilla::MediaDecoderStateMachine::UpdateOutputCaptured() [dom/media/MediaDecoderStateMachine.cpp:3755]
[task 2021-05-28T23:05:03.505Z] 23:05:03     INFO - GECKO(9716) | #13: mozilla::WatchManager<mozilla::MediaDecoderStateMachine>::PerCallbackWatcher::Notify::<unnamed-tag>::operator()() const [xpcom/threads/StateWatching.h:253]
[task 2021-05-28T23:05:03.505Z] 23:05:03     INFO - GECKO(9716) | #14: mozilla::detail::RunnableFunction<`lambda at /builds/worker/workspace/obj-build/dist/include/mozilla/StateWatching.h:248:34'>::Run() [xpcom/threads/nsThreadUtils.h:535]
[task 2021-05-28T23:05:03.506Z] 23:05:03     INFO - GECKO(9716) | #15: mozilla::SimpleTaskQueue::DrainTasks() [xpcom/threads/TaskDispatcher.h:43]
[task 2021-05-28T23:05:03.506Z] 23:05:03     INFO - GECKO(9716) | #16: mozilla::TaskQueue::DrainDirectTasks() [xpcom/threads/TaskQueue.cpp:270]
[task 2021-05-28T23:05:03.507Z] 23:05:03     INFO - GECKO(9716) | #17: mozilla::AutoTaskDispatcher::TaskGroupRunnable::Run() [xpcom/threads/TaskDispatcher.h:226]
[task 2021-05-28T23:05:03.507Z] 23:05:03     INFO - GECKO(9716) | #18: mozilla::TaskQueue::Runner::Run() [xpcom/threads/TaskQueue.cpp:215]
[task 2021-05-28T23:05:03.508Z] 23:05:03     INFO - GECKO(9716) | #19: nsThreadPool::Run() [xpcom/threads/nsThreadPool.cpp:305]
[task 2021-05-28T23:05:03.508Z] 23:05:03     INFO - GECKO(9716) | #20: nsThread::ProcessNextEvent(bool, bool*) [xpcom/threads/nsThread.cpp:1153]
[task 2021-05-28T23:05:03.509Z] 23:05:03     INFO - GECKO(9716) | #21: NS_ProcessNextEvent(nsIThread*, bool) [xpcom/threads/nsThreadUtils.cpp:548]
[task 2021-05-28T23:05:03.509Z] 23:05:03     INFO - GECKO(9716) | #22: mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate*) [ipc/glue/MessagePump.cpp:301]
[task 2021-05-28T23:05:03.510Z] 23:05:03     INFO - GECKO(9716) | #23: MessageLoop::RunHandler() [ipc/chromium/src/base/message_loop.cc:329]
[task 2021-05-28T23:05:03.510Z] 23:05:03     INFO - GECKO(9716) | #24: MessageLoop::Run() [ipc/chromium/src/base/message_loop.cc:311]
[task 2021-05-28T23:05:03.511Z] 23:05:03     INFO - GECKO(9716) | #25: static nsThread::ThreadFunc(void*) [xpcom/threads/nsThread.cpp:397]
[task 2021-05-28T23:05:03.691Z] 23:05:03     INFO - GECKO(9716) | #26: PR_NativeRunThread(void*) [nsprpub/pr/src/threads/combined/pruthr.c:408]
[task 2021-05-28T23:05:03.692Z] 23:05:03     INFO - GECKO(9716) | #27: pr_root(void*) [nsprpub/pr/src/md/windows/w95thred.c:140]
[task 2021-05-28T23:05:03.701Z] 23:05:03     INFO -  fix-stacks: error: failed to read debug info file `ucrtbase.pdb` for `C:\Windows\System32\ucrtbase.dll`
[task 2021-05-28T23:05:03.701Z] 23:05:03     INFO -  fix-stacks: note: this is expected and harmless for all PDB files on opt automation runs
[task 2021-05-28T23:05:03.701Z] 23:05:03     INFO -  fix-stacks: The system cannot find the file specified. (os error 2)
[task 2021-05-28T23:05:03.702Z] 23:05:03     INFO - GECKO(9716) | #28: o_ceil [C:\Windows\System32\ucrtbase.dll + 0x1c4be]
[task 2021-05-28T23:05:03.709Z] 23:05:03     INFO -  fix-stacks: error: failed to read debug info file `wkernel32.pdb` for `C:\Windows\System32\KERNEL32.DLL`
[task 2021-05-28T23:05:03.709Z] 23:05:03     INFO -  fix-stacks: note: this is expected and harmless for all PDB files on opt automation runs
[task 2021-05-28T23:05:03.709Z] 23:05:03     INFO -  fix-stacks: The system cannot find the file specified. (os error 2)
[task 2021-05-28T23:05:03.710Z] 23:05:03     INFO - GECKO(9716) | #29: BaseThreadInitThunk [C:\Windows\System32\KERNEL32.DLL + 0x13034]
[task 2021-05-28T23:05:03.716Z] 23:05:03     INFO -  fix-stacks: error: failed to read debug info file `wntdll.pdb` for `C:\Windows\SYSTEM32\ntdll.dll`
[task 2021-05-28T23:05:03.717Z] 23:05:03     INFO -  fix-stacks: note: this is expected and harmless for all PDB files on opt automation runs
[task 2021-05-28T23:05:03.717Z] 23:05:03     INFO -  fix-stacks: The system cannot find the file specified. (os error 2)
[task 2021-05-28T23:05:03.717Z] 23:05:03     INFO - GECKO(9716) | #30: RtlUserThreadStart [C:\Windows\SYSTEM32\ntdll.dll + 0x71461]
[task 2021-05-28T23:05:03.718Z] 23:05:03     INFO - GECKO(9716) | [Child 9788, Main Thread] WARNING: early callback, or time went backwards: '!aAllowIdleDispatch', file /builds/worker/checkouts/gecko/xpcom/threads/IdleTaskRunner.cpp:179
[task 2021-05-28T23:05:03.718Z] 23:05:03     INFO - TEST-PASS | dom/media/test/test_bug1113600.html | flac-s24.flac ended 
[task 2021-05-28T23:05:03.719Z] 23:05:03     INFO - [finished flac-s24.flac-11] remaining= 
[task 2021-05-28T23:05:03.719Z] 23:05:03     INFO - TEST-PASS | dom/media/test/test_bug1113600.html | [finished flac-s24.flac-11 t=9.374] Length of array should match number of running tests 
[task 2021-05-28T23:05:03.720Z] 23:05:03     INFO - Finished at Fri May 28 2021 23:04:56 GMT+0000 (Greenwich Mean Time) (1622243096.555s)
[task 2021-05-28T23:05:03.720Z] 23:05:03     INFO - Running time: 9.581s
[task 2021-05-28T23:05:03.720Z] 23:05:03     INFO - GECKO(9716) | MEMORY STAT | vsize 2103898MB | vsizeMaxContiguous 69652773MB | residentFast 141MB | heapAllocated 8MB
[task 2021-05-28T23:05:03.721Z] 23:05:03     INFO - TEST-OK | dom/media/test/test_bug1113600.html | took 9754ms
[task 2021-05-28T23:05:03.721Z] 23:05:03     INFO - TEST-UNEXPECTED-FAIL | dom/media/test/test_bug1113600.html | assertion count 1 is more than expected 0 assertions
[task 2021-05-28T23:05:03.722Z] 23:05:03     INFO - TEST-START | dom/media/test/test_bug1120222.html

Comment 1

[Intermittent Failures Robot]

10 failures in 2908 pushes (0.003 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 7
• mozilla-central: 3

Platform and build breakdown:

• windows10-64: 2
  • debug: 2
• windows10-64-qr: 3
  • debug: 3
• windows10-32: 5
  • debug: 5

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

Comment 2

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

Regression from bug 1712598?

Comment 3

[Alastor Wu [:alwu]]

Possible, but not sure what happened. I push a patch to check if we can grasp the debug log while that error happens.

Comment 4

[Intermittent Failures Robot]

24 failures in 3065 pushes (0.008 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 18
• mozilla-central: 6

Platform and build breakdown:

• windows10-64-qr: 12
  • debug: 12
• windows10-64: 5
  • debug: 5
• windows10-32: 7
  • debug: 7

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

Comment 5

[Intermittent Failures Robot]

22 failures in 3502 pushes (0.006 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 16
• mozilla-central: 6

Platform and build breakdown:

• windows10-64-qr: 11
  • debug: 11
• windows10-32: 5
  • debug: 5
• windows10-64: 6
  • debug: 6

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1713410&startday=2021-06-07&endday=2021-06-13&tree=all

Comment 6

[Natalia Csoregi [:nataliaCs]]

Update:

There have been 41 failures within the last 7 days:

• 18 failures on Windows 10 x64 WebRender debug
• 13 failures on Windows 10 x64 debug
• 10 failures on Windows 10 x86 debug

Recent failure log: https://treeherder.mozilla.org/logviewer?job_id=343264006&repo=autoland&lineNumber=4963

[task 2021-06-19T10:10:41.679Z] 10:10:41     INFO - TEST-PASS | dom/media/test/test_bug1113600.html | [started flac-s24.flac-11 t=3.53] Length of array should match number of running tests 
[task 2021-06-19T10:10:43.045Z] 10:10:43     INFO - GECKO(10608) | [Child 11256, MediaDecoderStateMachine #1] WARNING: 2635b033670 Could not set cubeb stream name.: file /builds/worker/checkouts/gecko/dom/media/AudioStream.cpp:367
[task 2021-06-19T10:10:44.244Z] 10:10:44     INFO - flac-s24.flac capture started at 1.193219. Duration=4.04
[task 2021-06-19T10:10:44.262Z] 10:10:44     INFO - GECKO(10608) | [Child 11256, MediaDecoderStateMachine #1] ###!!! ASSERTION: Dropping samples: '(UINT32_MAX - aInRate + 1) / c.mDuration >= aOutRate', file /builds/worker/checkouts/gecko/dom/media/AudioSegment.h:321
[task 2021-06-19T10:10:44.339Z] 10:10:44     INFO -  Initializing stack-fixing for the first stack frame, this may take a while...
[task 2021-06-19T10:10:54.726Z] 10:10:54     INFO - GECKO(10608) | #01: NS_DebugBreak(unsigned int, char const*, char const*, char const*, int) [xpcom/base/nsDebugImpl.cpp:431]
[task 2021-06-19T10:10:54.726Z] 10:10:54     INFO - GECKO(10608) | #02: mozilla::AudioSegment::Resample<float>(nsAutoRef<SpeexResamplerState_>&, unsigned int*, unsigned int, unsigned int) [dom/media/AudioSegment.h:322]
[task 2021-06-19T10:10:54.727Z] 10:10:54     INFO - GECKO(10608) | #03: mozilla::AudioSegment::ResampleChunks(nsAutoRef<SpeexResamplerState_>&, unsigned int*, unsigned int, unsigned int) [dom/media/AudioSegment.cpp:62]
[task 2021-06-19T10:10:54.727Z] 10:10:54     INFO - GECKO(10608) | #04: mozilla::AudioDecoderInputTrack::ConvertAudioDataToSegment(mozilla::AudioData*, mozilla::AudioSegment&, nsMainThreadPtrHandle<nsIPrincipal> const&) [dom/media/mediasink/AudioDecoderInputTrack.cpp:85]
[task 2021-06-19T10:10:54.728Z] 10:10:54     INFO - GECKO(10608) | #05: mozilla::AudioDecoderInputTrack::BatchData(mozilla::AudioData*, nsMainThreadPtrHandle<nsIPrincipal> const&) [dom/media/mediasink/AudioDecoderInputTrack.cpp:137]
[task 2021-06-19T10:10:54.728Z] 10:10:54     INFO - GECKO(10608) | #06: mozilla::AudioDecoderInputTrack::AppendData(nsTArray<RefPtr<mozilla::AudioData> >&, nsMainThreadPtrHandle<nsIPrincipal> const&) [dom/media/mediasink/AudioDecoderInputTrack.cpp:105]
[task 2021-06-19T10:10:54.728Z] 10:10:54     INFO - GECKO(10608) | #07: mozilla::DecodedStream::SendAudio(nsMainThreadPtrHandle<nsIPrincipal> const&) [dom/media/mediasink/DecodedStream.cpp:756]
[task 2021-06-19T10:10:54.729Z] 10:10:54     INFO - GECKO(10608) | #08: mozilla::DecodedStream::SendData() [dom/media/mediasink/DecodedStream.cpp:1051]
[task 2021-06-19T10:10:54.729Z] 10:10:54     INFO - GECKO(10608) | #09: mozilla::DecodedStream::Start(mozilla::media::TimeUnit const&, mozilla::MediaInfo const&) [dom/media/mediasink/DecodedStream.cpp:603]
[task 2021-06-19T10:10:54.730Z] 10:10:54     INFO - GECKO(10608) | #10: mozilla::VideoSink::Start(mozilla::media::TimeUnit const&, mozilla::MediaInfo const&) [dom/media/mediasink/VideoSink.cpp:217]
[task 2021-06-19T10:10:54.730Z] 10:10:54     INFO - GECKO(10608) | #11: mozilla::MediaDecoderStateMachine::StartMediaSink() [dom/media/MediaDecoderStateMachine.cpp:3422]
[task 2021-06-19T10:10:54.731Z] 10:10:54     INFO - GECKO(10608) | #12: mozilla::MediaDecoderStateMachine::UpdateOutputCaptured() [dom/media/MediaDecoderStateMachine.cpp:3783]
[task 2021-06-19T10:10:54.731Z] 10:10:54     INFO - GECKO(10608) | #13: mozilla::WatchManager<mozilla::MediaDecoderStateMachine>::PerCallbackWatcher::Notify::<unnamed-tag>::operator()() const [xpcom/threads/StateWatching.h:253]
[task 2021-06-19T10:10:54.731Z] 10:10:54     INFO - GECKO(10608) | #14: mozilla::detail::RunnableFunction<`lambda at /builds/worker/workspace/obj-build/dist/include/mozilla/StateWatching.h:248:34'>::Run() [xpcom/threads/nsThreadUtils.h:535]
[task 2021-06-19T10:10:54.732Z] 10:10:54     INFO - GECKO(10608) | #15: mozilla::SimpleTaskQueue::DrainTasks() [xpcom/threads/TaskDispatcher.h:43]
[task 2021-06-19T10:10:54.732Z] 10:10:54     INFO - GECKO(10608) | #16: mozilla::TaskQueue::DrainDirectTasks() [xpcom/threads/TaskQueue.cpp:270]
[task 2021-06-19T10:10:54.732Z] 10:10:54     INFO - GECKO(10608) | #17: mozilla::AutoTaskDispatcher::TaskGroupRunnable::Run() [xpcom/threads/TaskDispatcher.h:226]
[task 2021-06-19T10:10:54.733Z] 10:10:54     INFO - GECKO(10608) | #18: mozilla::TaskQueue::Runner::Run() [xpcom/threads/TaskQueue.cpp:215]
[task 2021-06-19T10:10:54.733Z] 10:10:54     INFO - GECKO(10608) | #19: nsThreadPool::Run() [xpcom/threads/nsThreadPool.cpp:305]
[task 2021-06-19T10:10:54.733Z] 10:10:54     INFO - GECKO(10608) | #20: nsThread::ProcessNextEvent(bool, bool*) [xpcom/threads/nsThread.cpp:1146]
[task 2021-06-19T10:10:54.734Z] 10:10:54     INFO - GECKO(10608) | #21: NS_ProcessNextEvent(nsIThread*, bool) [xpcom/threads/nsThreadUtils.cpp:548]
[task 2021-06-19T10:10:54.734Z] 10:10:54     INFO - GECKO(10608) | #22: mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate*) [ipc/glue/MessagePump.cpp:301]
[task 2021-06-19T10:10:54.735Z] 10:10:54     INFO - GECKO(10608) | #23: MessageLoop::RunHandler() [ipc/chromium/src/base/message_loop.cc:325]
[task 2021-06-19T10:10:54.735Z] 10:10:54     INFO - GECKO(10608) | #24: MessageLoop::Run() [ipc/chromium/src/base/message_loop.cc:307]
[task 2021-06-19T10:10:54.735Z] 10:10:54     INFO - GECKO(10608) | #25: static nsThread::ThreadFunc(void*) [xpcom/threads/nsThread.cpp:394]
[task 2021-06-19T10:10:54.917Z] 10:10:54     INFO - GECKO(10608) | #26: PR_NativeRunThread(void*) [nsprpub/pr/src/threads/combined/pruthr.c:408]
[task 2021-06-19T10:10:54.917Z] 10:10:54     INFO - GECKO(10608) | #27: pr_root(void*) [nsprpub/pr/src/md/windows/w95thred.c:140]
[task 2021-06-19T10:10:54.923Z] 10:10:54     INFO -  fix-stacks: error: failed to read debug info file `ucrtbase.pdb` for `C:\Windows\System32\ucrtbase.dll`
[task 2021-06-19T10:10:54.923Z] 10:10:54     INFO -  fix-stacks: note: this is expected and harmless for all PDB files on opt automation runs
[task 2021-06-19T10:10:54.923Z] 10:10:54     INFO -  fix-stacks: The system cannot find the file specified. (os error 2)
[task 2021-06-19T10:10:54.924Z] 10:10:54     INFO - GECKO(10608) | #28: o_ceil [C:\Windows\System32\ucrtbase.dll + 0x1c4be]
[task 2021-06-19T10:10:54.927Z] 10:10:54     INFO -  fix-stacks: error: failed to read debug info file `wkernel32.pdb` for `C:\Windows\System32\KERNEL32.DLL`
[task 2021-06-19T10:10:54.928Z] 10:10:54     INFO -  fix-stacks: note: this is expected and harmless for all PDB files on opt automation runs
[task 2021-06-19T10:10:54.928Z] 10:10:54     INFO -  fix-stacks: The system cannot find the file specified. (os error 2)
[task 2021-06-19T10:10:54.928Z] 10:10:54     INFO - GECKO(10608) | #29: BaseThreadInitThunk [C:\Windows\System32\KERNEL32.DLL + 0x13034]
[task 2021-06-19T10:10:54.935Z] 10:10:54     INFO -  fix-stacks: error: failed to read debug info file `wntdll.pdb` for `C:\Windows\SYSTEM32\ntdll.dll`
[task 2021-06-19T10:10:54.935Z] 10:10:54     INFO -  fix-stacks: note: this is expected and harmless for all PDB files on opt automation runs
[task 2021-06-19T10:10:54.935Z] 10:10:54     INFO -  fix-stacks: The system cannot find the file specified. (os error 2)
[task 2021-06-19T10:10:54.935Z] 10:10:54     INFO - GECKO(10608) | #30: RtlUserThreadStart [C:\Windows\SYSTEM32\ntdll.dll + 0x71461]
[task 2021-06-19T10:10:54.936Z] 10:10:54     INFO - TEST-PASS | dom/media/test/test_bug1113600.html | flac-s24.flac ended 
[task 2021-06-19T10:10:54.936Z] 10:10:54     INFO - [finished flac-s24.flac-11] remaining= 
[task 2021-06-19T10:10:54.937Z] 10:10:54     INFO - TEST-PASS | dom/media/test/test_bug1113600.html | [finished flac-s24.flac-11 t=9.056] Length of array should match number of running tests 
[task 2021-06-19T10:10:54.937Z] 10:10:54     INFO - Finished at Sat Jun 19 2021 10:10:47 GMT+0000 (Coordinated Universal Time) (1624097447.404s)
[task 2021-06-19T10:10:54.937Z] 10:10:54     INFO - Running time: 9.254s
[task 2021-06-19T10:10:54.938Z] 10:10:54     INFO - GECKO(10608) | MEMORY STAT | vsize 2103879MB | vsizeMaxContiguous 73466995MB | residentFast 130MB | heapAllocated 8MB
[task 2021-06-19T10:10:54.938Z] 10:10:54     INFO - TEST-OK | dom/media/test/test_bug1113600.html | took 9404ms
[task 2021-06-19T10:10:54.938Z] 10:10:54     INFO - GECKO(10608) | [Child 11256, Main Thread] WARNING: early callback, or time went backwards: '!aAllowIdleDispatch', file /builds/worker/checkouts/gecko/xpcom/threads/IdleTaskRunner.cpp:179
[task 2021-06-19T10:10:54.939Z] 10:10:54     INFO - TEST-UNEXPECTED-FAIL | dom/media/test/test_bug1113600.html | assertion count 1 is more than expected 0 assertions

Comment 7

[Intermittent Failures Robot]

38 failures in 2888 pushes (0.013 failures/push) were associated with this bug in the last 7 days.

This is the #35 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: 25
• mozilla-central: 13

Platform and build breakdown:

• windows10-64: 11
  • debug: 11
• windows10-32: 11
  • debug: 11
• windows10-64-qr: 16
  • debug: 16

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

Comment 8

[Andreea Pavel [:apavel]]

Hi Alastor, are you still working on this?

Comment 9

[Intermittent Failures Robot]

40 failures in 3115 pushes (0.013 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:

• mozilla-central: 13
• autoland: 27

Platform and build breakdown:

• windows10-64-qr: 21
  • debug: 21
• windows10-32-qr: 18
  • debug: 18
• windows10-64: 1
  • debug: 1

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

Comment 10

[Atila Butkovits]

Attachment: Bug 1713410 - disable test_bug1113600.html on Win10_QR_Debug for frequent failures. r=#intermittent-reviewers

Comment 11

[Intermittent Failures Robot]

20 failures in 723 pushes (0.028 failures/push) were associated with this bug in the last 7 days.

This is the #35 most frequent failure this week.

Repository breakdown:

• autoland: 18
• mozilla-central: 2

Platform and build breakdown:

• windows10-32-qr: 11
  • debug: 11
• windows10-64-qr: 9
  • debug: 9

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

Comment 12

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/9f8eb3966833
disable test_bug1113600.html on Win10_QR_Debug for frequent failures. r=intermittent-reviewers,ahal DONTBUILD

Comment 13

[Iulian Moraru]

https://hg.mozilla.org/mozilla-central/rev/9f8eb3966833

Comment 14

[Intermittent Failures Robot]

26 failures in 2387 pushes (0.011 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 15
• mozilla-central: 10
• try: 1

Platform and build breakdown:

• windows10-64-qr: 13
  • debug: 13
• windows10-32-qr: 13
  • debug: 13

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

Comment 15

[Intermittent Failures Robot]

7 failures in 2224 pushes (0.003 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 2
• autoland: 5

Platform and build breakdown:

• windows10-32-qr: 4
  • debug: 4
• windows10-64-qr: 3
  • debug: 3

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

Comment 16

[Intermittent Failures Robot]

14 failures in 2940 pushes (0.005 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 9
• mozilla-central: 5

Platform and build breakdown:

• windows10-64-qr: 10
  • debug: 10
• windows10-32-qr: 4
  • debug: 4

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1713410&startday=2021-07-19&endday=2021-07-25&tree=all

Comment 17

[Intermittent Failures Robot]

5 failures in 3131 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 2
• autoland: 3

Platform and build breakdown:

• windows10-64-qr: 4
  • debug: 4
• windows10-32-qr: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1713410&startday=2021-07-26&endday=2021-08-01&tree=all

Comment 18

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 1
• mozilla-esr91: 1
• autoland: 2

Platform and build breakdown:

• windows10-32-qr: 3
  • debug: 3
• windows10-64-qr: 1
  • debug: 1

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

Comment 19

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-esr91: 1
• autoland: 1

Platform and build breakdown:

• windows10-64-qr: 1
  • debug: 1
• windows10-32-qr: 1
  • debug: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1713410&startday=2021-08-09&endday=2021-08-15&tree=all

Comment 20

[Paul Adenot (:padenot)]

Attachment: Bug 1713410 - Use a wider integer in resampling segment calculation, to avoid overflow. r?alwu

I caught this locally on Android, c.mDuration was 104517 (which is more than two
seconds at the rate it was), it was overflowing uint32_t because we want to do
this in integers so the multiplication is big. The alternative is to make the
computation in floating point, rounding up so that there's enough space in the
buffer.

Now I wonder why we have such a big segment sometimes, and only on some OSes, but
we can investigate this later.

Comment 21

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/1f98be6e6298
Use a wider integer in resampling segment calculation, to avoid overflow. r=alwu

Comment 22

[Noemi Erli[:noemi_erli]]

https://hg.mozilla.org/mozilla-central/rev/1f98be6e6298

Comment 23

[Paul Adenot (:padenot)]

Comment on attachment 9263072 [details]
Bug 1713410 - Use a wider integer in resampling segment calculation, to avoid overflow. r?alwu

Beta/Release Uplift Approval Request

• User impact if declined: None (this is simply fixing an assertion), but needs to be landed at the same time as 1754006 to avoid oranges.
• Is this code covered by automated tests?: Yes
• Has the fix been verified in Nightly?: Yes
• Needs manual test from QE?: No
• If yes, steps to reproduce:
• List of other uplifts needed: None
• Risk to taking this patch: Low
• Why is the change risky/not risky? (and alternatives if risky): This is just fixing an assertion -- not compiled in in non-debug builds.
• String changes made/needed:

Comment 24

[Pascal Chevrel:pascalc]

Comment on attachment 9229266 [details]
Bug 1713410 - disable test_bug1113600.html on Win10_QR_Debug for frequent failures. r=#intermittent-reviewers

This one landed in 91 so it doesn't need uplift

Comment 25

[Pascal Chevrel:pascalc]

Comment on attachment 9263072 [details]
Bug 1713410 - Use a wider integer in resampling segment calculation, to avoid overflow. r?alwu

Approved for 98 beta 7, thanks.

Comment 26

[Pascal Chevrel:pascalc]

https://hg.mozilla.org/releases/mozilla-beta/rev/bbdca32d1f7f