I see constant 10 sec CC pauses with the current nightly. My testcase: run ro.me for a min and close the tab. CC(T+311.5) duration: 10344ms, suspected: 150, visited: 8224 RCed and 8237124 GCed, collected: 73 RCed and 4 GCed (77 waiting for GC) ForgetSkippable 2 times before CC, min: 1 ms, max: 2 ms, avg: 2 ms, total: 4 ms, removed: 442 CC(T+364.0) duration: 10312ms, suspected: 294, visited: 8348 RCed and 8237116 GCed, collected: 23 RCed and 0 GCed (100 waiting for GC) ForgetSkippable 26 times before CC, min: 0 ms, max: 2 ms, avg: 0 ms, total: 12 ms, removed: 4663 CC(T+381.8) duration: 10387ms, suspected: 277, visited: 12516 RCed and 8237103 GCed, collected: 105 RCed and 0 GCed (205 waiting for GC) ForgetSkippable 5 times before CC, min: 1 ms, max: 7 ms, avg: 2 ms, total: 14 ms, removed: 40272 GC(T+382.4) Total Time: 551.8ms, Compartments Collected: 159, Total Compartments: 159, MMU (20ms): 0%, MMU (50ms): 0%, SCC Sweep Total: 43.2ms, SCC Sweep Max Pause: 37.9ms, Max Pause: 480.6ms, Allocated: 673MB, +Chunks: 6, -Chunks: 0 Slice: 0, Pause: 34.9 (When: 0.0ms, Reason: PAGE_HIDE): Mark: 33.1ms, Mark Discard Code: 1.3ms, Mark Roots: 32.7ms Slice: 4, Pause: 480.6 (When: 90.3ms, Reason: REFRESH_FRAME): Mark: 434.9ms, Mark Gray: 434.6ms, Mark Gray and Weak: 0.2ms, Sweep: 44.8ms, Sweep Compartments: 4.7ms, Sweep Tables: 2.3ms, Sweep Object: 36.2ms, Sweep String: 1.8ms, Sweep Script: 0.3ms, Sweep Discard Code: 0.6ms, Discard Analysis: 1.7ms, Discard TI: 0.5ms, Sweep Types: 1.0ms, Clear Script Analysis: 0.2ms, Finalize End Callback: 0.9ms Slice: 7, Pause: 0.1 (When: 593.0ms, Reason: REFRESH_FRAME): Totals: Mark: 494.5ms, Mark Discard Code: 1.3ms, Mark Roots: 32.7ms, Mark Gray: 434.6ms, Mark Gray and Weak: 0.2ms, Sweep: 48.6ms, Sweep Atoms: 4.1ms, Sweep Compartments: 4.7ms, Sweep Tables: 2.3ms, Sweep Object: 36.2ms, Sweep String: 1.8ms, Sweep Script: 0.3ms, Sweep Shape: 3.8ms, Sweep Discard Code: 0.6ms, Discard Analysis: 1.7ms, Discard TI: 0.5ms, Sweep Types: 1.0ms, Clear Script Analysis: 0.2ms, Finalize End Callback: 0.9ms CC(T+394.9) duration: 10513ms, suspected: 17743, visited: 43345 RCed and 8240013 GCed, collected: 35262 RCed and 2889 GCed (38151 waiting for GC) ForgetSkippable 2 times before CC, min: 5 ms, max: 8 ms, avg: 6 ms, total: 13 ms, removed: 19349 GC(T+399.9) Total Time: 492.1ms, Compartments Collected: 158, Total Compartments: 158, MMU (20ms): 0%, MMU (50ms): 0%, SCC Sweep Total: 5.1ms, SCC Sweep Max Pause: 1.5ms, Max Pause: 437.6ms, Allocated: 641MB, +Chunks: 0, -Chunks: 5 Slice: 0, Pause: 22.0 (When: 0.0ms, Reason: CC_WAITING): Mark: 20.8ms, Mark Discard Code: 0.7ms, Mark Roots: 20.5ms Slice: 3, Pause: 437.6 (When: 270.2ms, Reason: INTER_SLICE_GC): Mark: 431.0ms, Mark Gray: 430.8ms, Mark Gray and Weak: 0.2ms, Sweep: 6.1ms, Sweep Compartments: 3.9ms, Sweep Tables: 2.1ms, Sweep Object: 0.6ms, Sweep String: 0.2ms, Sweep Script: 0.3ms, Sweep Discard Code: 0.6ms, Discard Analysis: 1.2ms, Sweep Types: 0.9ms, Clear Script Analysis: 0.2ms, Finalize End Callback: 0.8ms Slice: 6, Pause: 0.1 (When: 1006.3ms, Reason: INTER_SLICE_GC): Totals: Mark: 478.4ms, Mark Discard Code: 0.7ms, Mark Roots: 20.5ms, Mark Gray: 430.8ms, Mark Gray and Weak: 0.2ms, Sweep: 8.1ms, Sweep Atoms: 2.6ms, Sweep Compartments: 3.9ms, Sweep Tables: 2.1ms, Sweep Object: 0.6ms, Sweep String: 0.2ms, Sweep Script: 0.3ms, Sweep Shape: 1.9ms, Sweep Discard Code: 0.6ms, Discard Analysis: 1.2ms, Sweep Types: 0.9ms, Clear Script Analysis: 0.2ms, Finalize End Callback: 0.8ms CC(T+410.4) duration: 10373ms, suspected: 246, visited: 8121 RCed and 8237121 GCed, collected: 58 RCed and 3 GCed (61 waiting for GC) ForgetSkippable 3 times before CC, min: 0 ms, max: 2 ms, avg: 1 ms, total: 3 ms, removed: 35377 CC(T+442.5) duration: 10391ms, suspected: 223, visited: 12560 RCed and 8237106 GCed, collected: 57 RCed and 0 GCed (118 waiting for GC) ForgetSkippable 9 times before CC, min: 0 ms, max: 0 ms, avg: 0 ms, total: 3 ms, removed: 1617 .. and so on It's hard to file a bug with all the 10sec freezes :)

