Closed
Bug 752259
Opened 13 years ago
Closed 13 years ago
Huge, 100MB+ Memory Usage Regression In Recent Nightly
Categories
(Firefox :: Untriaged, defect)
Tracking
()
RESOLVED
FIXED
People
(Reporter: danne.da, Unassigned)
References
Details
(Keywords: regression, Whiteboard: [MemShrink])
Attachments
(8 files)
User Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.6; rv:15.0) Gecko/15.0 Firefox/15.0a1
Build ID: 20120505030510
Steps to reproduce:
The memory usage jumped by over 100 MB just after browser start in the re-spin that came out before today's (2012-05-05) nightly build. This also happens on a completely fresh profile with no extensions. In fact the memory usage with the latest build is higher without any extensions than it is with a previous build with a dozen or extensions. On a clean profile that represents a memory usage regression of over 200%.
The rather large pushlog is here: http://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=2db9df42823d&tochange=9ebf3dc839c5
I'll try a few hourly builds to see if I can narrow it down a little further.
I've narrowed it down to this: http://hg.mozilla.org/integration/mozilla-inbound/pushloghtml?fromchange=ac00c792933e&tochange=bed8c4e3dfdf
Looks like Compartment-Per-Global (bug 650353) is to blame.
Comment 2•13 years ago
|
||
CPG does impact memory, but should only do so at the level of 3-5%.
Memshrink guys, can you work with d.a. to get more data on precisely what's changing? I'm not an expert on that stuff, so I don't know what about:memory numbers to ask for.
Comment 3•13 years ago
|
||
Thanks for the report, d.a. Could you attach the contents of about:memory?verbose from the above changeset where you are seeing the increase? It also might help to attach one from before that. about:memory was broken in there at some point, so if it isn't working there, just use about:memory from a recently nightly. If you could past each into a file and attach it to this bug, that would be a little easier to deal with. This is just startup memory?
Keywords: regression
Whiteboard: [MemShrink]
Comment 4•13 years ago
|
||
FWIW, I see only a small regression on AWSY (Linux64) [1].
There was a big jump in "RSS: After TP5, tabs closed [+30s]" (red line) -- zoom in to the RHS of the graph, around cset ec3c29434dee. It appears to have come back down. There isn't a corresponding jump in startup memory usage, though.
https://areweslimyet.com/
Comment 5•13 years ago
|
||
I thought CPG broke Mozmill, so I don't know if AWSY has actually updated properly.
Comment 6•13 years ago
|
||
Of course we have no telemetry for MEMORY_RESIDENT for Darwin from the past week. Naturally. The data from Windows doesn't show a big spike.
My RSS is 200mb (10.7) on startup. That does seem high, although I don't have a baseline.
Comment 7•13 years ago
|
||
(In reply to Andrew McCreight [:mccr8] from comment #5)
> I thought CPG broke Mozmill, so I don't know if AWSY has actually updated
> properly.
Maybe it's wrong, but we do have data up to 5/5/12.
Comment 8•13 years ago
|
||
I had added a workaround for the broken mozmill functions to AWSY, so the data should be up to date
Comment 9•13 years ago
|
||
(In reply to John Schoenick [:johns] from comment #8)
> I had added a workaround for the broken mozmill functions to AWSY, so the
> data should be up to date
Awesome!
![]() |
||
Comment 10•13 years ago
|
||
Similar to previous comments, compared about:memory on membuster before/after and see only a 1.8% regression.
Reporter | ||
Comment 11•13 years ago
|
||
Here is the about:memory (verbose) of the good build (http://hg.mozilla.org/integration/mozilla-inbound/rev/ac00c792933e) and looking at the Activity Monitor it peaks at 250 MB and stabilizes at around 230 MB.
The bad build (http://hg.mozilla.org/integration/mozilla-inbound/rev/bed8c4e3dfdf) it peaks at 390 MB and stabilizes at 370 MB. Simply opening about:memory drops this down to 310 MB, so some 60 MB is de-allocated here.
Reporter | ||
Comment 12•13 years ago
|
||
Reporter | ||
Comment 13•13 years ago
|
||
I don't know if this is related to this bug, but with the bad build I'm seeing a horrible performance regression, when loading pages. Activity Monitor shows Firefox using 110-120% (of 200%) of the CPU, if there are enough tabs being loaded Firefox becomes unresponsive for some time. With the good build this doesn't happen.
Comment 14•13 years ago
|
||
i have also a memory increase about 70-80% on clean Profile.
Comment 15•13 years ago
|
||
Comment 16•13 years ago
|
||
I should write an about:memory diff script. Anyways, here are a few before and after things I noticed that are pretty different. (ignore the ASCII art part of it)
Before:
177,353,368 B (100.0%) -- explicit
├──103,297,760 B (58.24%) -- js
│ ├───17,883,136 B (10.08%) ── gc-heap-decommitted
├───43,287,998 B (24.41%) ── heap-unclassified
├───17,352,632 B (09.78%) -- storage
After:
243,483,424 B (100.0%) -- explicit
├──153,701,920 B (63.13%) -- js
│ ├───40,005,632 B (16.43%) ── gc-heap-decommitted
├───68,668,300 B (28.20%) ── heap-unclassified
├────7,355,864 B (03.02%) -- storage
So, overall, there's 66mb more explicit memory used after. There's about 50mb more of JS, and of that, about 22mb of this is decommitted. The rest of the difference (about 28mb) looks like it is various system-compartment stuff. As for the increased decomitted, maybe there's more memory used by JS during startup that is quickly thrown out? There's 25mb more of heap-unclassified. There's 10mb _less_ of storage, which is probably just noise?
Comment 17•13 years ago
|
||
> Simply opening about:memory drops this down to 310 MB, so some 60 MB is de-allocated here.
On Mac, you cannot measure Firefox's memory from the activity monitor without first opening about:memory. The drop you observe isn't us de-allocating memory -- it's us forcing the operating system to notice that memory we've already freed is, in fact, freed. We do that when you open about:memory so we can get an accurate reading there.
But anyway, we're still looking at a sizable regression even with this effect accounted for.
Bobby, have a look at these about:memory?verbose results. There are a bazillion system compartments there. That looks pretty bad to me.
d.a. / SpeciesX -- Do you have a lot of tabs in your sessions?
Comment 18•13 years ago
|
||
heap-unused is also a lot higher. from 38,585,376 B to 111,579,944 B. You can look at the bottom to see which categories of memory (objects etc) have gone up.
Comment 19•13 years ago
|
||
(In reply to Justin Lebar [:jlebar] from comment #17)
> d.a. / SpeciesX -- Do you have a lot of tabs in your sessions?
nope, only one about:memory tab on on clean profile.
Comment 20•13 years ago
|
||
> d.a. / SpeciesX -- Do you have a lot of tabs in your sessions?
So every unloaded tab does get its own system compartment. And that's going to hit users who have hundreds of unloaded tabs really hard. I'll file a separate bug on that, since it sounds like it may not be the same thing we're observing here.
Reporter | ||
Comment 21•13 years ago
|
||
> d.a. / SpeciesX -- Do you have a lot of tabs in your sessions?
Only 3 pages loaded in total, first http://www.google.com/, then about:blank and finally about:memory
> On Mac, you cannot measure Firefox's memory from the activity monitor
> without first opening about:memory. The drop you observe isn't us
> de-allocating memory -- it's us forcing the operating system to notice that
> memory we've already freed is, in fact, freed. We do that when you open
> about:memory so we can get an accurate reading there.
Would it be possible to make the OS aware of the actual memory usage before going to about:memory? I've noticed after browsing for quite some time opening about:memory will reduce the memory reported in Activity Monitor by a lot. Before I got 8 GB RAM I noticed that visiting about:memory would prevent a lot of paging by the OS because the memory usage the OS saw was so high.
Comment 22•13 years ago
|
||
Here compare from my main profile with 3 tabs, memory increase from 230MB to 368MB.
Comment 23•13 years ago
|
||
(In reply to Justin Lebar [:jlebar] from comment #20)
> So every unloaded tab does get its own system compartment. And that's going
> to hit users who have hundreds of unloaded tabs really hard. I'll file a
> separate bug on that, since it sounds like it may not be the same thing
> we're observing here.
I'd think not, since the reporters here say they're using clean profiles.
(In reply to Justin Lebar [:jlebar] from comment #17)
> Bobby, have a look at these about:memory?verbose results. There are a
> bazillion system compartments there. That looks pretty bad to me.
I think a cold boot of firefox creates ~105 system globals, which translates to ~105 system compartments. This seems to be the same thing as reported in the log attached to this bug.
Theoretically, this definitely does leave us with some memory overhead, since things can be packed less tightly (we have the overhead of the minimum arena size, even if the compartment isn't allocating enough objects to fill it).
But IIUC, the minimum arena size is something on the order of 2-4k. If we're talking about a 100MB regression, then _each_ compartment would have an overhead on the order of 1MB, which is absurdly high. So there's clearly something fishy afoot here.
Comment 24•13 years ago
|
||
> Before I got 8 GB RAM I noticed that visiting about:memory would prevent a lot of paging
> by the OS because the memory usage the OS saw was so high.
Before you visit about:memory, the memory that's released when you open about:memory should be in a state such that the operating system will snatch it back before it starts paging.
So if you observed that your machine was paging, and then you opened about:memory, and then Firefox's memory usage decreased and the system immediately stopped paging because of the extra available memory, that would be a bug, either in Firefox or your operating system. To be honest, I doubt that was what was happening -- I tested all this specifically on 10.6 -- but it's possible, and we can tackle it in another but if you can reproduce.
Comment 25•13 years ago
|
||
(In reply to SpeciesX from comment #14)
> Created attachment 621420 [details]
> about:memory Changeset: 2db9df42823d
>
> i have also a memory increase about 70-80% on clean Profile.
Resident before: 117mb
Resident after: 140mb
This isn't a 70-80% increase. Am I misunderstanding something?
Comment 26•13 years ago
|
||
(In reply to Justin Lebar [:jlebar] from comment #25)
> Resident before: 117mb
> Resident after: 140mb
>
> This isn't a 70-80% increase. Am I misunderstanding something?
Maybe he's referring to explicit.
Comment 27•13 years ago
|
||
> Maybe he's referring to explicit.
FWIW, explicit is a bad number to look at because it includes memory that's decommitted -- it's taking up no space in physical memory. (If you think that's unfortunate and confusing, don't blame me; we have a long-running spat over this. :)
I just realized that our Mac js gc heap code decommits incorrectly. It should use MADV_FREE, not MADV_DONTNEED, and then we need to add the magic to kill the madvise'd pages, just like we do with jemalloc. We may need similar code to make Windows report correctly, too.
I don't remember what MADV_DONTNEED does on Mac -- it may not free the memory at all. :-/ I think at least the Windows code is freeing memory properly.
To analyze the situation as though this were fixed, look at heap-committed + js-gc-heap-committed instead of resident.
heap-committed + js-gc-heap-committed in d.a.'s data:
Good: 30mb + 8mb = 38mb
Bad: 44mb + 12mb = 56mb
So there's still a sizable increase here. We should try to reproduce this.
Comment 28•13 years ago
|
||
(In reply to Justin Lebar [:jlebar] from comment #25)
> (In reply to SpeciesX from comment #14)
> > Created attachment 621420 [details]
> > about:memory Changeset: 2db9df42823d
> >
> > i have also a memory increase about 70-80% on clean Profile.
>
> Resident before: 117mb
> Resident after: 140mb
>
> This isn't a 70-80% increase. Am I misunderstanding something?
i compared explicit only.
the good build varies explicit only +/-3MB, but the bad build varies explicit from 58MB up to 72MB and i took the lowest.
Comment 29•13 years ago
|
||
I filed bug 752339 and bug 752342 on the issues wrt the JS chunk allocator's decommit. But that's not the whole story here.
Comment 30•13 years ago
|
||
where i can find js-gc-heap-committed?
my main profile on the bad build
339.02 MB -- explicit
0.13 MB -- gfx-d2d-surfacecache
11.75 MB -- gfx-d2d-surfacevram
0.19 MB -- gfx-surface-image
0 -- ghost-windows
129.83 MB -- heap-allocated
166.07 MB -- heap-committed
27.89% -- heap-committed-unused-ratio
2.46 MB -- heap-dirty
124.16 MB -- heap-unused
0.01 MB -- images-content-used-uncompressed
193 -- js-compartments-system
12 -- js-compartments-user
205.00 MB -- js-gc-heap
3.77 MB -- js-main-runtime-analysis-temporary
56.08 MB -- js-main-runtime-gc-heap-allocated
32.81 MB -- js-main-runtime-gc-heap-arena-unused
35.00 MB -- js-main-runtime-gc-heap-chunk-clean-unused
81.12 MB -- js-main-runtime-gc-heap-chunk-dirty-unused
205.00 MB -- js-main-runtime-gc-heap-committed
148.92 MB -- js-main-runtime-gc-heap-committed-unused
265.57% -- js-main-runtime-gc-heap-committed-unused-ratio
0.00 MB -- js-main-runtime-gc-heap-decommitted
0.29 MB -- js-main-runtime-mjit
28.03 MB -- js-main-runtime-objects
8.01 MB -- js-main-runtime-scripts
16.90 MB -- js-main-runtime-shapes
22.61 MB -- js-main-runtime-strings
0.91 MB -- js-main-runtime-type-inference
419.41 MB -- private
456.85 MB -- resident
10.55 MB -- storage-sqlite
840.58 MB -- vsize
1.62 MB -- window-objects-dom
1.75 MB -- window-objects-layout-arenas
3.23 MB -- window-objects-layout-style-sets
0.14 MB -- window-objects-layout-text-runs
4.52 MB -- window-objects-style-sheets
same profile on the good build
184.90 MB -- explicit
0.13 MB -- gfx-d2d-surfacecache
11.75 MB -- gfx-d2d-surfacevram
0.19 MB -- gfx-surface-image
0 -- ghost-windows
101.40 MB -- heap-allocated
116.95 MB -- heap-committed
15.32% -- heap-committed-unused-ratio
3.57 MB -- heap-dirty
38.59 MB -- heap-unused
0.01 MB -- images-content-used-uncompressed
7 -- js-compartments-system
10 -- js-compartments-user
78.00 MB -- js-gc-heap
4.52 MB -- js-main-runtime-analysis-temporary
43.85 MB -- js-main-runtime-gc-heap-allocated
16.24 MB -- js-main-runtime-gc-heap-arena-unused
1.00 MB -- js-main-runtime-gc-heap-chunk-clean-unused
16.91 MB -- js-main-runtime-gc-heap-chunk-dirty-unused
78.00 MB -- js-main-runtime-gc-heap-committed
34.15 MB -- js-main-runtime-gc-heap-committed-unused
77.87% -- js-main-runtime-gc-heap-committed-unused-ratio
0.00 MB -- js-main-runtime-gc-heap-decommitted
1.59 MB -- js-main-runtime-mjit
19.08 MB -- js-main-runtime-objects
6.70 MB -- js-main-runtime-scripts
15.72 MB -- js-main-runtime-shapes
20.83 MB -- js-main-runtime-strings
0.78 MB -- js-main-runtime-type-inference
243.09 MB -- private
279.91 MB -- resident
10.34 MB -- storage-sqlite
592.77 MB -- vsize
1.62 MB -- window-objects-dom
1.77 MB -- window-objects-layout-arenas
3.23 MB -- window-objects-layout-style-sets
0.14 MB -- window-objects-layout-text-runs
4.52 MB -- window-objects-style-sheets
Comment 31•13 years ago
|
||
It's the main-runtime numbers that you should look at.
I tried to reproduce this bug on my 10.7 box. There's a lot of variance, but I wasn't able to get anywhere near the kind of blowup here.
The one thing I did see is that after forcing a bunch of minimize memory usage, the non-cpg build leveled off at 100mb, while cpg leveled off at 130mb RSS. I owe you about:memory dumps, but those will have to wait.
Comment 32•13 years ago
|
||
On my machine, all of the difference between CPG and non-CPG is apparently due to the overhead of loading about:memory?verbose, which is much larger post-CPG. Non-verbose mode isn't any better: We still load everything; we just hide it by default.
Doing things which don't involve about:memory yields nearly identical memory usage with and without CPG. Mac 10.7, measured via activity monitor (yes, I know I said not to do that, but desperate times... :)
* Start up: 100mb
* Start up, load google.com: 130mb
* Start up, load techcrunch.com: 205mb
Can you guys demonstrate a workload which doesn't involve about:memory which shows a repeatable, large difference in memory usage between CPG and non-CPG? If not, we should close this an open a new bug on the about:memory overhead. (We've looked at about:memory overhead before, but this is perhaps an unprecedented scale.)
Comment 33•13 years ago
|
||
here i make a video. :)
http://youtu.be/aaq61Df9hEc
![]() |
||
Comment 34•13 years ago
|
||
(In reply to Justin Lebar [:jlebar] from comment #32)
> On my machine, all of the difference between CPG and non-CPG is apparently
> due to the overhead of loading about:memory?verbose, which is much larger
> post-CPG. Non-verbose mode isn't any better: We still load everything; we
> just hide it by default.
Yeah, I've filed bug 752381 to fix that; fortunately it'll be easy. I suspect that'll account for a lot of what d.a. is seeing. about:memory isn't designed to handle so many reports for such a small session.
Depends on: 672439
![]() |
||
Updated•13 years ago
|
Comment 35•13 years ago
|
||
(In reply to SpeciesX from comment #33)
> here i make a video. :)
> http://youtu.be/aaq61Df9hEc
There are a ton of extensions visible in this video.
Comment 36•13 years ago
|
||
(In reply to Justin Lebar [:jlebar] from comment #35)
> There are a ton of extensions visible in this video.
only 14 :P
Adblock Plus is the cause.
ABP enabled
CPG build | non CPG build
442-467MB | 305-329MB
ABP disabled
CPG build | non CPG build
266-270MB | 236-246MB
Comment 37•13 years ago
|
||
(In reply to SpeciesX from comment #36)
> (In reply to Justin Lebar [:jlebar] from comment #35)
>
> Adblock Plus is the cause.
>
> ABP enabled
>
> CPG build | non CPG build
> 442-467MB | 305-329MB
>
> ABP disabled
>
> CPG build | non CPG build
> 266-270MB | 236-246MB
That sounds really important. Can you file a new bug on this, please?
Comment 38•13 years ago
|
||
(In reply to Justin Lebar [:jlebar] from comment #37)
> That sounds really important. Can you file a new bug on this, please?
could you file, my english isn't really well.
![]() |
||
Comment 39•13 years ago
|
||
This may be related/caused by bug 752200 (where a change in RegExp statics with CPG broke ABP and apparently caused slowdown). Bug 752200 comment 9 indicates that fixing the RegExp issue fixed the perf issue so perhaps this issue is fixed as well?
Comment 40•13 years ago
|
||
I'm use the latest ABP dev build, performance is restored, but not the higher memory Usage.
Comment 41•13 years ago
|
||
CPG caused 20 new compartments to be created in Adblock Plus core code - and lots of communication across compartments (with many wrappers being created I guess). This is likely the cause of this issue.
![]() |
||
Comment 42•13 years ago
|
||
I'll be optimistic and assume that bug 752381 fixed d.a.'s problem. d.a., please reopen if you try a recent Nightly and it's still a problem.
Status: UNCONFIRMED → RESOLVED
Closed: 13 years ago
Resolution: --- → FIXED
Reporter | ||
Comment 43•13 years ago
|
||
It seems like the memory usage has dropped a bit in recent nightly builds, but not to the level as before this change. Earlier builds with a clean profile the memory usage would be around 80-90 MB, now it's 110-120 MB.
With my normal profile I could get memory usage down to about 190 MB, but now it seems to stay at around 250 MB.
Reporter | ||
Comment 44•13 years ago
|
||
You need to log in
before you can comment on or make changes to this bug.
Description
•