Assertion failure: timeout->mFiringIndex > mLastFiringIndex, at zdom/base/TimeoutManager.cpp:938

REOPENED
Assigned to

Status

()

defect
P2
normal
REOPENED
3 months ago
10 days ago

People

(Reporter: bc, Assigned: jesup)

Tracking

(Blocks 1 bug, {assertion, leave-open})

Trunk
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(firefox-esr60 unaffected, firefox65 unaffected, firefox66 fix-optional, firefox67 fix-optional, firefox68 fix-optional)

Details

Attachments

(1 attachment)

Reporter

Description

3 months ago
  1. private url.

Assertion failure: timeout->mFiringIndex > mLastFiringIndex, at z:/build/build/src/dom/base/TimeoutManager.cpp:938
#01: mozilla::dom::TimeoutExecutor::Run() [dom/base/TimeoutExecutor.cpp:233]
#02: IdleRunnableWrapper::Run() [xpcom/threads/nsThreadUtils.cpp:319]
#03: nsThread::ProcessNextEvent(bool,bool *) [xpcom/threads/nsThread.cpp:1149]
#04: NS_ProcessNextEvent(nsIThread *,bool) [xpcom/threads/nsThreadUtils.cpp:474]
#05: mozilla::ipc::MessagePump::Run(base::MessagePump::Delegate *) [ipc/glue/MessagePump.cpp:88]
#06: MessageLoop::RunHandler() [ipc/chromium/src/base/message_loop.cc:309]
#07: MessageLoop::Run() [ipc/chromium/src/base/message_loop.cc:291]
#08: nsBaseAppShell::Run() [widget/nsBaseAppShell.cpp:139]
#09: nsAppShell::Run() [widget/windows/nsAppShell.cpp:411]
#10: XRE_RunAppShell() [toolkit/xre/nsEmbedFunctions.cpp:908]
#11: mozilla::ipc::MessagePumpForChildProcess::Run(base::MessagePump::Delegate *) [ipc/glue/MessagePump.cpp:238]
#12: MessageLoop::RunHandler() [ipc/chromium/src/base/message_loop.cc:309]
#13: MessageLoop::Run() [ipc/chromium/src/base/message_loop.cc:291]
#14: XRE_InitChildProcess(int,char * * const,XREChildData const *) [toolkit/xre/nsEmbedFunctions.cpp:750]
#15: NS_internal_main(int,char * *,char * *) [browser/app/nsBrowserApp.cpp:265]
#16: wmain [toolkit/xre/nsWindowsWMain.cpp:129]
#17: static int __scrt_common_main_seh() [f:/dd/vctools/crt/vcstartup/src/startup/exe_common.inl:288]
#18: KERNEL32.DLL + 0x13dc4
#19: ntdll.dll + 0x73691

Windows and Linux Nightly 67 at least.

Bughunter has seen this on two urls on a video sharing site. One was NSFW and the other was a copyrighted movie so I won't share them here. I'll keep an eye out for better urls but hopefully you can figure it out without them.

Is this a regression? Bug 1270059 changed this code quite a bit.

Flags: needinfo?(bob)
Reporter

Comment 2

3 months ago

Not sure. I wasn't able to reproduce this time on Fedora, Ubuntu or Windows 10. I'll try again later.

Reporter

Comment 3

3 months ago

After reproducing a couple of times on Ubuntu, I am once again unable to reproduce. The movie url has been taken down. I've set up a reload loop using Nightly to see if it will eventually assert. If I can do that, I'll try with Beta. I've also loaded 204 other mp4 urls from this site that Bughunter has tested in the past to see if this is reproducible elsewhere.

Reporter

Comment 4

3 months ago

Another stack with this assertion:

Assertion failure: timeout->mFiringIndex > mLastFiringIndex, at z:/build/build/src/dom/base/TimeoutManager.cpp:938
#01: mozilla::dom::TimeoutExecutor::Notify(nsITimer *) [dom/base/TimeoutExecutor.cpp:243]
#02: nsTimerImpl::Fire(int) [xpcom/threads/nsTimerImpl.cpp:571]
#03: nsTimerEvent::Run() [xpcom/threads/TimerThread.cpp:260]
#04: mozilla::ThrottledEventQueue::Inner::ExecuteRunnable() [xpcom/threads/ThrottledEventQueue.cpp:231]
#05: mozilla::ThrottledEventQueue::Inner::Executor::Run() [xpcom/threads/ThrottledEventQueue.cpp:77]
#06: mozilla::SchedulerGroup::Runnable::Run() [xpcom/threads/SchedulerGroup.cpp:292]
#07: nsThread::ProcessNextEvent(bool,bool *) [xpcom/threads/nsThread.cpp:1149]
#08: NS_ProcessNextEvent(nsIThread *,bool) [xpcom/threads/nsThreadUtils.cpp:474]
#09: mozilla::ipc::MessagePump::Run(base::MessagePump::Delegate *) [ipc/glue/MessagePump.cpp:88]
#10: MessageLoop::RunHandler() [ipc/chromium/src/base/message_loop.cc:309]

