Last Comment Bug 646941 - Cycle and garbage collectors can sometimes become very slow
: Cycle and garbage collectors can sometimes become very slow
Status: RESOLVED INCOMPLETE
[Snappy:P3]
:
Product: Core
Classification: Components
Component: General (show other bugs)
: unspecified
: x86 Windows 7
: -- normal with 7 votes (vote)
: ---
Assigned To: Nobody; OK to take it and work on it
:
:
Mentors:
Depends on: 565217
Blocks: 490122
  Show dependency treegraph
 
Reported: 2011-03-31 11:56 PDT by Roman
Modified: 2016-06-27 16:36 PDT (History)
25 users (show)
See Also:
Crash Signature:
(edit)
QA Whiteboard:
Iteration: ---
Points: ---
Has Regression Range: ---
Has STR: ---


Attachments
About memory with #19 (54.52 KB, text/plain)
2012-06-18 05:37 PDT, Martijn
no flags Details
about:memory with comment #23 (114.32 KB, text/plain)
2012-06-21 15:08 PDT, Martijn
no flags Details
CC-log with comment #23 (2.66 MB, application/octet-stream)
2012-06-21 15:11 PDT, Martijn
no flags Details

Description Roman 2011-03-31 11:56:11 PDT
User-Agent:       Mozilla/5.0 (Windows NT 6.1; WOW64; rv:2.0) Gecko/20100101 Firefox/4.0
Build Identifier: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:2.0) Gecko/20100101 Firefox/4.0

In certain situations, both CC and GC times can grow out of proportion, causing severe and very noticeable periodic hangs of the UI.

Typical CC/GC times when this starts happening:

GC mode: full, timestamp: 1301576510185000, duration: 496 ms.
CC timestamp: 1301576511101000, collected: 9981 (9981 waiting for GC), suspected: 4164, duration: 441 ms.
GC mode: full, timestamp: 1301576515486000, duration: 385 ms.
CC timestamp: 1301576520936000, collected: 0 (0 waiting for GC), suspected: 1356, duration: 449 ms.
CC timestamp: 1301576531144000, collected: 0 (0 waiting for GC), suspected: 1731, duration: 404 ms. 



Reproducible: Sometimes

Steps to Reproduce:
1. Browse lots of sites.
2. Leave the browser open and running for at least 24 hours, preferably more.





On 31.03.11 14:31, Olli Pettay wrote:
> How many tabs you have open, and which web sites.

46 tabs, all kinds of websites. Here's a screenshot to give a general idea: http://i.imgur.com/Tvx8a.png

> And do you have some addons?

Yes, 19 currently: Adblock Plus, Anti-Aliasing Tuner, Cutyfox URL Shortener, Download Statusbar, Firebug, Flagfox, Go Parent Folder, HashColouredTabs+, HttpFox, Locationbar 2, Open in Browser, Resurrect Pages, RightBar, RightToClick, SearchPreview, Show Parent Folder, Table2Clipboard, Web Developer, Xmarks

-------------

On 31.03.11 18:38, Andreas Gal wrote:
> I have seen this on stuart's machine, too. After a day or so of having FF
> open GCs got really slow, 500ms-ish and CC was 1s or so. We closed the
> browser and restarted with the same number of tabs and times went down 10x.
> I think this is some persistent leak that makes the mark phase take longer
> and longer.

--------------------

I agree that this behaviour doesn't happen immediately after Firefox is started, even if I restore all the same tabs. Also, if I close most of those 46 tabs I have at the moment (leaving only 4), the CC/GC times drop only very slightly, still taking about 300ms both.

Sometimes it takes days of uptime before Firefox starts doing this. I've sometimes seen this take only a couple of hours on 3.6, but not yet on 4. It appears to be unlikely to start happening if there were few tabs to start with.

-----------

Profiling experiment: Firefox at idle, doing nothing. Error console open. Visual Studio attached and doing sample-based profiling. Every time a CC timestamp is logged, I mark the time in the profiler. I then study the difference between "hot" functions during the long collections and during idle time.

When idle, all sorts of functions can show up in the trace, none taking a significant share of the time. Around the marked times, however, @PL_DHashTableOperate@12 consistently shows up as the #1 hit. It's hard to say exactly what proportion is spent in it because it's hard to find the exact boundaries of the CC in the profiler trace.

(didn't profile GCs because they didn't seem to occur when Firefox is idle)

-----------------

Here's a really curious observation I made today. Say it's happening and my times are in the 400ms range. Go to the spinning dial animation at http://hacks.mozilla.org/2010/01/javascript-speedups-in-firefox-3-6/ and start the dial. The times go back to sane values. Stop it. The times go back up. Perhaps this would give a good hint to someone familiar with the CC/GC?

GC: 327 ms.
CC: collected: 0 (0 waiting for GC), suspected: 2341, duration: 328 ms.

