1846396 - Assertion failure: aTime >= 0.0 (Cannot seek to a negative value.), at /builds/worker/checkouts/gecko/dom/media/MediaDecoder.cpp:657

Status: RESOLVED FIXED

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

Description

[Tyson Smith [:tsmith]]

Found with m-c 20230731-bb8659c8d955 (--enable-debug)

STR:

• Launch browser and visit: https://www.cbc.ca/news

Assertion failure: aTime >= 0.0 (Cannot seek to a negative value.), at /builds/worker/checkouts/gecko/dom/media/MediaDecoder.cpp:657

#0 0x128f6cf6642b in mozilla::MediaDecoder::Seek(double, mozilla::SeekTarget::Type) /builds/worker/checkouts/gecko/dom/media/MediaDecoder.cpp:657:3
#1 0x128f6cf6b10f in mozilla::MediaDecoder::DurationChanged() /builds/worker/checkouts/gecko/dom/media/MediaDecoder.cpp:1073:5
#2 0x128f6ce03b49 in mozilla::ChannelMediaDecoder::DurationChanged() /builds/worker/checkouts/gecko/dom/media/ChannelMediaDecoder.cpp:370:17
#3 0x128f6d078601 in mozilla::WatchManager<mozilla::MediaDecoder>::PerCallbackWatcher::Notify()::'lambda'()::operator()() const /builds/worker/workspace/obj-build/dist/include/mozilla/StateWatching.h:251:38
#4 0x128f6d078348 in mozilla::detail::RunnableFunction<mozilla::WatchManager<mozilla::MediaDecoder>::PerCallbackWatcher::Notify()::'lambda'()>::Run() /builds/worker/workspace/obj-build/dist/include/nsThreadUtils.h:548:5
#5 0x128f66d6f6eb in mozilla::SimpleTaskQueue::DrainTasks() /builds/worker/workspace/obj-build/dist/include/mozilla/TaskDispatcher.h:44:10
#6 0x128f66daa00c in nsThread::DrainDirectTasks() /builds/worker/checkouts/gecko/xpcom/threads/nsThread.cpp:1397:16
#7 0x128f66d7975f in mozilla::AutoTaskDispatcher::DrainDirectTasks() /builds/worker/workspace/obj-build/dist/include/mozilla/TaskDispatcher.h:133:30
#8 0x128f66d7a197 in mozilla::AutoTaskDispatcher::TaskGroupRunnable::MaybeDrainDirectTasks() /builds/worker/workspace/obj-build/dist/include/mozilla/TaskDispatcher.h:243:41
#9 0x128f66d79f74 in mozilla::AutoTaskDispatcher::TaskGroupRunnable::Run() /builds/worker/workspace/obj-build/dist/include/mozilla/TaskDispatcher.h:226:7
#10 0x128f66d7db22 in mozilla::XPCOMThreadWrapper::Runner::Run() /builds/worker/checkouts/gecko/xpcom/threads/AbstractThread.cpp:208:25
#11 0x128f66d76865 in mozilla::RunnableTask::Run() /builds/worker/checkouts/gecko/xpcom/threads/TaskController.cpp:559:16
#12 0x128f66d6b461 in mozilla::TaskController::DoExecuteNextTaskOnlyMainThreadInternal(mozilla::detail::BaseAutoLock<mozilla::Mutex&> const&) /builds/worker/checkouts/gecko/xpcom/threads/TaskController.cpp:886:26
#13 0x128f66d69409 in mozilla::TaskController::ExecuteNextTaskOnlyMainThreadInternal(mozilla::detail::BaseAutoLock<mozilla::Mutex&> const&) /builds/worker/checkouts/gecko/xpcom/threads/TaskController.cpp:709:15
#14 0x128f66d69854 in mozilla::TaskController::ProcessPendingMTTask(bool) /builds/worker/checkouts/gecko/xpcom/threads/TaskController.cpp:495:36
#15 0x128f66d886fa in mozilla::TaskController::TaskController()::$_0::operator()() const /builds/worker/checkouts/gecko/xpcom/threads/TaskController.cpp:218:37
#16 0x128f66d88678 in mozilla::detail::RunnableFunction<mozilla::TaskController::TaskController()::$_0>::Run() /builds/worker/checkouts/gecko/xpcom/threads/nsThreadUtils.h:548:5
#17 0x128f66da885a in nsThread::ProcessNextEvent(bool, bool*) /builds/worker/checkouts/gecko/xpcom/threads/nsThread.cpp:1199:16
#18 0x128f66db07c5 in NS_ProcessNextEvent(nsIThread*, bool) /builds/worker/checkouts/gecko/xpcom/threads/nsThreadUtils.cpp:480:10
#19 0x128f68312c0c in mozilla::ipc::MessagePump::Run(base::MessagePump::Delegate*) /builds/worker/checkouts/gecko/ipc/glue/MessagePump.cpp:85:21
#20 0x128f68314579 in mozilla::ipc::MessagePumpForChildProcess::Run(base::MessagePump::Delegate*) /builds/worker/checkouts/gecko/ipc/glue/MessagePump.cpp:268:30
#21 0x128f68175397 in MessageLoop::RunInternal() /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:370:10
#22 0x128f68175314 in MessageLoop::RunHandler() /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:363:3
#23 0x128f681752cf in MessageLoop::Run() /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:345:3
#24 0x128f6f767d2b in nsBaseAppShell::Run() /builds/worker/checkouts/gecko/widget/nsBaseAppShell.cpp:148:27
#25 0x128f742c2b36 in XRE_RunAppShell() /builds/worker/checkouts/gecko/toolkit/xre/nsEmbedFunctions.cpp:717:20
#26 0x128f683142da in mozilla::ipc::MessagePumpForChildProcess::Run(base::MessagePump::Delegate*) /builds/worker/checkouts/gecko/ipc/glue/MessagePump.cpp:235:9
#27 0x128f68175397 in MessageLoop::RunInternal() /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:370:10
#28 0x128f68175314 in MessageLoop::RunHandler() /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:363:3
#29 0x128f681752cf in MessageLoop::Run() /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:345:3
#30 0x128f742c1ec5 in XRE_InitChildProcess(int, char**, XREChildData const*) /builds/worker/checkouts/gecko/toolkit/xre/nsEmbedFunctions.cpp:652:34
#31 0x128f742d7026 in mozilla::BootstrapImpl::XRE_InitChildProcess(int, char**, XREChildData const*) /builds/worker/checkouts/gecko/toolkit/xre/Bootstrap.cpp:67:12
#32 0x557c37a32928 in content_process_main(mozilla::Bootstrap*, int, char**) /builds/worker/checkouts/gecko/browser/app/../../ipc/contentproc/plugin-container.cpp:57:28
#33 0x557c37a32bcc in main /builds/worker/checkouts/gecko/browser/app/nsBrowserApp.cpp:375:18
#34 0x7f6adc829d8f in __libc_start_call_main csu/../sysdeps/nptl/libc_start_call_main.h:58:16
#35 0x7f6adc829e3f in __libc_start_main csu/../csu/libc-start.c:392:3
#36 0x557c37a0a068 in _start (/home/user/workspace/browsers/m-c-20230731215815-fuzzing-noopt-debug/firefox-bin+0xce068) (BuildId: ab6d11dcfa2e704476a1fe8bc868b127c0de30a0)

