Closed Bug 852520 Opened 11 years ago Closed 11 years ago

Firefox not running garbage collection when needed

Categories

(Core :: JavaScript Engine, defect)

Product:
Core
Component:
JavaScript Engine
Platform:
x86
macOS
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

()

Status:
RESOLVED INVALID

People

(Reporter: u462496, Assigned: jonco)

Details

(Whiteboard: [MemShrink])

Attachments

(1 file, 2 obsolete files)

Benchmark test procedure and results demonstrating FF not doing thorough garbage collection
3.22 KB, text/plain
Details 
After careful testing, I have discovered a scenario where after loading a large number of tabs, then removing them, only a small amount of memory is reclaimed between post loaded state and post removal state, and I have been able to demonstrate that Firefox is not doing a thorough job of garbage collection.

I demonstrate this by the fact that after **10 minutes** of waiting, observing that the memory usage figure has **not** changed, I can do a forced CC and GC from about:memory, and the memory usage dramatically decreases.

(Note that I tried actions that I hoped might trigger a GC/CC cycle naturally in FF, such as opening a new tab and loading it, but this never brought a release in memory.)

Overview of test ("ave" means average of figures shown in the attached test results):

Load 123 tabs
record memory usage (1490 MB ave)
remove 122 tabs
record memory usage (1060 MB ave - 29% reduction ave)
wait 10 minutes
record memory usage (1060 MB ave - **still the same**)
manual force CC and GC in about:memory
record memory usage ( 286 MB ave - final 81% reduction ave)

Test was run dozens of times with very consistent results.  I have documented a segment of the testing showing the results of 3 consecutive rounds, along with a detailed description of the testing procedure. Please find it in attachment.
Assignee: nobody → general
Component: Untriaged → JavaScript Engine
Product: Firefox → Core
Thanks for doing this, Allasso. We try our best to run tests like this. You can see the results at areweslimyet.com. However, it's possible that the sites in your sessionrestore.js are triggering some sort of bug. Can you attach the file so we can try to reproduce the steps you took? If you'd rather not share it here, perhaps you could send it to me directly (billm@mozilla.com)?
Sure, I'm sending the file to you, Bill.  Let me know if you don't get it.
Got the file, thanks. I'm trying it now.
Whiteboard: [MemShrink]
By the way, how are you closing the tabs? Do you close each tab individually or do you use the "Close Other Tabs" menu?
I tend to not think that it is a webpage causing the bug, though.  I have also tested with a session file that loads 900 pages that are simple text-only stored locally on my computer.  I'll attach that session file as well, along with a couple of samples of the pages that are being loaded.  They are all identical, with the exception that the numerical references are incremented from 000 to 900.

ie, here is the text of the first one:  XXX_000, second, XXX_001, etc.

