Tuesday, March 15, 2011

Controlling GC logs at runtime

GC logging can be controlled using the following command line options:
  • -XX:+PrintGC (same as -verbose:gc) - Displays basic GC details 
  • -XX:+PrintGCDetails  - Displays advanced GC details 
  • -XX:+PrintGCTimeStamps - Displays the time stamp for every GC event  reported
  • -XX:+PrintGCDateStamps -  Displays the date for every GC event  reported  
  • -Xloggc:c:\gc.log     - Writes GC logging to the specified file.
It is usually recommended to run with -XX:+PrintGC -XX:+PrintGCTimeStamps -Xloggc:c:\gc.log even in production. The amount of data written to those files is not huge and it can help to analyze GC throughput ,pause time and even to expose bugs in the GC mechanism.
On the other hand these files are not managed by a "log4j style" rolling appender and will not be trimmed by default. So what would we choose ?
The good news is that logging GC can be configured at runtime. It can be enabled and disabled at will via JMX.
The JMX object com.sun.management:type=HotSpotDiagnostic has an attribute named DiagnosticOptions. This attribute contains 12 boolean sub-attributes (as for Java 1.6.0_24). All of them are very interesting but for the GC logging we need to take a look on 4 of them:
  • PrintGC
  • PrintGCDetails
  • PrintGCTimeStamps
  • PrintGCDateStamps

The bad news is that -Xloggc   cannot be configured via JMX so you will need to configure it on startup.

All these can be modified using jconsole or VisualVM using the operation setVMOption.

My recommendation is that even if you do not want to log GC by default add the following params to your command line -Xloggc:c:\gc.log -XX:-PrintGC -XX:+PrintGCTimeStamps 
(Notice that the PrintGC has a -  sign before it)
When you will need to analyze GC just turn on PrintGC and possible the PrintGCDetails.

No comments: