The JVM Verbose GC plugin is for the analysis of the verbose GC output generated by IBM JVM included in WebSphere Application Server (this plugin supports up to WebSphere version 8). The verbose GC output contains detailed information about the Java application's heap status and its garbage collection operations. With such information, this plugin is able to assist the analysis of many JVM heap usage problems.
To start using this plugin, choose “JVM::VerboseGc” in the plugin selection dialog. A file open dialog would appear for you to select the desired verbose GC log files for analysis. It is possible to select multiple log files, in which case multiple windows would be opened (one for each file opened). Please note that at the time of this writing, only verbose GC outputs generated by WebSphere version 8 or before are supported by this plugin. Any unsupported version or format would simply be ignored.
After the verbose GC log files are processed successfully, we will see several tabs opened in the main window. The first and probably the most useful one is the Gc Summary tab. This tab summarizes the most important metrics about JVM performance. This is a good starting point for checking the health of your Java application.
For WebSphere version 8, a Configuration tab is available showing detailed JVM parameters used for launching the application, as well as some system information like operating system, number of CPU, physical memory available … etc.
There are also tabs for detailed GC operation: tabs Scavenge Gc and Global Gc. Depending on the actual GC policy used, you might only see one of them. Different GC policy uses different strategy in collecting the unused memory. Scavenge Gc tab shows the GC operations in nursery area, while Global Gc tab shows the GC operations in tenured area.
For the purpose of this article, we will not go into the details of GC strategy. You can find the official documentation of IBM JVM GC strategy in “Diagnosis documentation of IBM JVM”. There are also several other useful developerWorks articles on this:
- IBM style: Garbage collection policies
- Garbage collection in WebSphere Application Server V8, Part 1: Generational as the new default policy
Gc Summary Tab
The GC summary tab contains many items. The following is an example analysis of verbose GC output generated by WebSphere version 8 using “optthruput” GC policy. Normally, we would like to see avg_gc_util less than 5% (the best) or at least not larger than 10%. You will get a critical error flagged in red color if this value is greater than 10%, or a warning flagged in yellow color if this value is less than 10% but still larger than 5%:
- avg_gc_util indicates the ratio of time spent on GC to the
total application run time, in other words, the GC overhead. If gencon policy is used, it is further divided into avg_scavenge_gc_util and avg_global_gc_util to indicate the overhead of different GC operations. A rule of thumb: GC overhead generally should be smaller than 10%, or better, smaller than 5%, otherwise the application might spend too much time in doing GC (hence not achieving optimal performance). When the GC overhead is hight, it usually means that you might have
chosen an inappropriate GC policy for your application, or you might have used an inadequate heap size.
To solve the above alert (in this example, optthruput GC policy was used), use a large Java heap size might be an effective approach. The maximum Java heap size of the JVM was originally set to 128MB for this application. We enlarged it to be 256BM by adding a JVM option “-Xmx256m” to adjust the maximum heap size. The result after enlarging the maximum heap size improved to 8.157% average GC utilization, which is much better:
- avg_occupancy_after_gc indicates the average memory occupation in percentage after each GC, in other words, the memory usage by live objects. For gencon policy, it is further divided into avg_occupancy_nursery_after _scavenge_gc and avg_occupancy_tenured_after_scavenge_gc to indicate the memory usage of live objects in nursery space and tenured space, respectively. Normally, the value should be between 40% and 70%. If this value is larger than 70%, the JVM heap size might be too small for your application, leading to frequent GC invocation. However, if this value is much less than 40%, it might take a long time to complete a single GC cycle, which would bring negative influence on applications having pause time concern. You can improve this number by controlling the maximum heap size, enlarging the heap if it is over 70%, shrinking the heap if it is below 40%.
- avg_gc_duration indicates the average time taken by a GC cycle. Garbage collection is a stop-the-world operation. If your application have pause time concern (like web applications, requiring immediate or very fast responses), pay more attention to this value. Obviously we don't want our applications stopping for too long. If this value is large for your application, either reduce the maximum heap size setting or change to use optavgpause or gencon policy.
- avg_gc_rate indicates the average recycling rate of the garbage collection in MB/sec. A low value means that the garbage collection is not very efficient and you should check whether you have chosen a proper GC policy or have used an appropriate heap size. Usually, gencon policy can handle a higher rate of garbage collection.
- Compressed reference: The compressed reference value should be true on 64 bits JVM.
The "-Xcompressedrefs" command-line option causes object references to be stored as 32-bit representation, which reduces the 64-bit object size to be the same as a 32-bit object. As the 64-bit objects with compressed references are smaller than default 64-bit objects, they occupy a smaller memory footprint in the Java heap and improves data locality. This results in better memory utilization and improved performance.
- Excessive GC threads: The number of GC threads should not be larger than the number of physical CPU available.
- Excessive heap size: The JVM heap size should not be larger than the available physical memory.
Scavenge/Global Gc Tab
If you need to dig into the detailed GC invocations, these tabs are what you want. There are also predefined rules for detecting abnormal GC invocation, via the standard ways of red/yellow color flagging.
On the bottom of the panel, you can use dropdown box “Top” to adjust the number of invocations to show. Enabling the check box option “Only Alerts” will only show the invocations having violations. In general, the less data shown in the the tool the better UI performance you will get.
You can search for desired data by using the 'Search' text box and the result will be marked with green color:
You also can click on a column header to sort the invocations by that column. For example, clicking on gc_util to get the invocations sorted by gc_util value in descending order:
The predefined rules includes:
- GC Utilization Warning: As we mentioned above, GC utilization represents the GC overhead in the application. The default warning threshold is 13% here:
- Excessive Finalizers Warning: Finalizers have too many drawbacks and is generally recommended to be avoided. In fact, we should use finalizers as little as possible. The default warning threshold is 2000 here:
- Larger Allocation Requests Warning: The large allocation requests should be avoided if possible, as they cannot be put into thread local heap (hence slower) and they also make heap fragmentation easier to happen. The default warning threshold is 1024 here:
- Small Heap Setting Warning: A small percent_after value implies the JVM heap size is too small for the application. The default warning threshold is 30% here. For gencon policy, this rule is spitted into small nursery area warning and small tenured area warning.
- Manual GC invocation: Generally, there shouldn't be any manual GC invocation in a production environment. It is not recommended and could be bad for application performance.
Other IBM tools for JVM GC Analysis