Closed Bug 728692 Opened 13 years ago Closed 12 years ago

Javascript becomes slow after Incremental GC gets disabled

Categories

(Core :: JavaScript Engine, defect)

Product:
Core
Component:
JavaScript Engine
Version:
13 Branch
Platform:
All
Windows 7
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

()

Status:
RESOLVED WORKSFORME

People

(Reporter: Optimizer, Unassigned)

References

Details

User Agent: Mozilla/5.0 (Windows NT 6.1; WOW64; rv:13.0a1) Gecko/13.0a1 Firefox/13.0a1
Build ID: 20120219031223

Steps to reproduce:

1. In a Clean profile/ or safe mode with the Latest Nightly build (that has IGC in it) open page [1] and check Incremental GC is 1 (enabled)
2. Then open page [2] and run the test. 
3. Sometime in between the test IGC gets disabled and after that the test runs slowly with each frame taking around 40-50 ms whereas in previous builds, the avg time is 10-20 ms

[1] about:support
[2] http://v8.googlecode.com/svn/branches/bleeding_edge/benchmarks/spinning-balls/index.html


Actual results:

Javascript speed declined as soon as IGC got disabled.


Expected results:

Javascript speed (at least) should have remained same, even if the spike size increased.
Blocks: IncrementalGC
Component: Untriaged → JavaScript Engine
Product: Firefox → Core
I don't know if I should say Javascript speed decreases or time taken for CC/GC increases, but fps in that stress test decreases to half of what they were in previous builds or during the time IGC was enabled on the latest build.
That large of a change does sound unusual.
You could also try the v8 benchmark suite with and without incremental GC. http://v8.googlecode.com/svn/data/benchmarks/v6/run.html
I tried on a new clean profile, and on safe mode of my normal profile.
The test runs peacefully for around 10 seconds and after that I see a sudden speed bump, when I refresh the already opened about:support page, I found that the entry IGC became 0.

So I thaght this was due to the switch of IGC during a test run. So I waited that test to complete, started it again, still the speed was as slow as in the previous run after disabling of IGC.

