699801 - Excessive memory usage (including 400MB of binary input streams) caused by firebug when chunking a file through XMLHTTPRequest

Status: RESOLVED FIXED

(Core :: General, defect)

Description

[Trev]

Attachment: Firefox-Memory-Before-Minimize.jpg

User Agent: Mozilla/5.0 (Ubuntu; X11; Linux x86_64; rv:9.0a2) Gecko/20111026 Firefox/9.0a2
Build ID: 20111026195829

Steps to reproduce:

I had restarted Firefox (9.0a2 2011-10-26) yesterday morning and left it running all night.  When I came in this morning, the heap-unclassified was 2.7GB.  This happens pretty frequently (about every other day causing me to restart the browser, tabs are different but length of uptime is similar).  Most of the time, the browser is completely frozen but this time I was able to get some screenshots of about:memory.  I took a screenshot before clicking "Minimize Memory Usage" and then one after I clicked it 5-10 times.  The heap-unclassified barely budged (2,706.72 MB to 2,696.65 MB).

I only had 4 tabs open.  Three were in Jira and one was a login page of an internal app.

My enabled extensions are:
about:telemetry 0.6
Adblock Plus 1.3.10
Add-on Compatibility Reporter 0.9.2
Clear Cache 1.2
Cookie Monster 1.1.0
Feedback 1.1.2
Firebug 1.9.0.a5
HttpFox 0.8.10
JSONView 0.7
Morning Coffee 1.35
Rainbow 1.4

My enabled plugins are:
Java(TM) Plug-in 1.6.0_26
Shockwave Flash

Comment 1

[Trev]

Attachment: Firefox-Memory-After-Minimize.jpg

Comment 2

[Trev]

Marking as blocking 563700 because that is a meta bug to reduce heap-unclassified to below 10% and this case has it >80%.  Since this is a linux build, I'm going to attempt to try and get the DMD working.

Comment 3

[Justin Lebar (not reading bugmail)]

This may be the same as what some people are seeing in bug 696761.  That bug may be partially understood (bug 696761 comment 77).

If you could get a DMD dump, that would be awesome.

Comment 4

[David Rees]

I see 60+ heap-unclassified consistently in 7.0.1. I suspect lastpass actually.

How does one do a DMD dump, and can I do it on Windows? The one hit I found googling seemed to imply it only runs on linux.

FYI, here is my about:memory with 

