466157 - Need tool to find CC roots

Status: RESOLVED FIXED

(Core :: XPCOM, defect)

Description

[Peter Van der Beken [:peterv]]

Attachment: Add logging to CC

When figuring out a leak it is often useful to know what CC 'roots' keep a specific object alive, because adding the missing edges that holds those 'roots' can solve the leak. I've been using this patch that logs the reversed edges per object to find those roots with a perl tool I'll attach too.

As an example, I used this to solve the leak in bug 458397. I set the environment variable XPCOM_CC_LOG_EDGES, then opened the site in FF and quit. 2 nsGlobalWindows leaked (with a whole lot of other stuff). I then ran |find-roots.pl cc-edges.log all nsGlobalWindow| which gave me:

0x15d19260 [nsGlobalWindow]

    0xee7fac0 [nsGenericElement ([none]) div]
        --[mAttrsAndChildren[i]]-> 0xee7fe60 [nsGenericElement ([none]) div]
        --[mAttrsAndChildren[i]]-> 0xee7ff30 [nsGenericElement ([none]) form]
        --[mAttrsAndChildren[i]]-> 0xee804d0 [nsGenericElement ([none]) fieldset]
        --[mAttrsAndChildren[i]]-> 0xee80ad0 [nsGenericElement ([none]) button]
        --[[via hash] mListenerManager]-> 0xf4b6d90 [nsEventListenerManager]
        --[mListeners[i] mListener]-> 0xf4b6d58 [nsXPCWrappedJS (nsIDOMEventListener)]
        --[]-> 0xe997120 [JS Object (Function) (global=15c94480)]
        --[__proto__]-> 0x15c93850 [JS Object (Function) (global=15c94480)]
        --[__parent__]-> 0x15c94480 [JS Object (Window) (global=15c94480)]
        --[scope prinicpal]-> 0x15d19260 [nsGlobalWindow]

        known edges:
            0xeedba30  --[mIdentity]--> 0xee7fac0
            0x15d340f0 nsGenericElement ([none]) body --[mAttrsAndChildren[i]]--> 0xee7fac0

0x13cfa6a0 [nsGlobalWindow]

    0xee7fac0 [nsGenericElement ([none]) div]
        --[mAttrsAndChildren[i]]-> 0xee7fe60 [nsGenericElement ([none]) div]
        --[mAttrsAndChildren[i]]-> 0xee7ff30 [nsGenericElement ([none]) form]
        --[mAttrsAndChildren[i]]-> 0xee804d0 [nsGenericElement ([none]) fieldset]
        --[mAttrsAndChildren[i]]-> 0xee80ad0 [nsGenericElement ([none]) button]
        --[[via hash] mListenerManager]-> 0xf4b6d90 [nsEventListenerManager]
        --[mListeners[i] mListener]-> 0xf4b6d58 [nsXPCWrappedJS (nsIDOMEventListener)]
        --[]-> 0xe997120 [JS Object (Function) (global=15c94480)]
        --[__parent__]-> 0xe993920 [JS Object (Call) (global=15c94480)]
        --[**UNKNOWN SLOT 14**]-> 0xe9546e0 [JS Object (HTMLDivElement) (global=15c94480)]
        --[__parent__]-> 0x15c948a0 [JS Object (HTMLDocument) (global=15c94480)]
        --[location]-> 0x15c946e0 [JS Object (Location) (global=920700)]
        --[__parent__]-> 0x920700 [JS Object (Window) (global=920700)]
        --[scope prinicpal]-> 0x13cfa6a0 [nsGlobalWindow]

        known edges:
            0xeedba30  --[mIdentity]--> 0xee7fac0
            0x15d340f0 nsGenericElement ([none]) body --[mAttrsAndChildren[i]]--> 0xee7fac0

(I also have a patch that logs more info for elements/documents/windows, still need to file a bug about that)

With traditional refcount logging I figured out that the nsHTMLDivElement had serial number 12, and then I used the refcount balancer which showed me that the element was held by nsDOMCSSComputedStyle (in addition to the edges that the CC knew about).

Comment 1

[Peter Van der Beken [:peterv]]

Attachment: Perl script to analyze edge log

Comment 2

[Peter Van der Beken [:peterv]]

Attachment: Add logging to CC

Comment 3

[Peter Van der Beken [:peterv]]

Attachment: Perl script to analyze edge log

Comment 4

[Peter Van der Beken [:peterv]]

Attachment: Add logging to CC

Comment 5

[Peter Van der Beken [:peterv]]

Attachment: Perl script to analyze edge log

Comment 6

[Peter Van der Beken [:peterv]]

Attachment: v1

This makes DEBUG_CC builds output a log of all edges that's easier to parse with a script than the .dot files.

Comment 7

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

Comment on attachment 458211 [details] [diff] [review]
v1

Given that this means that we might build reversed edges twice in one cycle collection, I think it means that you should set pi->mReversedEdges to null in the count phase of CreateReversedEdges.

Also, above CreateReversedEdges, maybe add a comment saying that when all edges is false, reversed edges are built only for black nodes (and the mReversedEdges pointer on other nodes is invalid and potentially dangling).

r=dbaron with that.

Sorry for the delay getting to this.

Comment 8

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