Dunno if only I am able to see this effect.
(In reply to Andrew McCreight [:mccr8] from comment #3)
> You could also try the v8 benchmark suite with and without incremental GC.
> http://v8.googlecode.com/svn/data/benchmarks/v6/run.html

Same behavior. If I try to run the V8 test in a normal( latest nightly ) profile where IGC is already 0 then I get around 4300 score.

But in safe mode where IGC is 1 initially and it gets disabled during the V8 benchmark, the score is around 120
QA Contact: untriaged → general
(In reply to scrapmachines from comment #5)
> Same behavior. If I try to run the V8 test in a normal( latest nightly )
> profile where IGC is already 0 then I get around 4300 score.
> 
> But in safe mode where IGC is 1 initially and it gets disabled during the V8
> benchmark, the score is around 120

I think if incremental GC is disabled, it could force a recompile of all JS, so I don't think a huge drop in performance if that happens during a test is too surprising.  My impression is that once it turns off, it stays off, so if it is only the switching off that is slow then it shouldn't be a problem.

Comment 4 sounds different though.  It sounds like that it was slow even if you started off with IGC disabled?
I'm not sure what's going on here, but there may be two issues at play:

1. Safe mode makes everything run much more slowly because it disables JIT compilation.
2. The spinning balls benchmark naturally becomes slower (i.e., lower framerate) after about 10 seconds. This is the point where it adds more balls or something.

So I suspect that incremental GC being disabled and the benchmark getting slower may not be related. If it's always getting turned off for you after a few seconds, then it seems hard to test either way.
(In reply to Andrew McCreight [:mccr8] from comment #6)
> I think if incremental GC is disabled, it could force a recompile of all JS,
> so I don't think a huge drop in performance if that happens during a test is
> too surprising.  My impression is that once it turns off, it stays off, so
> if it is only the switching off that is slow then it shouldn't be a problem.
> 
> Comment 4 sounds different though.  It sounds like that it was slow even if
> you started off with IGC disabled?

If started off with IGC disabled (by started off means started Firefox/Nightly) the scores are normal (but a little less).
But when you start off with IGC enabled, and it gets disabled during the test, then JS speed remains slow throughout the runtime of Firefox, unless you restart the browser.
(In reply to Bill McCloskey (:billm) from comment #7)
> So I suspect that incremental GC being disabled and the benchmark getting
> slower may not be related. If it's always getting turned off for you after a
> few seconds, then it seems hard to test either way.

May be you are right. Here are the stats :

Firefox 10 safe mode :
8000/320 38(max = 431) ms 729 frames

Score 1
0-10ms	=> 1
20-30ms	=> 393
30-40ms	=> 298
40-50ms	=> 17
50-60ms	=> 3
60-70ms	=> 3
130-140ms	=> 2
150-160ms	=> 2
160-170ms	=> 1
280-290ms	=> 1
290-300ms	=> 1
330-340ms	=> 1
340-350ms	=> 1
350-360ms	=> 1
360-370ms	=> 2
370-380ms	=> 1
430-440ms	=> 1

Firefox 10 normal
8000/320 19(max = 482) ms 1221 frames

Score 1
0-10ms	=> 32
10-20ms	=> 970
20-30ms	=> 194
30-40ms	=> 2
40-50ms	=> 1
50-60ms	=> 1
60-70ms	=> 2
70-80ms	=> 2
80-90ms	=> 2
90-100ms	=> 1
100-110ms	=> 2
130-140ms	=> 1
140-150ms	=> 1
180-190ms	=> 1
200-210ms	=> 2
250-260ms	=> 1
310-320ms	=> 1
320-330ms	=> 1
380-390ms	=> 1
390-400ms	=> 1
420-430ms	=> 1
480-490ms	=> 1

Nightly IGC disabled normal
8000/320 142(max = 579) ms 1353 frames

Score 1
0-10ms	=> 46
10-20ms	=> 1244
20-30ms	=> 42
30-40ms	=> 2
80-90ms	=> 1
100-110ms	=> 1
110-120ms	=> 3
120-130ms	=> 1
130-140ms	=> 1
140-150ms	=> 2
150-160ms	=> 1
170-180ms	=> 1
280-290ms	=> 1
300-310ms	=> 1
340-350ms	=> 1
350-360ms	=> 1
400-410ms	=> 3
570-580ms	=> 1

Nightly safe mode with IGC initially on
8000/320 40(max = 134) ms 768 frames

Score 4
0-10ms	=> 1
10-20ms	=> 1
20-30ms	=> 391
30-40ms	=> 19
40-50ms	=> 345
50-60ms	=> 7
60-70ms	=> 1
100-110ms	=> 1
130-140ms	=> 2

Still then, in the safe mode of Latest nightly, the major frames lies in 40-50 range as compared to Firefox 10 safe mode (20-30)
In comparison to before IGC landed, GC is actually much slower after iGC automatically turns off (see Bug 728686 for that case)

with my typical browsing session, GC takes 1.5x to 2x as much time after switching off iGC compared to aurora and beta.
(In reply to Danial Horton from comment #10)
> with my typical browsing session, GC takes 1.5x to 2x as much time after
> switching off iGC compared to aurora and beta.

Please file a separate bug about GC pause time regressions. It would be useful to know a specific site or set of sites that you see this change on. Thanks.
this bug covers the situation just fine, Girish's numbers correlate with my own.
Mozilla/5.0 (Windows NT 6.1; rv:14.0) Gecko/20120426 Firefox/14.0a2
Built from http://hg.mozilla.org/releases/mozilla-aurora/rev/7525533b3e42

On a new profile I set javascript.options.mem.gc_incremental to true and run the test from comment #0 and the results show that most frames fit the 40-50 ms interval, even though incremental GC is still enabled at the end:

8000/320 56(max = 207) ms 1307 frames

Score 1
10-20ms	=> 1
20-30ms	=> 105
30-40ms	=> 273
40-50ms	=> 542
50-60ms	=> 233
60-70ms	=> 106
70-80ms	=> 29
80-90ms	=> 8
90-100ms	=> 6
100-110ms	=> 3
200-210ms	=> 1
Hardware: x86_64 → All
Mozilla/5.0 (Windows NT 6.1; rv:15.0) Gecko/20120609 Firefox/15.0a2 (20120609042006)

I ran the test from comment 0 with IGC enabled (...mem.log was set as true so I could check in the Error console that several IGCs actually happened while running the test). Then I disabled IGC and ran the test again (also checked in the Error console that no IGC happened this time). For both runs, the vast majority of frames took 10-20ms.

I did this several times and there were no noticeable differences in the test results at any IGC disablings or enablings.
Here are the results of two of my test runs mentioned in comment 14:

IGC enabled:
0-10ms	=> 44
10-20ms	=> 3147
20-30ms	=> 325
30-40ms	=> 40
40-50ms	=> 11
50-60ms	=> 2
60-70ms	=> 1
90-100ms	=> 1
210-220ms	=> 1

IGC disabled:
0-10ms	=> 17
10-20ms	=> 3266
20-30ms	=> 236
30-40ms	=> 13
40-50ms	=> 10
50-60ms	=> 1
60-70ms	=> 1
80-90ms	=> 1
100-110ms	=> 1
110-120ms	=> 8
120-130ms	=> 1
140-150ms	=> 1
I don;t see any diff now (well from a long time back, actually). So closing
Status: UNCONFIRMED → RESOLVED
Closed: 12 years ago
Resolution: --- → WORKSFORME
You need to log in before you can comment on or make changes to this bug.