665995 - Memory reporter for cycle collector

Status: RESOLVED FIXED

(Core :: XPCOM, defect)

Description

[Andrew McCreight [:mccr8]]

njn is interested in hooking the CC up to the memory reporter system.  The only persistent data structure of any size the CC has is the purple buffer, but maybe we can think of some way to record how much memory the structures that only last the CC are using, too.

He found these allocations while doing a TechCrunch run using Massif.  Look how much memory the hash table is using!  It is using twice as much as for the cycle collector graph.  That seems pretty ridiculous, and is probably something worth investigating independently.  (The hash table also takes the largest % of the CC, at 8%, according to some Shark runs I've done.)

o1o> 10.69% (15,481,728B) 0x6689C90: PL_DHashAllocTable (pldhash.c:114)
| o2o> 06.55% (9,492,096B) 0x668A61C: ChangeTable (pldhash.c:563)
| | o3o> 06.52% (9,441,536B) 0x668A84F: PL_DHashTableOperate (pldhash.c:649)
| | | o4o> 02.90% (4,194,304B) 0x67073FE:
GCGraphBuilder::AddNode(void*, nsCycleCollectionParticipant*)
(nsCycleCollector.cpp:1516)
| | | | o5o> 02.90% (4,194,304B) 0x670A280:
GCGraphBuilder::AddNode(void*, nsCycleCollectionParticipant*, unsigned
int) (nsCycleCollector.
cpp:1456)
| | | |   o6o> 02.90% (4,194,304B) 0x6707B01:
GCGraphBuilder::NoteScriptChild(unsigned int, void*)
(nsCycleCollector.cpp:1721)  njnnjn
| | | |     o7o> 02.90% (4,194,304B) 0x6012214: NoteJSChild(JSTracer*,
void*, unsigned int) (nsXPConnect.cpp:688)
| | | |       o8o> 02.90% (4,194,304B) 0x6B79476: void
js::gc::Mark<JSObject>(JSTracer*, JSObject*) (jsgcmark.cpp:124)


o1o> 03.62% (5,243,080B) 0x67095F8: NodePool::Builder::Add(void*,
nsCycleCollectionParticipant*) (nsCycleCollector.cpp:622) njnnjn
| o2o> 03.62% (5,243,080B) 0x6707438: GCGraphBuilder::AddNode(void*,
nsCycleCollectionParticipant*) (nsCycleCollector.cpp:1525)
|   o3o> 03.62% (5,243,080B) 0x670A280: GCGraphBuilder::AddNode(void*,
nsCycleCollectionParticipant*, unsigned int) (nsCycleCollector.cpp:
1456)
|     o4o> 02.90% (4,194,464B) 0x6707B01:
GCGraphBuilder::NoteScriptChild(unsigned int, void*)
(nsCycleCollector.cpp:1721)
|     | o5o> 02.90% (4,194,464B) 0x6012214: NoteJSChild(JSTracer*,
void*, unsigned int) (nsXPConnect.cpp:688)
|     |   o6o> 02.90% (4,194,464B) 0x6B79476: void
js::gc::Mark<JSObject>(JSTracer*, JSObject*) (jsgcmark.cpp:124)


o1o> 02.90% (4,194,304B) 0x6709351: EdgePool::Builder::Add(PtrInfo*)
(mozalloc.h:229)   njnnjn
| o2o> 02.90% (4,194,304B) 0x6707B27:
GCGraphBuilder::NoteScriptChild(unsigned int, void*)
(nsCycleCollector.cpp:1724)
|   o3o> 02.53% (3,670,016B) 0x6012214: NoteJSChild(JSTracer*, void*,
unsigned int) (nsXPConnect.cpp:688)
|   | o4o> 02.53% (3,670,016B) 0x6B79476: void
js::gc::Mark<JSObject>(JSTracer*, JSObject*) (jsgcmark.cpp:124)

Comment 1

[Andrew McCreight [:mccr8]]

Attachment: memory reporter for the cycle collector

Untested.

It grabs the size of the CC graph, the white node array, and the purple buffer.  Only the purple buffer should have anything in it when the CC isn't running, so maybe I should just cut out the rest.

Comment 2

[Nicholas Nethercote [inactive]]

Comment on attachment 544929 [details] [diff] [review]
memory reporter for the cycle collector

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

What numbers are you seeing during regular browsing?

::: xpcom/base/nsCycleCollector.cpp
@@ +3329,5 @@
> +}
> +
> +
> +NS_MEMORY_REPORTER_IMPLEMENT(CycleCollectorMemReporter,
> +                             "explicit/cyclecollector",

Nit: "cycle-collector" reads better :)