(In reply to comment #7)
> Comment on attachment 458211 [details] [diff] [review]
> v1
> 
> Given that this means that we might build reversed edges twice in one cycle
> collection, I think it means that you should set pi->mReversedEdges to null in
> the count phase of CreateReversedEdges.

To be clear, this is because otherwise, the second time around, we'd have dangling pointers in the reversed edges list because we just prepend nodes to the existing list (which could, with this patch, start off as a dangling pointer).

Comment 9

[Peter Van der Beken [:peterv]]

Attachment: v2

I think I'm going to just obsolete v1 (sorry for obsoleting after review). This spits out a similar log while building the CC graph, it builds on some ideas from bug 497808. I have a perl script to reverse the edges and combine the different parts of the log into a new log that my analysis script can use to print out roots.

Comment 10

[Peter Van der Beken [:peterv]]

Attachment: Better logging for nodes v1

This adds some more information about nodes in their description in the CC.

Comment 11

[Peter Van der Beken [:peterv]]

Attachment: Perl script to process edge log

This reverse the edges and combines the two parts of the log. Not sure where this should go. Probably still needs some commenting and a help message.

Comment 12

[Peter Van der Beken [:peterv]]

Attachment: Perl script to analyze edge log

Probably still needs some commenting and a help message.

Comment 13

[Robert O'Callahan (:roc) (email my personal email if necessary)]

This looks great!

Comment 14

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

Comment on attachment 468813 [details] [diff] [review]
v2

Maybe NoteEdge should print the from address as well?  It might be
a useful sanity-check.

In GCGraphBuilder::GCGraphBuilder, I'd suggest keeping and rewording
the comment:
>-    // Do we need to set these all the time?

I presume the idea for using this is that an extension will create the 
logger component and call nsIDOMWindowUtils.garbageCollect(listener)?
(Otherwise I don't see any mechanism for end users to invoke it.)

r=dbaron; sorry for the delay

Comment 15

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

Comment on attachment 468814 [details] [diff] [review]
Better logging for nodes v1

Could you remove the NS_IMPL_CYCLE_COLLECTION_DESCRIBE from the end of  NS_IMPL_CYCLE_COLLECTION_TRAVERSE_BEGIN_REFCNT, insert it at the two existing users, rename NS_IMPL_CYCLE_COLLECTION_TRAVERSE_BEGIN_REFCNT (maybe s/REFCNT/INTERNAL/ if you can't think of anything better), and then use that renamed macro in these new users instead of copying its guts to 4 places?

Also, could you use |name| or |desc| instead of |foo| for the string in nsJSScriptTimeoutHandler?

r=dbaron with that

Comment 16

[Peter Van der Beken [:peterv]]

(In reply to comment #14)
> Maybe NoteEdge should print the from address as well?  It might be
> a useful sanity-check.

I don't think this is very important, so haven't done this.

> In GCGraphBuilder::GCGraphBuilder, I'd suggest keeping and rewording
> the comment:
> >-    // Do we need to set these all the time?

    // We want all edges and all info if DEBUG_CC is set or if we have a
    // listener. Do we want them all the time?

> I presume the idea for using this is that an extension will create the 
> logger component and call nsIDOMWindowUtils.garbageCollect(listener)?
> (Otherwise I don't see any mechanism for end users to invoke it.)

Entering |window.QueryInterface(Components.interfaces.nsIInterfaceRequestor).getInterface(Components.interfaces.nsIDOMWindowUtils).garbageCollect(Components.classes["@mozilla.org/cycle-collector-logger;1"].createInstance(Components.interfaces.nsICycleCollectorListener))| in the error console should work. We could make an extension to simplify it if needed.

Comment 17

[Peter Van der Beken [:peterv]]

Attachment: v2

Comment 18

[Peter Van der Beken [:peterv]]

Attachment: Better logging for nodes v1

Comment 19

[Robert O'Callahan (:roc) (email my personal email if necessary)]

There no longer is an Error Console, so we can't tell people to do what you said in comment #16.

Comment 20

[Robert O'Callahan (:roc) (email my personal email if necessary)]

Ah, but you can reenable it via about:config devtools.errorconsole.enabled, and then open a new window, and there it is. Phew.

Comment 21

[Robert O'Callahan (:roc) (email my personal email if necessary)]

Unfortunately trying to dump the heap graph causes a crash on trunk :-(. Filed bug 599672. Looks like it's related to JS compartments.

Comment 22

[Robert O'Callahan (:roc) (email my personal email if necessary)]

Filed bug 606106 on another compartments bug that causes a crash trying to get the heap dump.

Of course, these crashes are only fatal assertions; things work fine if you just use an opt build. So I'm going to blog about the steps to get a CC dump and encourage people to collect them and file bugs with them.

Comment 23

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

Since it wasn't actually noted here, these patches landed on mozilla-central:
http://hg.mozilla.org/mozilla-central/rev/d33f1f98bbf3
http://hg.mozilla.org/mozilla-central/rev/11de95cfdc8a
on September 14.

Comment 24

[Mike Beltzner [:beltzner, not reading bugmail]]

So is this FIXED? I'm adding [approved-patches-landed] to keep this off my query of approval2.0+ but not resolved.

Comment 25

[Andrew McCreight [:mccr8]]

Just for explanation here, the Firefox patches have landed, but the associated Perl scripts in this bug are still useful to analyze the script, and weren't landed anywhere.  I guess that makes this fixed, but it is still handy to have linked in the memory tools bug.

Comment 26

[(no longer active)]

(In reply to comment #25)
> Just for explanation here, the Firefox patches have landed, but the associated
> Perl scripts in this bug are still useful to analyze the script, and weren't
> landed anywhere.  I guess that makes this fixed, but it is still handy to have
> linked in the memory tools bug.

Can we land them somewhere in the tools/ directory?

Comment 27

[Jesse Ruderman]

And then update the entries on http://brasstacks.mozilla.com/toolbox/ ? ;)