Open Bug 1189015 Opened 7 years ago Updated 1 year ago

After removing an animated element w/ Animations Devtools open, "ASSERTION: shouldn't have observed an animation being removed/added twice: 'Not Reached', file dom/base/nsDOMMutationObserver.h"

Categories

(Core :: DOM: Animation, defect, P3)

defect

Tracking

()

Tracking Status
firefox42 --- affected

People

(Reporter: dholbert, Unassigned)

References

(Blocks 1 open bug)

Details

(Keywords: assertion)

Attachments

(3 files, 1 obsolete file)

STR:
 1. Load attached testcase in a debug build.
 2. Right-click the colorful box and choose "Inspect Element".
 3. Click "Animations" tab at right edge of devtools panel.
 4. Now, click the text in the testcase (which triggers the animated element to be removed). Or, remove the animated element manually by selecting it in the inspector & hitting "Del" key.

ACTUAL RESULTS:
At least one copy of this assertion:
 ###!!! ASSERTION: shouldn't have observed an animation being removed twice: 'Not Reached', file dom/base/nsDOMMutationObserver.h, line 830

...and usually also a variant of the same assertion, with s/removed/added/:

###!!! ASSERTION: shouldn't have observed an animation being added twice: 'Not Reached', file dom/base/nsDOMMutationObserver.h, line 790


...and usually many more copies of each of these assertions.
Attached file testcase 1
Birtles, mind taking a look?
Flags: needinfo?(bbirtles)
Component: CSS Parsing and Computation → DOM: Animation
Keywords: assertion
Yeah, I've seen this before. Cameron might be better able to look at this.
Flags: needinfo?(bbirtles) → needinfo?(cam)
The assertions are caused by when plural mutation observers observe the same element.
Flags: needinfo?(cam)
It seems like a common use case. I think we should remove the assertions there.

Cameron, what do you think?
Flags: needinfo?(cam)
I did a comparative experiment on try server:

With assertions (current trunk):
https://treeherder.mozilla.org/#/jobs?repo=try&revision=3ef245b9d1bc

Without assertions:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=e05254621aec

It revealed that this assertion causes an intermittent failure (bug 1227792). I guess the reason of the failure is that obtaining stack traces for the assertion takes inadmissible time there.

As I wrote in comment #5, these assertions are hit in common use cases, we should remove them.
Assignee: nobody → hiikezoe
Attachment #8684706 - Attachment is obsolete: true
Flags: needinfo?(cam)
Attachment #8702749 - Flags: review?(cam)
Blocks: 1227792
:hiro, Thanks for taking a look at this !

Do you know if this fixes bug 1186675 as well ? Your try push says it did, but I just want to be sure.
Thanks Daniel for the test, and Hiro for investigating.  Sorry for dropping this for a while.

I think the assertions are valid and indicative of a bug.  In the test, when we remove the element from the document, we have a single nsAutoAnimationMutationBatch object on the stack, yet we call nsAutoAnimationMutationBatch::AnimationRemoved twice -- once for each of the two observers watching the element.  Maybe we should either (a) be ensuring that we only record the information about the animation addition/change/removal once, so that our state tracking is accurate, or (b) this state should be stored per observer (i.e. pass in the observer to those static Animation{Added,Changed,Removed} methods and use it as part of the key to look up mEntryTable).

I'll have a think about this; I'm not sure why DOM mutation observers don't suffer from this problem.
nsAutoMutationBatch::NodesAdded calls Done every time, so it behaves a bit differently it seems.

I think the easiest thing to do is just ensure that the first time we pass on a given animation notification from the nsAnimationReceiver to the nsAutoAnimationMutationBatch that we update our state, and we don't update our state for subsequent calls to the batch for that same notification.  (Since there are multiple nsAnimationReceivers, we can't coordinate this "only inform the batch once" behaviour from nsAnimationReceiver, so instead let's do it from the code that invokes all of the nsIAnimationObservers.
Comment on attachment 8702749 [details] [diff] [review]
Remove assertions in nsAutoAnimationMutationBatch::AnimationAdded and AnimationRemoved

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