@@ +3330,5 @@
> +
> +
> +NS_MEMORY_REPORTER_IMPLEMENT(CycleCollectorMemReporter,
> +                             "explicit/cyclecollector",
> +                             KIND_HEAP,

All this memory is definitely allocated with malloc/new, right?

Comment 3

[Nicholas Nethercote [inactive]]

Comment on attachment 544929 [details] [diff] [review]
memory reporter for the cycle collector

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

::: xpcom/base/nsCycleCollector.cpp
@@ +3479,5 @@
>            mReply(mLock, "cycle collector reply condvar"),
>            mRunning(PR_FALSE),
>            mShutdown(PR_FALSE),
> +          mCollected(PR_FALSE),
> +          mMemReporter(new NS_MEMORY_REPORTER_NAME(CycleCollectorMemReporter))

NS_MEMORY_REPORTER_NAME(CycleCollector) would suffice :)

Comment 4

[Andrew McCreight [:mccr8]]

I had to double check because I wasn't sure, but yes, it is all allocated with malloc/new.  I could also add in the cycle collector runner, but like the nsCycleCollector structure, it should only be a single fairly small object.

I updated to address your comments.

I just found out that the browser crashes immediately on startup with this patch, so I'm not sure what normal browsing numbers are like. ;)

Comment 5

[Andrew McCreight [:mccr8]]

Attachment: memory reporter for the cycle collector (WIP)

Fixed up the minor things in your comments.  I also eliminated the explicit member variable for the reporter, and followed the "register new" style, as the CC reporter will be long lived anyways.  I also commented out the body of the CC reporter for debugging.

Even with these simplifications, it still crashes right on startup with the following stack trace:

Thread 0 Crashed:  Dispatch queue: com.apple.main-thread
0   XUL                           	0x00000001010cec89 PL_DHashTableOperate + 345 (pldhash.c:613)
1   XUL                           	0x0000000102b89761 nsComponentManagerImpl::GetServiceByContractID(char const*, nsID const&, void**) + 241 (nsTHashtable.h:171)
2   XUL                           	0x0000000102b15c7c nsGetServiceByContractID::operator()(nsID const&, void**) const + 44 (nsComponentManagerUtils.cpp:279)
3   XUL                           	0x0000000102baf4b5 NS_RegisterMemoryReporter(nsIMemoryReporter*) + 53 (nsCOMPtr.h:1252)
4   XUL                           	0x0000000102bac03e nsCycleCollector_startup() + 526 (nsCOMPtr.h:514)
5   XUL                           	0x0000000102b23b6c NS_InitXPCOM2_P + 636 (nsXPComInit.cpp:496)
6   XUL                           	0x00000001010db019 ScopedXPCOMStartup::Initialize() + 57 (nsAppRunner.cpp:1148)
7   XUL                           	0x00000001010e7bf7 XRE_main + 12919 (nsAppRunner.cpp:3330)
8   org.mozilla.nightlydebug      	0x0000000100001af8 main + 1176 (nsBrowserApp.cpp:198)
9   org.mozilla.nightlydebug      	0x0000000100001594 start + 52


I have no idea what this could be.  I'm calling the register function from the main thread.  Is it possible that nsCycleCollector_startup is being called before the memory reporter infrastructure fires up?

Comment 6

[Nicholas Nethercote [inactive]]

> I have no idea what this could be.  I'm calling the register function from
> the main thread.  Is it possible that nsCycleCollector_startup is being
> called before the memory reporter infrastructure fires up?

Hmm, maybe.  In general adding a new reporter is really easy, I've never seen something like this before.  Can you step through in the debugger and see if anything of note pops up?

Comment 7

[Kyle Huey (Exited; not receiving bugmail, old account, do not use)]

From the xpcom init code.

