1654885 - Intermittent MediaDecoderStateMachine #1] ###!!! ASSERTION: AudioStream position shouldn't go backward: 'pos >= mLastGoodPosition', file /builds/worker/checkouts/gecko/dom/media/mediasink/AudioSink.cpp, line 119

Status: RESOLVED FIXED

(Core :: Audio/Video, defect)

Description

[Alexandru Michis [:malexandru]]

Failure logs:

• https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=310878267&repo=autoland&lineNumber=2051
• https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=310869762&repo=autoland&lineNumber=1775

Raw logs:

• https://firefoxci.taskcluster-artifacts.net/CMLtJyq7QiilgCxUN40sXA/0/public/logs/live_backing.log
• https://firefoxci.taskcluster-artifacts.net/FKkB89o2RkmtS53tUKZZxw/0/public/logs/live_backing.log

[task 2020-07-23T17:38:17.705Z] 17:38:17     INFO - TEST-OK | dom/media/mediasource/test/test_BufferingWait.html | took 4660ms
[task 2020-07-23T17:38:17.805Z] 17:38:17     INFO - TEST-START | dom/media/mediasource/test/test_BufferingWait_mp4.html
[task 2020-07-23T17:38:17.805Z] 17:38:17     INFO - GECKO(1616) | [Child 1619, Main Thread] WARNING: Wrong inner/outer window combination!: file /builds/worker/checkouts/gecko/dom/base/Document.cpp, line 7051
[task 2020-07-23T17:38:17.805Z] 17:38:17     INFO - GECKO(1616) | [Child 1619, Main Thread] WARNING: Wrong inner/outer window combination!: file /builds/worker/checkouts/gecko/dom/base/Document.cpp, line 7051
[task 2020-07-23T17:38:17.805Z] 17:38:17     INFO - GECKO(1616) | [Child 1619, Main Thread] WARNING: Wrong inner/outer window combination!: file /builds/worker/checkouts/gecko/dom/base/Document.cpp, line 7051
[task 2020-07-23T17:38:22.751Z] 17:38:22     INFO - GECKO(1616) | [Child 1619, MediaDecoderStateMachine #1] ###!!! ASSERTION: AudioStream position shouldn't go backward: 'pos >= mLastGoodPosition', file /builds/worker/checkouts/gecko/dom/media/mediasink/AudioSink.cpp, line 119
[task 2020-07-23T17:38:22.751Z] 17:38:22     INFO -  Initializing stack-fixing for the first stack frame, this may take a while...
[task 2020-07-23T17:38:39.797Z] 17:38:39     INFO - GECKO(1616) | #01: mozilla::AudioSinkWrapper::GetPosition(mozilla::TimeStamp*) const [dom/media/mediasink/AudioSinkWrapper.cpp:70]
[task 2020-07-23T17:38:39.797Z] 17:38:39     INFO - GECKO(1616) | #02: mozilla::AudioSinkWrapper::OnAudioEnded() [dom/media/mediasink/AudioSinkWrapper.cpp:208]
[task 2020-07-23T17:38:39.797Z] 17:38:39     INFO - GECKO(1616) | #03: mozilla::MozPromise<bool, nsresult, false>::ThenValue<mozilla::AudioSinkWrapper*, void (mozilla::AudioSinkWrapper::*)(), void (mozilla::AudioSinkWrapper::*)()>::DoResolveOrRejectInternal(mozilla::MozPromise<bool, nsresult, false>::ResolveOrRejectValue&) [xpcom/threads/MozPromise.h:651]
[task 2020-07-23T17:38:39.797Z] 17:38:39     INFO - GECKO(1616) | #04: mozilla::MozPromise<bool, nsresult, false>::ThenValueBase::ResolveOrRejectRunnable::Run() [xpcom/threads/MozPromise.h:411]
[task 2020-07-23T17:38:39.797Z] 17:38:39     INFO - GECKO(1616) | #05: mozilla::TaskQueue::Runner::Run() [xpcom/base/nsCOMPtr.h:410]
[task 2020-07-23T17:38:39.798Z] 17:38:39     INFO - GECKO(1616) | #06: nsThreadPool::Run() [xpcom/base/nsCOMPtr.h:410]
[task 2020-07-23T17:38:39.798Z] 17:38:39     INFO - GECKO(1616) | #07: nsThread::ProcessNextEvent(bool, bool*) [xpcom/threads/nsThread.cpp:1236]
[task 2020-07-23T17:38:39.798Z] 17:38:39     INFO - GECKO(1616) | #08: NS_ProcessNextEvent(nsIThread*, bool) [xpcom/threads/nsThreadUtils.cpp:513]
[task 2020-07-23T17:38:39.798Z] 17:38:39     INFO - GECKO(1616) | #09: mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate*) [ipc/glue/MessagePump.cpp:332]
[task 2020-07-23T17:38:39.798Z] 17:38:39     INFO - GECKO(1616) | #10: MessageLoop::Run() [ipc/chromium/src/base/message_loop.cc:310]
[task 2020-07-23T17:38:39.798Z] 17:38:39     INFO - GECKO(1616) | #11: nsThread::ThreadFunc(void*) [xpcom/threads/nsThread.cpp:449]
[task 2020-07-23T17:38:40.110Z] 17:38:40     INFO - GECKO(1616) | #12: _pt_root [nsprpub/pr/src/pthreads/ptthread.c:204]
[task 2020-07-23T17:38:40.110Z] 17:38:40     INFO -  fix-stacks error: failed to read breakpad symbols dir `/Users/cltbld/tasks/task_1595524086/build/symbols/libsystem_pthread.dylib` for `/usr/lib/system/libsystem_pthread.dylib`
[task 2020-07-23T17:38:40.110Z] 17:38:40     INFO -  fix-stacks note:  this is expected and harmless for system libraries on debug automation runs
[task 2020-07-23T17:38:40.111Z] 17:38:40     INFO - GECKO(1616) | #13: _pthread_body [/usr/lib/system/libsystem_pthread.dylib + 0x32eb]
[task 2020-07-23T17:38:40.111Z] 17:38:40     INFO - GECKO(1616) | #14: _pthread_start [/usr/lib/system/libsystem_pthread.dylib + 0x6249]
[task 2020-07-23T17:38:40.111Z] 17:38:40     INFO - GECKO(1616) | MEMORY STAT | vsize 7384MB | residentFast 139MB | heapAllocated 18MB
[task 2020-07-23T17:38:40.111Z] 17:38:40     INFO - TEST-OK | dom/media/mediasource/test/test_BufferingWait_mp4.html | took 5173ms
[task 2020-07-23T17:38:40.111Z] 17:38:40     INFO - TEST-UNEXPECTED-FAIL | dom/media/mediasource/test/test_BufferingWait_mp4.html | assertion count 1 is more than expected 0 assertions
[task 2020-07-23T17:38:40.111Z] 17:38:40     INFO - TEST-START | dom/media/mediasource/test/test_ChangeType.html

Comment 2

[Alexandru Michis [:malexandru]]

Fixed by the backout of Bug 1654699:
https://bugzilla.mozilla.org/show_bug.cgi?id=1654699#c3