Thursday, August 26, 2021

How to Enable GC Logging in Java HotSpot JVM

When we are diagnosing problems in a Java (EE or otherwise) application, is often a good idea to check how garbage collection is performing. One of the basic and most unobtrusive actions is to enable garbage collection logging.


As you may know, if we add the following arguments to the java start command…


-Xloggc:<file_name> –XX:+PrintGCDetails -XX:+PrintGCDateStamps


… the JVM will start writing garbage collection messages to the file we set with the parameter -Xlogcc. The messages should be something like:



2010-04-22T18:12:27.796+0200: 22.317: [GC 59030K->52906K(97244K), 0.0019061 secs]

2010-04-22T18:12:27.828+0200: 22.348: [GC 59114K->52749K(97244K), 0.0021595 secs]

2010-04-22T18:12:27.859+0200: 22.380: [GC 58957K->53335K(97244K), 0.0022615 secs]

2010-04-22T18:12:27.890+0200: 22.409: [GC 59543K->53385K(97244K), 0.0024157 secs]


The bold part is simply the date and time when reported garbage collection event starts.


Unfortunately -XX:+PrintGCDateStamps is available only for Java 6 Update 4 and later JVMs. So, if we are unlucky and our application is running on older JVMs we are forced to use…


-Xloggc:<file> –XX:+PrintGCDetails


… and the messages will be like:



22.317: [GC 59030K->52906K(97244K), 0.0019061 secs]

22.348: [GC 59114K->52749K(97244K), 0.0021595 secs]

22.380: [GC 58957K->53335K(97244K), 0.0022615 secs]

22.409: [GC 59543K->53385K(97244K), 0.0024157 secs]


Now, the bold numbers (also present in previous format) are the seconds elapsed from JVM start time



-XX:+PrintGCDateStamps -verbose:gc -XX:+PrintGCDetails -Xloggc:"<path to log>"

These options make Java to log garbage collector activities into specified file. All records will be prepended with human readable date and time. Meanwhile you should avoid using -XX:+PrintGCTimeStamps as it will prepend record with useless timestamp since Java application start.


Generate log can be later analysed with GCViewer.


-XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=10 -XX:GCLogFileSize=100M

GC log files rotation makes analysis of garbage collection problems easier, also it guaranties that disk is protected from space overconsumption


Reference

https://blog.sokolenko.me/2014/11/javavm-options-production.html

https://176.34.122.30/blog/2010/05/26/human-readable-jvm-gc-timestamps/


java gc log file


java gc log format


how to read java gc log

No comments:

Post a Comment

Feel free to comment, ask questions if you have any doubt.