Closed Bug 752259 Opened 11 years ago Closed 11 years ago
Huge, 100MB+ Memory Usage Regression In Recent Nightly
25.76 KB, text/plain
423.07 KB, text/plain
208.12 KB, text/plain
10.30 KB, text/plain
141.74 KB, text/plain
102.28 KB, image/png
13.56 KB, text/plain
14.02 KB, text/plain
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.
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.
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?
FWIW, I see only a small regression on AWSY (Linux64) . 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/
I thought CPG broke Mozmill, so I don't know if AWSY has actually updated properly.
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.
(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.
I had added a workaround for the broken mozmill functions to AWSY, so the data should be up to date
(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!
Similar to previous comments, compared about:memory on membuster before/after and see only a 1.8% regression.
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.
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.
i have also a memory increase about 70-80% on clean Profile.
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?
> 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?
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.
(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.
> 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.
> 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.
Here compare from my main profile with 3 tabs, memory increase from 230MB to 368MB.
(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.
> 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.
(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?
(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.
> 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.
(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.
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.
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
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.
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.)
here i make a video. :) http://youtu.be/aaq61Df9hEc
(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
(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.
(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
(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?
(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.
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?
I'm use the latest ABP dev build, performance is restored, but not the higher memory Usage.
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.
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: 11 years ago
Resolution: --- → FIXED
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.
You need to log in before you can comment on or make changes to this bug.