Reporter

Comment 5

3 months ago

While the re-test found many examples of the assertion, attempting to reliably reproduce them manually was not possible. Ping me on irc @ bc if you need more information.

Flags: needinfo?(bob)

Hi Randell, since you added the assertion there, I'm thinking you may like to take a look.

Flags: needinfo?(rjesup)
Assignee: nobody → rjesup
Flags: needinfo?(rjesup)

I can finally (2700 runs this last time) repro. Seems to only happen on a multiple of 1 hour since content process startup.... it may just be a bug in the firing order assertion.

we could drop the LOG when we're going to assert anyways in the case of incorrect ordering, but it may make things easier to debug, and the code won't even be compiled in after Nightly. This restores it to DIAGNOSTIC_ASSERT as well as fixing the assertion.  We should uplift to Beta since right now DEBUG builds might incorrectly assert.
Attachment #9045422 - Flags: review?(ehsan)
Priority: -- → P2

Comment 9

3 months ago
Comment on attachment 9045422 [details] [diff] [review]
fix firing order assertions in nested event loops in RunTimeout

Review of attachment 9045422 [details] [diff] [review]:
-----------------------------------------------------------------

Makes sense, thanks!

::: dom/base/TimeoutManager.cpp
@@ +962,5 @@
> +                   timeout->mIsInterval ? "Interval" : "Timeout", this,
> +                   timeout.get(), timeout->mFiringId,
> +                   timeout->mFiringIndex, mFiringIndex));
> +        }
> +        MOZ_DIAGNOSTIC_ASSERT(timeout->mFiringIndex > mLastFiringIndex);

Turning this into a diagnostic assert is a good idea, and I applaud your audacity.  Hopefully this won't cause an endless stream of crashes on Nightly.  :-)  Please keep an eye out for regressions...
Attachment #9045422 - Flags: review?(ehsan) → review+

Comment 10

3 months ago
Pushed by rjesup@wgate.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/93b9c2a8212b
fix firing order assertions in nested event loops in RunTimeout r=ehsan

Comment 12

3 months ago
Pushed by rjesup@wgate.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/01175f1ce46d
fix firing order assertions in nested event loops in RunTimeout r=ehsan

Comment 13

3 months ago
bugherder
Status: NEW → RESOLVED
Last Resolved: 3 months ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla67
Reporter

Comment 15

3 months ago

Bughunter has hit this on Windows and Linux on a url to a copyrighted movie on the original site where we first reproduced. So far just one url has reproduced. I haven't reproduced yet locally.

mozversion INFO | application_buildid: 20190223041557
mozversion INFO | application_changeset: 6924dd16f7b1e2e6ce71a8eb4cbe330d3e4745dc

Assertion failure: timeout->mFiringIndex > mLastFiringIndex, at z:/build/build/src/dom/base/TimeoutManager.cpp:976
#01: mozilla::dom::TimeoutExecutor::Run() [dom/base/TimeoutExecutor.cpp:233]
#02: IdleRunnableWrapper::Run() [xpcom/threads/nsThreadUtils.cpp:319]

jesup: ping me?

Flags: needinfo?(rjesup)
Blocks: 1270059
Target Milestone: mozilla67 → ---

I've caught it in a local test again (after 1600 runs); it appears to be another case where nested event loops mess up the assertion code, but it does not look like a violation of spec.

Backing out the DIAGNOSTIC back down to DEBUG with r=smaug (and may well just disable entirely after more analysis).

Keywords: leave-open

Comment 19

3 months ago
Pushed by rjesup@wgate.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/3098f2ba2d33
move DIAGNOSTIC_ASSERT back down to DEBUG-only ASSERT r=smaug
Component: DOM → DOM: Core & HTML
Product: Core → Core

Comment 21

10 days ago

hi jesup, any update on this one? (tracking for 68)

Flags: needinfo?(rjesup)

This is DEBUG-only, and it almost certainly a bug in the assertion, not in the functionality.

Flags: needinfo?(rjesup)
Keywords: regression
You need to log in before you can comment on or make changes to this bug.