I've been watching my GC times after IGC was turned on again, and it seems like I never get IGC working for me, all I get are entries like these: GC(T+14450.0) Total Time: 187.9ms, Compartments Collected: 599, Total Compartments: 599, MMU (20ms): 0%, MMU (50ms): 0%, Reason: CC_WAITING, Nonincremental Reason: requested, Allocated: 198MB, +Chunks: 0, -Chunks: 0 Totals: Mark: 141.7ms, Mark Roots: 5.3ms, Mark Other: 14.9ms, Finalize Start Callback: 0.7ms, Sweep: 45.3ms, Sweep Compartments: 25.4ms, Sweep Object: 2.3ms, Sweep String: 0.2ms, Sweep Script: 1.0ms, Sweep Shape: 6.4ms, Discard Code: 2.3ms, Discard Analysis: 13.5ms, Discard TI: 2.0ms, Sweep Types: 6.3ms, Clear Script Analysis: 1.2ms, Finalize End Callback: 2.6ms, End Callback: 0.6ms GC(T+14485.5) Total Time: 207.0ms, Compartments Collected: 611, Total Compartments: 611, MMU (20ms): 0%, MMU (50ms): 0%, Reason: PAGE_HIDE, Nonincremental Reason: requested, Allocated: 208MB, +Chunks: 0, -Chunks: 0 Totals: Purge: 2.5ms, Mark: 145.9ms, Mark Roots: 8.9ms, Mark Other: 16.5ms, Finalize Start Callback: 0.7ms, Sweep: 54.8ms, Sweep Compartments: 29.7ms, Sweep Object: 5.7ms, Sweep String: 0.9ms, Sweep Script: 1.0ms, Sweep Shape: 7.0ms, Discard Code: 2.9ms, Discard Analysis: 15.1ms, Discard TI: 1.1ms, Sweep Types: 6.3ms, Clear Script Analysis: 1.2ms, Finalize End Callback: 3.0ms, End Callback: 3.4ms GC(T+14450.0) Total Time: 187.9ms, Compartments Collected: 599, Total Compartments: 599, MMU (20ms): 0%, MMU (50ms): 0%, Reason: CC_WAITING, Nonincremental Reason: requested, Allocated: 198MB, +Chunks: 0, -Chunks: 0 Totals: Mark: 141.7ms, Mark Roots: 5.3ms, Mark Other: 14.9ms, Finalize Start Callback: 0.7ms, Sweep: 45.3ms, Sweep Compartments: 25.4ms, Sweep Object: 2.3ms, Sweep String: 0.2ms, Sweep Script: 1.0ms, Sweep Shape: 6.4ms, Discard Code: 2.3ms, Discard Analysis: 13.5ms, Discard TI: 2.0ms, Sweep Types: 6.3ms, Clear Script Analysis: 1.2ms, Finalize End Callback: 2.6ms, End Callback: 0.6ms I don't know if this is expected or not, but I have not seen even a single GC so far that does not have a "Nonincremental Reason" (not that I watch every GC I get, but I do watch the error console pretty heavily).

If you have about:telemetry installed, you can check GC_NON_INCREMENTAL. FYI, I'm also seeing the same thing: 122 out of 122 of my GC have been non-incremental, despite GC_INCREMENTAL_DISABLED being 0 everywhere.