The results are not quite as dramatic because not much is being loaded into each tab, which is why I posted the results of the other session. However, you can definitely tell that the effect I described is present.
I've decided to send them directly to you, Bill, to avoid confusion.  However, feel free to share either session with whomever you like.
(In reply to Bill McCloskey (:billm) from comment #4)
> By the way, how are you closing the tabs? Do you close each tab individually
> or do you use the "Close Other Tabs" menu?

I have done it both ways with the same results.  I think in the results that were uploaded, I was closing them with cmd+w.
I'm going to see if I can create a more generic example and try uploading it to my website.
For some reason this reproduces for me on Mac but not on Linux. Jon, can you try to figure out what's happening?

It's kinda weird that when I refresh about:memory after closing all the tabs and waiting, it reports that nothing is being used or held onto, and the memory is freed almost immediately afterward. I don't even need to ask for a GC.
(In reply to Bill McCloskey (:billm) from comment #9)
 
> It's kinda weird that when I refresh about:memory after closing all the tabs
> and waiting, it reports that nothing is being used or held onto, and the
> memory is freed almost immediately afterward. I don't even need to ask for a
> GC.

I just observed that as well, all I have to do is refresh about:memory, I don't need to press the button.
> It's kinda weird that when I refresh about:memory after closing all the tabs
> and waiting, it reports that nothing is being used or held onto, and the
> memory is freed almost immediately afterward. I don't even need to ask for a
> GC.

A bunch of JS code gets run when about:memory is refreshed.  It quite often happens that a GC is triggered when this happens.
By the way, this suggests that we should be running areweslimyet on other platforms. I wonder if running the suite directly would reproduce this behavior.
Status: UNCONFIRMED → NEW
Ever confirmed: true
(In reply to Nicholas Nethercote [:njn] from comment #11)
> > It's kinda weird that when I refresh about:memory after closing all the tabs
> > and waiting, it reports that nothing is being used or held onto, and the
> > memory is freed almost immediately afterward. I don't even need to ask for a
> > GC.
> 
> A bunch of JS code gets run when about:memory is refreshed.  It quite often
> happens that a GC is triggered when this happens.

Yes, that is indeed what is happening, and not only that, it is actually the *only* thing that is causing GC to run, not the call from the UI (at least on Mac).  See bug 853624.

https://bugzilla.mozilla.org/show_bug.cgi?id=853624
Summary: Firefox not running garbage collection when it is direly appropriate to do so → Firefox not running garbage collection when needed
Updated original with this addition:

NOTE: refreshing about:memory page or clicking update on that page will trigger a thorough GC. (See Bug 853624). So it is important not to do either of those actions while testing or it will give misleading results.  Also, any other activity that is using nsIMemoryReporterManager or nsIMemoryReporter may trigger a thorough GC as well. Accessing nsIMemoryReporterManager.resident for sure does, as well as accessing nsIMemoryReporter.amount when nsIMemoryReporter.path == "resident".
Same as the last one, just forgot to obselete the one before it.
Attachment #726643 - Attachment is obsolete: true
Attachment #728201 - Attachment is obsolete: true
probably goes without saying by now, but don't do the demo using any other memory related extensions or FF tools or you will get misleading results.
Assigning this to Jon since he's able to reproduce. It sounds like maybe we're doing enough GC, but the memory isn't being released to the OS. It might even be a jemalloc issue instead of a GC issue.
Assignee: general → jcoppeard
Perhaps that is what is going on with updating about:memory, or any other operations that run nsIMemoryReporterX code?  Maybe they aren't doing a GC like I initially thought, but they are just releasing memory to the system that has already been GC'd but is hanging?  I wonder this because of the fact that there is no GC or CC activity logged to the console when about:memory is updated, even though you see a lot of memory suddenly released.
> I wonder this because of the
> fact that there is no GC or CC activity logged to the console when
> about:memory is updated, even though you see a lot of memory suddenly
> released.

If you look at the "decommitted-arenas" measurement near the bottom of about:memory (in the "Other Measurements" section) that might give you a clue.  This decommitted memory is exactly memory that has been "almost freed" without actually being freed, and might get freed later on.
I've verified that GC is happening as expected in the test scenario after the tabs have been closed.

However it seems that MacOS works differently to other operating systems when it comes to pages handed back to the OS with madvise(MADV_FREE).  MacOS doesn't take them back immediately, but only when the machine is running out of physical memory.

This is why the observered memory use is not decreasing after all the tabs have been closed on MacOS, wheras it does on linux.

Reloading about:memory forces these unused pages to be removed just so it can get an accurate measurement for memory usage.  See the comments here for more details:

http://mxr.mozilla.org/mozilla-central/source/xpcom/base/nsMemoryReporterManager.cpp#258

http://mxr.mozilla.org/mozilla-central/source/memory/build/mozmemory.h#54

Logging memory usage before and after the call jemalloc_purge_freed_pages() showed that this was responsible for the change observed.
Status: NEW → RESOLVED
Closed: 11 years ago
Resolution: --- → INVALID
I'm sorry the situation here is so confusing.

I wish we had a better solution, particularly because the current situation means that we have to run purge_freed_pages() in order to collect meaningful RSS for telemetry, and since purge_freed_pages() is sometimes slow, we can't do that.  We therefore do not have meaningful RSS values on macos telemetry.  See bug 789975.

See also bug 752339 and bug 752342.  The latter means that we don't currently have meaningful RSS even in about:memory on MacOS.
Please also see bug 829047 what happens when we have a low memory condition on OS X! As I mention over there the browser is barely usable and keeps freezing all the time. So I wonder if we should really do something for that platform.

(In reply to Jon Coppeard (:jonco) from comment #20)
> Reloading about:memory forces these unused pages to be removed just so it
> can get an accurate measurement for memory usage.  See the comments here for
> more details:
> 
> http://mxr.mozilla.org/mozilla-central/source/xpcom/base/
> nsMemoryReporterManager.cpp#258

Given that we make use of the same interface for Memchaser, I'm a bit worried now that we get false values due to that behavior. Why does requesting the used memory force a GC/CC? In that case we will never be able to show the correct memory usage via Memchaser and invalidate the test scenarios. :(
(In reply to Henrik Skupin (:whimboo) [away 03/15 - 03/22] from comment #22)
> Given that we make use of the same interface for Memchaser, I'm a bit
> worried now that we get false values due to that behavior.

FWIW, I have observed that Memchaser resident readings, along with about:memory, seem to reflect quite closely those of Activity Monitor.  But maybe you are talking about something else.
> Why does requesting the used memory force a GC/CC?

It doesn't.  Purging free'd pages is not a GC/CC.

Requesting used memory purges free'd pages because that's the only way we can get an accurate measurement of the heap's RSS.  Purging free'd pages has no effect except to change the value we read for RSS.  It does not change anything other than the measured RSS.

Per the last bug I linked to in comment 21, even if you purge jemalloc's free'd pages before reading RSS, your RSS on Mac will still be incorrect because the JS engine does not have similar functionality.

Given how many problems we have had with Memchaser causing memory leaks (either itself or via the addon SDK) and possibly causing other problems (e.g. bug 829047), I believe that Memchaser is a poor way of measuring Firefox's memory usage.  We should use tools provided by the OS instead.
(In reply to Justin Lebar [:jlebar] from comment #24)
> > Why does requesting the used memory force a GC/CC?
> 
> It doesn't.  Purging free'd pages is not a GC/CC.
> 
> Requesting used memory purges free'd pages because that's the only way we
> can get an accurate measurement of the heap's RSS.  Purging free'd pages has
> no effect except to change the value we read for RSS.  It does not change
> anything other than the measured RSS.
> 
> Per the last bug I linked to in comment 21, even if you purge jemalloc's
> free'd pages before reading RSS, your RSS on Mac will still be incorrect
> because the JS engine does not have similar functionality.
> 
> Given how many problems we have had with Memchaser causing memory leaks
> (either itself or via the addon SDK) and possibly causing other problems
> (e.g. bug 829047), I believe that Memchaser is a poor way of measuring
> Firefox's memory usage.  We should use tools provided by the OS instead.

I've done some nominal checking to observe OS X's effectiveness in purging GCed memory under pressure from other applications.  It seems to be doing it, but I observed about 350 - 400 MB had gone to swap and still about 100 MB had still not been released.  I was able to release the remainder by updating about:memory.  This doesn't seem very optimal, but maybe there are parts of the picture I am not seeing.

Is there any reason forcing a memory release (in OS X) from Firefox or an extension by calling jemalloc_purge_freed_pages() via nsIMemoryReporterManager.resident be a bad idea, eg, the allocation issues talked about in comment #3 in Bug 752342 (https://bugzilla.mozilla.org/show_bug.cgi?id=752342#c3)? Or any other reason?
Or would it just be better to not try to help the system do its job?
> This doesn't seem very optimal, but maybe there are parts of the picture I am not seeing.

That indeed sounds pretty bad.  Let's discuss this in another bug, if you don't mind.

> Is there any reason forcing a memory release (in OS X) from Firefox or an extension by calling 
> jemalloc_purge_freed_pages() via nsIMemoryReporterManager.resident be a bad idea

Yes: It can be very slow, for reasons we don't understand.  That's what bug 789975 was about.
(In reply to Justin Lebar [:jlebar] from comment #26)
> That indeed sounds pretty bad.  Let's discuss this in another bug, if you
> don't mind.

Okay, I'll work up some more detailed observation, and file a report.
(In reply to Justin Lebar [:jlebar] from comment #26)
> Yes: It can be very slow, for reasons we don't understand.  That's what bug
> 789975 was about.

Is 44 ms slow to release 565 MB of memory?  That is the average of 3 tests I made using this code:

var t1 = Date.now();

let res = Cc["@mozilla.org/memory-reporter-manager;1"].
                getService(Ci.nsIMemoryReporterManager).resident;
                
dump("    et : "+(Date.now() - t1)+"\n");

I saw cpu in Activity Monitor spike momentarily 2%, then go back to 0.

Is this test naive?  Is there stuff that runs in the background?
Can we please move this into a separate bug?
(In reply to Justin Lebar [:jlebar] from comment #29)
> Can we please move this into a separate bug?

Bug 854879
(In reply to Justin Lebar [:jlebar] from comment #26)
> That indeed sounds pretty bad.  Let's discuss this in another bug, if you
> don't mind.

Bug 855151
was this added to firefox22?  in v22 I am getting very noticeable stalls with only about 15 FG tabs open.  eg. typing in this box the text keeps pausing on display and has to catch up.

Please make a firefox which has all GC disabled.
Chris, let's please keep the discussion of your particular issue in bug 892376, thanks.  This bug is kind of about the opposite of the problem you are having.
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: