680482 - Dump more complete Javascript heap graph

Status: RESOLVED FIXED

(Core :: JavaScript Engine, defect)

Description

[Andrew McCreight [:mccr8]]

Despite its description, JS_DumpHeap does not dump a complete object graph.  Instead, it produces an arbitrary path to each object it finds.  This is not helpful if you eg want to find all roots holding onto a particular JS object, as in my leak hunting in Bug 561359.  Just dumping all paths is not a solution either, as the number of paths grows exponentially.

I would like to add a new JS heap dumping mechanism similar to the cycle collector heap dump (either in addition to or replacing the existing method).  In this model, each object is visited once, and all of its children are produced in the log.  This lets you write an analysis outside of the browser, in a scripting language like Python, which is easier on a number of levels than splicing new C++ code into Firefox itself.

In addition to the graph itself, it should also indicate which objects are roots, and ideally what sort of roots.

Comment 1

[Nicholas Nethercote [inactive]]

This is MemShrink:P1 because any tools that help find JS leaks are invaluable.

Comment 2

[Andrew McCreight [:mccr8]]

Attachment: dump complete JS heap

only lightly tested, but it looks okay.

Here's a random slice of output:
0x11928a500 Function 119215b00
> 0x119212780 proto
> 0x1192051a8 parent
> 0x119215b00 private
> 0x119231670 upvars[0]
> 0x1192117c0 shape
0x119231670 Array 2
> 0x1192031f0 proto
> 0x1192051a8 parent
> 0x11920dde0 element[0]
> 0x11920de40 element[1]
0x11920de40 string nsISupportsWeakReference
0x11920dde0 string nsIObserver
0x11928a3a0 XPCWrappedNative_NoHelper 100199c30
> 0x11920c7c0 proto
> 0x1192830d0 parent
> 0x1192830d0 XPCWrappedNativeScope::mGlobalJSObject
> 0x119203ca0 XPCWrappedNativeScope::mPrototypeJSObject
> 0x119285e80 XPCWrappedNativeScope::mPrototypeJSFunction
> 0x119287e00 shape
0x119287e00 shape <shape>
0x11920c7c0 XPC_WN_NoHelper_Proto_JSClass 0
> 0x119203ca0 proto
> 0x1192830d0 parent
> 0x119287dc0 emptyShape
> 0x119287e00 emptyShape
> 0x119287d80 shape

Comment 3

[Andrew McCreight [:mccr8]]

I added back in the little hack to print out the file and line number of functions.  It seems a little off to me to print it on the outer function object, and not with the inner script thing, which in at least some cases is represented in the GC heap, but I think I tried it the other way and it didn't work.  I don't really understand enough about the representation of functions to fully work it out.

0x12997f1e8 Function 12726c180 file:http://s2.wp.com/wp-content/themes/vip/tctechcrunch2/js/techcrunch.js?m=1312841473g&ver=MU line:14
> 0x118c6ca00 proto
> 0x118c6a088 parent
> 0x12726c180 private
> 0x12727ae40 shape
> 0x127276c58 **UNKNOWN SLOT 1**

Comment 4

[Andrew McCreight [:mccr8]]

Implemented a find_roots script, iterated the patch a few times.  When you apply the leaky version of the patch from Bug 561359, and search for the chrome window, you get this:

host-4-131:1 amccreight$ python ~/mz/heapgraph/gc/find_roots.py gc-edges-3.log 0x1198e1628
Parsing gc-edges-3.log. Done loading graph. Reversing graph. Done.