r=me on the test, but please leave the assertion.  I'll upload a patch to fix the underyling problem.
Attachment #8702749 - Flags: review?(cam) → review+
Comment on attachment 8702749 [details] [diff] [review]
Remove assertions in nsAutoAnimationMutationBatch::AnimationAdded and AnimationRemoved

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

::: dom/animation/test/chrome/test_animation_observers.html
@@ +1489,2 @@
>  // Run the tests.
> +SimpleTest.expectAssertions(0);

I don't think this will do anything, since the default is 0.
Comment on attachment 8705467 [details] [diff] [review]
Process an animation mutation notification on a batch only once.


>+++ b/dom/base/nsNodeUtils.cpp
>@@ -80,16 +80,17 @@ using mozilla::AutoJSContext;
>     nsDOMMutationObserver::EnterMutationHandling();               \
>   }                                                               \
>   nsINode* node = content_;                                       \
>   do {                                                            \
>     nsINode::nsSlots* slots = node->GetExistingSlots();           \
>     if (slots && !slots->mMutationObservers.IsEmpty()) {          \
>       /* No need to explicitly notify the first observer first    \
>          since that'll happen anyway. */                          \
>+      nsAutoAnimationMutationBatch::NextBatchNotification();      \

this looks weird.
Need to think about this a bit.
(In reply to Cameron McCormack (:heycam) from comment #10)
> nsAutoMutationBatch::NodesAdded calls Done every time, so it behaves a bit
> differently it seems.

So in case of DOM mutation ContentInserted/Appended, those method don't do really anything with the
mutation record. They just tell to the batch object that this particular mutationobserver is interested in the mutation.

ContentRemoved is a bit different, there the first call during batch ends up adding the removed node to the batch's removedNodes list.


 
> I think the easiest thing to do is just ensure that the first time we pass
> on a given animation notification from the nsAnimationReceiver to the
> nsAutoAnimationMutationBatch that we update our state, and we don't update
> our state for subsequent calls to the batch for that same notification. 
yes, this sounds right. 
But I don't understand how the patch helps with this. What if there a mutation observer is observing several ancestor nodes?
Doesn't your patch help only in case there are separate mutation observers observing ancestor nodes or something.

I think you could do something similar to ContentRemoved here. 
AnimationAdded/Changed/Removed would tell to batch that the particular observer is interested in that animation and
also record the animation, but only once.
Looks like the first part is there already (nsAutoAnimationMutationBatch::AddObserver call), but it is the
nsAutoAnimationMutationBatch::AnimationAdded/Changed/Removed which would need to check if something during the current batch already reported about that particular animation...
so doesn't that actually just mean the assertions are invalid.
Attachment #8705467 - Flags: review?(bugs) → review-
Flags: needinfo?(cam)
Duplicate of this bug: 1250538
Priority: -- → P3
Summary: After removing an animated element w/ Animations Devtools open, "ASSERTION: shouldn't have observed an animation being removed twice: 'Not Reached', file dom/base/nsDOMMutationObserver.h, line 830" → After removing an animated element w/ Animations Devtools open, "ASSERTION: shouldn't have observed an animation being removed/added twice: 'Not Reached', file dom/base/nsDOMMutationObserver.h"
Duplicate of this bug: 1290215
Assignee: hikezoe → cam
Depends on: 1469769

Making DidComposite a high priority message, and thus letting RefreshDriver tick more often if normal priority queue is flooded seems to make this more often
https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=228117419&repo=mozilla-inbound&lineNumber=65478

Blocks: 1506376
See Also: → 1275466

Won't have time to get back to this.

Assignee: cam → nobody
Flags: needinfo?(cam)
You need to log in before you can comment on or make changes to this bug.