Andrew, could this be the same problem what bill had with his demo? Looks like there is lots of GCed stuff in the CC. Gregor, cc log would be nice.

This suggests we're leaking ro.me after we close the page. A previous bug, bug 763730, was about getting a single long CC when we closed the page. That was fixed by compartment merging, but compartment merging intentionally only is done a few times after a tab close, so then because we're leaking, it fails and we get long CCs again.

No, in Bill's case, he didn't close the tab, so the page was still in the BFCache. My understanding is that with a tab close, the page should get thrown out right away.

Hm maybe I just changed to another URL. Let me try again.

Ok I definitely closed it. The strange thing is that I see short and long CC pauses afterwards. CC(T+118.5) duration: 10110ms, suspected: 522, visited: 13728 RCed and 8236804 GCed, collected: 1093 RCed and 2144 GCed (3237 waiting for GC) ForgetSkippable 3 times before CC, min: 1 ms, max: 2 ms, avg: 1 ms, total: 5 ms, removed: 3956 CC(T+121.5) duration: 183ms, suspected: 386, visited: 13236 RCed and 4177 merged GCed, collected: 595 RCed and 2174 GCed (2769 waiting for GC) ForgetSkippable 3 times before CC, min: 1 ms, max: 2 ms, avg: 1 ms, total: 5 ms, removed: 2381 CC(T+147.2) duration: 10202ms, suspected: 598, visited: 16215 RCed and 8263826 GCed, collected: 3535 RCed and 29609 GCed (33144 waiting for GC) ForgetSkippable 9 times before CC, min: 0 ms, max: 2 ms, avg: 0 ms, total: 7 ms, removed: 4208

The short ones are ones where the compartments are merged. I put in code to ensure we don't merge too much, because it can be leaky.

But as you can see it is very effective, making CCs around 54 times faster. ;)

Is ro.me a WebGL thing? If so, I wonder if this leak has something to do with Bug 802834.

Oh, good point.

This is fixed by https://hg.mozilla.org/integration/mozilla-inbound/rev/15b7770dcfcc , in my limited testing which consists in loading RO.ME, letting it run for a minute, opening a new tab with about:memory, closing the RO.ME tab, and clicking GC and CC (but NOT 'minimize memory usage') a few times in about:memory and verifying that all webgl metrics disappear.