401393 - "ASSERTION: Event listener manager hash not empty at shutdown!" with Flash and Greasemonkey

Status: RESOLVED FIXED

(Core Graveyard :: Plug-ins, defect, P3)

Description

[Jesse Ruderman]

Loading the testcase (in Mac trunk debug Firefox) triggers:

###!!! ASSERTION: Event listener manager hash not empty at shutdown!: 'sEventListenerManagersHash.entryCount == 0', file /Users/jruderman/trunk/mozilla/content/base/src/nsContentUtils.cpp, line 708

It also makes Firefox leak 1 nsEventListenerManager, 1 nsGenericElement, 1 nsHTMLSharedObjectElement, and a bunch of other objects.

Comment 1

[Jesse Ruderman]

Attachment: testcase

Comment 2

[Jesse Ruderman]

Attachment: debug output: warnings, leak log

Comment 3

[Boris Zbarsky [:bzbarsky]]

You'll get that assert any time you leak an element, basically.

Can you get a balance tree for that nsHTMLSharedObjectElement leak?  And possibly for the nsPluginInstanceOwner and ns4xPluginInstance?

I would assume the  nsPluginInstanceOwner leaks the element, but not sure how the plugin stuff ends up leaking itself here.

Comment 4

[Robert Sayre]

This doesn't leak for me.

Comment 5

[Jesse Ruderman]

Attachment: balance tree for the leaked nsHTMLSharedObjectElement

This is my first time trying to make a balance tree, so I don't know whether I did it correctly.

Comment 6

[Boris Zbarsky [:bzbarsky]]

Hmm.  What command line did you use?  That tree has some really odd things going on...

Comment 7

[Jesse Ruderman]

The command line is included in the attachment.

Comment 8

[Boris Zbarsky [:bzbarsky]]

Ah, ok. Try something more like:

  export XPCOM_MEM_REFCNT_LOG=log-file.dat
  export XPCOM_MEM_COMPTR_LOG=log-comptr.dat
  export XPCOM_MEM_LOG_CLASSES=nsHTMLSharedObjectElement

Run firefox.  Run find-leakers.pl on log-file.dat to find the address.

  make-tree.pl --object ADDRESS_HERE --comptr log-comptr.dat --ignore-balanced < ~/log-file.dat | fix-macosx-stack.pl

The difference with what you did is logging all the nsCOMPtr activity and getting rid of the matching addrefs/releases from that even if they're in different parts of the balance tree.  Makes the tree smaller and simpler to read.

Comment 9

[Jesse Ruderman]

Attachment: ignoring nsCOMPtr activity

Ignoring nsCOMPtr activity made the whole tree go away?

Comment 10

[Jesse Ruderman]

Attachment: balance tree for the leaked nsPluginInstanceOwner

This log makes more sense.  There's even some stuff at the bottom involving "scroll position listeners".

Comment 11

[David Baron :dbaron: (⌚️UTC-4, no longer working on Mozilla)]

