1502623 - Intermittent GECKO(1767) | Assertion failure: !IsPending(), at /builds/worker/workspace/build/src/obj-firefox/dist/include/mozilla/MozPromise.h:1074

Status: RESOLVED INCOMPLETE

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

Description

[Treeherder Bug Filer]

Filed by: ncsoregi [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=208168542&repo=try

https://queue.taskcluster.net/v1/task/TbBDHqsGQHSlrFl5NgB04w/runs/0/artifacts/public/logs/live_backing.log

[task 2018-10-27T11:31:48.699Z] 11:31:48     INFO - GECKO(1767) | [Child 1879, MediaPDecoder #3] WARNING: No previous granule position to use for Opus end trimming.: file /builds/worker/workspace/build/src/dom/media/ogg/OggCodecState.cpp, line 1232
[task 2018-10-27T11:31:48.838Z] 11:31:48     INFO - GECKO(1767) | [Child 1879, MediaPlayback #1] WARNING: Decoder=7fceebbcb800 state=SEEKING Audio not synced after seek, maybe a poorly muxed file?: file /builds/worker/workspace/build/src/dom/media/MediaDecoderStateMachine.cpp, line 1213
[task 2018-10-27T11:31:53.250Z] 11:31:53     INFO - GECKO(1767) | Assertion failure: !IsPending(), at /builds/worker/workspace/build/src/obj-firefox/dist/include/mozilla/MozPromise.h:1074
[task 2018-10-27T11:33:23.206Z] 11:33:23     INFO - GECKO(1767) | #01: mozilla::MozPromise<mozilla::media::TimeUnit, mozilla::SeekRejectValue, true>::Private::~Private() [memory/mozalloc/mozalloc.h:163]
[task 2018-10-27T11:33:23.207Z] 11:33:23     INFO - 
[task 2018-10-27T11:33:23.208Z] 11:33:23     INFO - GECKO(1767) | #02: mozilla::MozPromiseRefcountable::Release() [xpcom/threads/MozPromise.h:146]
[task 2018-10-27T11:33:23.209Z] 11:33:23     INFO - 
[task 2018-10-27T11:33:23.211Z] 11:33:23     INFO - GECKO(1767) | #03: <name omitted> [memory/mozalloc/mozalloc.h:163]
[task 2018-10-27T11:33:23.212Z] 11:33:23     INFO - 
[task 2018-10-27T11:33:23.214Z] 11:33:23     INFO - GECKO(1767) | #04: mozilla::Runnable::Release() [xpcom/threads/nsThreadUtils.cpp:47]
[task 2018-10-27T11:33:23.215Z] 11:33:23     INFO - 
[task 2018-10-27T11:33:23.217Z] 11:33:23     INFO - GECKO(1767) | #05: nsTArray_Impl<nsCOMPtr<nsIRunnable>, nsTArrayInfallibleAllocator>::ClearAndRetainStorage() [xpcom/ds/nsTArray.h:2349]
[task 2018-10-27T11:33:23.219Z] 11:33:23     INFO - 
[task 2018-10-27T11:33:23.221Z] 11:33:23     INFO - GECKO(1767) | #06: nsTArray_Impl<nsCOMPtr<nsIRunnable>, nsTArrayInfallibleAllocator>::~nsTArray_Impl() [xpcom/ds/nsTArray.h:940]
[task 2018-10-27T11:33:23.222Z] 11:33:23     INFO - 
[task 2018-10-27T11:33:23.224Z] 11:33:23     INFO - GECKO(1767) | #07: mozilla::AutoTaskDispatcher::PerThreadTaskGroup::~PerThreadTaskGroup() [xpcom/threads/TaskDispatcher.h:183]
[task 2018-10-27T11:33:23.226Z] 11:33:23     INFO - 
[task 2018-10-27T11:33:23.228Z] 11:33:23     INFO - GECKO(1767) | #08: mozilla::UniquePtr<mozilla::AutoTaskDispatcher::PerThreadTaskGroup, mozilla::DefaultDelete<mozilla::AutoTaskDispatcher::PerThreadTaskGroup> >::reset(mozilla::AutoTaskDispatcher::PerThreadTaskGroup*) [memory/mozalloc/mozalloc.h:163]
[task 2018-10-27T11:33:23.229Z] 11:33:23     INFO - 
[task 2018-10-27T11:33:23.231Z] 11:33:23     INFO - GECKO(1767) | #09: mozilla::AutoTaskDispatcher::TaskGroupRunnable::~TaskGroupRunnable() [memory/mozalloc/mozalloc.h:163]
[task 2018-10-27T11:33:23.233Z] 11:33:23     INFO - 
[task 2018-10-27T11:33:23.235Z] 11:33:23     INFO - GECKO(1767) | #10: mozilla::Runnable::Release() [xpcom/threads/nsThreadUtils.cpp:47]
[task 2018-10-27T11:33:23.236Z] 11:33:23     INFO - 
[task 2018-10-27T11:33:23.238Z] 11:33:23     INFO - GECKO(1767) | #11: mozilla::TaskQueue::Dispatch(already_AddRefed<nsIRunnable>, mozilla::AbstractThread::DispatchReason) [xpcom/threads/TaskQueue.h:81]
[task 2018-10-27T11:33:23.240Z] 11:33:23     INFO - 
[task 2018-10-27T11:33:23.241Z] 11:33:23     INFO - GECKO(1767) | #12: mozilla::AutoTaskDispatcher::DispatchTaskGroup(mozilla::UniquePtr<mozilla::AutoTaskDispatcher::PerThreadTaskGroup, mozilla::DefaultDelete<mozilla::AutoTaskDispatcher::PerThreadTaskGroup> >) [xpcom/threads/TaskDispatcher.h:265]
[task 2018-10-27T11:33:23.242Z] 11:33:23     INFO - 
[task 2018-10-27T11:33:23.243Z] 11:33:23     INFO - GECKO(1767) | #13: mozilla::AutoTaskDispatcher::~AutoTaskDispatcher() [mfbt/UniquePtr.h:340]
[task 2018-10-27T11:33:23.245Z] 11:33:23     INFO - 
[task 2018-10-27T11:33:23.246Z] 11:33:23     INFO - GECKO(1767) | #14: mozilla::TaskQueue::Runner::Run() [mfbt/RefPtr.h:69]
[task 2018-10-27T11:33:23.248Z] 11:33:23     INFO - 
[task 2018-10-27T11:33:23.249Z] 11:33:23     INFO - GECKO(1767) | #15: nsThreadPool::Run() [xpcom/threads/nsThreadPool.cpp:244]
[task 2018-10-27T11:33:23.251Z] 11:33:23     INFO - 
[task 2018-10-27T11:33:23.253Z] 11:33:23     INFO - GECKO(1767) | #16: non-virtual thunk to nsThreadPool::Run() [xpcom/threads/nsThreadPool.cpp:0]
[task 2018-10-27T11:33:23.254Z] 11:33:23     INFO - 
[task 2018-10-27T11:33:23.256Z] 11:33:23     INFO - GECKO(1767) | #17: nsThread::ProcessNextEvent(bool, bool*) [xpcom/threads/nsThread.cpp:1232]
[task 2018-10-27T11:33:23.258Z] 11:33:23     INFO - 
[task 2018-10-27T11:33:23.259Z] 11:33:23     INFO - GECKO(1767) | #18: NS_ProcessNextEvent(nsIThread*, bool) [xpcom/threads/nsThreadUtils.cpp:530]
[task 2018-10-27T11:33:23.261Z] 11:33:23     INFO - 
[task 2018-10-27T11:33:23.263Z] 11:33:23     INFO - GECKO(1767) | #19: mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate*) [ipc/glue/MessagePump.cpp:335]
[task 2018-10-27T11:33:23.264Z] 11:33:23     INFO - 
[task 2018-10-27T11:33:23.266Z] 11:33:23     INFO - GECKO(1767) | #20: MessageLoop::Run() [ipc/chromium/src/base/message_loop.cc:598]
[task 2018-10-27T11:33:23.268Z] 11:33:23     INFO - 
[task 2018-10-27T11:33:23.270Z] 11:33:23     INFO - GECKO(1767) | #21: nsThread::ThreadFunc(void*) [xpcom/threads/nsThread.cpp:507]
[task 2018-10-27T11:33:23.271Z] 11:33:23     INFO - 
[task 2018-10-27T11:33:23.618Z] 11:33:23     INFO - GECKO(1767) | #22: _pt_root [nsprpub/pr/src/pthreads/ptthread.c:204]
[task 2018-10-27T11:33:23.620Z] 11:33:23     INFO - 
[task 2018-10-27T11:33:23.621Z] 11:33:23     INFO - GECKO(1767) | #23: libpthread.so.0 + 0x76ba
[task 2018-10-27T11:33:23.621Z] 11:33:23     INFO - 
[task 2018-10-27T11:33:23.622Z] 11:33:23     INFO - GECKO(1767) | #24: libc.so.6 + 0x10741d
[task 2018-10-27T11:33:23.623Z] 11:33:23     INFO - 
[task 2018-10-27T11:33:23.623Z] 11:33:23     INFO - GECKO(1767) | #25: ??? (???:???)
[task 2018-10-27T11:33:23.625Z] 11:33:23     INFO - GECKO(1767) | ###!!! [Parent][MessageChannel] Error: (msgtype=0x190084,name=PBrowser::Msg_Destroy) Channel error: cannot send/recv
[task 2018-10-27T11:33:23.626Z] 11:33:23     INFO - GECKO(1767) | ++DOCSHELL 0x7f7cfdba8800 == 7 [pid = 1767] [id = {e1c0c6ca-2414-4d09-b41d-e84c7f6ce66e}]

Comment 1

[Intermittent Failures Robot]

1 failures in 2584 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:
* try: 1

Platform breakdown:
* linux64-qr: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1502623&startday=2018-10-22&endday=2018-10-28&tree=all

Comment 2

[Intermittent Failures Robot]

1 failures in 2978 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:
* autoland: 1

Platform breakdown:
* linux64-qr: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1502623&startday=2018-10-29&endday=2018-11-04&tree=all

Comment 3

[Firefox Bug Husbandry Bot]

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup

Comment 4

[Intermittent Failures Robot]

1 failures in 2383 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 1

Platform breakdown:

• linux64-qr: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1502623&startday=2019-01-21&endday=2019-01-27&tree=all

Comment 5

[Cristian Brindusan [:cbrindusan]]

New occurrence:
https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=279905007&repo=autoland&lineNumber=7235

Comment 6

[Cosmin Sabou [:CosminS]]

These latest failures here are a regression from Bug 1522830 and it causes crashes on windows debug reftests [@ mozilla::MozPromise<mozilla::Maybe<mozilla::UntrustedModulesProcessor::ModulesMapResultWithLoads>,nsresult,1>::~MozPromise()]
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?startday=2019-12-01&endday=2019-12-08&tree=trunk&bug=1502623

Failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=280118165&repo=mozilla-central&lineNumber=20669

It has quite a high occurrence rate: https://treeherder.mozilla.org/#/jobs?repo=mozilla-central&group_state=expanded&resultStatus=pending%2Crunning%2Csuccess%2Ctestfailed%2Cbusted%2Cexception&searchStr=Windows%2C10%2Cx64%2CCCov%2Cdebug%2CReftests%2Ctest-windows10-64-ccov%2Fdebug-reftest-e10s&fromchange=0d24f14c08476bc68595f38ad28ac1f34085d862&selectedJob=280118165

[task 2019-12-07T12:09:50.954Z] 12:09:50 INFO - Assertion failure: !IsPending(), at z:/build/build/src/obj-firefox/dist/include\mozilla/MozPromise.h:1021
[task 2019-12-07T12:09:51.101Z] 12:09:51 INFO - ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2019-12-07T12:10:39.320Z] 12:10:39 INFO - #01: mozilla::MozPromiseRefcountable::Release() [xpcom/threads/MozPromise.h:145]
[task 2019-12-07T12:10:39.320Z] 12:10:39 INFO -
[task 2019-12-07T12:10:39.320Z] 12:10:39 INFO - #02: mozilla::UntrustedModulesProcessor::ProcessModuleLoadQueueChildProcess(mozilla::UntrustedModulesProcessor::Priority) [toolkit/xre/UntrustedModulesProcessor.cpp:788]
[task 2019-12-07T12:10:39.320Z] 12:10:39 INFO -
[task 2019-12-07T12:10:39.321Z] 12:10:39 INFO - #03: mozilla::UntrustedModulesProcessor::BackgroundProcessModuleLoadQueueChildProcess() [toolkit/xre/UntrustedModulesProcessor.cpp:502]
[task 2019-12-07T12:10:39.321Z] 12:10:39 INFO -
[task 2019-12-07T12:10:39.321Z] 12:10:39 INFO - #04: mozilla::UntrustedModulesProcessor::ProcessModuleLoadQueue() [toolkit/xre/UntrustedModulesProcessor.cpp:549]
[task 2019-12-07T12:10:39.321Z] 12:10:39 INFO -
[task 2019-12-07T12:10:39.322Z] 12:10:39 INFO - #05: mozilla::UntrustedModulesProcessor::BackgroundProcessModuleLoadQueue() [toolkit/xre/UntrustedModulesProcessor.cpp:451]
[task 2019-12-07T12:10:39.322Z] 12:10:39 INFO -
[task 2019-12-07T12:10:39.322Z] 12:10:39 INFO - #06: nsresult mozilla::detail::RunnableMethodImpl<mozilla::UntrustedModulesProcessor ,void (mozilla::UntrustedModulesProcessor::)(),1,mozilla::RunnableKind::Standard>::Run() [xpcom/threads/nsThreadUtils.h:1176]
[task 2019-12-07T12:10:39.322Z] 12:10:39 INFO -
[task 2019-12-07T12:10:39.323Z] 12:10:39 INFO - #07: nsThread::ProcessNextEvent(bool,bool *) [xpcom/threads/nsThread.cpp:1250]
[task 2019-12-07T12:10:39.323Z] 12:10:39 INFO -
[task 2019-12-07T12:10:39.323Z] 12:10:39 INFO - #08: NS_ProcessNextEvent(nsIThread *,bool) [xpcom/threads/nsThreadUtils.cpp:486]
[task 2019-12-07T12:10:39.323Z] 12:10:39 INFO -
[task 2019-12-07T12:10:39.324Z] 12:10:39 INFO - #09: mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate *) [ipc/glue/MessagePump.cpp:332]
[task 2019-12-07T12:10:39.324Z] 12:10:39 INFO -
[task 2019-12-07T12:10:39.324Z] 12:10:39 INFO - #10: MessageLoop::RunInternal() [ipc/chromium/src/base/message_loop.cc:315]
[task 2019-12-07T12:10:39.324Z] 12:10:39 INFO -
[task 2019-12-07T12:10:39.324Z] 12:10:39 INFO - #11: MessageLoop::RunHandler() [ipc/chromium/src/base/message_loop.cc:309]
[task 2019-12-07T12:10:39.324Z] 12:10:39 INFO -
[task 2019-12-07T12:10:39.325Z] 12:10:39 INFO - #12: MessageLoop::Run() [ipc/chromium/src/base/message_loop.cc:291]
[task 2019-12-07T12:10:39.325Z] 12:10:39 INFO -
[task 2019-12-07T12:10:39.325Z] 12:10:39 INFO - #13: nsThread::ThreadFunc(void *) [xpcom/threads/nsThread.cpp:460]
[task 2019-12-07T12:10:39.325Z] 12:10:39 INFO -
[task 2019-12-07T12:10:43.307Z] 12:10:43 INFO - #14: PR_NativeRunThread [nsprpub/pr/src/threads/combined/pruthr.c:408]
[task 2019-12-07T12:10:43.307Z] 12:10:43 INFO -
[task 2019-12-07T12:10:43.307Z] 12:10:43 INFO - #15: static unsigned int pr_root(void *) [nsprpub/pr/src/md/windows/w95thred.c:140]
[task 2019-12-07T12:10:43.307Z] 12:10:43 INFO -
[task 2019-12-07T12:10:43.308Z] 12:10:43 INFO - #16: ucrtbase.dll + 0x1c4be
[task 2019-12-07T12:10:43.308Z] 12:10:43 INFO -
[task 2019-12-07T12:10:43.308Z] 12:10:43 INFO - #17: KERNEL32.DLL + 0x13034
[task 2019-12-07T12:10:43.308Z] 12:10:43 INFO -
[task 2019-12-07T12:10:43.451Z] 12:10:43 INFO - #18: static void patched_BaseThreadInitThunk(int, void *, void *) [mozglue/dllservices/WindowsDllBlocklist.cpp:583]
[task 2019-12-07T12:10:43.451Z] 12:10:43 INFO -
[task 2019-12-07T12:10:43.452Z] 12:10:43 INFO - #19: ntdll.dll + 0x71461
[task 2019-12-07T12:10:43.452Z] 12:10:43 INFO -
[task 2019-12-07T12:10:43.453Z] 12:10:43 INFO - [Child 8216, Main Thread] WARNING: '!mIOThread', file z:/build/build/src/xpcom/io/nsSegmentedBuffer.cpp, line 165
[task 2019-12-07T12:10:43.454Z] 12:10:43 INFO - [Child 8216, Main Thread] WARNING: '!mIOThread', file z:/build/build/src/xpcom/io/nsSegmentedBuffer.cpp, line 165
[task 2019-12-07T12:10:43.454Z] 12:10:43 INFO - [Child 8216, Main Thread] WARNING: '!mIOThread', file z:/build/build/src/xpcom/io/nsSegmentedBuffer.cpp, line 165
[task 2019-12-07T12:10:43.455Z] 12:10:43 INFO - [Child 8216, Main Thread] WARNING: '!mIOThread', file z:/build/build/src/xpcom/io/nsSegmentedBuffer.cpp, line 165
[task 2019-12-07T12:10:43.456Z] 12:10:43 INFO - [Child 8216, Main Thread] WARNING: '!mIOThread', file z:/build/build/src/xpcom/io/nsSegmentedBuffer.cpp, line 165
[task 2019-12-07T12:10:43.456Z] 12:10:43 INFO - [Child 8216, Main Thread] WARNING: '!mIOThread', file z:/build/build/src/xpcom/io/nsSegmentedBuffer.cpp, line 165
[task 2019-12-07T12:10:43.457Z] 12:10:43 INFO - nsStringStats
[task 2019-12-07T12:10:43.458Z] 12:10:43 INFO - => mAllocCount: 9189
[task 2019-12-07T12:10:43.458Z] 12:10:43 INFO - => mReallocCount: 0
[task 2019-12-07T12:10:43.459Z] 12:10:43 INFO - => mFreeCount: 9189
[task 2019-12-07T12:10:43.460Z] 12:10:43 INFO - => mShareCount: 8861
[task 2019-12-07T12:10:43.460Z] 12:10:43 INFO - => mAdoptCount: 533
[task 2019-12-07T12:10:43.461Z] 12:10:43 INFO - => mAdoptFreeCount: 539
[task 2019-12-07T12:10:43.462Z] 12:10:43 INFO - => Process ID: 8216, Thread ID: 1100
[task 2019-12-07T12:10:43.462Z] 12:10:43 INFO - [Child 432, Main Thread] WARNING: NS_ENSURE_TRUE(mPresShell) failed: file z:/build/build/src/layout/base/nsPresContext.cpp, line 847
[task 2019-12-07T12:10:43.463Z] 12:10:43 INFO - [Child 432, Main Thread] WARNING: '!aWin', file z:/build/build/src/dom/base/Document.cpp, line 1378
[task 2019-12-07T12:10:43.463Z] 12:10:43 INFO - [Child 432, Main Thread] WARNING: '!aWin', file z:/build/build/src/dom/base/Document.cpp, line 1378
[task 2019-12-07T12:10:43.465Z] 12:10:43 INFO - REFTEST INFO | drawWindow flags = DRAWWINDOW_DRAW_CARET | DRAWWINDOW_DRAW_VIEW | DRAWWINDOW_USE_WIDGET_LAYERS; window size = 816,1039; test browser size = 800,1000
[task 2019-12-07T12:10:43.466Z] 12:10:43 INFO - REFTEST TEST-UNEXPECTED-FAIL | file:///Z:/task_1575715529/build/tests/reftest/tests/layout/reftests/svg/as-image/zoom/img-zoomIn-1.html == file:///Z:/task_1575715529/build/tests/reftest/tests/layout/reftests/svg/as-image/zoom/squaredCircle-150x150-ref.html | crash-check | This test left crash dumps behind, but we weren't expecting it to!

Aaron, could you please take a look over this?

Comment 7

[(No longer employed by Mozilla) Aaron Klotz]

This should be filed as a different bug. Filed bug 1602279.

Comment 8

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 3
• mozilla-central: 13

Platform breakdown:

• windows10-64-qr: 4
• windows10-64-ccov: 12

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1502623&startday=2019-12-02&endday=2019-12-08&tree=all