Closed Bug 1052147 Opened 8 years ago Closed 8 years ago

Assertion failure: !aOther.IsNull() in mozilla::dom::AnimationPlayer::SetSource

Categories

(Core :: DOM: Core & HTML, defect)

x86
macOS
defect
Not set
normal

Tracking

()

RESOLVED FIXED
mozilla34

People

(Reporter: martijn.martijn, Assigned: birtles)

References

Details

(Keywords: assertion, crash)

Attachments

(1 file, 1 obsolete file)

Currently, after updating my tree, I now get this randomly with --run-until-failure:
TEST-INFO | Main app process: killed by SIGHUP
 0:13.15 TEST-UNEXPECTED-FAIL | /tests/testing/mochitest/tests/Harness_sanity/test_sanity.html | application terminated with exit code 1
 0:13.15 runtests.py | Application ran for: 0:00:07.987645

This is with:
./mach mochitest-plain --run-until-failure testing/mochitest/tests/Harness_sanity/test_sanity.html
Ok, this is a crash, the stack shows just above that SIGHUP message.
Brian, could this be fallout from bug 1040543?

246 INFO Assertion failure: !aOther.IsNull() (Cannot compute with aOther null value), at ../../dist/include/mozilla/TimeStamp.h:359
247 INFO mozilla::dom::AnimationPlayer::SetSource(mozilla::dom::Animation*)+0x00000068 [/Users/mwargers/mozilla-central/obj-x86_64-apple-darwin13.3.0/dist/NightlyDebug.app/Contents/MacOS/XUL +0x00C8DBD8]
248 INFO nsAnimationManager::BuildAnimations(nsStyleContext*, mozilla::dom::AnimationTimeline*, nsTArray<nsRefPtr<mozilla::dom::AnimationPlayer> >&)+0x000003BE [/Users/mwargers/mozilla-central/obj-x86_64-apple-darwin13.3.0/dist/NightlyDebug.app/Contents/MacOS/XUL +0x01F9623E]
249 INFO nsAnimationManager::CheckAnimationRule(nsStyleContext*, mozilla::dom::Element*)+0x000001BB [/Users/mwargers/mozilla-central/obj-x86_64-apple-darwin13.3.0/dist/NightlyDebug.app/Contents/MacOS/XUL +0x01F9598B]
250 INFO nsStyleSet::GetContext(nsStyleContext*, nsRuleNode*, nsRuleNode*, nsIAtom*, nsCSSPseudoElements::Type, mozilla::dom::Element*, unsigned int)+0x00000486 [/Users/mwargers/mozilla-central/obj-x86_64-apple-darwin13.3.0/dist/NightlyDebug.app/Contents/MacOS/XUL +0x02059516]
251 INFO nsStyleSet::ResolveStyleFor(mozilla::dom::Element*, nsStyleContext*, TreeMatchContext&)+0x00000298 [/Users/mwargers/mozilla-central/obj-x86_64-apple-darwin13.3.0/dist/NightlyDebug.app/Contents/MacOS/XUL +0x0205AE38]
252 INFO nsStyleSet::ResolveStyleFor(mozilla::dom::Element*, nsStyleContext*)+0x000000B5 [/Users/mwargers/mozilla-central/obj-x86_64-apple-darwin13.3.0/dist/NightlyDebug.app/Contents/MacOS/XUL +0x0205AB65]
253 INFO nsCSSFrameConstructor::MaybeRecreateFramesForElement(mozilla::dom::Element*)+0x00000089 [/Users/mwargers/mozilla-central/obj-x86_64-apple-darwin13.3.0/dist/NightlyDebug.app/Contents/MacOS/XUL +0x02103F49]
254 INFO mozilla::RestyleManager::RestyleElement(mozilla::dom::Element*, nsIFrame*, nsChangeHint, mozilla::RestyleTracker&, nsRestyleHint)+0x0000030C [/Users/mwargers/mozilla-central/obj-x86_64-apple-darwin13.3.0/dist/NightlyDebug.app/Contents/MacOS/XUL +0x020CE3EC]
255 INFO mozilla::RestyleTracker::ProcessOneRestyle(mozilla::dom::Element*, nsRestyleHint, nsChangeHint)+0x000001D4 [/Users/mwargers/mozilla-central/obj-x86_64-apple-darwin13.3.0/dist/NightlyDebug.app/Contents/MacOS/XUL +0x020E02C4]
256 INFO mozilla::RestyleTracker::DoProcessRestyles()+0x0000054A [/Users/mwargers/mozilla-central/obj-x86_64-apple-darwin13.3.0/dist/NightlyDebug.app/Contents/MacOS/XUL +0x020D46EA]
257 INFO mozilla::RestyleManager::ProcessPendingRestyles()+0x000001D3 [/Users/mwargers/mozilla-central/obj-x86_64-apple-darwin13.3.0/dist/NightlyDebug.app/Contents/MacOS/XUL +0x020D03E3]
258 INFO PresShell::FlushPendingNotifications(mozilla::ChangesToFlush)+0x00000308 [/Users/mwargers/mozilla-central/obj-x86_64-apple-darwin13.3.0/dist/NightlyDebug.app/Contents/MacOS/XUL +0x02095E48]
259 INFO nsRefreshDriver::Tick(long long, mozilla::TimeStamp)+0x00000DFB [/Users/mwargers/mozilla-central/obj-x86_64-apple-darwin13.3.0/dist/NightlyDebug.app/Contents/MacOS/XUL +0x020B011B]
260 INFO mozilla::RefreshDriverTimer::Tick()+0x00000168 [/Users/mwargers/mozilla-central/obj-x86_64-apple-darwin13.3.0/dist/NightlyDebug.app/Contents/MacOS/XUL +0x020B2878]
261 INFO nsTimerImpl::Fire()+0x000003AE [/Users/mwargers/mozilla-central/obj-x86_64-apple-darwin13.3.0/dist/NightlyDebug.app/Contents/MacOS/XUL +0x000BE30E]
262 INFO nsTimerEvent::Run()+0x0000010F [/Users/mwargers/mozilla-central/obj-x86_64-apple-darwin13.3.0/dist/NightlyDebug.app/Contents/MacOS/XUL +0x000BE60F]
263 INFO nsThread::ProcessNextEvent(bool, bool*)+0x000004F7 [/Users/mwargers/mozilla-central/obj-x86_64-apple-darwin13.3.0/dist/NightlyDebug.app/Contents/MacOS/XUL +0x000B9977]
264 INFO NS_ProcessPendingEvents(nsIThread*, unsigned int)+0x0000004D [/Users/mwargers/mozilla-central/obj-x86_64-apple-darwin13.3.0/dist/NightlyDebug.app/Contents/MacOS/XUL +0x000E53CD]
265 INFO nsBaseAppShell::NativeEventCallback()+0x00000077 [/Users/mwargers/mozilla-central/obj-x86_64-apple-darwin13.3.0/dist/NightlyDebug.app/Contents/MacOS/XUL +0x018CA767]
266 INFO nsAppShell::ProcessGeckoEvents(void*)+0x000000BE [/Users/mwargers/mozilla-central/obj-x86_64-apple-darwin13.3.0/dist/NightlyDebug.app/Contents/MacOS/XUL +0x019201CE]
267 INFO __CFRUNLOOP_IS_CALLING_OUT_TO_A_SOURCE0_PERFORM_FUNCTION__+0x00000011 [/System/Library/Frameworks/CoreFoundation.framework/Versions/A/CoreFoundation +0x0007F5B1]
268 INFO __CFRunLoopDoSources0+0x000000F2 [/System/Library/Frameworks/CoreFoundation.framework/Versions/A/CoreFoundation +0x00070C62]
269 INFO __CFRunLoopRun+0x0000033F [/System/Library/Frameworks/CoreFoundation.framework/Versions/A/CoreFoundation +0x000703EF]
270 INFO CFRunLoopRunSpecific+0x00000135 [/System/Library/Frameworks/CoreFoundation.framework/Versions/A/CoreFoundation +0x0006FE75]
271 INFO RunCurrentEventLoopInMode+0x000000E2 [/System/Library/Frameworks/Carbon.framework/Versions/A/Frameworks/HIToolbox.framework/Versions/A/HIToolbox +0x0002EA0D]
272 INFO ReceiveNextEventCommon+0x000001DF [/System/Library/Frameworks/Carbon.framework/Versions/A/Frameworks/HIToolbox.framework/Versions/A/HIToolbox +0x0002E7B7]
273 INFO _BlockUntilNextEventMatchingListInModeWithFilter+0x00000041 [/System/Library/Frameworks/Carbon.framework/Versions/A/Frameworks/HIToolbox.framework/Versions/A/HIToolbox +0x0002E5BC]
274 INFO _DPSNextEvent+0x0000059A [/System/Library/Frameworks/AppKit.framework/Versions/C/AppKit +0x0002424E]
275 INFO -[NSApplication nextEventMatchingMask:untilDate:inMode:dequeue:]+0x0000007A [/System/Library/Frameworks/AppKit.framework/Versions/C/AppKit +0x0002389B]
276 INFO -[GeckoNSApplication nextEventMatchingMask:untilDate:inMode:dequeue:]+0x00000056 [/Users/mwargers/mozilla-central/obj-x86_64-apple-darwin13.3.0/dist/NightlyDebug.app/Contents/MacOS/XUL +0x0191F686]
277 INFO -[NSApplication run]+0x00000229 [/System/Library/Frameworks/AppKit.framework/Versions/C/AppKit +0x0001799C]
278 INFO nsAppShell::Run()+0x00000212 [/Users/mwargers/mozilla-central/obj-x86_64-apple-darwin13.3.0/dist/NightlyDebug.app/Contents/MacOS/XUL +0x01920872]
279 INFO nsAppStartup::Run()+0x00000082 [/Users/mwargers/mozilla-central/obj-x86_64-apple-darwin13.3.0/dist/NightlyDebug.app/Contents/MacOS/XUL +0x027AE1A2]
280 INFO XREMain::XRE_mainRun()+0x0000160C [/Users/mwargers/mozilla-central/obj-x86_64-apple-darwin13.3.0/dist/NightlyDebug.app/Contents/MacOS/XUL +0x0281399C]
281 INFO XREMain::XRE_main(int, char**, nsXREAppData const*)+0x00000117 [/Users/mwargers/mozilla-central/obj-x86_64-apple-darwin13.3.0/dist/NightlyDebug.app/Contents/MacOS/XUL +0x02814067]
282 INFO XRE_main+0x000000DF [/Users/mwargers/mozilla-central/obj-x86_64-apple-darwin13.3.0/dist/NightlyDebug.app/Contents/MacOS/XUL +0x0281440F]
283 INFO main+0x000007B3 [/Users/mwargers/mozilla-central/obj-x86_64-apple-darwin13.3.0/dist/NightlyDebug.app/Contents/MacOS/firefox +0x000022B3]
TEST-INFO | Main app process: killed by SIGHUP
Component: Mochitest → DOM
Flags: needinfo?(birtles)
Keywords: assertion, crash
Product: Testing → Core
Summary: Getting randomly killed when trying to do ./mach mochitest-plain --run-until-failure → Assertion failure: !aOther.IsNull() in mozilla::dom::AnimationPlayer::SetSource
Version: unspecified → Trunk
Yes, this is almost definitely a regression from bug 1040543. I'll look into it later today.
Flags: needinfo?(birtles)
Blocks: 1040543
Attached patch Debug assertion (obsolete) — Splinter Review
The assertion in nsTimeStamp::operator >= occasionally fails due to a null RHS
timestamp when called from AnimationPlayer::GetCurrentTimeDuration, which, in
turn, is called from AnimationPlayer::SetSource.