492     // Create the Component/Service Manager
493     nsComponentManagerImpl::gComponentManager = new nsComponentManagerImpl();
494     NS_ADDREF(nsComponentManagerImpl::gComponentManager);
495     
496     rv = nsCycleCollector_startup();
497     if (NS_FAILED(rv)) return rv;
498 
499     rv = nsComponentManagerImpl::gComponentManager->Init();

So yes, nsCycleCollector_startup is too early.

Comment 8

[Andrew McCreight [:mccr8]]

Attachment: memory reporter for the cycle collector

I hacked around the problem with the CC being initialized before the memory reporter by checking a flag every time we CC.  If the flag is unset, we init the mem reporter and set the flag.  The cycle collector seems to use something like 10KB to 400KB.  Not a huge amount.

One thing I have considered doing is caching the high-water mark of memory usage during the last CC, and reporting that number to about:memory, to be put under the "other measurements" category.  This would require determining the largest size of each of the data structures the CC uses (caching that data), then summing up the totals for various points and selecting the largest when about:memory is called.

Comment 9

[Kyle Huey (Exited; not receiving bugmail, old account, do not use)]

You could do this from nsCycleCollector_registerRuntime, which is called later (from xpconnect).

Comment 10

[Andrew McCreight [:mccr8]]

Attachment: memory reporter for the cycle collector

Oh, that's a good idea.  Here's a patch that does that.  I added a static local variable to keep the CC mem reporter from being registered multiple times, though I don't think it is a problem.

Comment 11

[Andrew McCreight [:mccr8]]

I've hoisted the registration out of the check for the static cycle collector structure being there, though in practice it shouldn't matter.

I've confirmed that the size is zero when you only include the graph and the white nodes.  The cycle collector structure itself is 2336 on my machine.

The number of purple buffer blocks never drops below 10 for me, which seems a little weird.  I'd think that it would be 0 after a CC, but maybe just rendering the about:memory page generates enough activity that you hit exactly 10 blocks worth?

Comment 12

[Andrew McCreight [:mccr8]]

Attachment: CC memory reporter

We compute the size of all of the structures that the top level CC structure holds on to, including the graph, even though they are expected to be zero except when the CC is running.  Only the CC itself and the purple buffer should contain anything when the CC is idle.

Comment 13

[Nicholas Nethercote [inactive]]

Comment on attachment 546018 [details] [diff] [review]
CC memory reporter

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

::: xpcom/base/nsCycleCollector.cpp
@@ +3336,5 @@
> +                             "explicit/cycle-collector",
> +                             KIND_HEAP,
> +                             UNITS_BYTES,
> +                             ReportCycleCollectorMem,
> +                             "Memory used by the cycle collector.")

More info here might be useful.  Eg. you could list the various data structures, and maybe explain how some of them are expected to be zero unless CC is running.  I'll leave the decision up to you!

Comment 14

[Ben Turner (not reading bugmail, use the needinfo flag!)]

Comment on attachment 546018 [details] [diff] [review]
CC memory reporter

>+            mNumBlocks--;

Do you want to assert that mNumBlocks > 0 before you decrement? r=me either way.

Comment 15

[Andrew McCreight [:mccr8]]

Sure, I'll add the assert and also make the message a bit more descriptive, as njn suggested.  Thanks for the quick review.

Comment 16

[Andrew McCreight [:mccr8]]

njn, how about this for the description?  (the split string is just my getting a long string to not be super wide...)

"Memory used by the cycle collector for the "
"cycle collector structure, the purple buffer, "
"the graph, and the white nodes.  The latter two "
"are expected to be zero when the cycle collector "
"is idle.""

Comment 17

[Nicholas Nethercote [inactive]]

Sounds good, here's a tweaked version that reads better IMO:

"Memory used by the cycle collector.  This includes the "
"cycle collector structure, the purple buffer, "
"the graph, and the white nodes.  The latter two "
"are expected to be zero when the cycle collector "
"is idle."

Comment 18

[Andrew McCreight [:mccr8]]

Attachment: CC mem reporter

Addressed bent's review and njn's comments.  Carrying forward bent's review.  This passed a try run.

Comment 19

[Andrew McCreight [:mccr8]]

http://hg.mozilla.org/integration/mozilla-inbound/rev/df22b13ce797

Comment 20

[Marco Bonardo [:mak]]

http://hg.mozilla.org/mozilla-central/rev/df22b13ce797