I have seen it do a couple of slices a few times. I'm not sure what that means precisely: GC(T+2243.9) Total Time: 224.7ms, Compartments Collected: 393, Total Compartments: 393, MMU (20ms): 0%, MMU (50ms): 0%, Max Pause: 201.5ms, Nonincremental Reason: requested, Allocated: 96MB, +Chunks: 3, -Chunks: 0 Slice: 0, Pause: 23.2 (When: 23.2ms, Reason: MAYBEGC): Purge: 0.1ms, Mark: 16.8ms, Mark Roots: 6.7ms, Discard Code: 4.6ms Slice: 1, Pause: 201.5 (When: 324.9ms, Reason: INTER_SLICE_GC, Reset: requested): Mark: 107.1ms, Mark Roots: 5.3ms, Mark Other: 4.3ms, Finalize Start Callback: 0.5ms, Sweep: 78.4ms, Sweep Compartments: 54.0ms, Sweep Object: 5.2ms, Sweep String: 1.4ms, Sweep Script: 0.7ms, Sweep Shape: 5.8ms, Discard Code: 2.3ms, Discard Analysis: 42.2ms, Discard TI: 4.4ms, Sweep Types: 5.4ms, Clear Script Analysis: 1.4ms, Finalize End Callback: 2.7ms, Deallocate: 0.1ms, End Callback: 9.8ms Totals: Purge: 0.2ms, Mark: 123.8ms, Mark Roots: 12.0ms, Mark Other: 4.3ms, Finalize Start Callback: 0.5ms, Sweep: 78.4ms, Sweep Compartments: 54.0ms, Sweep Object: 5.2ms, Sweep String: 1.4ms, Sweep Script: 0.7ms, Sweep Shape: 5.8ms, Discard Code: 6.9ms, Discard Analysis: 42.2ms, Discard TI: 4.4ms, Sweep Types: 5.4ms, Clear Script Analysis: 1.4ms, Finalize End Callback: 2.7ms, Deallocate: 0.1ms, End Callback: 9.8ms

about:telemetry isn't required, just that javascript.options.mem.log is set to true :)

oh, my bad, you were speaking of that specific GC function.

