1.7 G1GC significantly slower than 1.6 Mark and Sweep?

Fri Apr 29 20:21:55 UTC 2011

John,

If you do additional runs to look at this issue, please
add -XX:+PrintGCTimesStamps.  Helps with plotting
vs. time.  Thanks.

Jon

On 4/28/2011 11:10 PM, John Hendrikx wrote:
> I tried many -XX:MaxGCPauseMillis settings, including not setting it 
> at all, 20, 10, 5, 2.  The results were similar each time -- it didn't 
> really have much of an effect.  In retrospect you might say that the 
> total CPU use is what is causing the problems, not necessarily the 
> length of the pauses -- whether this extra CPU use is caused by the 
> collector or because of some other change in Java 7 I donot know; the 
> program is the same.  Is there perhaps another collector that I could 
> try to see if this lowers CPU use?  Or settings (even non-GC related) 
> that could lower CPU use?
>
> Java 6's CMS I didn't need to tune.  After determining that the length 
> of GC pauses was causing problems in the application, I tried turning 
> CMS on and it resolved the problems.
>
> What I observe is that even though with Java 7 the pauses seem (are?) 
> very short, the CPU use is a lot higher (from 65% under Java 6 to 95% 
> with 7).  This could be related to other causes (perhaps threading 
> overhead, debug code in Java 7, etc) but I doubt it is in any specific 
> Java code that I wrote as most of the heavy lifting is happening in 
> native methods.  It could for example be that several ByteBuffers 
> being used are being copied under Java 7 while under 6 direct access 
> was possible.
>
> John.
>
> Jon Masamitsu wrote:
>> John,
>>
>> You're telling G1 (UseG1GC) to limit pauses to 2ms.
>> (-XX:MaxGCPauseMillis=2) but seemed to have tuned
>> CMS (UseConcMarkSweepGC) toward a 20ms goal.
>> G1 is trying to do very short collections and needs to do many
>> of them to keep up with the allocation rate.  Did you
>> mean you are setting MaxGCPauseMillis to 20?
>>
>> Jon
>>
>> On 4/26/2011 7:59 AM, John Hendrikx wrote:
>>> Hi list,
>>>
>>> I've been testing Java 1.6 performance vs Java 1.7 performance with a
>>> timing critical application -- it's essential that garbage collection
>>> pauses are very short.  What I've found is that Java 1.6 seems to
>>> perform significantly better than 1.7 (b137) in this respect, although
>>> with certain settings 1.6 will also fail catastrophically.   I've used
>>> the following options:
>>>
>>> For 1.6.0_22: -Xms256M -Xmx256M -XX:+UseConcMarkSweepGC
>>> For 1.7.0b137: -Xms256M -Xmx256M  -XX:+UseG1GC -XX:MaxGCPauseMillis=2
>>>
>>> The amount of garbage created is roughly 150 MB/sec.  The application
>>> demands a response time of about 20 ms and uses half a dozen threads
>>> which deal with buffering and decoding of information.
>>>
>>> With the above settings, the 1.6 VM will meet this goal over a 2 minute
>>> period>99% of the time (with an average CPU consumption of 65% per CPU
>>> core for two cores) -- from verbosegc I gather that the pause times are
>>> around 0.01-0.02 seconds:
>>>
>>> [GC 187752K->187559K(258880K), 0.0148198 secs]
>>> [GC 192156K(258880K), 0.0008281 secs]
>>> [GC 144561K->144372K(258880K), 0.0153497 secs]
>>> [GC 148965K(258880K), 0.0008028 secs]
>>> [GC 166187K->165969K(258880K), 0.0146546 secs]
>>> [GC 187935K->187754K(258880K), 0.0150638 secs]
>>> [GC 192344K(258880K), 0.0008422 secs]
>>>
>>> Giving the 1.6 VM more RAM (-Xms1G -Xmx1G) increases these times a bit.
>>> It can also introduce OutOfMemory conditions and other catastrophic
>>> failures (one time the GC took 10 seconds after the application had 
>>> only
>>> been running 20 seconds).  How stable 1.6 will perform with the initial
>>> settings remains to be seen; the results with more RAM worry me 
>>> somewhat.
>>>
>>> The 1.7 VM however performs significantly worse.  Here is some of its
>>> output (over roughtly a one second period):
>>>
>>> [GC concurrent-mark-end, 0.0197681 sec]
>>> [GC remark, 0.0030323 secs]
>>> [GC concurrent-count-start]
>>> [GC concurrent-count-end, 0.0060561]
>>> [GC cleanup 177M->103M(256M), 0.0005319 secs]
>>> [GC concurrent-cleanup-start]
>>> [GC concurrent-cleanup-end, 0.0000676]
>>> [GC pause (partial) 136M->136M(256M), 0.0046206 secs]
>>> [GC pause (partial) 139M->139M(256M), 0.0039039 secs]
>>> [GC pause (partial) (initial-mark) 158M->157M(256M), 0.0039424 secs]
>>> [GC concurrent-mark-start]
>>> [GC concurrent-mark-end, 0.0152915 sec]
>>> [GC remark, 0.0033085 secs]
>>> [GC concurrent-count-start]
>>> [GC concurrent-count-end, 0.0085232]
>>> [GC cleanup 163M->129M(256M), 0.0004847 secs]
>>> [GC concurrent-cleanup-start]
>>> [GC concurrent-cleanup-end, 0.0000363]
>>>
>>>   From the above output one would not expect the performance to be 
>>> worse,
>>> however, the application fails to meet its goals 10-20% of the time.
>>> The amount of garbage created is the same.  CPU time however is 
>>> hovering
>>> around 90-95%, which is likely the cause of the poor performance.  The
>>> GC seems to take a significantly larger amount of time to do its work
>>> causing these stalls in my test application.
>>>
>>> I've experimented with memory sizes and max pause times with the 1.7 
>>> VM,
>>> and although it seemed to be doing better with more RAM, it never comes
>>> even close to the performance observed with the 1.6 VM.
>>>
>>> I'm not sure if there are other useful options I can try to see if I 
>>> can
>>> tune the 1.7 VM performance a bit better. I can provide more
>>> information, although not any (useful) source code at this time due to
>>> external dependencies (JNA/JNI) of this application.
>>>
>>> I'm wondering if I'm missing something as it seems strange to me that
>>> 1.7 is actually underperforming for me when in general most seem to
>>> agree that the G1GC is a huge improvement.
>>>
>>> --John
>>>
>>> _______________________________________________
>>> hotspot-gc-use mailing list
>>> hotspot-gc-use at openjdk.java.net
>>> http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
>> _______________________________________________
>> hotspot-gc-use mailing list
>> hotspot-gc-use at openjdk.java.net
>> http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
>>
>
_______________________________________________
hotspot-gc-use mailing list
hotspot-gc-use at openjdk.java.net
http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use