Comment 1

[Tyson Smith [:tsmith]]

A Pernosco session is available here: https://pernos.co/debug/YlijSkKdYO3r92PdRdXigw/index.html

Comment 2

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

The severity field is not set for this bug.
:jimm, could you have a look please?

For more information, please visit BugBot documentation.

Comment 3

[Karl Tomlinson (:karlt)]

MediaDecoderStateMachine::mBuffered contains a single TimeInterval from -2048/96000 to -1024/96000. MediaDecoderStateMachine::mDuration is nothing, so mDuration is updated with -1024/96000 from mBuffered.

This looks like a regression from bug 1385699.
Previously, duration would only be updated if the end of mBuffered was greater than the previous observed duration, which started at zero.

mInfo is empty, so https://hg.mozilla.org/mozreview/gecko/rev/71adbb7dbb053cb3c8c97e3587540dd3258149ab would have avoided this, but bug 1402584 comment 6 did not think that was fixing the cause of that bug.

Comment 4

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

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

Comment 5

[Karl Tomlinson (:karlt)]

https://treeherder.mozilla.org/jobs?repo=try&revision=1cbec02799b133cf4da0841aa088565885147c4c

Comment 6

[Karl Tomlinson (:karlt)]

In bug 1389304 comment 3 and subsequent, negative values in MediaFormatReader::mBuffered were not expected, at least because these were not expected in HTMLMediaElement.seekable.