Explicit Allocations
899.19 MB (100.0%) -- explicit
├──593.04 MB (65.95%) -- heap-unclassified
├──209.84 MB (23.34%) -- js
│  ├──137.16 MB (15.25%) -- compartment([System Principal])
│  │  ├───59.28 MB (06.59%) -- gc-heap
│  │  │   ├──31.43 MB (03.49%) -- objects
│  │  │   ├──12.73 MB (01.42%) -- shapes
│  │  │   ├──11.01 MB (01.22%) -- arena-unused
│  │  │   └───4.11 MB (00.46%) -- (4 omitted)
│  │  ├───33.52 MB (03.73%) -- scripts
│  │  ├───21.39 MB (02.38%) -- mjit-code
│  │  ├───11.38 MB (01.27%) -- string-chars
│  │  ├────9.02 MB (01.00%) -- object-slots
│  │  └────2.57 MB (00.29%) -- (3 omitted)
│  ├───41.37 MB (04.60%) -- gc-heap-chunk-unused
│  ├───13.77 MB (01.53%) -- (13 omitted)
│  ├────8.88 MB (00.99%) -- compartment(atoms)
│  │    ├──6.12 MB (00.68%) -- string-chars
│  │    └──2.75 MB (00.31%) -- (7 omitted)
│  └────8.66 MB (00.96%) -- compartment(https://www.google.com/voice/b/0#inbox)
│       ├──5.06 MB (00.56%) -- gc-heap
│       │  └──5.06 MB (00.56%) -- (7 omitted)
│       └──3.60 MB (00.40%) -- (7 omitted)
├───89.66 MB (09.97%) -- storage
│   └──89.66 MB (09.97%) -- sqlite
│      ├──75.68 MB (08.42%) -- places.sqlite
│      │  ├──75.42 MB (08.39%) -- cache-used
│      │  └───0.26 MB (00.03%) -- (2 omitted)
│      ├───8.16 MB (00.91%) -- urlclassifier3.sqlite
│      │   ├──8.07 MB (00.90%) -- cache-used
│      │   └──0.08 MB (00.01%) -- (2 omitted)
│      └───5.83 MB (00.65%) -- (13 omitted)
└────6.65 MB (00.74%) -- (3 omitted)

Other Measurements
1,157.33 MB -- vsize
1,012.82 MB -- resident
1,004.21 MB -- private
  916.83 MB -- heap-committed
  872.73 MB -- heap-used
  116.00 MB -- js-gc-heap
   66.26 MB -- heap-unused
    5.56 MB -- gfx-surface-win32
    3.27 MB -- heap-dirty
    0.24 MB -- canvas-2d-pixel-bytes
    0.00 MB -- gfx-surface-image
    0.00 MB -- gfx-d2d-surfacecache
    0.00 MB -- gfx-d2d-surfacevram

Comment 5

[Justin Lebar (not reading bugmail)]

> I suspect lastpass actually.

Is that an extension?  Many to most extensions leak, badly.  If it's not a binary extension, we should be able to track its memory in about:memory.  If it's running C++ code, all bets are off...

[e-mail], the extensions you're running might legitimately be causing this problem for you, too.

> How does one do a DMD dump, and can I do it on Windows? The one hit I found googling 
> seemed to imply it only runs on linux.

It might work on Mac, but definitely not on Windows.

Comment 6

[Andrew McCreight [:mccr8]]

DMD is based on valgrind, so it makes the browser around 10 times slower, I believe.  This makes it hard to use in these scenarios where things are bad when left overnight.

David Rees, thanks for the report, but you should please file a separate bug, also blocking the DarkMatter bug.  You can clone this bug (in the lower right corner of bugzilla) to get the same people CCed.  It sounds like you have a different set of addons than the original reporter, so you probably have a different problem.  Your problem may be easier to find, because it happens a lot.  You can try disabling addons one by one and see if the problem goes away.  Start with the most suspicious addons.  If you have a lot of them, you'll want to disable a number of them at a time, though that still be a little tedious and error prone.

Comment 7

[Trev]

i got DMD kind of working but it crashes the build a lot (which makes duplicating this scenario pretty difficult).  Does DMD add more instability to nightly or did I just get a buggy build?  I'm attempting to use a copy of my profile so that I have all the same extensions.  Enabling Firebug (the console, script or network) crashes it and there was some weird issue that the nightly with the DMD patch would crash when the browser opened.  I didn't test without the DMD patch.

Comment 8

[Andrew McCreight [:mccr8]]

njn is probably the only one who can answer your questions about DMD.

Comment 9

[Trev]

I've filled bug 700040 about one of the crashes I'm seeing with the DMD modifications.  It looks like it is either caused by the DMD modifications (though I can't see how) or the mozconfig that is recommended in https://wiki.mozilla.org/Performance/MemShrink/DMD#Setting_up_Firefox.

Comment 10

[Nicholas Nethercote [inactive]]

AFAIK you're the first person other than me who has run DMD.  DMD's very unpolished, the crashes are almost certainly DMD's fault rather than Firefox's fault.  DMD doesn't work on Windows, sorry.

I agree with jlebar, there's a good chance that one or more of your add-ons are at fault.  So there are two issues here:

- What's causing the leak?  (Probably an add-on, but which one?)

- Why is heap-unclassified so high?

(W.r.t. comment 4, FF7 has fewer memory reporters than FF9 so the fact that David saw high heap-unclassified is less indicative of something.  David, if you can try again with a Nightly build (http://nightly.mozilla.org/) that would be very helpful.)

[e-mail], is there any chance you could selectively disable your add-ons in a bisecting manner (turn off half of them, try to reproduce, etc)?

Comment 11

[David Rees]

Here is what I am seeing with the nightly after running for about 20 minutes, opening a bunch of windows, closing them all except for about:memory, then hitting minimize memory usage. This is the summary and I have attached the verbose. This still seems wrong to me, am I correct? If so I guess I should create an issue on it?

403.48 MB (100.0%) -- explicit
├──177.05 MB (43.88%) -- heap-unclassified
├──119.46 MB (29.61%) -- js
├───91.28 MB (22.62%) -- storage
│   └──91.28 MB (22.62%) -- sqlite
│      ├──43.16 MB (10.70%) -- other
│      ├──42.38 MB (10.50%) -- places.sqlite
├────9.82 MB (02.43%) -- dom

PS, According to lastpass they "reserve a chunk of memory", not sure what they mean by that or what it should look like in about:memory - http://forums.lastpass.com/viewtopic.php?f=12&t=78091&p=261824#p261824.

Comment 12

[David Rees]

Attachment: about:memory verbose for comment11

Comment 13

[David Rees]

Attachment: about:memory verbose after restart for comment11

Comment 14

[Justin Lebar (not reading bugmail)]

That's a fair bit of heap-unclassified, yes.

If this extension is C++, the chunk of memory they reserve would show up as heap-unclassified.

Comment 15

[David Rees]

And here it is after restart, verbose attached for that as well
162,878,130 B (100.0%) -- explicit
├───95,388,436 B (58.56%) -- js
├───32,537,825 B (19.98%) -- heap-unclassified
├───22,585,520 B (13.87%) -- storage
├───10,291,247 B (06.32%) -- dom

Comment 16

[David Rees]

Attachment: about:telemetry for comment 11 (before restart)

Comment 17

[David Rees]

It seems to be all XUL/JS, but then I have other addons installed as well. I guess I have to do some more narrowing down. The problem is, as an earlier poster said, its kind of hard to use firefox effectively without some of these extensions because I depend on them.

Maybe its something I just need to automate. Anyone happen to know a good, simple scripting approach for Firefox? It would be great to give it a bunch of pages to open/navigate, saving the about:memory along the way.

Comment 18

[Nicholas Nethercote [inactive]]

(In reply to David Rees from comment #17)
> 
> Maybe its something I just need to automate. Anyone happen to know a good,
> simple scripting approach for Firefox? It would be great to give it a bunch
> of pages to open/navigate, saving the about:memory along the way.

http://gregor-wagner.com/tmp/mem isn't bad, it opens 150 tabs.  You have to do the about:memory reloads yourself, you can't do it from a script because it's a privileged page.

Comment 19

[Justin Lebar (not reading bugmail)]

You can also specify a list of URLs on the command line.  If you hack nsSessionStore.js and change MAX_CONCURRENT_TAB_RESTORES to 1 (*), you might be able to specify a list of URLs, including about:memory at various points, and get what you want.

(*) This used to be a pref; I have no idea why it was changed.  Anyway, if you don't change it to 1, your results will be harder to reproduce, since the tabs won't all load in order.

Comment 20

[Trev]

I disabled all of my addons but 5: about:telemetry, add-on compatibility reporter, clear cache, cookie monster, and firebug.

I'm currently at 50% heap-unclassified (360MB)

Comment 21

[Trev]

Attachment: about:memory with DMD

I was able to get a DMD build running and used it for about an hour.  I'm attaching the about:memory output and the dmd output can be found at http://www.peacekeeper.therichins.net/dmd_output (it is quite large and can't be uploaded through bugzilla).

The heap-allocated/unallocated (which I hope is because I was using the DMD patch) did not report anything but the resident size is 1.4GB and everything under explicit is just 204MB.

Comment 22

[Justin Lebar (not reading bugmail)]

Attachment: DMD output from comment 21

Comment 23

[Nicholas Nethercote [inactive]]

Attachment: highlights of the DMD output from comment 21

I've taken just the top 23 records from the DMD output in comment 21.  They are dominated by over 400MB in this record and numerous minor variants (i.e. the "???" line has a different address):

 Unreported: 34,603,296 (cumulative: 34,603,296) bytes in 15 heap block(s) in record 1 of 28498:
  Requested bytes unreported: 31,458,903 / 31,458,903
  Slop      bytes unreported: 3,144,393 / 3,144,393
    at 0x4C276AA: malloc (vg_replace_malloc.c:263)
    by 0x887F887: NS_Alloc_P (nsMemoryImpl.cpp:198)
    by 0x886254C: nsBinaryInputStream::ReadBytes(...) (nsMemory.h:68)
    by 0x888704E: NS_InvokeByIndex_P (xptcinvoke_x86_64_unix.cpp:195)
    by 0x85144B0: XPCWrappedNative::CallMethod(...) (XPCWrappedNative.cpp:2882)
    by 0x8518844: XPC_WN_CallMethod(JSContext*, unsigned int, JS::Value*) (XPCWrappedNativeJSOps.cpp:1554)
    by 0x8C3D46D: js::mjit::stubs::UncachedCallHelper(...) (jscntxtinlines.h:297)
    by 0x8C3D6CD: js::mjit::stubs::UncachedCall(...) (InvokeHelpers.cpp:433)
    by 0x1D9BBF1B: ???
    by 0x8BA6D13: js::mjit::EnterMethodJIT(...) (MethodJIT.cpp:1064)
    by 0x8BA780D: js::mjit::JaegerShot(...) (MethodJIT.cpp:1125)
    by 0x8A82DA8: js::Interpret(...) (jsinterp.cpp:3987)

We definitely don't have any memory reporters for XPCWrappedNatives.

[e-mail], thanks for getting DMD running!  This is very helpful.  And yes, heap-unclassified doesn't show up under DMD, unfortunately.

I'd put my money on either Firebug or maybe Cookie Monster causing these allocations.

Comment 24

[Josh Matthews [:jdm]]

That stack suggests to me that we should have reporters for various input/output streams that allocate buffers, not that XPCWrappedNatives need reporters.

Comment 25

[Nicholas Nethercote [inactive]]

(In reply to Josh Matthews [:jdm] from comment #24)
> That stack suggests to me that we should have reporters for various
> input/output streams that allocate buffers, not that XPCWrappedNatives need
> reporters.

Yeah, I totally misinterpreted the stack.  I opened bug 700885 for adding an input/output stream memory reporter.  This bug can be about the excessive memory use by one of the add-ons.

David Rees, since [e-mail] narrowed down the original problem to an add-on, this bug should just be about that.  If you want to continue investigation of your problem, can you file a new bug?  It makes things much easier if we have one issue per bug report.  Thanks!

Comment 26

[Trev]

It is firebug that is causing the issue.  In our internal app, we upload large files (~400MB).  We use chunking to upload the file.  It splits it up into 10MB files and uploads each one with XMLHTTPRequest.  If I don't have firebug enabled, I have no problem with memory.  If I have firebug enabled but net disabled, I'll see a problem (about 400MB).  If I have net enabled, I see a really big problem with about 2GB.  I'll try and make a small test case to duplicate it.  It does look like the memory is never cleaned up because clicking the buttons at the bottom of about:memory have no affect on the amount of memory.

Comment 27

[Jan Honza Odvarko [:Honza] (always need-info? me)]

(In reply to [e-mail] from comment #26)
> It is firebug that is causing the issue.  In our internal app, we upload
> large files (~400MB).  We use chunking to upload the file.  It splits it up
> into 10MB files and uploads each one with XMLHTTPRequest.  If I don't have
> firebug enabled, I have no problem with memory.  If I have firebug enabled
> but net disabled, I'll see a problem (about 400MB).  If I have net enabled,
> I see a really big problem with about 2GB.  I'll try and make a small test
> case to duplicate it.  It does look like the memory is never cleaned up
> because clicking the buttons at the bottom of about:memory have no affect on
> the amount of memory.
Do you see the problem if you disable "Show XMLHttpRequests" option in the Console panel? (using the mini tab menu)

Any chance I could have a simplified test case so, I can reproduce the problem on my machine?

Honza

Comment 28

[Trev]

Attachment: Test Case

In this test case, select a file on your system that is large (I'm using a 450MB file) and click run.  It will upload 10MB chunks.

I'll be attaching about:memory output of a few runs.  I ran it with:

1 - firebug disabled
  Looked fine
2 - firebug enabled but console, script, and net disabled
  Looked fine
3 - firebug enabled and console enabled (as well as XMLHTTPRequest watcher)
  Started to leak
4 - same as #3 but with script enabled
  Not much different than #3
5 - same as #4 but with net enabled
  Leaked a lot more.

Comment 29

[Trev]

Attachment: all about:memory outputs

I did two about:memory readings for each test in the previous comment.  I would open firefox (initial page is google).  Go to the test case.  Run the test case.  Open about:memory in a new tab.  Copy the output.  Close the tab of the test case.  "Minimize memory usage" three times.  Copy the output.

So, about_memory_1.txt and about_memory_2.txt is for the first test case, about_memory_3.txt and about_memory_4.txt is for the second, etc.

Comment 30

[Trev]

> Do you see the problem if you disable "Show XMLHttpRequests" option in the
> Console panel? (using the mini tab menu)

If I run my test #3 with the XMLHTTPRequests watcher disabled, it looks like #1 or #2.

Comment 31

[Jan Honza Odvarko [:Honza] (always need-info? me)]

Attachment: Firebug test build

Thanks for the excellent test case!

I did one fix in Firebug (http://code.google.com/p/fbug/source/detail?r=12232) and attached a test build, please try the test case  (attachment 573206 [details]) and let me know how it looks for you.

Honza

Comment 32

[Trev]

That looks much better.  I see the memory climb to 1GB and then if I close the tab, go to another page in the tab, or close firebug (completely), the memory goes away.  Also, all the memory is under the string-chars section of about:memory.

One thing, though, is that when I have xmlhttprequest in the console disabled, but I do have console, net, and script enabled, the memory used is 235MB for a 450MB file.  But if I enable xmlhttprequest in the console and then disable net, the memory used is roughly twice that of the file (900MB).

Comment 33

[Jan Honza Odvarko [:Honza] (always need-info? me)]

(In reply to [e-mail] from comment #32)
> That looks much better.  I see the memory climb to 1GB and then if I close
> the tab, go to another page in the tab, or close firebug (completely), the
> memory goes away.
Yes, tab reload (or tab close) is necessary so, Firebug forgets all collected data (the posted body in this case).

> Also, all the memory is under the string-chars section of
> about:memory.
Yeah that make sense, btw. it was 'heap-unclassified' before, correct?

> One thing, though, is that when I have xmlhttprequest in the console
> disabled, but I do have console, net, and script enabled, the memory used is
> 235MB for a 450MB file.  But if I enable xmlhttprequest in the console and
> then disable net, the memory used is roughly twice that of the file (900MB).
Nice observation! It looks like posted-body is kept in the memory twice. Once by Firebug - Firebug has an internal cache used by the Net, Script and XHR Spy (xmlhttprequest option) - and once by the HTTP request object, that is referenced by the XHR Spy. I guess the request object shouldn't be held in the memory (by the XHR Spy object). I'll take a look at this and fix if the theory is true.

Honza

Comment 34

[Jan Honza Odvarko [:Honza] (always need-info? me)]

Now I realized that my previous theory is probably false. Now I am not sure what causes the double-memory problem.

Honza

Comment 35

[Trev]

> > Also, all the memory is under the string-chars section of
> > about:memory.
> Yeah that make sense, btw. it was 'heap-unclassified' before, correct?

Once the tab was closed, it all went to heap-unclassified.  Before that, there were some cases where it was all heap-unclassified and some where part of it was in string-chars.

Comment 36

[Trev]

(In reply to [e-mail] from comment #35)
> > > Also, all the memory is under the string-chars section of
> > > about:memory.
> > Yeah that make sense, btw. it was 'heap-unclassified' before, correct?
> 
> Once the tab was closed, it all went to heap-unclassified.  Before that,
> there were some cases where it was all heap-unclassified and some where part
> of it was in string-chars.

Actually, I'm wrong.  It appears that there was always data in string-chars and in heap-unclassified.  The string-chars was always cleaned up but the heap-unclassified wasn't.

In case #3 and #4 (from comment 28), it was 900MB string-chars and 530MB unclassified.
In case #5, it was 900MB string-chars and 1500MB unclassified.

Comment 37

[Trev]

What is the state on this?  Has the firebug changes been included in the normal firebug extension?  Or are you still looking into comment 32?

Comment 38

[Jan Honza Odvarko [:Honza] (always need-info? me)]

(In reply to Trev from comment #37)
> What is the state on this?  Has the firebug changes been included in the
> normal firebug extension?
Yes, all related changes are included in Firebug 1.9b3
http://getfirebug.com/releases/firebug/1.9/firebug-1.9.0b3.xpi

> Or are you still looking into comment 32?
No, I don't know how to solve this problem. But since there is no memory leak (just ineffective usage of the memory), it's not a priority for now.

Honza

Comment 39

[Trev]

I've just checked with Firebug 1.9b3 and it looks good.  So unless we want this to stay open to look into comment 32, I'd say this bug is fixed.

Comment 40

[Nicholas Nethercote [inactive]]

Agreed.  Someone can file a follow-up bug for comment 32 if they're so inclined.  Thanks, everyone!