via machine stack :
0x1194058f8 [BackstagePass 10018f600]
    --[PlacesUtils]-> 0x11abbe508 [Object <no private>]
    --[_shutdownFunctions]-> 0x1198c2de0 [Array 1]
    --[element[0]]-> 0x122f66978 [Function 11af0d080 file:resource://gre/modules/PlacesUtils.jsm line:2088]
    --[parent]-> 0x122f66920 [Block 0]
    --[parent]-> 0x122f3df78 [Call 0]
    --[aScope]-> 0x11af21c58 [Object <no private>]
    --[_uri]-> 0x122f60818 [XPCWrappedNative_NoHelper 122ea2520]
    --[proto, XPCWrappedNativeProto::mJSProtoObject]-> 0x122f607c0 [XPC_WN_NoMods_NoCall_Proto_JSClass 122ea24e0]
    --[parent, XPCWrappedNativeScope::mGlobalJSObject]-> 0x1198e1628 [ChromeWindow 119769d20]

via resource://gre/modules/PlacesUtils.jsm :
0x11abcd628 [BackstagePass 1055cfe10]
    --[PlacesUtils]-> 0x11abbe508 [Object <no private>]
    --[_shutdownFunctions]-> 0x1198c2de0 [Array 1]
    --[element[0]]-> 0x122f66978 [Function 11af0d080 file:resource://gre/modules/PlacesUtils.jsm line:2088]
    --[parent]-> 0x122f66920 [Block 0]
    --[parent]-> 0x122f3df78 [Call 0]
    --[aScope]-> 0x11af21c58 [Object <no private>]
    --[_uri]-> 0x122f60818 [XPCWrappedNative_NoHelper 122ea2520]
    --[proto, XPCWrappedNativeProto::mJSProtoObject]-> 0x122f607c0 [XPC_WN_NoMods_NoCall_Proto_JSClass 122ea24e0]
    --[parent, XPCWrappedNativeScope::mGlobalJSObject]-> 0x1198e1628 [ChromeWindow 119769d20]

Comment 5

[Andrew McCreight [:mccr8]]

Actually, because of some code hanging around from my CC logging script, you don't even have to give the explicit address, you can just invoke it with the desired class name and it will produce the same output as above, like so:
python ~/mz/heapgraph/gc/find_roots.py gc-edges-3.log ChromeWindow

I put my GC and CC scripts up on GitHub in the URL at the top.

Comment 6

[Andrew McCreight [:mccr8]]

Attachment: dump complete JS heap

Updated patch.

I change the "global object" string in XPCJSRuntime::TraceXPConnectRoots to "XPC global object" to distinguish it from the global objects that are marked elsewhere.  I believe these "XPC global objects" will be grey, and the other ones are black.  This is part of my hack to try to figure out which roots are black and which are grey...

Comment 7

[Nicholas Nethercote [inactive]]

mccr8: what's the end goal for this bug?  How do we decide when it's finished?

Comment 8

[Andrew McCreight [:mccr8]]

It is more or less "feature complete" right now.  I want to land a JS_DumpHeap that outputs a complete graph (possibly replacing the one that is there, but that's not necessary), along with an analysis script that duplicates a reasonable portion of the functionality of JS_DumpHeap, except that it handles things like grey roots and multiple roots more cleanly.  I'm not sure where the right place to put the script is.

Comment 9

[Nicholas Nethercote [inactive]]

Put it somewhere under tools/ ?  That's where trace-malloc lives.

Comment 10

[Andrew McCreight [:mccr8]]

So, as I said before, I have this in a reasonable state.  One thing I'm not sure about is if it should live in JSAPI.  Ideally, I'd also have a more generic listener like the cycle collector, so we could create in-browser clients of the JS dumper, but I guess that can be done in a followup.

Comment 11

[Andrew McCreight [:mccr8]]

Attachment: example rooting path for a script

example output of find_roots script.  took 18 seconds, mostly parsing.  44 meg log file.  there's some garbage in the node names due to Bug 682353 (such as "type_object bject").

Comment 12

[Andrew McCreight [:mccr8]]

Attachment: code to dump GC heap at every CC

Not intended to land, just an example of how you might use this.  To land, there would need to be some way to turn this off, plus a little cleanup.

Comment 13

[Andrew McCreight [:mccr8]]

Attachment: part 1: add js::DumpHeapComplete to jsfriendapi

This dumps the entire JS GC heap to a file, using JS_TraceChildren.  Roots are first identified using MarkRuntime, then the main heap is dumped out.  The format is similar to the cycle collector dumping tools.

Comment 14

[Andrew McCreight [:mccr8]]

Attachment: part 2: trivial string change in XPConnect to aid analysis scripts

This is a trivial patch, I just want to make sure it won't break something I'm not aware of.  It changes the string used for tracing global objects found in XPConnect.

This is needed for GC log analysis scripts to disambiguate whether a root is black or gray by just by looking at the name.  The JS engine marks black some other roots that are called "global object".  These XPC global objects are marked gray.

It is lame that we have to do this, but no other client of JSTraceChildren seems to care whether things are black or gray, so this is an easy fix.

Comment 15

[Andrew McCreight [:mccr8]]

Attachment: example output log

Comment 16

[Bill McCloskey [inactive unless it's an emergency] (:billm)]

Comment on attachment 568214 [details] [diff] [review]
part 1: add js::DumpHeapComplete to jsfriendapi

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

Thanks, looks great.

::: js/src/jsapi.cpp
@@ +2434,5 @@
>      buf[bufsize - 1] = '\0';
>  }
>  
> +extern JS_PUBLIC_API(const char *)
> +JS_GetTraceEdgeName(JSTracer *trc, char *buffer, int bufferLen)

I think bufferSize is a better name, since length usually means "excluding the null terminator".

@@ +2521,5 @@
>          entry->key = thing;
>      }
>  
> +    edgeName = JS_GetTraceEdgeName(&dtrc->base,
> +                                   dtrc->buffer, sizeof(dtrc->buffer));

SpiderMonkey allows 100 characters per line. It looks like you might be able to fit this.

::: js/src/jsfriendapi.cpp
@@ +239,5 @@
> +        : node(n), kind(k)
> +    {}
> +};
> +
> +typedef HashSet<void *, DefaultHasher<void *>, SystemAllocPolicy> PtrSet;

If you use ContextAllocPolicy, you don't have to worry about reporting OOMs. Same for the Vector.

@@ +277,5 @@
> +        return;
> +    }
> +
> +    DumpingChildInfo dci(thing, kind);
> +    dtrc->nodes.append(dci);

I think you can just say dtrc->nodes.append(DumpChildInfo(thing, kind));
Also, append could fail due to OOM. But honestly, besides converting to ContextAllocPolicy, I would suggest ignoring OOM here. I guess you might want to exit early, but it doesn't seem all that important.

@@ +320,5 @@
> +        JS_TraceChildren(&dtrc, dci.node, dci.kind);
> +    }
> +
> +    dtrc.visited.finish();
> +

