Last Comment Bug 466157 - Need tool to find CC roots
: Need tool to find CC roots
Status: RESOLVED FIXED
[approved-patches-landed][MemShrink:P2]
:
Product: Core
Classification: Components
Component: XPCOM (show other bugs)
: Trunk
: All All
: -- normal (vote)
: ---
Assigned To: Peter Van der Beken [:peterv]
:
Mentors:
Depends on: 651273
Blocks: 497808 MemShrinkTools
  Show dependency treegraph
 
Reported: 2008-11-21 05:30 PST by Peter Van der Beken [:peterv]
Modified: 2011-06-14 16:21 PDT (History)
14 users (show)
See Also:
Crash Signature:
(edit)
QA Whiteboard:
Iteration: ---
Points: ---
Has Regression Range: ---
Has STR: ---


Attachments
Add logging to CC (5.29 KB, patch)
2008-11-21 05:30 PST, Peter Van der Beken [:peterv]
no flags Details | Diff | Review
Perl script to analyze edge log (3.43 KB, text/plain)
2008-11-21 05:31 PST, Peter Van der Beken [:peterv]
no flags Details
Add logging to CC (5.63 KB, patch)
2008-11-24 11:17 PST, Peter Van der Beken [:peterv]
no flags Details | Diff | Review
Perl script to analyze edge log (3.42 KB, text/plain)
2008-11-24 11:18 PST, Peter Van der Beken [:peterv]
no flags Details
Add logging to CC (5.64 KB, patch)
2009-04-29 11:15 PDT, Peter Van der Beken [:peterv]
no flags Details | Diff | Review
Perl script to analyze edge log (3.46 KB, text/plain)
2009-04-29 11:16 PDT, Peter Van der Beken [:peterv]
no flags Details
v1 (7.05 KB, patch)
2010-07-18 14:06 PDT, Peter Van der Beken [:peterv]
dbaron: review+
Details | Diff | Review
v2 (34.19 KB, patch)
2010-08-24 14:41 PDT, Peter Van der Beken [:peterv]
dbaron: review+
Details | Diff | Review
Better logging for nodes v1 (8.94 KB, patch)
2010-08-24 14:44 PDT, Peter Van der Beken [:peterv]
dbaron: review+
Details | Diff | Review
Perl script to process edge log (1.18 KB, text/plain)
2010-08-24 14:46 PDT, Peter Van der Beken [:peterv]
no flags Details
Perl script to analyze edge log (3.74 KB, text/plain)
2010-08-24 14:47 PDT, Peter Van der Beken [:peterv]
no flags Details
v2 (35.62 KB, patch)
2010-09-14 16:24 PDT, Peter Van der Beken [:peterv]
peterv: review+
jst: approval2.0+
Details | Diff | Review
Better logging for nodes v1 (12.41 KB, patch)
2010-09-14 16:24 PDT, Peter Van der Beken [:peterv]
peterv: review+
jst: approval2.0+
Details | Diff | Review

Description Peter Van der Beken [:peterv] 2008-11-21 05:30:35 PST
Created attachment 349413 [details] [diff] [review]
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] 2008-11-21 05:31:30 PST
Created attachment 349414 [details]
Perl script to analyze edge log
Comment 2 Peter Van der Beken [:peterv] 2008-11-24 11:17:57 PST
Created attachment 349788 [details] [diff] [review]
Add logging to CC
Comment 3 Peter Van der Beken [:peterv] 2008-11-24 11:18:52 PST
Created attachment 349789 [details]
Perl script to analyze edge log
Comment 4 Peter Van der Beken [:peterv] 2009-04-29 11:15:30 PDT
Created attachment 375055 [details] [diff] [review]
Add logging to CC
Comment 5 Peter Van der Beken [:peterv] 2009-04-29 11:16:22 PDT
Created attachment 375056 [details]
Perl script to analyze edge log
Comment 6 Peter Van der Beken [:peterv] 2010-07-18 14:06:34 PDT
Created attachment 458211 [details] [diff] [review]
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-7 (review requests must explain patch) 2010-08-13 15:45:34 PDT
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-7 (review requests must explain patch) 2010-08-13 15:47:12 PDT
(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] 2010-08-24 14:41:55 PDT
Created attachment 468813 [details] [diff] [review]
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] 2010-08-24 14:44:37 PDT
Created attachment 468814 [details] [diff] [review]
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] 2010-08-24 14:46:25 PDT
Created attachment 468816 [details]
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] 2010-08-24 14:47:10 PDT
Created attachment 468818 [details]
Perl script to analyze edge log

Probably still needs some commenting and a help message.
Comment 13 Robert O'Callahan (:roc) (Exited; email my personal email if necessary) 2010-08-24 15:54:09 PDT
This looks great!
Comment 14 David Baron :dbaron: ⌚️UTC-7 (review requests must explain patch) 2010-08-30 08:20:12 PDT
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-7 (review requests must explain patch) 2010-08-30 08:28:04 PDT
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] 2010-09-14 13:39:59 PDT
(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] 2010-09-14 16:24:29 PDT
Created attachment 475307 [details] [diff] [review]
v2
Comment 18 Peter Van der Beken [:peterv] 2010-09-14 16:24:59 PDT
Created attachment 475308 [details] [diff] [review]
Better logging for nodes v1
Comment 19 Robert O'Callahan (:roc) (Exited; email my personal email if necessary) 2010-09-25 13:22:01 PDT
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) (Exited; email my personal email if necessary) 2010-09-25 13:24:36 PDT
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) (Exited; email my personal email if necessary) 2010-09-25 17:24:03 PDT
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) (Exited; email my personal email if necessary) 2010-10-20 22:35:01 PDT
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-7 (review requests must explain patch) 2010-10-25 18:53:42 PDT
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] 2011-02-23 10:07:45 PST
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 (PTO-ish through 6-29) [:mccr8] 2011-06-14 14:39:26 PDT
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 :Ehsan Akhgari (busy, don't ask for review please) 2011-06-14 14:52:51 PDT
(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 2011-06-14 16:21:27 PDT
And then update the entries on http://brasstacks.mozilla.com/toolbox/ ? ;)

Note You need to log in before you can comment on or make changes to this bug.