1.7 G1GC significantly slower than 1.6 Mark and Sweep?

[John Hendrikx]

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