Last Comment Bug 696761 - big memory leak? causing CC times to move into multiple seconds
: big memory leak? causing CC times to move into multiple seconds
Status: RESOLVED INCOMPLETE
[Snappy]
: qawanted, regression
Product: Core
Classification: Components
Component: XPCOM (show other bugs)
: Trunk
: x86_64 Windows 7
: -- major with 3 votes (vote)
: ---
Assigned To: Andrew McCreight [:mccr8]
:
Mentors:
Depends on: 700645 700647 700668 701443
Blocks: 608954 711900 720779
  Show dependency treegraph
 
Reported: 2011-10-24 07:48 PDT by Asa Dotzler [:asa]
Modified: 2015-10-07 18:44 PDT (History)
50 users (show)
See Also:
Crash Signature:
(edit)
QA Whiteboard:
Iteration: ---
Points: ---
Has Regression Range: ---
Has STR: ---
+
-


Attachments
about:memory (Cww) (58.38 KB, text/plain)
2011-10-24 13:04 PDT, [:Cww]
no flags Details
about:memory (Unfocused) (403.82 KB, text/plain)
2011-10-25 04:18 PDT, Blair McBride [:Unfocused] (UNAVAILABLE)
no flags Details
About:memory (Dolske) (255.52 KB, text/plain)
2011-11-01 16:43 PDT, Justin Dolske [:Dolske]
no flags Details
about:telemetry extract (Unfocused) (27.64 KB, image/png)
2011-11-02 15:23 PDT, Blair McBride [:Unfocused] (UNAVAILABLE)
no flags Details
jprof of 2.2s CC time (1.07 MB, text/html)
2011-11-07 10:21 PST, Randell Jesup [:jesup]
no flags Details
After running for less than a day, Mozilla/5.0 (Macintosh; Intel Mac OS X 10.7; rv:11.0a1) Gecko/20111109 Firefox/11.0a1 (475.66 KB, text/plain)
2011-11-10 23:37 PST, Alex Limi (:limi) — Firefox UX Team
no flags Details
about:memory (ttaubert) (319.02 KB, text/plain)
2011-11-24 15:39 PST, Tim Taubert [:ttaubert]
no flags Details

Description Asa Dotzler [:asa] 2011-10-24 07:48:16 PDT
Yesterday, on the latest nightly build, I found Firefox was pausing for more than a second every 10 or 15 seconds and it was interrupting my typing in the Web app http://irccloud.com  Smaug suggested I check my CC times and those were up well north of a second. He further suggested I might be swapping to cause those otherwise short times to be so long. Firefox was using an unusually large amount of RAM (over 2GB on my 4GB system) I restarted Firefox and everything seemed fine. 

This morning I woke up to a nearly paralyzed Firefox that was again over 2GB of RAM and barely responsive. After a re-start, things seemed better. 

The three pages I had open for the half a day or so it took to make Firefox start hanging/pausing are the MoCo Zimbra calendar, Twitter, and irccloud.com (each as pinned app tabs.)  I suspect one of these is causing us to leak or otherwise over-use RAM which gets me into a state of swapping and causing the CC pauses to be highly interruptive and for the browser to get really painfully slow.

cc'ing smaug and njn who were helpful last night. 

Testing with latest nightly build on Win7. I've been away from Firefox for 5 weeks so I don't know when this started, but it's definitely some kind of regression.
Comment 1 Andrew McCreight [:mccr8] 2011-10-24 08:00:29 PDT
You've probably gotten some of these questions from Nick, but I'll go ahead and ask them anyways.

What addons are you using?

What does your about:memory look like when things are really slow?

I have Twitter and Zimbra Mail (but not Calendar) open for a long time so if one of these pages is at fault, I would guess irccloud.  Is irccloud holding onto the entire history?  I could imagine that could add up.

Does closing individual tabs help?  You could try closing one, clicking mimize memory in about:memory, see if that helps, close another, etc.
Comment 2 Asa Dotzler [:asa] 2011-10-24 08:16:27 PDT
Only add-on is "nightly tester tools 3.1.5.1"

About memory last night was showing some older pages/compartments that I would have expected to have been removed. I didn't check about:memory this morning but here's something from last night http://grab.by/b73w -- I don't recall the compartment specifics.

I also suspect irccloud. I'll look more carefully at about:memory when it builds up again today.  This was not a problem for me using IRC Cloud 5 and 6 weeks ago, though.
Comment 3 Boris Zbarsky [:bz] (still a bit busy) 2011-10-24 08:35:25 PDT
Yeah, full about:memory output would be really nice....
Comment 4 Andrew McCreight [:mccr8] 2011-10-24 08:43:37 PDT
about:memory cut and pastes nicely so you don't need to take a screenshot.
Comment 5 [:Cww] 2011-10-24 13:04:39 PDT
Created attachment 569159 [details]
about:memory (Cww)

I'm not using irccloud and this bug is killing me with text areas everywhere (zimbra, bugzilla, etherpad).