(In reply to Andrew McCreight [:mccr8] from comment #1) > If you have about:telemetry installed, you can check GC_NON_INCREMENTAL. > FYI, I'm also seeing the same thing: 122 out of 122 of my GC have been > non-incremental, despite GC_INCREMENTAL_DISABLED being 0 everywhere. GC_NON_INCREMENTAL 490 samples, average = 1, sum = 488 Now, how you would make sense of what this means is beyond me. But the chart shows 2 samples of 0, and 488 of 1, which tells me that we do IGC 2/490 % of the time for me. ;-)

I launched Nightly in a temp profile and installed memchaser, and let it sit for 10-15 seconds to find it stayed at GC constantly with 23-35ms cycles Normally letting it sit for roughly 10-15 seconds the addonbar info would start reflecting concurrent Incremental collection and sit at roughly 10-13ms. similarly, my active profile sits at 50-60ms GC's from a fresh start where as with the build i was using prior would be 17ms iGC's.

I started testing backwards to find when this started happening and thought i had narrowed it down to the 3rd, but subsequent retesting of the build from the 2nd and 1st also failed to perform any Incremental slices.

MC Working 20120525113255 http://hg.mozilla.org/mozilla-central/rev/034bbdc7b9c9 Broken 20120527030515 http://hg.mozilla.org/mozilla-central/rev/133aa3a2ef0a

nvm that last post, i screwed up by forgetting to set incremental back to on in the 27th build.

(In reply to Ehsan Akhgari [:ehsan] from comment #5) > Now, how you would make sense of what this means is beyond me. But the > chart shows 2 samples of 0, and 488 of 1, which tells me that we do IGC > 2/490 % of the time for me. ;-) Yeah, it would be nice if it showed a % for booleans or something. Thanks for looking that up. That is interesting that you are getting a few incremental GCs.

Not all that strange, i also got one or 2 completely random incremental slices and then was not able to get them again

(In reply to Andrew McCreight [:mccr8] from comment #10) > (In reply to Ehsan Akhgari [:ehsan] from comment #5) > > Now, how you would make sense of what this means is beyond me. But the > > chart shows 2 samples of 0, and 488 of 1, which tells me that we do IGC > > 2/490 % of the time for me. ;-) > Yeah, it would be nice if it showed a % for booleans or something. Thanks > for looking that up. That is interesting that you are getting a few > incremental GCs. Vlad and Jeff sit near me at the office, and they're getting roughly the same.

This time i did it right MC Working 20120601030520 http://hg.mozilla.org/mozilla-central/rev/73783bf75c4c Not/Barely Working 20120602030527 http://hg.mozilla.org/mozilla-central/rev/5199196b65ec

i found the cause of the random Incremental Slice; Having the window minimised to tray.

Taskbar*

http://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=73783bf75c4c&tochange=5199196b65ec Time for somebody to bisect this I guess! :-)

im betting something within http://hg.mozilla.org/mozilla-central/pushloghtml?changeset=12ab69851e05

That includes the push that re-enabled incremental GC, which also flipped the javascript.options.mem.disable_explicit_compartment_gc pref to true. It could be the case that incremental scheduling somehow has come to depend on that, which also affected how GCs are scheduled. Try flipping that to false and see what happens. As a note, if you try to bisect earlier to see how that goes, the pref used to be javascript.options.disable_explicit_compartment_gc. http://hg.mozilla.org/mozilla-central/rev/a6be10cfee3f

I flipped javascript.options.mem.disable_explicit_compartment_gc to false, and now my GCs are all incremental.

(In reply to Andrew McCreight [:mccr8] from comment #19) > I flipped javascript.options.mem.disable_explicit_compartment_gc to false, > and now my GCs are all incremental. I tried it as well, and I see a lot of incremental GCs now, with an occasional non-incremental one.

good call Andrew, Is this to be expected Bill?

I think bug 758034 is supposed to fix this, or something like it.

I've also seen this issue on: Mozilla/5.0 (Windows NT 6.1; rv:15.0) Gecko/20120606 Firefox/15.0a2 (20120606042008)

Mozilla/5.0 (X11; Linux i686; rv:15.0) Gecko/20120608 Firefox/15.0a2 Mozilla/5.0 (Windows NT 6.1; rv:15.0) Gecko/20120606 Firefox/15.0a2 (20120606042008) Apparently, IGC gets triggered but quite rarely. When using Aurora for about 2 hours I barely saw 2-3 GCs without a "Nonincremental reason" in the Error console.

Good point.

(In reply to Ioana Budnar [QA] from comment #24) > Mozilla/5.0 (X11; Linux i686; rv:15.0) Gecko/20120608 Firefox/15.0a2 > Mozilla/5.0 (Windows NT 6.1; rv:15.0) Gecko/20120606 Firefox/15.0a2 > (20120606042008) > > Apparently, IGC gets triggered but quite rarely. When using Aurora for about > 2 hours I barely saw 2-3 GCs without a "Nonincremental reason" in the Error > console. Also checked on Mac 10.7.4 with the same build. The behaviour is the same.

This was a big screwup on my part. This patch will be superseded by the ones in bug 758034, but this one is simpler and hopefully we can get it into Aurora.

Comment on attachment 631782 [details] [diff] [review] fix [Approval Request Comment] Bug caused by (feature/regressing bug #): NA User impact if declined: Longer GC pauses Testing completed (on m-c, etc.): Just landed to m-c Risk to taking this patch (and alternatives if risky): Somewhat risky, since incremental GC hasn't got lots of testing (Alternative is to disable incremental GC on Aurora and re-enable explicit compartment GCs) String or UUID changes made by this patch: NA

(In reply to Olli Pettay [:smaug] from comment #30) > Risk to taking this patch (and alternatives if risky): > Somewhat risky, since incremental GC hasn't got lots of testing > (Alternative is to disable incremental GC on Aurora and re-enable > explicit compartment GCs) How would a regression from this patch look? Memory/performance issues?

(In reply to Alex Keybl [:akeybl] from comment #31) > How would a regression from this patch look? Memory/performance issues? It isn't a regression per se. IGC is disabled in 14. It is "enabled" in 15, but due to this bug is basically behaving like it is disabled. I think there may be additional patches that are needed aside from this one to make IGC okay for 15. billm would know more.

See comment 27. I believe the patch here should be enough for FF15. iGC has behaved quite ok on m-c after the patch landed.

Comment on attachment 631782 [details] [diff] [review] fix Approving for Aurora so we can get some bake time to confirm this is enough for 15.

Setting tracking in case we need to disable this patch in favour of the ones in bug 758034 or some other backout/followup is needed.

Not looking good. Bill, is Aurora missing some other GC patches?

does javascript.options.mem.disable_explicit_compartment_gc;false improve things on aurora?

For Aurora, Bobby needs to land the new expando stuff in bug 758415. That already has Aurora approval, but I think it depends on bug 763381, which just landed.

We're not going to land this on Aurora. Instead, we're going to do bug 768688.

[Triage Comment] Removing tracking-firefox15 as per comment 40 - bug 768788 has been tracked and landed in 15.