I *think* the issue is that we're not initializing AnimationPlayer.mPlayState to
the running state and so we occasionally end up with it being in the paused
state but with mPauseStart not set to a valid (non-null) TimeStamp.

This gets tickled because since bug 1040543 we call AnimationPlayer::SetSource
from nsAnimationManager::BuildAnimations *before* we set mPlayState and
mPauseStart.

This patch initializes mPlayState to the running state so we don't accidentally
end up in an inconsistent state (mPlayState = paused but mPauseStart is null).

It also removes some (now unnecessary) initialization of mPlayState and
mPauseStart from nsTransitionManager::ConsiderStartingTransition.

This patch also adds a couple of assertions temporarily in case I've
misdiagnosed the problem and instead we're actually setting mPauseStart to
a null TimeStamp.

In future we could also consider reworking nsAnimationManager::BuildAnimations
so that we call SetSource on the new animation player *after* setting up its
play state. That may be more correct and would further avoid this problem but
may not be necessary since all this code is likely to change in the near future.
Assignee: nobody → birtles
Status: NEW → ASSIGNED
Martijn, I'm unable to reproduce this locally on Windows. Are you able to try with attachment 8471358 [details] [diff] [review] applied and see if it fixes it?
Flags: needinfo?(martijn.martijn)
Yes, this patch seems to fix it. I don't get to see the crash with it.
Flags: needinfo?(martijn.martijn)
(In reply to Martijn Wargers [:mwargers] (QA) from comment #5)
> Yes, this patch seems to fix it. I don't get to see the crash with it.

Great, thanks Martijn!
Attachment #8471358 - Attachment is obsolete: true
Comment on attachment 8471369 [details] [diff] [review]
Initialize AnimationPlayer::mPlayState to running state

r=dbaron, but it would be good to add a testcase.  But also good to land today rather than waiting to land it.  (It's surprising that an assertion that is triggered this easily isn't hit anywhere in our test suite.)

Also, the commit message refers to "compilers that don't initialize integer member variables to 0" -- I haven't heard of any such compilers.  You should probably adjust the commit message.


(That said, I've been looking at this in GDB, since I updated my tree earlier today and then hit this crash on startup, and gdb is telling me mStartTime is also null, which doesn't make sense given the IsNull check around the subtraction.  Maybe gdb is just lying to me.)
Attachment #8471369 - Flags: review?(dbaron) → review+
Oh, I guess the testcase bit would be probabilistic.
(In reply to David Baron [:dbaron] (UTC-7) (needinfo? for questions) from comment #8)
> Also, the commit message refers to "compilers that don't initialize integer
> member variables to 0" -- I haven't heard of any such compilers.  You should
> probably adjust the commit message.

That said, the *allocator* on Windows debug builds might be initializing "uninitialized" memory to 0xcdcdcdcd or 0xddddddddd or similar.  (I've forgotten the exact behavior.)
(In reply to David Baron [:dbaron] (UTC-7) (needinfo? for questions) from comment #8)
> r=dbaron, but it would be good to add a testcase.  But also good to land
> today rather than waiting to land it.  (It's surprising that an assertion
> that is triggered this easily isn't hit anywhere in our test suite.)
> 
> Also, the commit message refers to "compilers that don't initialize integer
> member variables to 0" -- I haven't heard of any such compilers.  You should
> probably adjust the commit message.

In that case I'm not sure what's happening. I'm unable to reproduce this locally so I'm just guessing. The ctor is being called since otherwise this patch would have no effect. But it would seem that the mPlayState member is not being initialized to zero.

I'm going to go ahead and land this as-is (with adjustments to the commit message) since you're hitting it on startup and I don't want this to block anyone's work. I can try to reproduce later in a VM to see what's going on exactly.
https://hg.mozilla.org/mozilla-central/rev/1681a1c1962c
Status: ASSIGNED → RESOLVED
Closed: 8 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla34
It's not a function of the compiler; it's a function of the memory allocator.

(The memory allocator in debug builds on Windows always uses certain patterns.)
Component: DOM → DOM: Core & HTML
You need to log in before you can comment on or make changes to this bug.