Extra line.

Comment 17

[Andrew McCreight [:mccr8]]

Attachment: part 1: add js::DumpHeapComplete to jsfriendapi

Addressed Bill's review comments.

Comment 18

[Andrew McCreight [:mccr8]]

Looked good on try. https://tbpl.mozilla.org/?tree=Try&rev=f9144e15dc09

https://hg.mozilla.org/integration/mozilla-inbound/rev/5314e3475f86
https://hg.mozilla.org/integration/mozilla-inbound/rev/9a6b48af2f9f

Comment 19

[Andrew McCreight [:mccr8]]

Attachment: code to dump GC heap at every CC

The previous version of this patch was using the wrong JSContext, which caused hangs when you clicked on "minimize memory usage" (but not during normal cycle collections for some reason).

(The actual patch I landed is okay, this patch is just a little addition to try out the feature I added.)

Comment 20

[Andrew McCreight [:mccr8]]

Comment on attachment 568457 [details] [diff] [review]
code to dump GC heap at every CC

Okay, my attempt at a fix didn't really work either. I filed Bug 696174 for this side project that doesn't affect what I landed on mozilla-inbound.

Comment 21

[Marco Bonardo [:mak] (Away Apr 25 - May 5)]

https://hg.mozilla.org/mozilla-central/rev/5314e3475f86
https://hg.mozilla.org/mozilla-central/rev/9a6b48af2f9f