(In reply to comment #9)
> Ignoring nsCOMPtr activity made the whole tree go away?

When that's the case, generally find-comptr-leakers will show some leaks.

Comment 12

[Jesse Ruderman]

find-comptr-leakers.pl tells me that it's the nsPluginInstanceOwner's mContent pointer that continues to hold onto the nsHTMLSharedObjectElement.

Comment 13

[Jesse Ruderman]

nsPluginInstanceOwner::ScrollPositionDidChange's use of timers is Mac-specific.

Comment 14

[Boris Zbarsky [:bzbarsky]]

Note that the leak log (XPCOM_MEM_LEAK_LOG) will say for the leaked things how many refs were from COMPtrs, so you can tell whether to use find-comptr-leakers or find-leakers.

Comment 15

[Boris Zbarsky [:bzbarsky]]

Hmm.  So there are all sorts of CancelTimer() calls in nsPluginInstanceOwner.  So I'd expect this cycle to be broken...  Why aren't we hitting any of them?  Should the frame Destroy() method make sure the timer gets killed?

Comment 16

[Boris Zbarsky [:bzbarsky]]

And for what it's worth, I can't reproduce on Mac either.

Comment 17

[Jesse Ruderman]

Hmm, so it's up to me to debug it, then?

Comment 18

[Boris Zbarsky [:bzbarsky]]

If it's consistently reproducible, yes....

I'd start by adding printfs to the places where the timer is set up and to CancelTimer and seeing whether the latter is being hit at all, I guess.

Does this perhaps depend on Flash version?

Comment 19

[Jonas Sicking (:sicking) No longer reading bugmail consistently]

Jesse, here's your first blocker :)

Let me know if you need help and I'll do my best.

Comment 20

[Jesse Ruderman]

I can't reproduce in a completely clean profile, but once I install Greasemonkey (even without installing any user scripts), I can reproduce.

It seems like two nsPluginInstanceOwner objects are being created for the same frame, and one of them isn't getting torn down properly.  More soon.

Comment 21

[Jesse Ruderman]

I might have figured out what's going wrong.  nsPluginInstanceOwner::PrepareToStop is called on the first nsPluginInstanceOwner object, but mWidget is null, so PrepareToStop bails out early and doesn't unregister its scroll listener.  Later, the scroll listener is notified, setting up a cycle between the timer and the nsPluginInstanceOwner.  nsPluginInstanceOwner::Destroy doesn't get to break this cycle because it is called before the cycle is set up.

If I change the mWidget null check in nsPluginInstanceOwner::PrepareToStop to only wrap the code added in bug 347743 (which uses mWidget) instead of bailing early (and skipping the "Unregister scroll position listener" code), the leak goes away.  Eli and jst, do you remember why you made the null check do that in bug 347743?

I don't know why Greasemonkey causes two nsPluginInstanceOwners to be created, though.  I wonder if that's related to bug 390183.

Comment 22

[Jesse Ruderman]

Attachment: patch to add printfs (not for review)

This is what I used to debug the leak so far.

Comment 23

[Jesse Ruderman]

Attachment: output with that patch

Comment 24

[Jesse Ruderman]

Attachment: patch that fixes the leak

Comment 25

[Boris Zbarsky [:bzbarsky]]

> It seems like two nsPluginInstanceOwner objects are being created 

What are the stacks to those creations?

Comment 26

[Jesse Ruderman]

Attachment: stacks to nsPluginInstanceOwner creations

Comment 27

[Boris Zbarsky [:bzbarsky]]

Uh.  So we reenter nsObjectFrame::Instantiate, looks like.  I think we need to flag ourselves as being inside Instantiate and bail out if it's reentered.  Probably a separate (blocking1.9) bug on that?

It looks like greasemonkey installs a content policy implementation?  I wonder what they do in it...

Comment 28

[Jesse Ruderman]

http://greasemonkey.devjavu.com/browser/trunk/src/components/greasemonkey.js#L119

Comment 29

[Boris Zbarsky [:bzbarsky]]

Huh.  OK, that's kinda cute.

Comment 30

[Jesse Ruderman]

Are Greasemonkey's nsIContentPolicy callbacks doing anything that's disallowed?   Do we have assertions to catch that kind of thing?

Boris, can you file the bug you mentioned in comment 27?  I think you can describe it better than I can.

Comment 31

[Boris Zbarsky [:bzbarsky]]

> Are Greasemonkey's nsIContentPolicy callbacks doing anything that's disallowed?

Not offhand, no.

> Do we have assertions to catch that kind of thing?

For the most part, yeah.

I filed bug 402937.

Comment 32

[Jesse Ruderman]

Patch checked in.

For automated testing: once bug 397725 is fixed, I can check the testcase in as a crashtest, but the tests would have to be run with Greasemonkey installed to trigger the assertion and leak.  Hmm.