[start the spin]

GC: 75 ms.
CC: collected: 0 (0 waiting for GC), suspected: 7285, duration: 79 ms.

[stop the spin]

GC: 77 ms.
CC: collected: 22 (44 waiting for GC), suspected: 4350, duration: 87 ms.

[do a full reload of any random tab]

GC: 566 ms.
CC: collected: 690 (690 waiting for GC), suspected: 3517, duration: 333 ms.
CC: collected: 0 (2 waiting for GC), suspected: 1725, duration: 320 ms.

Observe that CC/GC become instantly fast when I start the dial, and become instantly slow when I do a full reload of some random tab (but not when I stop the dial). Most curiously, if I leave the dial spinning the times remain short even on full reloads.
Comment 1 Roman 2011-11-03 08:12:29 PDT
Finally got this in 7.0.1.

GC mode: full, timestamp: 1320332795002000, duration: 408 ms.
CC timestamp: 1320332796021000, collected: 6708 (6708 waiting for GC), suspected: 4262, duration: 257 ms.

etc.

Curiously enough, the spinning dial animation at http://hacks.mozilla.org/2010/01/javascript-speedups-in-firefox-3-6/ still causes the same speedup as before. I'm tempted to leave it running in the background just so that I can get fast GC without pauses...


GC mode: full, timestamp: 1320332895204000, duration: 358 ms.

[start the dial]

GC mode: full, timestamp: 1320332899995000, duration: 31 ms.
GC mode: full, timestamp: 1320332901240000, duration: 29 ms.

[stop the dial]

GC mode: full, timestamp: 1320332908058000, duration: 348 ms.