https://hg.mozilla.org/mozilla-central/rev/5125278fa1d7 changed MediaDecoder::GetSeekableImpl() to exclude negative sub-intervals coming from mBuffered.
Similarly this assertion is failing now because mFirstDemuxedSampleTime is set with a time now clamped to be >= 0, so the raw MediaFormatReader::mBuffered intervals are no longer adjusted by a negative first sample time.

Comment 7

[Karl Tomlinson (:karlt)]

MediaTrackDemuxer::GetBuffered() is used in
  DemuxerProxy::Wrapper::UpdateBuffered() for mBuffered for
    DemuxerProxy::Wrapper::GetBuffered() overrides MediaTrackDemuxer,
  MediaFormatReader::UpdateBuffered() for mBuffered for
    MediaFormatReader::CanonicalBuffered() for
      ReaderProxy::CanonicalBuffered() for
        MediaDecoderStateMachineBase::CanonicalBuffered() for
          MediaDecoder::ConnectMirrors() for mBuffered for
            MediaDecoder::UpdateReadyState() for
              MediaDecoderOwner::UpdateReadyState(void),
            MediaDecoder::GetBuffered() for
              HTMLMediaElement::Buffered() for buffered for content,
              MediaDecoder::GetSeekableImpl() for
                MediaDecoder::GetSeekable() unused
                MediaDecoder::GetSeekableTimeRanges() for
                  HTMLMediaElement::Seek(), for seek() for content
                  HTMLMediaElement::Seekable() for seekable for content,
              MediaDecoder::NextFrameBufferedStatus() for
                HTMLMediaElement::UpdateReadyStateInternal(),
        MediaDecoderStateMachineBase::InitializationTask for mBuffered for
          HasLowBufferedData()
            where intervals outside of [0, mDuration] have no effect,
          BufferedRangeUpdated() for mDuration for
            Duration() for playback end point,
            CanonicalDuration() for
              MediaDecoder::mStateMachineDuration for
                MediaDecoder::DurationChanged() for mDuration,
                  if not set by MSE, for
                    MediaDecoder::GetSeekableImpl(),
                    ChannelMediaDecoder::ComputePlaybackRate(),
                    GetDuration() for
                      HTMLMediaElement::CurrentTime
                        to clamp currentTime for content,
                      HTMLMediaElement::Duration for duration for content.

No uses want to know the buffered ranges outside of [0, duration], so if the clamping of buffered ranges from GetSeekableImpl() can be moved to a root location, it will suffice for all purposes.

The circular effect of buffered affecting duration affecting buffered might need some care to use the right duration(s).

Comment 8

[Karl Tomlinson (:karlt)]

https://treeherder.mozilla.org/jobs?repo=try&revision=a825b6b0e02fb74a10e353bde012febf68eb37cc

Comment 9

[Karl Tomlinson (:karlt)]

Attachment: Bug 1846396 trim buffered ranges from MP4TrackDemuxer consistently with samples r?padenot

test_buffered.html uses gSeekTests https://searchfox.org/mozilla-central/rev/28bc51699a56f6fa4d0e4d3fe9cded581a70844d/dom/media/test/test_buffered.html#112

Comment 10

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/893bba06f7dd
trim buffered ranges from MP4TrackDemuxer consistently with samples r=padenot

Comment 11

[Cosmin Sabou [:CosminS]]

https://hg.mozilla.org/mozilla-central/rev/893bba06f7dd

Comment 12

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

The patch landed in nightly and beta is affected.
:karlt, is this bug important enough to require an uplift?

• If yes, please nominate the patch for beta approval.
• If no, please set status-firefox118 to wontfix.

For more information, please visit BugBot documentation.

Comment 13

[Karl Tomlinson (:karlt)]

If this were earlier in the release cycle, I would request uplift, but there may be potential for a regression here. For example, these changes would expose the existing bug 1853278 in more circumstances.