Attached about:memory.  I restarted Firefox earlier today so it's not using as much as it usually does.
Comment 6 Boris Zbarsky [:bz] (still a bit busy) 2011-10-24 13:13:43 PDT
Lots of JS and unclassified in there... and a lot of the JS bit is gc-heap-chunk-dirty-unused
Comment 7 Justin Lebar (not reading bugmail) 2011-10-24 14:03:24 PDT
(In reply to [:Cww] from comment #5)
> Created attachment 569159 [details]
> about:memory (Cww)
> 
> I'm not using irccloud and this bug is killing me with text areas everywhere
> (zimbra, bugzilla, etherpad).
> 
> Attached about:memory.  I restarted Firefox earlier today so it's not using
> as much as it usually does.

What tabs did you have open at this point?  There's a bunch of things other than zimbra, bugzilla, and etherpad in there.  Did you click minimize memory usage before collecting the data?  Do you have any extensions?

This is weird:

  485,003,264 B -- heap-committed
  239,075,328 B -- js-gc-heap
  104,820,736 B -- js-gc-heap-chunk-dirty-unused

  983,511,040 B -- resident

The sum of the first three should be close to resident.  (Those three plus code should equal resident, I think...)  On my machine, the difference is about 30mb.  But here, the difference is 155mb!
Comment 8 [:Cww] 2011-10-24 15:17:11 PDT
I clicked minimize about a half-hour before copying this data.  Also open: iGoogle, gmail, input, SUMO, Google voice, maybe a couple copies of some of those.

From about:support, my extensions are:

        Adblock Plus1.3.10true{d10d0bf8-f5b5-c8b4-a8b2-2b9879e08c5d}Add-on Compatibility Reporter0.9.2truecompatibility@addons.mozilla.orgEasy App Tabs4trueeasy.app.tabs@phob.netGreasemonkey0.9.1true{e4a8a97b-f2ed-450b-b12d-ee082ba24781}Jetpack Prototype0.8.2truejetpack@labs.mozilla.comLive HTTP headers0.15true{8f8fe09b-0bd3-4470-bc1b-8cad42b8203a}Mass Password Reset1.04truemasspasswordreset@johnathan.nightingale

(wow, that copy-paste sucks)
Comment 9 Nicholas Nethercote [:njn] 2011-10-24 16:45:18 PDT
The add-ons from comment 8, more legibly:

Adblock Plus 1.3.10
Add-on Compatibility Reporter 0.9.2
Easy App Tabs 4
Greasemonkey 0.9.1
Jetpack Prototype 0.8.2
Mass Password Reset 1.04
Comment 10 Olli Pettay [:smaug] (way behind * queues, especially ni? queue) 2011-10-25 03:03:52 PDT
Cww, is the bad behavior a recent regression? I assume you're using Nightly. Asa mentioned
that situation wasn't bad 5 or 6 weeks ago.

Cww, could you also set javascript.options.mem.log=true and look at 
error console messages. Is it CC which is taking time (like it was for Asa) or GC?
Comment 11 Blair McBride [:Unfocused] (UNAVAILABLE) 2011-10-25 04:18:46 PDT
Created attachment 569324 [details]
about:memory (Unfocused)

I'm having similar issues. CC currently taking ~370ms, GC taking ~240ms. It's a recent-ish issue - first noticed something like this about a week ago, around the time the Win64 builds stopped updating (sadly, I've been too swamped to look into it), but it comes and goes.


CC timestamp: 1319540977253000, collected: 119 (119 waiting for GC), suspected: 6453, duration: 372 ms.
 ----------
GC mode: full, timestamp: 1319540979572000, duration: 244 ms.
 ----------
CC timestamp: 1319540984954000, collected: 6182 (6182 waiting for GC), suspected: 4159, duration: 382 ms.
 ----------
GC mode: full, timestamp: 1319540989195000, duration: 241 ms.
 ----------
CC timestamp: 1319540992850000, collected: 4 (4 waiting for GC), suspected: 2252, duration: 372 ms.
 ----------
CC timestamp: 1319541009240000, collected: 0 (4 waiting for GC), suspected: 1229, duration: 373 ms.
 ----------
CC timestamp: 1319541019665000, collected: 0 (4 waiting for GC), suspected: 1126, duration: 370 ms.
 ----------
CC timestamp: 1319541033126000, collected: 0 (4 waiting for GC), suspected: 1592, duration: 371 ms.
 ----------
CC timestamp: 1319541040850000, collected: 0 (4 waiting for GC), suspected: 1359, duration: 372 ms.
 ----------
CC timestamp: 1319541048593000, collected: 0 (4 waiting for GC), suspected: 1858, duration: 367 ms.
 ----------
CC timestamp: 1319541059170000, collected: 0 (4 waiting for GC), suspected: 1759, duration: 361 ms.
Comment 12 Olli Pettay [:smaug] (way behind * queues, especially ni? queue) 2011-10-25 05:22:46 PDT
Whoever sees this problem, do you happen to use some specific features of Firefox. Like
Tab groups, or private browsing, web console or other web dev tools ?

We clearly need regression range and also some way to reproduce this problem.
Comment 13 Olli Pettay [:smaug] (way behind * queues, especially ni? queue) 2011-10-25 05:24:18 PDT
Also, does this happen on Aurora?
Comment 14 Asa Dotzler [:asa] 2011-10-25 07:51:03 PDT
(In reply to Olli Pettay [:smaug] from comment #12)
> Whoever sees this problem, do you happen to use some specific features of
> Firefox. Like
> Tab groups, or private browsing, web console or other web dev tools ?
> 
> We clearly need regression range and also some way to reproduce this problem.

The only specific features I use that might not be common is App Tabs and Sync. I have Zimbra calendar, IRCCloud, and Twitter pinned as app tabs. I have several other Firefox installs that I keep synced.

The unfortunate news is that when I woke up this morning, expecting Firefox to be in a bad way, things seem mostly OK. I'll keep monitoring this closely though.
Comment 15 Justin Lebar (not reading bugmail) 2011-10-25 07:55:14 PDT
Comment on attachment 569324 [details]
about:memory (Unfocused)

44mb of DOM, 140mb of layout, 160mb system compartment...  Either you have a bazillion tabs open, or something is going wrong.  (Also, why the heck are there so many getspool.com layout shells??)

It's not surprising to me that with such a big gc/cc graph, gc/cc would take a long time.

Do you have any extensions enabled?  What tabs did you have open when you collected about:memory?  Did you click minimize memory usage before posting this capture?
Comment 16 Andrew McCreight [:mccr8] 2011-10-25 07:59:43 PDT
Hmm.  I was actually hitting 350ms-ish CC times yesterday.  Closing tabs didn't seem to help.  It wasn't as bad as Asa's second-long pause times, so I didn't investigate, but I guess I should do that.

One data point that might be useful, without being as annoying as a full CC dump, are the CYCLE_COLLECTOR_VISITED_GCED and CYCLE_COLLECTOR_VISITED_REF_COUNTED stats from about:telemetry, if you have those addons installed.  Maybe I should file a bug to get those added to the error console.

Suspected alone doesn't tell you a huge amount.  One possible reason I can think of is Bug 678830, which added scripts to the CC graph, which I guess could cause the graph to blowup.  That went in at the end of September, it looks like, so probably about a month too early for the recent problems we've seen.
Comment 17 Justin Lebar (not reading bugmail) 2011-10-25 08:00:49 PDT
I don't think we can track this for FF10 until we understand what's going on.  At this point, all I see are large object graphs, which could be caused by site bugs.

Cww's high memory usage could be caused by extensions, and since we don't have a full about:memory dump for Asa's machine, we don't know what's going on there.
Comment 18 Andrew McCreight [:mccr8] 2011-10-25 08:05:34 PDT
(In reply to Andrew McCreight [:mccr8] from comment #16)
> One data point that might be useful, without being as annoying as a full CC
> dump, are the CYCLE_COLLECTOR_VISITED_GCED and
> CYCLE_COLLECTOR_VISITED_REF_COUNTED stats from about:telemetry, if you have
> those addons installed.  Maybe I should file a bug to get those added to the
> error console.
Filed Bug 697115 for that.
Comment 19 Andrew McCreight [:mccr8] 2011-10-25 10:47:40 PDT
Randell is also seeing multi-second pause times.  I had him install the about:telemetry addon.  The number of objects collected is pretty normal but his CC graph is gigantic:

CYCLE_COLLECTOR_VISITED_GCED 141850 samples, average = 1188448.9, sum = 168581475596
CYCLE_COLLECTOR_VISITED_REF_COUNTED 141850 samples, average = 759910.6, sum = 107793318874

His CC graph is about 30 times larger than mine, and his CC is taking about 30 times longer than me, so I guess that part at least makes sense.

Part of that is probably that he has a lot of tabs open.  But that's still around 2 million nodes in the CC graph.

Look at those totals... over 168 billion nodes in the graphs, across all his CCs!
Comment 20 [:Cww] 2011-10-25 10:52:07 PDT
All this in the space of 2-3 minutes after enabling logging:

GC mode: full, timestamp: 1319564886686582, duration: 3550 ms.

CC timestamp: 1319564887483738, collected: 685 (685 waiting for GC), suspected: 1574, duration: 506 ms.

GC mode: full, timestamp: 1319564893304775, duration: 1827 ms.

CC timestamp: 1319564893960436, collected: 141 (141 waiting for GC), suspected: 2094, duration: 395 ms.

CC timestamp: 1319564902322764, collected: 294 (435 waiting for GC), suspected: 1518, duration: 313 ms.

GC mode: full, timestamp: 1319564908833463, duration: 2510 ms.

CC timestamp: 1319564914335990, collected: 411 (411 waiting for GC), suspected: 1538, duration: 504 ms.

GC mode: full, timestamp: 1319564920221654, duration: 1885 ms.

CC timestamp: 1319564925512450, collected: 202 (202 waiting for GC), suspected: 1150, duration: 297 ms.

CC timestamp: 1319564939139071, collected: 84 (286 waiting for GC), suspected: 1150, duration: 498 ms.

GC mode: full, timestamp: 1319564945790772, duration: 2643 ms.

CC timestamp: 1319564951228529, collected: 359 (359 waiting for GC), suspected: 1112, duration: 456 ms.
Comment 21 Olli Pettay [:smaug] (way behind * queues, especially ni? queue) 2011-10-25 10:58:11 PDT
Those *GC* times are crazy.
Comment 22 [:Cww] 2011-10-25 10:58:38 PDT
For me:

CYCLE_COLLECTOR_VISITED_GCED
1422 samples, average = 102764.8, sum = 146131553

CYCLE_COLLECTOR_VISITED_REF_COUNTED
1422 samples, average = 40766, sum = 57969291
Comment 23 Andrew McCreight [:mccr8] 2011-10-25 11:02:42 PDT
Yeah, the GC times are crazy, and I've noticed recently that almost all GCs everywhere I've seen are full GCs and not compartmental.  I emailed Bill and Gregor about that, as that doesn't seem right to me.

Cww: Your numbers aren't too high, except that your numbers are skewed more towards JS numbers than what I usually see.  For me, I have 10310 for GCed and 58050 for RCed.
Comment 24 Andrew McCreight [:mccr8] 2011-10-25 11:06:58 PDT
Bill said the fact that most GCs are full is expected.
Comment 25 [:Cww] 2011-10-25 11:15:21 PDT
Not sure what I should be doing... it sounds like I have a different bug, so should I file? This 2-3 second pause every minute is insanely annoying.
Comment 26 Andrew McCreight [:mccr8] 2011-10-25 11:19:56 PDT
You could try getting a cycle collector heap dump, and I can try analyzing it.  Follow the instructions here: https://wiki.mozilla.org/Performance:Leak_Tools#Cycle_collector_heap_dump

Probably will be too big to attach to here, even compressed.  If it isn't too large, you could email it to me.  I can try to figure out what exactly it making
Comment 27 Blair McBride [:Unfocused] (UNAVAILABLE) 2011-10-25 15:50:19 PDT
(In reply to Justin Lebar [:jlebar] from comment #15)
> 44mb of DOM, 140mb of layout, 160mb system compartment...  Either you have a
> bazillion tabs open, or something is going wrong.  

About 85 tabs open, not sure how many of those were actually loaded. But I typically have many more open (200-300, though not all loaded), and I never had this trouble. And even after restarting and restoring my session (I have tabs set to lazy load, so only my 6 app-tabs + 1 normal tab load on startup), I have the same symptoms.


> (Also, why the heck are
> there so many getspool.com layout shells??)

The Spool extension adds buttons to links on various sites (for me, Twitter and Google Reader) - probably loaded in an iframe, much like Facebook's like button.

> Do you have any extensions enabled?

Many. :\

> What tabs did you have open when you
> collected about:memory?  

Many. :\ 

I also use nearly all features smaug mentioned in comment 12 - tab groups, web console, other web dev tools. I doubt my profile will be terribly useful to delve into.

> Did you click minimize memory usage before posting
> this capture?

No, but I did afterwards and it didn't seem to do much.
Comment 28 Dão Gottwald [:dao] 2011-10-26 07:33:58 PDT
(In reply to Blair McBride (:Unfocused) from comment #27)
> About 85 tabs open, not sure how many of those were actually loaded. But I
> typically have many more open (200-300, though not all loaded), and I never
> had this trouble. And even after restarting and restoring my session (I have
> tabs set to lazy load, so only my 6 app-tabs + 1 normal tab load on
> startup), I have the same symptoms.

[...]

> I doubt my profile will be terribly useful to delve into.

However, it sounds like you (like anybody else who seems to reproducibly experience this bug) could help finding a regression range, e.g. the first bad nightly.
Comment 29 Andrew McCreight [:mccr8] 2011-10-26 08:43:49 PDT
I wrote some scripts to take a census of the types of objects in a cycle collector dump.  These strip out the global from the node name, then buckets together nodes with the same name.  I also skip over every marked object, on the theory that in an actual CC run the CC will probably skip these objects.

The top 10 most common node names from CWW's graph are these:
37722 JS Object (Function)
28563 JS Object (Object)
26344 nsGenericDOMDataNode
22063 JS Script
17520 other
16476 nsGenericElement (xhtml) div
10037 nsXBLBinding
 6683 nsGenericElement (xhtml) td
 6663 EditTxn
 6447 JS Object (XULElement)

"other" is every node with 50 or less instances, combined together, so there's a fairly long tail here.  Note that there is a ton of gray JS in the CC graph.  Compare this to my current browsing session:
48299 nsGenericDOMDataNode
17328 nsGenericElement (xhtml) div
15037 nsGenericElement (xhtml) a
11018 nsGenericElement (xhtml) span
10339 other
 9480 nsGenericElement (xhtml) td
 7033 EditTxn
 4911 nsEventListenerManager
 4398 nsXPCWrappedJS (nsIDOMEventListener)
 3766 nsJSEventListener
I have a number of JS-y things open (gmail, facebook, twitter, two Google spreadsheets), but there are no actual JS objects in the top ten.

CWW's probably looks more like a JS-side thing.  The cycle collector times, while bad enough to be annoying, are only about twice as long as I'm seeing on my own browser, while his GC times are about ten times mine.
Comment 30 Andrew McCreight [:mccr8] 2011-10-26 09:21:53 PDT
In Blair's case, cycle collections are about twice as long as mine, and GCs look normal, so maybe that is a different problem.

For Randell's log, the top ten look like this:
1149812     nsGenericDOMDataNode
 525054     JS Object (Function)
 365388     JS Object (Object)
 337609     JS Script
 245032     nsGenericElement (xhtml) span
 161747     JS Object (Array)
 153246     nsGenericElement (xhtml) a
 111561     nsGenericElement (xhtml) td
  83459     nsGenericElement (xhtml) div
  63792     nsEventListenerManager
Again, a ton of JS.  It seems a little odd to me that there are about as many scripts as there are generic JS objects.  Bug 678830 made scripts into CC things at the same time as GC things, but they used to have enclosing JS Objects anyways, so I'm not sure what impact that had on the CC graph.  A fair number have no children, so in a real CC they may not be in the CC graph.  I'm not sure how much script entrain, or if they entrain new things.  I would hope not.
Comment 31 Boris Zbarsky [:bz] (still a bit busy) 2011-10-26 09:35:56 PDT
> It seems a little odd to me that there are about as many scripts as there are generic JS
> objects.

Modulo function cloning, there is a script per function, yes?
Comment 32 Luke Wagner [:luke] 2011-10-26 09:40:26 PDT
(In reply to Andrew McCreight [:mccr8] from comment #30)
> graph.  I'm not sure how much script entrain, or if they entrain new things.
> I would hope not.

I don't know if this is meaningful or not but: if a JSScript has a TypeScript (via JSScript::types), then it can mark both its containing global and associated function object.

(In reply to Boris Zbarsky (:bz) from comment #31)
> > It seems a little odd to me that there are about as many scripts as there are generic JS
> > objects.
> 
> Modulo function cloning, there is a script per function, yes?

Also modulo native functions (builtins, DOM methods), but yes.
Comment 33 Andrew McCreight [:mccr8] 2011-10-26 09:54:45 PDT
(In reply to Boris Zbarsky (:bz) from comment #31)
> Modulo function cloning, there is a script per function, yes?
I guess there are just a ton of functions, then.

(In reply to Luke Wagner [:luke] from comment #32)
> I don't know if this is meaningful or not but: if a JSScript has a
> TypeScript (via JSScript::types), then it can mark both its containing
> global and associated function object.
Okay, makes sense.  If that is mostly what scripts are reaching, they probably don't affect the graph much, aside from their presence.
Comment 34 Bill McCloskey (:billm) 2011-10-26 10:52:30 PDT
To summarize what's going on:

Asa:
> 1 second pauses (GC/CC division unknown)
333MB JS heap
No extensions besides nightly tester tools
IRC Cloud tab open
Not reproducible after restart

:Cww:
~2000-3000ms GCs, ~500ms CCs
370 MB JS heap
Addons listed in comment 9
Sounds like it is reproducible after restart?

Blair:
~240ms GCs, ~370ms CCs
810MB JS heap
Lots of addons
Reproducible after restart

:Cww, how reproducible is this problem for you? Your symptoms seem to be the worst. Did this problem start happening recently? If so, would you be able to try a series of builds to see when the problem first began?
Comment 35 Randell Jesup [:jesup] 2011-10-26 11:55:15 PDT
My results haven't been analyzed yet (probably still crunching the 900MB CC log...), but I was seeing 3.8-8s CC's, 750-85ms GCs.  That was after running for a couple of weeks, circa 100 tabs loaded, 700 tabs total, with tbpl app tab always (though every few days I'd force a reload to give back memory).  Also a G+ app tab, GMail app tab, and one google doc (spreadsheet) in an app tab (though generally not touched)

Appears to reproduce after days to maybe a week.  Seems to be slowly climbing since I restarted yesterday: CC 315, now 450 usually, GC 150-180, now 225 - but CC of 1/3-1/2 second is pretty darn long when typing.  Up <24 hours, 29 tabs loaded of 705.  (Started at 16 loaded).  RSS was 1.15GB right after start, now 1.5GB; biggest grower was G+ (20->82MB).  Note that I disabled tbpl (closed the app tab) a day or two before restarting, though mem use continued to grow I believe.
Comment 36 [:Cww] 2011-10-26 12:11:09 PDT
I'd say the problem is very reproducible right now, even after nightly updates.  After an update/restart, it may be a bit better for an hour or so (?).  Probably started sometime between Thursday of last week and Monday of this week.  I was using tabs insanely heavily this weekend so it's hard to know which slowness this weekend was expected and which is this bug.

I'm still using the same session I had when this started so it could be something specific to some set of tabs (I keep about a dozen that I've had since Thursday and maybe 20-25 that I open and close as I go).

I recently switched to release Firefox where this problem doesn't happen at all (CC ~ 100-120ms, GC~200-250ms, same session)... I didn't think to back up my profile before doing that, but I'll see if switching back to nightly brings the problem back.  If so, I'll be happy to try a few candidate builds.  I'm also happy to lend my laptop to someone in the MV office who wants to troubleshoot (although I'm less OK with putting my profile somewhere as it has a lot of personal information and passwords).
Comment 37 Asa Dotzler [:asa] 2011-10-26 14:01:18 PDT
OK. My machine is currently in a bad way again. On yesterday's nightly m-c build. My memory has spiraled out of control again and I'm getting GC or CC pause times that are long enough to interrupt some typing, though that seems to have just fixed itself as I'm typing into this bugzilla text field. I have Zimbra, IRC Cloud, Twitter, and a couple of wiki pages including a mozilla intranet wiki page open. When I scroll the intranet wiki page, I'm getting flashes of black and if I scroll a lot while that's happening, I get a temporary browser hang (Win7 turns the page white-ish and gives me a spinner) for 10 seconds or so. Here's my about:memory

Main Process

Explicit Allocations
3,110,434,112 B (100.0%) -- explicit
+--2,843,283,991 B (91.41%) -- heap-unclassified
+----204,809,154 B (06.58%) -- js
¦    +---54,403,072 B (01.75%) -- gc-heap-chunk-dirty-unused
¦    +---46,320,969 B (01.49%) -- compartment(https://irccloud.com/#!/ircs://irc.mozilla.org:6697/%23planning)
¦    ¦   +--35,278,848 B (01.13%) -- gc-heap
¦    ¦   ¦  +--24,731,472 B (00.80%) -- arena-unused
¦    ¦   ¦  +---6,456,112 B (00.21%) -- objects
¦    ¦   ¦  +---2,153,824 B (00.07%) -- strings
¦    ¦   ¦  +---1,156,720 B (00.04%) -- shapes
¦    ¦   ¦  +-----379,848 B (00.01%) -- scripts
¦    ¦   ¦  +-----185,368 B (00.01%) -- arena-padding
¦    ¦   ¦  +-----137,808 B (00.00%) -- arena-headers
¦    ¦   ¦  +------77,696 B (00.00%) -- type-objects
¦    ¦   +---2,969,357 B (00.10%) -- analysis-temporary
¦    ¦   +---2,426,244 B (00.08%) -- string-chars
¦    ¦   +---2,424,832 B (00.08%) -- mjit-code
¦    ¦   ¦   +--2,261,496 B (00.07%) -- method
¦    ¦   ¦   +----106,784 B (00.00%) -- regexp
¦    ¦   ¦   +-----56,552 B (00.00%) -- unused
¦    ¦   +---1,662,800 B (00.05%) -- object-slots
¦    ¦   +-----513,040 B (00.02%) -- script-data
¦    ¦   +-----449,440 B (00.01%) -- property-tables
¦    ¦   +-----325,832 B (00.01%) -- type-inference
¦    ¦   ¦     +--189,640 B (00.01%) -- object-main
¦    ¦   ¦     +--116,640 B (00.00%) -- script-main
¦    ¦   ¦     +---19,552 B (00.00%) -- tables
¦    ¦   +-----213,488 B (00.01%) -- mjit-data
¦    ¦   +------50,272 B (00.00%) -- shape-kids
¦    ¦   +-------6,816 B (00.00%) -- object-empty-shapes
¦    +---39,006,752 B (01.25%) -- compartment(https://twitter.com/#!/mozillapeople/awesome)
¦    ¦   +--22,405,120 B (00.72%) -- gc-heap
¦    ¦   ¦  +--10,836,696 B (00.35%) -- arena-unused
¦    ¦   ¦  +---6,013,656 B (00.19%) -- objects
¦    ¦   ¦  +---2,344,880 B (00.08%) -- shapes
¦    ¦   ¦  +---1,668,448 B (00.05%) -- scripts
¦    ¦   ¦  +-----843,072 B (00.03%) -- strings
¦    ¦   ¦  +-----509,600 B (00.02%) -- type-objects
¦    ¦   ¦  +-----101,248 B (00.00%) -- arena-padding
¦    ¦   ¦  +------87,520 B (00.00%) -- arena-headers
¦    ¦   +---5,505,024 B (00.18%) -- mjit-code
¦    ¦   ¦   +--5,004,296 B (00.16%) -- method
¦    ¦   ¦   +----470,124 B (00.02%) -- regexp
¦    ¦   ¦   +-----30,604 B (00.00%) -- unused
¦    ¦   +---2,297,048 B (00.07%) -- script-data
¦    ¦   +---2,181,424 B (00.07%) -- object-slots
¦    ¦   +---2,055,712 B (00.07%) -- property-tables
¦    ¦   +---1,640,856 B (00.05%) -- string-chars
¦    ¦   +---1,440,324 B (00.05%) -- analysis-temporary
¦    ¦   +---1,059,340 B (00.03%) -- type-inference
¦    ¦   ¦   +----943,392 B (00.03%) -- object-main
¦    ¦   ¦   +-----65,792 B (00.00%) -- tables
¦    ¦   ¦   +-----50,156 B (00.00%) -- script-main
¦    ¦   +-----260,768 B (00.01%) -- shape-kids
¦    ¦   +-----141,408 B (00.00%) -- mjit-data
¦    ¦   +------19,728 B (00.00%) -- object-empty-shapes
¦    +---27,125,606 B (00.87%) -- compartment(https://mail.mozilla.com/zimbra/?app=calendar#1)
¦    ¦   +--13,324,288 B (00.43%) -- gc-heap
¦    ¦   ¦  +---7,238,280 B (00.23%) -- objects
¦    ¦   ¦  +---2,690,480 B (00.09%) -- shapes
¦    ¦   ¦  +---1,563,456 B (00.05%) -- arena-unused
¦    ¦   ¦  +---1,389,240 B (00.04%) -- scripts
¦    ¦   ¦  +-----195,904 B (00.01%) -- type-objects
¦    ¦   ¦  +-----130,784 B (00.00%) -- strings
¦    ¦   ¦  +------64,096 B (00.00%) -- arena-padding
¦    ¦   ¦  +------52,048 B (00.00%) -- arena-headers
¦    ¦   +---3,276,800 B (00.11%) -- mjit-code
¦    ¦   ¦   +--3,147,112 B (00.10%) -- method
¦    ¦   ¦   +-----69,856 B (00.00%) -- unused
¦    ¦   ¦   +-----59,832 B (00.00%) -- regexp
¦    ¦   +---3,058,344 B (00.10%) -- script-data
¦    ¦   +---2,216,528 B (00.07%) -- object-slots
¦    ¦   +---1,782,656 B (00.06%) -- property-tables
¦    ¦   +---1,584,556 B (00.05%) -- type-inference
¦    ¦   ¦   +--1,424,368 B (00.05%) -- object-main
¦    ¦   ¦   +-----90,272 B (00.00%) -- tables
¦    ¦   ¦   +-----69,916 B (00.00%) -- script-main
¦    ¦   +---1,304,562 B (00.04%) -- analysis-temporary
¦    ¦   +-----280,960 B (00.01%) -- shape-kids
¦    ¦   +-----190,848 B (00.01%) -- string-chars
¦    ¦   +------90,576 B (00.00%) -- object-empty-shapes
¦    ¦   +------15,488 B (00.00%) -- mjit-data
¦    +---21,443,395 B (00.69%) -- compartment([System Principal], 0x6468000)
¦    ¦   +---9,773,056 B (00.31%) -- gc-heap
¦    ¦   ¦   +--4,876,920 B (00.16%) -- objects
¦    ¦   ¦   +--3,032,840 B (00.10%) -- shapes
¦    ¦   ¦   +----942,752 B (00.03%) -- scripts
¦    ¦   ¦   +----480,424 B (00.02%) -- arena-unused
¦    ¦   ¦   +----286,224 B (00.01%) -- strings
¦    ¦   ¦   +-----93,024 B (00.00%) -- type-objects
¦    ¦   ¦   +-----38,176 B (00.00%) -- arena-headers
¦    ¦   ¦   +-----21,976 B (00.00%) -- arena-padding
¦    ¦   ¦   +--------720 B (00.00%) -- xml
¦    ¦   +---3,538,944 B (00.11%) -- mjit-code
¦    ¦   ¦   +--3,455,720 B (00.11%) -- method
¦    ¦   ¦   +-----42,896 B (00.00%) -- regexp
¦    ¦   ¦   +-----40,328 B (00.00%) -- unused
¦    ¦   +---1,593,184 B (00.05%) -- script-data
¦    ¦   +---1,457,976 B (00.05%) -- object-slots
¦    ¦   +---1,270,225 B (00.04%) -- analysis-temporary
¦    ¦   +---1,225,248 B (00.04%) -- mjit-data
¦    ¦   +---1,017,920 B (00.03%) -- property-tables
¦    ¦   +-----873,262 B (00.03%) -- string-chars
¦    ¦   +-----221,920 B (00.01%) -- shape-kids
¦    ¦   +-----198,720 B (00.01%) -- tjit-data
¦    ¦   ¦     +--122,944 B (00.00%) -- trace-monitor
¦    ¦   ¦     +---51,200 B (00.00%) -- allocators-reserve
¦    ¦   ¦     +---24,576 B (00.00%) -- allocators-main
¦    ¦   +-----147,804 B (00.00%) -- type-inference
¦    ¦   ¦     +---93,024 B (00.00%) -- object-main
¦    ¦   ¦     +---54,780 B (00.00%) -- script-main
¦    ¦   +-----125,136 B (00.00%) -- object-empty-shapes
¦    +----6,134,512 B (00.20%) -- compartment(atoms)
¦    ¦    +--4,078,320 B (00.13%) -- string-chars
¦    ¦    +--2,056,192 B (00.07%) -- gc-heap
¦    ¦       +--1,786,320 B (00.06%) -- strings
¦    ¦       +----258,192 B (00.01%) -- arena-unused
¦    ¦       +------8,032 B (00.00%) -- arena-headers
¦    ¦       +------3,648 B (00.00%) -- arena-padding
¦    +----3,909,712 B (00.13%) -- compartment(https://wiki.mozilla.org/Features/Desktop)
¦    ¦    +--2,129,920 B (00.07%) -- gc-heap
¦    ¦    ¦  +----879,800 B (00.03%) -- objects
¦    ¦    ¦  +----663,720 B (00.02%) -- shapes
¦    ¦    ¦  +----295,936 B (00.01%) -- scripts
¦    ¦    ¦  +----175,616 B (00.01%) -- arena-unused
¦    ¦    ¦  +-----79,456 B (00.00%) -- type-objects
¦    ¦    ¦  +-----23,408 B (00.00%) -- strings
¦    ¦    ¦  +------8,320 B (00.00%) -- arena-headers
¦    ¦    ¦  +------3,664 B (00.00%) -- arena-padding
¦    ¦    +----653,440 B (00.02%) -- script-data
¦    ¦    +----524,288 B (00.02%) -- mjit-code
¦    ¦    ¦    +--400,484 B (00.01%) -- method
¦    ¦    ¦    +--100,624 B (00.00%) -- regexp
¦    ¦    ¦    +---23,180 B (00.00%) -- unused
¦    ¦    +----219,776 B (00.01%) -- property-tables
¦    ¦    +----154,432 B (00.00%) -- type-inference
¦    ¦    ¦    +--135,296 B (00.00%) -- object-main
¦    ¦    ¦    +---19,136 B (00.00%) -- tables
¦    ¦    +----134,016 B (00.00%) -- object-slots
¦    ¦    +-----41,056 B (00.00%) -- shape-kids
¦    ¦    +-----35,568 B (00.00%) -- string-chars
¦    ¦    +------9,024 B (00.00%) -- object-empty-shapes
¦    ¦    +------8,192 B (00.00%) -- analysis-temporary
¦    +----2,265,088 B (00.07%) -- runtime
¦    ¦    +--2,097,152 B (00.07%) -- atoms-table
¦    ¦    +----167,936 B (00.01%) -- runtime-object
¦    +----2,228,224 B (00.07%) -- gc-heap-chunk-admin
¦    +------713,200 B (00.02%) -- compartment(https://intranet.mozilla.org/)
¦    ¦      +--516,096 B (00.02%) -- gc-heap
¦    ¦      ¦  +--207,760 B (00.01%) -- shapes
¦    ¦      ¦  +--191,912 B (00.01%) -- objects
¦    ¦      ¦  +---90,104 B (00.00%) -- arena-unused
¦    ¦      ¦  +---16,048 B (00.00%) -- scripts
¦    ¦      ¦  +----6,208 B (00.00%) -- type-objects
¦    ¦      ¦  +----2,016 B (00.00%) -- arena-headers
¦    ¦      ¦  +----1,456 B (00.00%) -- strings
¦    ¦      ¦  +------592 B (00.00%) -- arena-padding
¦    ¦      +---65,536 B (00.00%) -- mjit-code
¦    ¦      ¦   +--44,588 B (00.00%) -- method
¦    ¦      ¦   +--14,444 B (00.00%) -- unused
¦    ¦      ¦   +---6,504 B (00.00%) -- regexp
¦    ¦      +---40,960 B (00.00%) -- script-data
¦    ¦      +---38,768 B (00.00%) -- object-slots
¦    ¦      +---30,336 B (00.00%) -- property-tables
¦    ¦      +---10,976 B (00.00%) -- type-inference
¦    ¦      ¦   +---8,864 B (00.00%) -- object-main
¦    ¦      ¦   +---2,112 B (00.00%) -- tables
¦    ¦      +----4,384 B (00.00%) -- shape-kids
¦    ¦      +----3,744 B (00.00%) -- object-empty-shapes
¦    ¦      +----1,760 B (00.00%) -- string-chars
¦    ¦      +------640 B (00.00%) -- analysis-temporary
¦    +------331,680 B (00.01%) -- compartment(http://hg.mozilla.org/mozilla-central/filelog/08cb321ba6bf/browser/locales/en-US/chrome/browser/browser.properties)
¦    ¦      +--262,144 B (00.01%) -- mjit-code
¦    ¦      ¦  +--223,540 B (00.01%) -- method
¦    ¦      ¦  +---32,208 B (00.00%) -- unused
¦    ¦      ¦  +----6,396 B (00.00%) -- regexp
¦    ¦      +---61,440 B (00.00%) -- gc-heap
¦    ¦      ¦   +--46,320 B (00.00%) -- arena-unused
¦    ¦      ¦   +---8,344 B (00.00%) -- objects
¦    ¦      ¦   +---5,480 B (00.00%) -- shapes
¦    ¦      ¦   +-----576 B (00.00%) -- type-objects
¦    ¦      ¦   +-----272 B (00.00%) -- scripts
¦    ¦      ¦   +-----240 B (00.00%) -- arena-headers
¦    ¦      ¦   +-----208 B (00.00%) -- arena-padding
¦    ¦      +----5,472 B (00.00%) -- object-slots
¦    ¦      +----1,088 B (00.00%) -- type-inference
¦    ¦      ¦    +----576 B (00.00%) -- object-main
¦    ¦      ¦    +----512 B (00.00%) -- tables
¦    ¦      +------704 B (00.00%) -- property-tables
¦    ¦      +------480 B (00.00%) -- shape-kids
¦    ¦      +------336 B (00.00%) -- object-empty-shapes
¦    ¦      +-------16 B (00.00%) -- script-data
¦    +------262,144 B (00.01%) -- stack
¦    +------233,512 B (00.01%) -- compartment(https://api.twitter.com/receiver.html)
¦    ¦      +--131,072 B (00.00%) -- mjit-code
¦    ¦      ¦  +---65,156 B (00.00%) -- method
¦    ¦      ¦  +---56,400 B (00.00%) -- regexp
¦    ¦      ¦  +----9,516 B (00.00%) -- unused
¦    ¦      +---90,112 B (00.00%) -- gc-heap
¦    ¦      ¦   +--33,168 B (00.00%) -- arena-unused
¦    ¦      ¦   +--27,824 B (00.00%) -- objects
¦    ¦      ¦   +--27,640 B (00.00%) -- shapes
¦    ¦      ¦   +-----832 B (00.00%) -- type-objects
¦    ¦      ¦   +-----352 B (00.00%) -- arena-headers
¦    ¦      ¦   +-----160 B (00.00%) -- arena-padding
¦    ¦      ¦   +-----136 B (00.00%) -- scripts
¦    ¦      +----6,880 B (00.00%) -- object-slots
¦    ¦      +----3,008 B (00.00%) -- property-tables
¦    ¦      +------960 B (00.00%) -- object-empty-shapes
¦    ¦      +------832 B (00.00%) -- type-inference
¦    ¦      ¦      +--832 B (00.00%) -- object-main
¦    ¦      +------640 B (00.00%) -- shape-kids
¦    ¦      +--------8 B (00.00%) -- script-data
¦    +------226,192 B (00.01%) -- compartment(http://mxr.mozilla.org/mozilla-central/source/browser/components/nsBrowserGlue.js)
¦    ¦      +--212,992 B (00.01%) -- gc-heap
¦    ¦      ¦  +--165,776 B (00.01%) -- arena-unused
¦    ¦      ¦  +---23,688 B (00.00%) -- objects
¦    ¦      ¦  +---20,880 B (00.00%) -- shapes
¦    ¦      ¦  +----1,088 B (00.00%) -- type-objects
¦    ¦      ¦  +------832 B (00.00%) -- arena-headers
¦    ¦      ¦  +------408 B (00.00%) -- scripts
¦    ¦      ¦  +------320 B (00.00%) -- arena-padding
¦    ¦      +----7,616 B (00.00%) -- object-slots
¦    ¦      +----2,496 B (00.00%) -- property-tables
¦    ¦      +----1,344 B (00.00%) -- type-inference
¦    ¦      ¦    +--1,088 B (00.00%) -- object-main
¦    ¦      ¦    +----256 B (00.00%) -- tables
¦    ¦      +----1,120 B (00.00%) -- shape-kids
¦    ¦      +------576 B (00.00%) -- object-empty-shapes
¦    ¦      +-------48 B (00.00%) -- script-data
¦    +------169,120 B (00.01%) -- compartment(https://twimg0-a.akamaihd.net/a/1319563663/details_pane_content_sandbox.html?xdm_e=https%3A%2F%2Ftwitter.com&xdm_c=default5295&xdm_p=1)
¦    ¦      +---94,208 B (00.00%) -- gc-heap
¦    ¦      ¦   +--77,504 B (00.00%) -- arena-unused
¦    ¦      ¦   +---8,952 B (00.00%) -- objects
¦    ¦      ¦   +---6,200 B (00.00%) -- shapes
¦    ¦      ¦   +-----640 B (00.00%) -- type-objects
¦    ¦      ¦   +-----368 B (00.00%) -- arena-headers
¦    ¦      ¦   +-----272 B (00.00%) -- arena-padding
¦    ¦      ¦   +-----272 B (00.00%) -- scripts
¦    ¦      +---65,536 B (00.00%) -- mjit-code
¦    ¦      ¦   +--51,656 B (00.00%) -- unused
¦    ¦      ¦   +--12,904 B (00.00%) -- method
¦    ¦      ¦   +-----976 B (00.00%) -- regexp
¦    ¦      +----5,472 B (00.00%) -- object-slots
¦    ¦      +----1,280 B (00.00%) -- property-tables
¦    ¦      +----1,280 B (00.00%) -- shape-kids
¦    ¦      +------896 B (00.00%) -- type-inference
¦    ¦      ¦      +--640 B (00.00%) -- object-main
¦    ¦      ¦      +--256 B (00.00%) -- tables
¦    ¦      +------432 B (00.00%) -- object-empty-shapes
¦    ¦      +-------16 B (00.00%) -- script-data
¦    +-------35,976 B (00.00%) -- compartment(moz-nullprincipal:{96686e1a-c630-42d3-b111-9557c0df46ac})
¦    ¦       +--32,768 B (00.00%) -- gc-heap
¦    ¦       ¦  +--26,576 B (00.00%) -- arena-unused
¦    ¦       ¦  +---3,480 B (00.00%) -- objects
¦    ¦       ¦  +---2,240 B (00.00%) -- shapes
¦    ¦       ¦  +-----136 B (00.00%) -- scripts
¦    ¦       ¦  +-----128 B (00.00%) -- arena-headers
¦    ¦       ¦  +-----112 B (00.00%) -- arena-padding
¦    ¦       ¦  +------96 B (00.00%) -- type-objects
¦    ¦       +---2,544 B (00.00%) -- object-slots
¦    ¦       +-----256 B (00.00%) -- property-tables
¦    ¦       +-----160 B (00.00%) -- shape-kids
¦    ¦       +-----144 B (00.00%) -- object-empty-shapes
¦    ¦       +------96 B (00.00%) -- type-inference
¦    ¦       ¦      +--96 B (00.00%) -- object-main
¦    ¦       +-------8 B (00.00%) -- script-data
¦    +------------0 B (00.00%) -- gc-heap-chunk-clean-unused
+-----19,254,799 B (00.62%) -- dom
+-----16,851,679 B (00.54%) -- layout
¦     +---6,790,396 B (00.22%) -- shell(https://mail.mozilla.com/zimbra/?app=calendar#1)
¦     ¦   +--6,445,312 B (00.21%) -- arenas
¦     ¦   +----345,084 B (00.01%) -- styledata
¦     +---3,377,956 B (00.11%) -- shell(https://irccloud.com/#!/ircs://irc.mozilla.org:6697/%23developers)
¦     ¦   +--3,250,064 B (00.10%) -- arenas
¦     ¦   +----127,892 B (00.00%) -- styledata
¦     +---2,190,967 B (00.07%) -- shell(https://twitter.com/#!/mozillapeople/awesome)
¦     ¦   +--1,900,967 B (00.06%) -- arenas
¦     ¦   +----290,000 B (00.01%) -- styledata
¦     +-----815,276 B (00.03%) -- shell(chrome://browser/content/browser.xul)
¦     ¦     +--607,488 B (00.02%) -- arenas
¦     ¦     +--207,564 B (00.01%) -- styledata
¦     ¦     +------224 B (00.00%) -- textruns
¦     +-----726,328 B (00.02%) -- shell(https://wiki.mozilla.org/Features/Add-ons/Add-ons_Default_to_Compatible)
¦     ¦     +--460,112 B (00.01%) -- arenas [2]
¦     ¦     +--266,216 B (00.01%) -- styledata [2]
¦     +-----642,240 B (00.02%) -- shell(https://intranet.mozilla.org/2011Q4Goals#Strategic_goals)
¦     ¦     +--506,432 B (00.02%) -- arenas
¦     ¦     +--114,352 B (00.00%) -- styledata
¦     ¦     +---21,456 B (00.00%) -- textruns
¦     +-----446,816 B (00.01%) -- shell(chrome://global/content/console.xul)
¦     ¦     +--364,464 B (00.01%) -- arenas
¦     ¦     +---75,360 B (00.00%) -- styledata
¦     ¦     +----6,992 B (00.00%) -- textruns
¦     +-----415,988 B (00.01%) -- shell(https://wiki.mozilla.org/Firefox/Windows_8_Integration)
¦     ¦     +--282,880 B (00.01%) -- arenas
¦     ¦     +--133,108 B (00.00%) -- styledata
¦     +-----305,556 B (00.01%) -- shell(https://wiki.mozilla.org/Platform/Features/Firefox10Bugs)
¦     ¦     +--172,448 B (00.01%) -- arenas
¦     ¦     +--133,108 B (00.00%) -- styledata
¦     +-----303,024 B (00.01%) -- shell(https://intranet.mozilla.org/Vidyo)
¦     ¦     +--188,672 B (00.01%) -- arenas
¦     ¦     +--114,352 B (00.00%) -- styledata
¦     +-----201,240 B (00.01%) -- shell(about:blank)
¦     ¦     +--143,288 B (00.00%) -- styledata [2]
¦     ¦     +---57,952 B (00.00%) -- arenas [2]
¦     +-----185,008 B (00.01%) -- shell(about:memory)
¦     ¦     +---82,176 B (00.00%) -- arenas
¦     ¦     +---77,404 B (00.00%) -- styledata
¦     ¦     +---25,428 B (00.00%) -- textruns
¦     +-----118,252 B (00.00%) -- shell(https://mail.mozilla.com/zimbra/?app=calendar)
¦     ¦     +---83,788 B (00.00%) -- styledata
¦     ¦     +---34,464 B (00.00%) -- arenas
¦     +-----114,000 B (00.00%) -- shell(about:memory?verbose)
¦     ¦     +---77,404 B (00.00%) -- styledata
¦     ¦     +---36,480 B (00.00%) -- arenas
¦     ¦     +------116 B (00.00%) -- textruns
¦     +-----111,140 B (00.00%) -- shell(resource://gre-resources/hiddenWindow.html)
¦     ¦     +---68,388 B (00.00%) -- styledata
¦     ¦     +---42,752 B (00.00%) -- arenas
¦     +-----107,492 B (00.00%) -- shell(https://api.twitter.com/receiver.html)
¦           +---74,900 B (00.00%) -- styledata
¦           +---32,592 B (00.00%) -- arenas
+-----14,081,696 B (00.45%) -- storage
¦     +--14,081,696 B (00.45%) -- sqlite
¦        +---9,675,296 B (00.31%) -- places.sqlite
¦        ¦   +--9,347,392 B (00.30%) -- cache-used [4]
¦        ¦   +----276,744 B (00.01%) -- stmt-used [4]
¦        ¦   +-----51,160 B (00.00%) -- schema-used [4]
¦        +---1,003,928 B (00.03%) -- other
¦        +-----966,496 B (00.03%) -- cookies.sqlite
¦        ¦     +--954,752 B (00.03%) -- cache-used
¦        ¦     +----9,920 B (00.00%) -- stmt-used
¦        ¦     +----1,824 B (00.00%) -- schema-used
¦        +-----586,864 B (00.02%) -- webappsstore.sqlite
¦        ¦     +--527,272 B (00.02%) -- cache-used
¦        ¦     +---55,640 B (00.00%) -- stmt-used
¦        ¦     +----3,952 B (00.00%) -- schema-used
¦        +-----404,264 B (00.01%) -- signons.sqlite
¦        ¦     +--362,480 B (00.01%) -- cache-used
¦        ¦     +---38,904 B (00.00%) -- stmt-used
¦        ¦     +----2,880 B (00.00%) -- schema-used
¦        +-----376,592 B (00.01%) -- formhistory.sqlite
¦        ¦     +--329,592 B (00.01%) -- cache-used
¦        ¦     +---45,320 B (00.00%) -- stmt-used
¦        ¦     +----1,680 B (00.00%) -- schema-used
¦        +-----322,984 B (00.01%) -- chromeappsstore.sqlite
¦        ¦     +--264,048 B (00.01%) -- cache-used
¦        ¦     +---54,984 B (00.00%) -- stmt-used
¦        ¦     +----3,952 B (00.00%) -- schema-used
¦        +-----208,368 B (00.01%) -- content-prefs.sqlite
¦        ¦     +--197,984 B (00.01%) -- cache-used
¦        ¦     +----7,984 B (00.00%) -- stmt-used
¦        ¦     +----2,400 B (00.00%) -- schema-used
¦        +-----121,024 B (00.00%) -- extensions.sqlite
¦        ¦     +---99,256 B (00.00%) -- cache-used
¦        ¦     +---14,880 B (00.00%) -- stmt-used
¦        ¦     +----6,888 B (00.00%) -- schema-used
¦        +-----106,984 B (00.00%) -- downloads.sqlite
¦        ¦     +---99,256 B (00.00%) -- cache-used
¦        ¦     +----5,944 B (00.00%) -- stmt-used
¦        ¦     +----1,784 B (00.00%) -- schema-used
¦        +-----106,416 B (00.00%) -- permissions.sqlite
¦        ¦     +---99,264 B (00.00%) -- cache-used
¦        ¦     +----5,888 B (00.00%) -- stmt-used
¦        ¦     +----1,264 B (00.00%) -- schema-used
¦        +-----105,648 B (00.00%) -- search.sqlite
¦        ¦     +---99,248 B (00.00%) -- cache-used
¦        ¦     +----5,184 B (00.00%) -- stmt-used
¦        ¦     +----1,216 B (00.00%) -- schema-used
¦        +------96,832 B (00.00%) -- urlclassifier3.sqlite
¦               +--85,152 B (00.00%) -- stmt-used
¦               +---9,016 B (00.00%) -- cache-used
¦               +---2,664 B (00.00%) -- schema-used
+------4,759,840 B (00.15%) -- images
¦      +--4,344,284 B (00.14%) -- content
¦      ¦  +--4,344,284 B (00.14%) -- used
¦      ¦  ¦  +--2,696,381 B (00.09%) -- uncompressed-heap
¦      ¦  ¦  +--1,647,903 B (00.05%) -- raw
¦      ¦  ¦  +----------0 B (00.00%) -- uncompressed-nonheap
¦      ¦  +----------0 B (00.00%) -- unused
¦      ¦             +--0 B (00.00%) -- raw
¦      ¦             +--0 B (00.00%) -- uncompressed-heap
¦      ¦             +--0 B (00.00%) -- uncompressed-nonheap
¦      +----415,556 B (00.01%) -- chrome
¦           +--415,556 B (00.01%) -- used
¦           ¦  +--415,556 B (00.01%) -- uncompressed-heap
¦           ¦  +--------0 B (00.00%) -- raw
¦           ¦  +--------0 B (00.00%) -- uncompressed-nonheap
¦           +--------0 B (00.00%) -- unused
¦                    +--0 B (00.00%) -- raw
¦                    +--0 B (00.00%) -- uncompressed-heap
¦                    +--0 B (00.00%) -- uncompressed-nonheap
+------3,962,953 B (00.13%) -- network-memory-cache
+------2,316,824 B (00.07%) -- spell-check
+--------930,840 B (00.03%) -- xpti-working-set
+--------133,892 B (00.00%) -- history-links-hashtable
+---------35,944 B (00.00%) -- gfx
¦         +--35,944 B (00.00%) -- textrun-word-cache
+---------12,500 B (00.00%) -- cycle-collector

Other Measurements
          784 B -- canvas-2d-pixel-bytes
      309,356 B -- gfx-d2d-surfacecache
   15,883,608 B -- gfx-d2d-surfacevram
    3,147,640 B -- gfx-surface-image
            0 B -- gfx-surface-win32
2,946,708,552 B -- heap-allocated
2,982,277,120 B -- heap-committed
          1.19% -- heap-committed-unallocated-fraction
    2,883,584 B -- heap-dirty
  556,574,790 B -- heap-unallocated
              2 -- js-compartments-system
             11 -- js-compartments-user
  142,606,336 B -- js-gc-heap
   38,485,304 B -- js-gc-heap-arena-unused
            0 B -- js-gc-heap-chunk-clean-unused
   54,403,072 B -- js-gc-heap-chunk-dirty-unused
         65.13% -- js-gc-heap-unused-fraction
3,251,302,400 B -- private
1,818,308,608 B -- resident
    2,650,112 B -- shmem-allocated
    2,650,112 B -- shmem-mapped
4,122,492,928 B -- vsize
Comment 38 Kyle Huey [:khuey] (Exited; not receiving bugmail, email if necessary) 2011-10-26 14:02:39 PDT
Woah, something is seriously wrong with 91% heap-unclassified.
Comment 39 [:Cww] 2011-10-26 14:26:17 PDT
I should add that I'm on Mac and Asa is on Windows.  Not sure if it matters but it may not have been clear from my earlier posts.
Comment 40 Boris Zbarsky [:bz] (still a bit busy) 2011-10-26 14:46:21 PDT
Nicholas, I assume running under DMD is too slow for Asa to just do it for a few days so we can see where that unclassified number comes from?  :(
Comment 41 Nicholas Nethercote [:njn] 2011-10-26 15:55:55 PDT
(In reply to Boris Zbarsky (:bz) from comment #40)
> Nicholas, I assume running under DMD is too slow for Asa to just do it for a
> few days so we can see where that unclassified number comes from?  :(

Yeah, it's painfully slow, and it doesn't work on Windows.

I'll echo khuey: 91% heap-unclassified is *bizarre*.  Something is seriously wrong.
Comment 42 Justin Lebar (not reading bugmail) 2011-10-26 16:06:13 PDT
I've sent the irccloud guys an e-mail asking if we can get an account for testing.  Maybe it's doing something weird to us?
Comment 43 Justin Lebar (not reading bugmail) 2011-10-26 16:11:52 PDT
Well, that was fast.  Asa and ttaubert have invites, but the site sent me an invite as soon as I requested one.

I'm also happy to send my login credentials over a private channel.
Comment 44 Blair McBride [:Unfocused] (UNAVAILABLE) 2011-10-26 17:09:38 PDT
I also use IRCCloud, and have invites available. Although, I closed the IRCCloud tab and restarted the browser yesterday, and the symptoms persisted.
Comment 45 Justin Lebar (not reading bugmail) 2011-10-26 18:05:22 PDT
irccloud doesn't seem to be causing high heap-unclassified for me.
Comment 46 Randell Jesup [:jesup] 2011-10-26 21:20:01 PDT
(In reply to Randell Jesup [:jesup] from comment #35)
> Appears to reproduce after days to maybe a week.  Seems to be slowly
> climbing since I restarted yesterday: CC 315, now 450 usually, GC 150-180,
> now 225 - but CC of 1/3-1/2 second is pretty darn long when typing.  Up <24
> hours, 29 tabs loaded of 705.  (Started at 16 loaded).  RSS was 1.15GB right
> after start, now 1.5GB; biggest grower was G+ (20->82MB).  Note that I
> disabled tbpl (closed the app tab) a day or two before restarting, though
> mem use continued to grow I believe.

Ok, with no tbpl use, 9 hours later (and 42 tabs loaded now = +13), I'm at 1.9GB RSS and it's mostly ~670ms CC, but moderately frequent spikes to 1.25s.  GC ~290ms.

650ms pauses while typing are very noticable.  Even 300 is annoying.  1.2s pauses are painful and lead to typing errors.

If perchance this is *not* a bug, but a fact of life with large numbers of (unloaded) tabs, we may need to rethink our UI and how many tabs we let/encourage the user open.  I do believe much of the progressive problem here is a bug, though.
Comment 47 Andrew McCreight [:mccr8] 2011-10-27 08:30:49 PDT
Asa reported in IRC that this morning his computer was experiencing the same symptoms (90%+ heap-unclassified, huge memory usage, browser soon crashing from apparent OOM).
Comment 48 :Ehsan Akhgari 2011-10-27 08:54:21 PDT
I hit this problem today.  Firefox was using about 1.37 gigs but I was hitting really bad pauses.  I closed facebook, gmail, and TBPL in that order, which reclaimed about 300gigs for me, but then I noticed that the browser is responsive again.  So I think that one of these three websites could be the culprit...
Comment 49 Kyle Huey [:khuey] (Exited; not receiving bugmail, email if necessary) 2011-10-27 08:56:09 PDT
I use all three of those, but I don't keep TBPL open any longer than I have to, so I suspect that Ehsan's problems are related to TBPL and distinct from Asa/Cww's (which are probably also not the same).
Comment 50 [:Cww] 2011-10-27 09:55:48 PDT
Tried earlier builds yesterday afternoon/evening

10.0a1 (2011-10-25)
(After about an hour of moderate browsing, same session, I didn't get startup info)
GC: 800-1400 ms
CC: 200-400 ms

10.0a1 (2011-10-20)
startup
GC: ~ 400 ms
CC ~ 100-200 ms
After ~ 2 hours of browsing.
GC: 500-800 ms
CC: 150-200 ms

10.0a1 (2011-10-26)
startup
GC: ~ 400-500ms
CC: 90-150ms
3-4 hours later
GC: ~ 2500-4000 ms
CC: 200-400 ms


startup means after starting the browser and restoring all open tabs (that is going through and clicking on all the tabs to make sure they load).
Comment 51 Andrew McCreight [:mccr8] 2011-10-28 13:20:03 PDT
Gavin is getting similar symptoms.  Normal level of heap-unclassified, but a large CC graph, very long GC times, long-ish CC times.

gavin: CYCLE_COLLECTOR_VISITED_GCED
[1:12pm] gavin: 11343 samples, average = 217136.1, sum = 2462974704
[1:12pm] gavin: CYCLE_COLLECTOR_VISITED_REF_COUNTED
[1:12pm] gavin: 11343 samples, average = 144313.9, sum = 1636952291

GC mode: full, timestamp: 1319832336464496, duration: 3378 ms.
[1:06pm] gavin: CC timestamp: 1319832345131485, collected: 0 (0 waiting for GC), suspected: 894, duration: 710 ms.
[1:07pm] gavin: GC mode: full, timestamp: 1319832412238167, duration: 4528 ms.

[1:15pm] gavin: mccr8: 977.58 MB (27.05%) -- heap-unclassified
Comment 52 Andrew McCreight [:mccr8] 2011-10-28 13:36:17 PDT
(In reply to [:Cww] from comment #50)
> Tried earlier builds yesterday afternoon/evening

Thanks for doing this!  It looks like something may have landed between 10-10 and 10-25 that cause problems.
Comment 53 Nicholas Nethercote [:njn] 2011-10-30 20:24:23 PDT
A stupid question:  does pinning a site as an app tab change anything about how it uses memory?
Comment 54 Dão Gottwald [:dao] 2011-10-31 01:41:03 PDT
(In reply to Nicholas Nethercote [:njn] from comment #53)
> A stupid question:  does pinning a site as an app tab change anything about
> how it uses memory?

No, except for bug 674452.
Comment 55 Andrew McCreight [:mccr8] 2011-11-01 12:42:13 PDT
Asa, is this still causing problems for you?  If it does, could you provide me with a cycle collector heap dump?  The directions for this are here:  https://wiki.mozilla.org/Performance:Leak_Tools#Cycle_collector_heap_dump

It requires that you have write access for the current working directory, so you may have to change the working directory, or run Firefox as administrator.  Unfortunately due to a bug I introduced, Firefox will crash if it can't successfully dump a CC log, so watch out for that...
Comment 56 Asa Dotzler [:asa] 2011-11-01 15:33:19 PDT
(In reply to Andrew McCreight [:mccr8] from comment #55)
> Asa, is this still causing problems for you?  If it does, could you provide
> me with a cycle collector heap dump?

Yes. And I will try to get you a heap dump as soon as I have a minute free.
Comment 57 Alex Limi (:limi) — Firefox UX Team 2011-11-01 15:39:15 PDT
I don't use IRCloud, and I'm seeing the following:

CYCLE_COLLECTOR_COLLECTED: 3907 samples, average = 1955.4
CYCLE_COLLECTOR_VISITED_GCED: 3907 samples, average = 80663.6
CYCLE_COLLECTOR_VISITED_REF_COUNTED: 3907 samples, average = 94497.1, sum = 369200284

OS X reports that I'm using ~1.2 GB, and about:memory shows:

690.16 MB (100.0%) -- explicit
├──832.62 MB (120.64%) -- js
│  ├──238.87 MB (34.61%) -- gc-heap-chunk-dirty-unused
│  ├──110.50 MB (16.01%) -- compartment([System Principal], 0x1009fe400)

I also have a zombie Yammer tab that isn't open anywhere that I can find (used search in Panorama, it's not there), it looks like this:

│  ├──106.29 MB (15.40%) -- compartment(https://www.yammer.com/mozilla.com/#/threads/index?type=all)
│  │  ├───70.73 MB (10.25%) -- gc-heap

Let me know if there are other numbers from about:memory or about:telemetry that would be interesting. I'll leave it running as long as I can.

(This is UX channel, which is similar to Nightly)
Comment 58 Justin Lebar (not reading bugmail) 2011-11-01 15:46:31 PDT
Whoa, major about:memory bug if js is greater than explicit.  Can youp lease post the full about:memory dump?  You can e-mail it to me if you want me to strip out the full URLs.
Comment 59 Andrew McCreight [:mccr8] 2011-11-01 15:52:19 PDT
The wrongness of Limi's about:memory doesn't stop at that JS number, as his total heap-unclassified is -60%:  -439,490,805 B (-60.66%) -- heap-unclassified
Comment 60 Nicholas Nethercote [:njn] 2011-11-01 16:07:43 PDT
heap-unclassified is derived from others, so it's bogus because some of the others are bogus.  

As jlebar said, we need the full about:memory?verbose dump, please!
Comment 61 Justin Dolske [:Dolske] 2011-11-01 16:43:13 PDT
Created attachment 571186 [details]
About:memory (Dolske)

Le sigh, this seems to be the bug for what I've seen seeing too.

Attached is the verbose about:memory, right after I wrote the below...

The only addons I have are Mass Password Reset, DOM Inspector, and About:Telemetry. I disabled Bugzilla JS a while ago thinking it might be the cause (no change), and recently installed Firefox Share... Presumably those two are not involved unless they're both doing something similar. [Though now that I'm looking at about:memory, I see LOTS of fx-share stuff there. I'm going to disable it, but this issue definately predates Share.]

Not sure I have any particularly interesting stuff open in the browser... The usual Mozilla sites we all have. Pinned Google Reader, Zimbra Calendar, Twitter, Yammer. Usually 40-50 tabs open, and another 40 in other tab groups (which I haven't actually touched this session, they're all still blank in panorama).

Lots of 100-200ms CC runs, maybe 10% hit 400-700ms. GCs consistently above 500ms. Last few lines:

GC mode: full, timestamp: 1320190310320173, duration: 564 ms.
CC timestamp: 1320190315452792, collected: 292 (292 waiting for GC), suspected: 2841, duration: 131 ms.
GC mode: full, timestamp: 1320190320734530, duration: 1281 ms.
CC timestamp: 1320190325936399, collected: 288 (288 waiting for GC), suspected: 2095, duration: 183 ms.
Comment 62 Justin Lebar (not reading bugmail) 2011-11-01 16:49:25 PDT
The only addons that I have any confidence *don't* leak are Adblock Plus and about:telemetry.  Even simple addons often cause massive leaks.  So it would be helpful to know whether you can reproduce with only about:telemetry enabled.

I wonder if Panorama use is common to the people here who have been seeing large CC times.
Comment 63 Justin Dolske [:Dolske] 2011-11-01 16:49:47 PDT
(I should also note that was for the 10/29 OS X Nightly)
Comment 64 Olli Pettay [:smaug] (way behind * queues, especially ni? queue) 2011-11-01 16:59:25 PDT
It would help greatly if someone seeing this could try to figure out more exact regression range than
what is in comment 50.
(I know, it is hard to find the regression range for this kind of problem)
Comment 65 Bill McCloskey (:billm) 2011-11-01 17:05:29 PDT
Sadly, I think bisection is the only way we'll track this down. It may be an add-on problem, but it doesn't really sound like it so far. It's hard to tell from :Cww's results whether this started before or after the 10-20 nightly.
Comment 66 Boris Zbarsky [:bz] (still a bit busy) 2011-11-01 17:23:53 PDT
"explicit" is just bogus on 10.7, as far as I can tell.  That came up earlier today: on a page that I _know_ takes over a gig of RAM about:memory was listing 30MB for a user under "explicit".
Comment 67 Nicholas Nethercote [:njn] 2011-11-01 17:27:23 PDT
I filed bug 698953 for the bogus about:memory values.  Let's keep this bug about the GC/CC pause times.
Comment 68 [:Cww] 2011-11-01 17:48:09 PDT
I took the weekend off (birthdays and all that) and accidentally trashed my session.  I've been using release Firefox all day so I can't say if it's happening with a new session. 

I do have the old session backed up and will restore to see if it re-occurs, if necessary.

jlebar: I don't use panorama and haven't in a long time, but I may be a unique case since it's my GC that's taking forever.
Comment 69 Asa Dotzler [:asa] 2011-11-01 19:39:10 PDT
(In reply to Justin Lebar [:jlebar] from comment #62)
> I wonder if Panorama use is common to the people here who have been seeing
> large CC times.

I don't use Panorama.
Comment 70 Aaron Kaluszka 2011-11-01 20:12:45 PDT
I am seeing this, and I don't use Panorama, IRCloud, or pinned tabs. I am seeing major memory thrashing, where ~100MB is quickly allocated and deallocated, according to Windows Task Manager, when doing something simple like bringing an blank tab into focus.
Comment 71 Justin Dolske [:Dolske] 2011-11-01 20:29:17 PDT
I restarted earlier with addons disabled, and am currently getting such data as:

CC timestamp: 1320204042128245, collected: 288 (288 waiting for GC), suspected: 1112, duration: 353 ms.
GC mode: full, timestamp: 1320204046544133, duration: 420 ms.
CC timestamp: 1320204051621798, collected: 355 (355 waiting for GC), suspected: 1989, duration: 77 ms.
GC mode: full, timestamp: 1320204056174524, duration: 552 ms.

I'm happy to start (slowly) bisecting by running old builds for a while and checking to see how they feel. I'm not sure how to make a good/bad call based just on CC/GC numbers, though. For builds within the past few weeks (which is my gut guess for when this might have started), is there a "normal" CC/GC range that's expected, given my environment in comment 61? Or is that just too hard to define?
Comment 72 Randell Jesup [:jesup] 2011-11-01 22:33:29 PDT
(In reply to Aaron Kaluszka from comment #70)
> I am seeing this, and I don't use Panorama, IRCloud, or pinned tabs. I am
> seeing major memory thrashing, where ~100MB is quickly allocated and
> deallocated, according to Windows Task Manager, when doing something simple
> like bringing an blank tab into focus.

Just to rule out something: what's the size of sessionstore.js in your profile?  Saving sessionstore temporarily grabs 3-5x the size of the file.
Comment 73 Aaron Kaluszka 2011-11-02 00:06:23 PDT
Ah, it's 19MB, so that could explain that part.
Comment 74 Randell Jesup [:jesup] 2011-11-02 07:04:47 PDT
Aaron: see bug 669034 and bug 669603 for large sessionstore.js issues.  (How many tabs do you have open?  Is hidden google search state data using up most of that, or is it another site?  Discussion should probably move to one of those bugs.)
Comment 75 Bill McCloskey (:billm) 2011-11-02 15:09:19 PDT
After talking to Andrew today, I think it might be useful if people who are experiencing long GC times could post GC_MARK_MS and GC_SWEEP_MS from the about:telemetry add-on.
Comment 76 Blair McBride [:Unfocused] (UNAVAILABLE) 2011-11-02 15:23:41 PDT
Created attachment 571475 [details]
about:telemetry extract (Unfocused)
Comment 77 Kyle Huey [:khuey] (Exited; not receiving bugmail, email if necessary) 2011-11-04 08:04:14 PDT
Peter says it's *possible* that this behavior is a result of Bug 699796.
Comment 78 Andrew McCreight [:mccr8] 2011-11-07 09:09:17 PST
Bug 699668 is a possible cause of long GC times.  It was causing an increase of about 100ms for me, which is an increase of 50% to 100%.
Comment 79 Andrew McCreight [:mccr8] 2011-11-07 09:40:47 PST
bz was getting multi-second CC times, and he sharked it.  50% of the 1 second segment he sharked time was spent in XPCWrappedNative traversal.  In a normal run, I see about 2.4% of CC time spent on that, so it sounds like his set of XPConnect roots is exploding.

He was also seeing high numbers for some other things, such as nsXULElement traversal (16% vs the 2% I am seeing in a normal run, which is even worse considering that my shark run probably covers about around 100ms).
Comment 80 Randell Jesup [:jesup] 2011-11-07 10:21:45 PST
Created attachment 572516 [details]
jprof of 2.2s CC time

I'm up to ~2.2s CC, 500ms GC.  I took a jprof @ 2ms sampling; something like 15 seconds of CPU time were sampled:

(63.6%) nsCycleCollectorRunner::Run()
 (58.4%) GCGraphBuilder::Traverse(PtrInfo*)
  (27.0%) nsXPConnect::Traverse()
    (21.0%) js::gc::MarkChildren()
      (18.5%) GCGraphBuilder::NoteScriptChild()  (includes other sources)
        (19.9%) GCGraphBuilder::AddNode (includes yet more sources)

(15.1%) js_GC()
Comment 81 Randell Jesup [:jesup] 2011-11-07 10:27:46 PST
Probably an expected side-effect, but this is a top routine with almost 8% in this alone, another 7% in things called by it.

568 (7.8%)      1074 (14.9%) TraverseExpandoObjects()

That accounts for almost all the time used by 
1206 (16.7%) XPCWrappedNative::cycleCollection::Traverse()
(via PL_DHashTableEnumerate)
Comment 82 Boris Zbarsky [:bz] (still a bit busy) 2011-11-07 11:34:17 PST
Yes, that's what I was seeing too.  I'm trying to get better data now; it might take me a few days to get back into that state...
Comment 83 Nicholas Nethercote [:njn] 2011-11-08 00:42:52 PST
Asa told me the following via email:

> I've found the culprit on my crazy unclassified heap numbers (like below) 
>
> 1,882.61 MB (100.0%) -- explicit
> ├──1,681.80 MB (89.33%) -- heap-unclassified
>
> It happens when I've been using IRC Cloud for a day or two. I discovered 
> today that when it gets bad, if I reload my IRC Cloud tab, the numbers
> return to something very normal immediately. I've just tested a second
> time and both times the reloading of IRC Cloud got the heap unclassified
> down to about 17% and the total memory back to very normal as well.
>
> Is this some kind of leak from that web app? Can I help figure out why 
> it's leaking into "unclassified" rather than something more normal? Is
> that even useful?

The first step is to try to reproduce this, then maybe I can point DMD at it.  I'm going to run IRCCloud for a couple of days on my Linux box.  (jlebar, if you want to try again, just be warned that your account deactivates if you don't use it for two days(!)  But you can still invite up to 3 other people, so I just sent myself an invitation to a different email address.)

It's not clear if these huge heap-unclassified numbers correlate with the large CC times Asa was seeing.
Comment 84 Kyle Huey [:khuey] (Exited; not receiving bugmail, email if necessary) 2011-11-08 04:23:27 PST
Can we split IRCCloud out into a separate bug?
Comment 85 Andrew McCreight [:mccr8] 2011-11-08 06:14:52 PST
I'll do that.  Thanks for looking into this, Asa!
Comment 86 Andrew McCreight [:mccr8] 2011-11-08 06:23:57 PST
I filed bug 700647 for this.

To everybody reading this thread who is having problems, try updating to today's nightly, whenever that happens.  Peterv landed a number of leak fixes yesterday that might help with some of these problems.
Comment 87 Peter Van der Beken [:peterv] 2011-11-08 07:07:58 PST
Do we report anything about wrappers, in particular XPCWrappedNatives and things like the expando hashes, in the memory reports? It seems like we're traversing a lot of those based on the profiles, so that might explain some of the heap-unclassified?
Comment 88 Andrew McCreight [:mccr8] 2011-11-08 07:13:44 PST
I'm not sure if we are or not, but only Asa was seeing particularly high heap-unclassified numbers.
Comment 89 Peter Van der Beken [:peterv] 2011-11-08 07:54:17 PST
(In reply to Randell Jesup [:jesup] from comment #81)
> Probably an expected side-effect, but this is a top routine with almost 8%
> in this alone, another 7% in things called by it.
> 
> 568 (7.8%)      1074 (14.9%) TraverseExpandoObjects()
> 
> That accounts for almost all the time used by 
> 1206 (16.7%) XPCWrappedNative::cycleCollection::Traverse()
> (via PL_DHashTableEnumerate)

I filed bug 700668 on this. We might be doing some unnecessary work here.
Comment 90 Nicholas Nethercote [:njn] 2011-11-08 11:41:18 PST
(In reply to Peter Van der Beken [:peterv] from comment #87)
> Do we report anything about wrappers, in particular XPCWrappedNatives and
> things like the expando hashes, in the memory reports? It seems like we're
> traversing a lot of those based on the profiles, so that might explain some
> of the heap-unclassified?

We don't, they've never shown up very high in DMD profiles, but the runs I've been doing with DMD have been short and small because it's so slow.  Some kind of lightweight profiling (e.g. inserting debugging printfs into the relevant code) to test the hypothesis would be useful.
Comment 91 Nicholas Nethercote [:njn] 2011-11-08 11:42:13 PST
BTW, Asa filed bug 700645 about the heap-unclassified blow-up on irccloud (comment 83).
Comment 92 DB Cooper 2011-11-08 14:03:22 PST
Hmm, I have recently been noticing occasional long pauses and big increases in heap-unclassified size with the nightly moz-central builds (including todays) when switching to my pinned google reader app tab. e.g.

After I switched from about:memory to my google reader app tab, memory use jumped about 120MB.

    321.66 MB (100.0%) -- explicit
    ├──161.30 MB (50.15%) -- heap-unclassified
    ├──109.69 MB (34.10%) -- js


Heap unclassified returned to about 70MB after ~ 20 s after switching back to about:memory. Clicking "minimize memory usage" did little, but entering then leaving private browsing mode reduced it to ~ 30MB.
Comment 93 Andrew McCreight [:mccr8] 2011-11-10 10:53:28 PST
I filed bug 701443 for a leak similar to what Asa found, with a specific page.
Comment 94 Alex Limi (:limi) — Firefox UX Team 2011-11-10 23:37:15 PST
Created attachment 573757 [details]
After running for less than a day, Mozilla/5.0 (Macintosh; Intel Mac OS X 10.7; rv:11.0a1) Gecko/20111109 Firefox/11.0a1

Attaching my about:memory output, seeing this again. I do have share installed, but not using IRCloud.

Telemetry data:

CYCLE_COLLECTOR
2267 samples, average = 174.2, sum = 394895

CYCLE_COLLECTOR_COLLECTED
2267 samples, average = 388.1, sum = 879788

CYCLE_COLLECTOR_VISITED_GCED
2267 samples, average = 34388.2, sum = 77957989

CYCLE_COLLECTOR_VISITED_REF_COUNTED
2267 samples, average = 115522.5, sum = 261889404
Comment 95 Justin Lebar (not reading bugmail) 2011-11-11 07:11:56 PST
limi, we need a cc dump and your list of extensions, please.

https://wiki.mozilla.org/Performance:Leak_Tools#Cycle_collector_heap_dump
Comment 96 Philipp von Weitershausen [:philikon] 2011-11-13 21:32:15 PST
FWIW, I see very the same behaviour as limi does. I just have to leave Nightly running on my Macbook for a day. I don't even use it much, maybe an hour or two. The rest of the time it's just sitting there doing nothing. I come back the next day and it's dog slow. As in, entering things into form fields has *considerable* lag. GC/CC times are up to 500-1000 ms.

I run the following add-ons:

Adblock Plus
Firefox Share
Mass Password Reset
Vertical Tabs

(In reply to Justin Lebar [:jlebar] from comment #95)
> https://wiki.mozilla.org/Performance:Leak_Tools#Cycle_collector_heap_dump

I tried doing that. It crashed my browser every single time. See e.g. https://crash-stats.mozilla.com/report/index/bp-8a8c131b-c860-41a6-887c-fb6c82111113. Should I file this?
Comment 97 Andrew McCreight [:mccr8] 2011-11-13 21:39:39 PST
(In reply to Philipp von Weitershausen [:philikon] from comment #96)
> I tried doing that. It crashed my browser every single time. See e.g.
> https://crash-stats.mozilla.com/report/index/bp-8a8c131b-c860-41a6-887c-
> fb6c82111113. Should I file this?
That sounds like bug 694436.  The CC dump goes to the current working directory, and unfortunately if you don't have write access it ends up crashing the browser.  If you invoke the browser say from the command line in a directory you have write access to, it should work.
Comment 98 Olli Pettay [:smaug] (way behind * queues, especially ni? queue) 2011-11-13 22:20:02 PST
philikon, could you perhaps try running several instances of Firefox (from different dates) using same
(cloned) profile. That might help with regression range hunting.
Comment 99 Philipp von Weitershausen [:philikon] 2011-11-13 22:25:45 PST
(In reply to Andrew McCreight [:mccr8] from comment #97)
> That sounds like bug 694436.  The CC dump goes to the current working
> directory, and unfortunately if you don't have write access it ends up
> crashing the browser.  If you invoke the browser say from the command line
> in a directory you have write access to, it should work.

Alright, will do.

(In reply to Olli Pettay [:smaug] from comment #98)
> philikon, could you perhaps try running several instances of Firefox (from
> different dates) using same (cloned) profile. That might help with regression
> range hunting.

Sure. Which dates should I get?
Comment 100 Olli Pettay [:smaug] (way behind * queues, especially ni? queue) 2011-11-13 22:33:06 PST
I'd start with latest 9b, some build from a month ago, an something a bit newer.
Comment 101 Tim Taubert [:ttaubert] 2011-11-24 15:39:37 PST
Created attachment 576835 [details]
about:memory (ttaubert)

I'm seeing the same problem. I have CC times from 400-900ms and thus serious lags while typing, scrolling, etc. Sometimes it's even as high as:

CC(T+2363.2) collected: 164355 (164355 waiting for GC), suspected: 3366, duration: 1863 ms.

I'm running UX Nightly 11.0a1 (2011-11-22) on Mac with the following add-ons:

about:telemetry 0.6
Adblock Plus 1.3.10
Add-on Compatibility Reporter 1.0
AutoAuth 2.1
Bugzilla Tweaks 1.11.3
Easy App Tabs 4
Facebook Auto-Logout 0.2
Hide Facebook News Ticker 0.1.1

Here's a link to my cc dump:

http://timtaubert.de/wp-content/cc-edges.log.zip
Comment 102 Johnny Stenback (:jst, jst@mozilla.com) 2011-11-24 16:16:49 PST
Tim, can you reproduce the problems with all those extensions disabled? I hear there's a known leak in Adblock plus, which has been fixed in a beta release, but not pushed to the public yet. Either way, we'd love to know if you see these problems without any extensions.
Comment 103 Andrew McCreight [:mccr8] 2011-11-24 17:48:13 PST
Tim's problem looks like this is another instance of bug 700645, as he has IRCcloud in there.  He also has over 2700 separate DOMs that are not in documents.  One I checked was from IRCcloud, but another associated with Twitter has 5000 nodes in it.  Most of the DOM clumps are node as big as jlebar had, around a couple hundred.

There are large DOMs, like one with 144k nodes associated with IRCcloud and one with 55k associated with Twitter, that are being traversed.  It seems like currently-viewable window is falling down here, or these are zombie documents.
Comment 104 Andrew McCreight [:mccr8] 2011-11-24 17:48:45 PST
"are node as big" should be "are not as big".
Comment 105 Andrew McCreight [:mccr8] 2011-11-24 17:55:37 PST
(In reply to Andrew McCreight [:mccr8] from comment #103)
> There are large DOMs, like one with 144k nodes associated with IRCcloud and
> one with 55k associated with Twitter, that are being traversed.  It seems
> like currently-viewable window is falling down here, or these are zombie
> documents.

Wait, never mind, this optimization is disabled when doing a CC dump, so it is probably not being traversed in a real CC.  Sorry.
Comment 106 Alex Keybl [:akeybl] 2012-01-06 13:40:56 PST
Andrew - what's the next step here? Thanks!
Comment 107 Andrew McCreight [:mccr8] 2012-01-06 14:09:28 PST
Probably to check up and see if people are still having these problems.  Asa's problem was IRCCloud, which has been spun off into a new bug.  (As of a few weeks ago, that was still causing problems.)

Cww, philikon, limi, ttaubert, are you still experiencing long CC or GC pauses?  There have been a few fixes and improvements landed in the last month.  Randell and his mega profile is probably still out of luck, but I'd still be interested to hear if he feels it is any better or not.
Comment 108 Andrew McCreight [:mccr8] 2012-01-06 14:10:26 PST
I've heard less complaining recently, but maybe this has just become the "new normal", which would be bad...
Comment 109 Andrew McCreight [:mccr8] 2012-01-09 15:36:19 PST
Cww had the worst symptoms.  Jesse talked to him today, and apparently Cww thinks the horrible CC and GC times he was getting (multiple seconds) was due to some Greasemonkey script that serialized the content of all tabs into some kind of data structure, then did some kind of regexp search.  And it did this every few seconds.  That would certainly cause insane garbage, which would cause long CC and GC times.  Cww said he would try disabling that and see if GC and CC performance holds up.
Comment 110 Andrew McCreight [:mccr8] 2012-01-10 09:28:05 PST
More details, from Jesse on Twitter: "A Greasemonkey script called “TeX the World” was slowing @chengwang’s Firefox to a crawl. It serializes every tab’s DOM every 3 seconds!"
Comment 111 [:Cww] 2012-01-11 10:58:55 PST
Actually the script isn't the (only) problem.  I used to get the hangs after 2 hours of browsing and have CCs take 4-7 seconds.  Now it's more like 4-5 hours of browsing and hangs are 2-3 seconds.  Still unusably bad.
Comment 112 Andrew McCreight [:mccr8] 2012-01-11 12:29:55 PST
blassey is also having this problem.  His symptoms are generally similar to Cww's: after about 4 hours of browsing, his CC times get longer.  His GC times are also pretty long (around 800ms), and spend a disturbing amount of time in sweep and disanl.  Bill and I looked at his CC log a tiny bit, and our current theory is that a live DOM is holding onto a ton of JS that isn't reachable otherwise, which causes the CC to fall apart.  His CC graphs are huge, but are mostly JS.

Unlike CWW and some other cases I've seen, blassey has almost no addons.  He has about:telemetry and some kind of bugzilla-related thing (bugzilla tweaks maybe?).  The latter could be a problem, I guess.

The other thing of note here is that both blassey and CWW use a ton of tabs, 40+.  bz and jesup, who also have had similar problems, also use a lot of tabs.
Comment 113 Olli Pettay [:smaug] (way behind * queues, especially ni? queue) 2012-01-11 21:47:20 PST
Yet tab usage itself isn't necessarily causing the problems.
I use lots of tabs, and haven't had the problems.
Comment 114 Andrew McCreight [:mccr8] 2012-01-17 20:41:34 PST
No real MemShrink issue was identified here.  The initial report appears to mostly be a leaky webapp that the CC can't handle well.  We did identify the need to track memory usage of orphan DOM nodes, which is being tracked in bug 704623.
Comment 115 (dormant account) 2012-01-19 16:01:07 PST
Andrew, can you snappy-prioritize this?
Comment 116 Alex Keybl [:akeybl] 2012-02-15 16:54:32 PST
This was originally tracked for FF10 because we thought it may be related to recent OS X hang regressions. That doesn't appear to be the case. No need to track for a specific release at this point.
Comment 117 Andrew McCreight [:mccr8] 2012-02-16 11:56:23 PST
This is kind of an amorphous bucket of problems with CC and GC slowness.  We carved out some concrete bits of other bugs, so I'm inclined to just close this one.  If you are experiencing CC slowness, please file a new bug and CC me.  Thanks.

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