Any ideas why the dial fixes the pauses?
Comment 2 Andrew McCreight [:mccr8] 2011-11-03 08:18:03 PDT
It could generate activity in a way that causes the GC to be run more often.  Which might cause it to spend less time at each GC sweeping in the main thread?  Or something?  Bill or Gregor will probably have a better idea than me.
Comment 3 Gregor Wagner [:gwagner] 2011-11-03 08:32:54 PDT
(In reply to Roman from comment #1)
> Finally got this in 7.0.1.
> 
> GC mode: full, timestamp: 1320332795002000, duration: 408 ms.
> CC timestamp: 1320332796021000, collected: 6708 (6708 waiting for GC),
> suspected: 4262, duration: 257 ms.
> 
> etc.
> 
> Curiously enough, the spinning dial animation at
> http://hacks.mozilla.org/2010/01/javascript-speedups-in-firefox-3-6/ still
> causes the same speedup as before. I'm tempted to leave it running in the
> background just so that I can get fast GC without pauses...
> 
> 
> GC mode: full, timestamp: 1320332895204000, duration: 358 ms.
> 
> [start the dial]
> 
> GC mode: full, timestamp: 1320332899995000, duration: 31 ms.
> GC mode: full, timestamp: 1320332901240000, duration: 29 ms.
> 
> [stop the dial]
> 
> GC mode: full, timestamp: 1320332908058000, duration: 348 ms.
> 
> 
> Any ideas why the dial fixes the pauses?

I would say the GC mode is wrong here and we perform a per-compartment GC.
Comment 4 Andrew McCreight [:mccr8] 2011-11-03 08:49:06 PDT
(In reply to Gregor Wagner from comment #3)
> I would say the GC mode is wrong here and we perform a per-compartment GC.
Ah, that would make sense!  I think a bug was fixed (probably post-7) that was always displaying GCs are full even when they are compartmental.

It still sounds like the triggering logic is off somehow if forcing a per-compartment GC in a tab by running an animation ends up improving the overall experience by suppressing full GCs.

Per-compartment GCs would likely reduce CC time by marking everything in other compartments non-gray.
Comment 5 Gregor Wagner [:gwagner] 2011-11-03 09:21:06 PDT
(In reply to Andrew McCreight [:mccr8] from comment #4)
> (In reply to Gregor Wagner from comment #3)
> > I would say the GC mode is wrong here and we perform a per-compartment GC.
> Ah, that would make sense!  I think a bug was fixed (probably post-7) that
> was always displaying GCs are full even when they are compartmental.
> 
> It still sounds like the triggering logic is off somehow if forcing a
> per-compartment GC in a tab by running an animation ends up improving the
> overall experience by suppressing full GCs.

Ha that's a nice way to stop global GCs :) 
Incremental / parallel marking and triggering compartment GCs more aggressively will help.
Comment 6 Andrew McCreight [:mccr8] 2011-12-01 12:59:58 PST
Roman: have you tried reproducing this in safe mode?  It could be an addon.  What does your about:memory look like?  It could be a leak.

Marking this as P3.  We have a bunch of work on the way that should improve GC and CC pause times.  If it turns out there's a leak, then we can turn this into MemShrink.
Comment 7 Krzysiek 2012-03-12 02:55:29 PDT
I can confirm this too. Freezes of the UI takes several seconds. This happens for me after few hours of prowsing, sometimes it kaes only hour. During this time I visit about 150-200 pages and I keep about 20-30 tabs open. It started right at 3.6.4 and it is present still in 10.0.2. If you need more info contact me.
Comment 8 Olli Pettay [:smaug] (reviewing overload) 2012-03-12 03:06:47 PDT
Krzysiek, could you try Nightly? Do you have any addons?
Comment 9 Krzysiek 2012-03-12 03:40:48 PDT
Aplikacja: Firefox 10.0.2 (20120215223356)
System operacyjny: WINNT (x86-msvc) 7.0

Liczba elementów: 51 Wyłączone means disabled, Niekompatybilne means incompatible

- Aardvark 3.0 (Wyłączone, Niekompatybilne)
- Adblock Plus 2.0.3
- Adblock Plus Pop-up Addon 0.3
- Add Bookmark Here ² 4.0.20120221
- Add-on Compatibility Reporter 1.1
- Aero Window Title 1.6
- Anti-Banner 12.0.0.470 (Wyłączone)
- BetterPrivacy 1.68
- British English Dictionary 1.19.1 (Wyłączone)
- Click to call with Skype 5.5.0.8013 (Wyłączone, Niekompatybilne)
- Context Search 0.4.6
- Controle de Scripts 1.0.3
- Cookie Monster 1.1.0
- DeeperWeb for Google 1.3.3 (Wyłączone)
- Download Statusbar 0.9.10
- DownloadHelper 4.9.8
- Element Hiding Helper dla Adblock Plusa 1.2.1 (Wyłączone)
- Extension List Dumper 1.15.2
- Facebook Auto-Logout 0.3.2
- FEBE 7.0.3.2 (Wyłączone)
- FlashGot 1.4
- Free Download Manager plugin 1.5.5
- gTranslate 0.9
- IE View 1.5.0
- Image Search Options 2.0.2
- ImageTools 1.0.4
- Is It Compatible? 0.5.3 (Wyłączone)
- Kaspersky URL Advisor 12.0.0.470 (Wyłączone)
- Kaspersky Virtual Keyboard 12.0.0.470 (Wyłączone)
- MemChaser 0.2
- Memory Fox 7.4
- Multi Links 3.0.0.19 (Wyłączone)
- NoSquint 2.1.5
- OperaView 0.7
- Personas 1.6.2 (Wyłączone)
- Places Maintenance 1.3
- Priv3 0.11 (Wyłączone)
- PrivacyChoice TrackerBlock 2.2
- QuickJava 1.7.5
- RefreshBlocker 0.8 (Wyłączone)
- Replace Bookmark 1.3.8
- SearchPreview 5.3 (Wyłączone)
- Session Manager 0.7.8.1
- Shareaholic 3.0.1
- Tab To Window 1.2.9
- Text Link 4.0.2011021601
- Tree Style Tab 0.14.2012021101
- UnPlug 2.050
- UpdateBookmark 0.2
- Vacuum Places Improved 1.2
- Web Developer 1.1.9 (Wyłączone)

But I have made some tests with various sets of add-ons, disabling almost all of them and this produced no significinant improvement. This bug does not occur on my home computer with almost identical ann-ons (but it has XP, different Av, etc.). It also does not occur on computer of my work friend, which is identical on software and hardware level, he just uses a bit different set of add-ons.
I haven't tried nightly yet, I will check it soon.
Comment 10 Olli Pettay [:smaug] (reviewing overload) 2012-03-12 03:45:00 PDT
(In reply to Krzysiek from comment #9)
> But I have made some tests with various sets of add-ons, disabling almost
> all of them and this produced no significinant improvement.
The "almost all" can be the key. Perhaps just the addon which causes the problem wasn't disabled -
if the problem you see is related to addons.
Comment 11 Krzysiek 2012-03-12 07:15:27 PDT
I am pretty much sure that I've disabled every all add-ons in some test, and testing in dafe mode with the same results, but I can't remember for sure now.
Anyway, I've tested Nightly and it behaves a bit different but not fully ok. I was testing using my profile from release FF.
After some time, when memory reaches levels from 10.0.2 when hangs start to occur, it hang one time, but kept working, altough slower and some page elements start to fail loading/displaying (images). In the console I saw: http://imgur.com/Ao7eh
Comment 12 Wayne Mery (:wsmwk, NI for questions) 2012-05-17 20:33:10 PDT
(In reply to Krzysiek from comment #11)
> I am pretty much sure that I've disabled every all add-ons in some test, and
> testing in dafe mode with the same results, but I can't remember for sure
> now.
> Anyway, I've tested Nightly and it behaves a bit different but not fully ok.
> I was testing using my profile from release FF.
> After some time, when memory reaches levels from 10.0.2 when hangs start to
> occur, it hang one time, but kept working, altough slower and some page
> elements start to fail loading/displaying (images). In the console I saw:
> http://imgur.com/Ao7eh

well, your error console logs an "out of memory" from sessionstore.js - that's pretty serious doo doo.  How many tabs are open?  How big is your sessionstore.js on disk in your profile?   Does it definitely reproduce in safe mode?
Comment 13 Roman 2012-05-18 04:27:23 PDT
(In reply to Andrew McCreight [:mccr8] from comment #6)
> Roman: have you tried reproducing this in safe mode?  It could be an addon. 
> What does your about:memory look like?  It could be a leak.

I have tried reproducing this in safe mode, and couldn't. But keep in mind that it's also not easy reproducing this in normal mode.

Firefox is generally more responsive nowadays (v12) and I don't seem to have had periodic pauses due to CC/GC for quite a while. The current log seems to agree:

> CC(T+67406.7) collected: 22288 (22288 waiting for GC),
>    suspected: 1246, duration: 51 ms.
> ForgetSkippable 7 times before CC, min: 0 ms, max: 10 ms,
>    avg: 2 ms, total: 14 ms, removed: 621

So I suppose this bug has since gone away, presumably thanks to the work done on CC/GC on numerous other bugs. I'll make sure to post here if I see slow CC/GC again.
Comment 14 Krzysiek 2012-05-18 04:42:31 PDT
It is still here in newest full release. Memory keeps rising till it reaches 1.2-1.3GB - at some moment pages starts  to miss loading some pictures, FF slows down to a crawl, dimms page content, GUI reactions are delayed a minute or more. After few minutes it finally crashes and closes. 
I am still trying to track if it some plugin or not.
Comment 15 Wayne Mery (:wsmwk, NI for questions) 2012-05-18 05:35:09 PDT
(In reply to Roman from comment #13)
> So I suppose this bug has since gone away, presumably thanks to the work
> done on CC/GC on numerous other bugs. I'll make sure to post here if I see
> slow CC/GC again.

I think then we close WFM. ANd reopen if you see the problem again. 
Krzysiek must be seeing some other manifestation - which may be an addon
Comment 16 Roman 2012-06-09 17:28:40 PDT
The problem has reoccurred :/  The only relevant change recently is the upgrade to Firefox 13.0 (on Win7/64). The CC times *while holding the Down arrow to scroll* are around 400-500ms, which is, of course, very noticeable. Also happening right now as I type, temporarily swallowing whole words and making Firefox feel really sluggish as a result. Logs below.


(In reply to Andrew McCreight [:mccr8] from comment #6)
> Roman: have you tried reproducing this in safe mode?  It could be an addon. 
> What does your about:memory look like?  It could be a leak.

It's as hard to reproduce as it's always been. I restarted Firefox and it went away. I did a capture of about:memory first though; see below. I had about 20 open tabs, plus something on the order of 100 in several panorama groups, though I have them set to load on first use and most were unused.


CC/GC TIMES LOG:

CC(T+34.4) duration: 430ms, suspected: 2533, visited: 83205 RCed and 277925 GCed, collected: 0 RCed and 0 GCed (38 waiting for GC)
ForgetSkippable 14 times before CC, min: 1 ms, max: 14 ms, avg: 2 ms, total: 39 ms, removed: 12826

CC(T+41.2) duration: 413ms, suspected: 2793, visited: 83333 RCed and 275369 GCed, collected: 0 RCed and 0 GCed (38 waiting for GC)
ForgetSkippable 13 times before CC, min: 1 ms, max: 10 ms, avg: 2 ms, total: 36 ms, removed: 4574

...

GC(T+659.7) TotalTime: 137.5ms, Type: compartment, MMU(20ms): 0%, MMU(50ms): 0%, Reason: TOO_MUCH_MALLOC, NonIncrementalReason: GC mode, +chunks: 0, -chunks: 0
mark: 73.4, mark-roots: 15.0, mark-other: 9.0, sweep: 45.0, sweep-obj: 10.8, sweep-string: 4.8, sweep-script: 0.1, sweep-shape: 3.9, discard-code: 0.7, discard-analysis: 0.7, xpconnect: 9.8, deallocate: 0.0

GC(T+664.0) TotalTime: 308.6ms, Type: global, MMU(20ms): 0%, MMU(50ms): 0%, Reason: POST_COMPARTMENT, NonIncrementalReason: GC mode, +chunks: 0, -chunks: 0
mark: 237.3, mark-roots: 13.3, mark-other: 68.8, sweep: 68.1, sweep-obj: 7.0, sweep-string: 0.7, sweep-script: 1.6, sweep-shape: 12.1, discard-code: 5.6, discard-analysis: 20.1, xpconnect: 6.6, deallocate: 0.1

CC(T+670.0) duration: 410ms, suspected: 331, visited: 79834 RCed and 278508 GCed, collected: 119 RCed and 20 GCed (139 waiting for GC)
ForgetSkippable 3 times before CC, min: 1 ms, max: 23 ms, avg: 8 ms, total: 26 ms, removed: 339

...

AFTER CLOSING ~10 tabs:

CC(T+881.1) duration: 780ms, suspected: 2192, visited: 119549 RCed and 491483 GCed, collected: 27423 RCed and 147498 GCed (174921 waiting for GC)
ForgetSkippable 2 times before CC, min: 2 ms, max: 22 ms, avg: 12 ms, total: 24 ms, removed: 257

CC(T+887.9) duration: 539ms, suspected: 109, visited: 92084 RCed and 343999 GCed, collected: 31 RCed and 14 GCed (45 waiting for GC)
ForgetSkippable 3 times before CC, min: 1 ms, max: 18 ms, avg: 7 ms, total: 21 ms, removed: 177

(780ms!...)


ABOUT:MEMORY

Explicit Allocations
580.32 MB (100.0%) -- explicit
├──291.55 MB (50.24%) -- js
│  ├───65.49 MB (11.28%) ++ (33 tiny)
│  ├───52.41 MB (09.03%) -- compartment([System Principal], 0x5881000)
│  │   ├──30.96 MB (05.34%) -- gc-heap
│  │   │  ├──10.19 MB (01.76%) ++ objects
│  │   │  ├───8.86 MB (01.53%) -- arena
│  │   │  │   ├──8.66 MB (01.49%) ── unused
│  │   │  │   └──0.20 MB (00.03%) ++ (2 tiny)
│  │   │  ├───8.19 MB (01.41%) ++ shapes
│  │   │  └───3.73 MB (00.64%) ++ (4 tiny)
│  │   └──21.44 MB (03.70%) ++ (7 tiny)
│  ├───38.75 MB (06.68%) -- compartment(...)
│  │   ├──20.36 MB (03.51%) -- gc-heap
│  │   │  ├──13.80 MB (02.38%) ++ (5 tiny)
│  │   │  └───6.55 MB (01.13%) ++ objects
│  │   ├──10.93 MB (01.88%) ── script-data
│  │   └───7.46 MB (01.29%) ++ (6 tiny)
│  ├───18.64 MB (03.21%) ── gc-heap-decommitted
│  ├───18.51 MB (03.19%) -- compartment(...)
│  │   ├───9.42 MB (01.62%) ++ (7 tiny)
│  │   └───9.09 MB (01.57%) ++ gc-heap
│  ├───14.59 MB (02.51%) -- compartment(...)
│  │   ├───9.19 MB (01.58%) ++ gc-heap
│  │   └───5.40 MB (00.93%) ++ (7 tiny)
│  ├───13.52 MB (02.33%) -- compartment(...)
│  │   ├───8.57 MB (01.48%) -- shapes-extra
│  │   │   ├──8.42 MB (01.45%) ── tree-tables
│  │   │   └──0.15 MB (00.03%) ++ (3 tiny)
│  │   └───4.95 MB (00.85%) ++ (7 tiny)
│  ├───11.52 MB (01.99%) -- compartment(atoms)
│  │   ├───7.74 MB (01.33%) ── string-chars
│  │   └───3.78 MB (00.65%) ++ gc-heap
│  ├───11.50 MB (01.98%) -- compartment(...)
│  │   ├───6.65 MB (01.15%) ++ gc-heap
│  │   └───4.85 MB (00.84%) ++ (7 tiny)
│  ├────9.51 MB (01.64%) ++ compartment(...)
│  ├────9.04 MB (01.56%) ++ compartment(...)
│  ├────7.24 MB (01.25%) ++ compartment(...)
│  ├────7.21 MB (01.24%) ++ compartment(...)
│  ├────7.18 MB (01.24%) ++ compartment(...)
│  └────6.44 MB (01.11%) ++ compartment(...)
├──112.29 MB (19.35%) ── heap-unclassified
├──110.21 MB (18.99%) -- window-objects
│  ├───83.13 MB (14.33%) -- active
│  │   ├──75.87 MB (13.07%) ++ (110 tiny)
│  │   └───7.27 MB (01.25%) -- top=3216 (inner=3219)
│  │       ├──7.27 MB (01.25%) ++ inner-window(id=3219, uri=https://bugzilla.mozilla.org/show_bug.cgi?id=490122)
│  │       └──0.00 MB (00.00%) ++ inner-window(id=3218, uri=[system])
│  ├───27.05 MB (04.66%) ++ cached
│  └────0.03 MB (00.01%) ++ other
├───31.10 MB (05.36%) -- storage
│   ├──29.79 MB (05.13%) -- sqlite
│   │  ├──11.96 MB (02.06%) ── other
│   │  ├──11.13 MB (01.92%) -- places.sqlite
│   │  │  ├──10.69 MB (01.84%) ── cache-used [3]
│   │  │  └───0.44 MB (00.08%) ++ (2 tiny)
│   │  └───6.70 MB (01.15%) ++ (12 tiny)
│   └───1.31 MB (00.23%) ++ prefixset
├───24.95 MB (04.30%) -- images
│   ├──24.04 MB (04.14%) -- content
│   │  ├──24.01 MB (04.14%) -- used
│   │  │  ├──13.03 MB (02.25%) ── raw
│   │  │  ├───8.51 MB (01.47%) ── uncompressed-nonheap
│   │  │  └───2.47 MB (00.43%) ── uncompressed-heap
│   │  └───0.03 MB (00.00%) ++ unused
│   └───0.91 MB (00.16%) ++ chrome
└───10.22 MB (01.76%) ++ (8 tiny)

Other Measurements
  2.39 MB ── canvas-2d-pixel-bytes
580.26 MB ── explicit
  0.00 MB ── gfx-d2d-surfacecache
  0.00 MB ── gfx-d2d-surfacevram
  0.00 MB ── gfx-surface-image
 12.72 MB ── gfx-surface-win32
399.96 MB ── heap-allocated
414.97 MB ── heap-committed
    3.61% ── heap-committed-fragmentation
  2.79 MB ── heap-dirty
 38.04 MB ── heap-unallocated
 10.98 MB ── images-content-used-uncompressed
        7 ── js-compartments-system
      115 ── js-compartments-user
160.00 MB ── js-gc-heap
  4.63 MB ── js-main-runtime-analysis-temporary
 44.71 MB ── js-main-runtime-gc-heap-arena-unused
  0.00 MB ── js-main-runtime-gc-heap-chunk-clean-unused
  0.00 MB ── js-main-runtime-gc-heap-chunk-dirty-unused
 18.64 MB ── js-main-runtime-gc-heap-decommitted
    0.17% ── js-main-runtime-gc-heap-unused-fraction
  8.69 MB ── js-main-runtime-mjit
 49.55 MB ── js-main-runtime-objects
 65.17 MB ── js-main-runtime-scripts
 54.68 MB ── js-main-runtime-shapes
 20.81 MB ── js-main-runtime-strings
  9.60 MB ── js-main-runtime-type-inference
        0 ── low-commit-space-events
        0 ── low-memory-events-physical
        0 ── low-memory-events-virtual
628.09 MB ── private
656.64 MB ── resident
  0.00 MB ── shmem-allocated
  0.00 MB ── shmem-mapped
 29.80 MB ── storage-sqlite
880.34 MB ── vsize
 21.90 MB ── window-objects-dom
 23.36 MB ── window-objects-layout-arenas
 48.61 MB ── window-objects-layout-style-sets
  0.04 MB ── window-objects-layout-text-runs
 16.30 MB ── window-objects-style-sheets


(In reply to Wayne Mery (:wsmwk) from comment #15)
> ANd reopen if you see the problem again. 

Reopening.
Comment 17 Daniel Beardsmore 2012-06-09 17:35:18 PDT
It's weird, I got a dreadful bout of it the day that Firefox upgraded itself from 12 to 13 at login: by the afternoon, I was struggling to use it and eventually restarted it to stop the onslaught of freezing.

I held off commenting here, and in the two days after that, it behaved normally again.

Maybe the new tab page gallery feature is broken? I switched that straight off as it's of no interest to me on that computer.
Comment 18 Olli Pettay [:smaug] (reviewing overload) 2012-06-10 03:37:51 PDT
Roman, could you perhaps create a CC log when the CC times are bad.
https://wiki.mozilla.org/Performance:Leak_Tools#Cycle_collector_heap_dump
Use the script in the first gray box.
(The log may contain URLs of visited pages)
zip the log and send it to me.
Comment 19 Martijn 2012-06-18 05:36:34 PDT
I'm also experiencing a lot of overall sluggishness since upgrading from 12 to 13. I'm not sure if CC is the problem here. The pauses are periodic and the didn't occur to me on v12.

Win7/64, 8 GB memory

Add-ons:
- DOM-Inspector
- Downloadhelper
- LogMeIn RA plugin
- Pencil
- Skype (disabled)

Plugins:
- 2007 Microsoft Office System
- Adobe Acrobat (two versions)
- Google earth
- Google Talk, Google Talk Video Accelerator
- Google Update
- iTunes application detector
- Java deployment toolkit
- Java platform
- LogmeIn RA components
- Windows Media Player plugin
- Picasa
- Quicktime
- Shockwave flash
- Shockwave for director
- Silverlight
- Winamp application detector
(holy ****, all those plugins that are installed without you knowing!)

It's pretty bad: we're talking pauses of around 1 second, perhaps more.

I will upload a about:memory and CC-log in a moment.
Comment 20 Martijn 2012-06-18 05:37:39 PDT
Created attachment 633998 [details]
About memory with #19
Comment 21 Martijn 2012-06-18 05:40:02 PDT
CC-log is too big. I will send it directly to Olli Pettay as requested in #18
Comment 22 Andrew McCreight [:mccr8] 2012-06-18 08:20:12 PDT
If you install the MemChaser addon then you can at least tell whether they are CC or GC pauses or what. https://addons.mozilla.org/en-US/firefox/addon/memchaser/
Comment 23 Martijn 2012-06-21 15:07:31 PDT
I have installed memchaser a few days ago. Both GC and CC times have been marked red after a few hours as far as I remember. GC times are currently ~750ms after a few days of surfing. CC is doing ~290ms. It looks like it also prints things to my error console, and these are the last ones I got:

GC(T+224962.7) TotalTime: 742,5ms, Type: global, MMU(20ms): 0%, MMU(50ms): 0%, Reason: CC_WAITING, NonIncrementalReason: GC mode, +chunks: 0, -chunks: 0
mark: 579,1, mark-roots: 75,7, mark-other: 24,9, sweep: 159,4, sweep-obj: 12,0, sweep-string: 0,3, sweep-script: 0,4, sweep-shape: 22,5, discard-code: 1,8, discard-analysis: 6,1, xpconnect: 34,5, deallocate: 0,2

CC(T+224965.2) duration: 282ms, suspected: 59, visited: 178425 RCed and 44894 GCed, collected: 0 RCed and 0 GCed (0 waiting for GC)
ForgetSkippable 6 times before CC, min: 0 ms, max: 120 ms, avg: 20 ms, total: 120 ms, removed: 1136

I will send my about:memory and this time I have a 27.8 MB big CC-log, 2.6 MB compressed so that should fit here.

My previous CC-log which I sent to Olli Pettay was 161 MB uncompressed. To that, he replied (listing it here for reference):
"Odd looking log. You seem to leak all the browser UI documents, 222 instances to be exact.
Usually there should be no nsDocuments in the log.

There are nsXPCWrappedJS (nsIObserver) objects keeping each document alive :/
Do you happen to have any addons? Can you reproduce the problem using Nightly
nightly.mozilla.org?"

The CC-log I'm about to submit has only two nsDocument entries so perhaps my previous log was just some hard to trigger situation and not relevant to this bug.
Comment 24 Martijn 2012-06-21 15:08:20 PDT
Created attachment 635495 [details]
about:memory with comment #23
Comment 25 Martijn 2012-06-21 15:11:13 PDT
Created attachment 635497 [details]
CC-log with comment #23
Comment 26 Martijn 2012-06-21 15:46:45 PDT
In addition to my previous posts, I forgot to mention that I mainly use seperate windows for browsing instead of tabs. I rarely use tabs. It's a matter of preference. I just find it easier to organise, switch between, and keep track of windows instead of tabs.

Of course using windows shouldn't result in problems with GC/CC, but I may be something that helps trigger it.

Sites and documents that I regularly view in my browser are google mail, google documents, youtube (with webm-format movies where possible), soundcloud (uses Flash), and several news sites. Nothing special I'd say.
Comment 27 Chris 2013-12-10 15:25:52 PST
This problem is still around, I have done at least one PR on it.

Here is my observation.

When memory usage is high enough CC's or GC's slow down, cant remember which off hand and I have just restarted firefox so wont know right this moment.
this affects firefox a lot as it seems to run a cc or gc whenever loading a page.  So if they are slow then the page load is slow.

I have tracked down much of my memory usage to the following addons, sadly I consider them important.

Tabmix plus - even tho this one is a gui plugin not one that should affect content, it adds a ton of memory usage even from when you fist open the app.  Opening firefox without this addon uses approx 95meg of ram on my system, with the addon it uses 300meg off the bat.  Triple the memory.    since its normal for me to have 50+ tabs navigating them without multirow etc. is a real pain.  tabmix plus sadly is required for me unless I find a suitable alternative.

Adblock plus - A very popular plugin, this adds a ton of memory usage, I found it on average doubles my ram usage and in addition gc and cc stop working so eg. when I close tabs the memory doesnt come back if I have adblock plus loaded.  Firefox devs claim to have fixed issues with this plugin but its defenitly problematic on my install.  alternate ways to block ads such as requestpolicy make firefox run much faster and use much less memory but they require hand holding to allow the right requests and can mess up things like payment pages, whilst adblock plus just works.

On plugins such as adobe plugin, I find these affect cc/gc performance even if they disabled, sadly I cant find a way for firefox to NOT detect these plugins, if I remove the files the respective apps automatically reinstall them as if they constantly monitoring for the presence of the plugin.  I havent found a way to make firefox not scan the registry for plugins.  I dont want to disable these plugins I want to REMOVE/PURGE them.

Also opening new windows I found adds to memory and gc/cc demand.  so 50 tabs in  windows is worse than 50 tabs in 1 window.  I requested a version of firefox where gc/cc is turned off, I expect if ever made it will run at lightning speed.
Comment 28 Olli Pettay [:smaug] (reviewing overload) 2013-12-11 07:35:46 PST
Please file new bugs about each issue. Hopefully with exact steps to reproduce and please tell
which OS you're using. Cc me (:smaug) and :mccr8 to the bugs. Thanks.


Addons change. At some point Adblock plus was working quite well. It is possible that it has
changed and leaks, or Firefox has changed.
Also, web sites change. Facebook was leaking like a maniac still few weeks ago.

And when you say cc or gc is slow, what kind of times are you talking about? Based on telemetry data
median cc time is 8ms.
Comment 29 Andrew McCreight [:mccr8] 2016-02-23 08:04:22 PST
The GC and CC have changed a lot in the last three years, so I'm going to mark this incomplete. The most common reason for slow CC and GC times is memory leaks. When there is a ton of stuff to look at, the CC and GC start slowing down.
Comment 30 Olli Pettay [:smaug] (reviewing overload) 2016-02-23 08:23:34 PST
And we've fixed lots of memory leaks! But if anyone sees anything suspicious, too high memory usage or high CC/GC times, please file new bugs.
Comment 31 Phoenix 2016-02-23 14:09:00 PST
Olli, what about fixing old bugs, like Bug 713216, or only new bugs get attention nowadays?
Comment 32 Wayne Mery (:wsmwk, NI for questions) 2016-06-26 07:46:29 PDT
(In reply to Olli Pettay [:smaug] (high review load, please consider other reviewers) from comment #30)
> And we've fixed lots of memory leaks! But if anyone sees anything
> suspicious, too high memory usage or high CC/GC times, please file new bugs.

(In reply to Phoenix from comment #31)
> Olli, what about fixing old bugs, like Bug 713216, or only new bugs get
> attention nowadays?

Phoenix, I don't think Olli is saying old bug reports are always obsolete, but he is saying this bug report is :)

So your question is also partly answered in comment 29. If you have a reproducible testcase, an OPEN bug report that clearly describes it should be updated, or a new bug filed for just your case.
Comment 33 Phoenix 2016-06-27 10:54:35 PDT
(In reply to Wayne Mery (:wsmwk, NI for questions) from comment #32)
> Phoenix, I don't think Olli is saying old bug reports are always obsolete,
Actions says more than thousand words

(In reply to Wayne Mery (:wsmwk, NI for questions) from comment #32)
> If you have a reproducible testcase, an OPEN bug report that clearly describes it...
... that doesn't matter anything to devs, they can simply ignore it for years, as it usually happens here
Comment 34 Daniel Beardsmore 2016-06-27 16:36:49 PDT
It's ironic that the situation that anecdotally seems to cause the most trouble in terms of recurring periods of unresponsiveness is making use of the debugger. After all, Firebug used to cause this problem, which is why I ditched it, and why I was glad that Firefox integrated a debugger of its own. Now it seems we're slowly returning to square one.

I would never want to be without all my add-ons for long enough to figure out why I still have to restart Firefox regularly due to what I guess is still the same problem. In 64-bit Firefox (which I run at home in Windows 10 now that it's finally become available) it would seem more practical to me to care less about garbage collection and more about responsiveness -- after all, I only run 64-bit Firefox to stop it crashing after hitting 2 GB RAM. There's less value in collecting garbage since it's got as much virtual memory as it could dream of. Also, surely it could collect garbage when every window is inactive? If I'm using other software, that's a good time to for Firefox take a long hard look at the RAM, instead of when I'm trying to watch a video or scroll through a page. GC cycles that run during scrolling are the most idiotic.

With that said, it's a waste of time. I still don't understand why Firefox gobbles up RAM so fast. The about:memory features do little: Firefox and/or addons just won't let go of so much rubbish in RAM, so running continual GC cycles seems senseless as you're never getting that RAM back no matter how many times you beg the heap to let go of its unused objects. Generally the only time you ever see RAM released is directly after closing a tab with large images, and it releases the RAM the images took. The rest of it is just lost.

All browsers now eat RAM like there's no tomorrow, and I have no idea why. Firefox is the worst hit as it's effectively single process (for now anyway), while other browsers keep spawning more RAM-chugging processes and can avoid hitting 1.5 GB limit in any one process.

Looking at the about:memory figures never told me anything: all the memory is just in use by everything. In 32-bit Firefox it's a toss-up regarding whether I have to restart it due to constant freezes as it fights to save its life as it butts up against the 1.5 GB limit, or whether it's freezing too often. Normally the RAM runs out. Sometimes so much so that it crashes on exit, but normally it only gets to the screaming in pain stage before I safely restart it.

</rant>

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