GC Log Visulation, HPJmeter

Jon has a great blogging about different JAVA gc collections. check the link : http://blogs.sun.com/jonthecollector/entry/our_collectors, basically it means different Collector means different   young age / old generation collection behavior.

Each blue box represents a collector that is used to collect a generation. The young generation is collected by the blue boxes in the yellow region and the tenured generation is collected by the blue boxes in the gray region.

"Serial" is a stop-the-world, copying collector which uses a single GC thread.

"ParNew" is a stop-the-world, copying collector which uses multiple GC threads. It differs from "Parallel Scavenge" in that it has enhancements that make it usable with CMS. For example, "ParNew" does the synchronization needed so that it can run during the concurrent phases of CMS.

"Parallel Scavenge" is a stop-the-world, copying collector which uses multiple GC threads.

"Serial Old" is a stop-the-world, mark-sweep-compact collector that uses a single GC thread.

"CMS" is a mostly concurrent, low-pause collector.

"Parallel Old" is a compacting collector that uses multiple GC threads.

Using the -XX flags for our collectors for jdk6,

UseSerialGC is "Serial" + "Serial Old"

UseParNewGC is "ParNew" + "Serial Old"

UseConcMarkSweepGC is "ParNew" + "CMS" + "Serial Old". "CMS" is used most of the time to collect the tenured generation. "Serial Old" is used when a concurrent mode failure occurs.

UseParallelGC is "Parallel Scavenge" + "Serial Old"

UseParallelOldGC is "Parallel Scavenge" + "Parallel Old"

given different options, you need to compare and balance the different tradeoffs. like latency, responsetime, low footprint. etc.  How to make sure which one fits you? HPJmeter is your friend to tell that.

How it works. 
  Turn on GC log which will enable the jvm to dump GC detailed information to a Logfile. try different colelctors, then you get the result matrix. HPJmeter has the feature to compare several log files. then you can compare the GC time, Heap Allocation.

for example, Like me, I want to compare the ParallenGC vs the Concurrent GC. here is how it do it.
download HPJmeter from HP, it’s a free tool.

then enable the gc loging and try different switch. here is two options I tried

java -XX:+UseParallelGC  -Xloggc:gcParallelGC.log MyApplication

java -XX:+UseConcMarkSweepGC  -Xloggc:gccms.log MyApplication

after run the app for a while, you get enough gc information and stop you app. two logs are generated. they are basically text file and has a fixed format.

0.158: [GC 20544K->18152K(32192K), 0.0062129 secs] 0.185: [GC 22312K->19728K(36352K), 0.0103363 secs] 0.236: [GC 28048K->22500K(36352K), 0.0135180 secs] 0.250: [Full GC 22500K->5706K(27264K), 0.0271364 secs] clock time :{gc type, before->after, pause time]

start the HPJmeter, and open the log you just collected. there are several tabls that show you the summary /Heap usage/Duration,etc

the above summary tells the ParallelGC does’t work well in my application. 20% of CPU time is spent on GC collection. and several FULL GCs which is CPU intensive has been invoked.
then click the user-defined tab and select cumulative GC, it shows the GC time vs the clock time

of course, the less time spent on GC, the more you app get responsive.

now time to compare with the Concurrent collectors. CLick the File->compare to load another log file.

the CMS with Concurrent Collector wins, it takes less time . test it , and the chart tells.