IBM i Tuning GC for Java

LANSA Integrator

IBM i - Tuning GC for Java

At times, it may be helpful to collect additional data about the garbage collector as it's running.

This can be accomplished with verbose GC, which dumps information each time the collector runs.

This includes the current heap size, as well as the number and size of objects collected, number of objects in the heap, amount of time the collector ran and other information.

Sample Verbose GC Output:

 

GC 4: starting collection, threshold allocation reached.

GC 4: live objects 2562187; collected objects 4936351; collected (KB) 541840.

GC 4: queued for finalization 0; total soft references 92; cleared soft references 5.

GC 4: current heap (KB) 1171424; current threshold (KB) 524288.

GC 4: collect (milliseconds) 4138.

GC 4: current cycle allocation (KB) 236160; previous cycle allocation (KB) 524314.

GC 4: total weak references 684; cleared weak references 0.

GC 4: total final references 11797; cleared final references 63.

GC 4: total phantom references 0; cleared phantom references 0.

GC 4: total old soft references 0; cleared old soft references 0.

 

The most important of these fields for tuning GC are:

  • Memory allocated since the last cycle began Previous cycle allocation (KB).
  • Memory allocated since the current cycle began Current cycle allocation (KB).
  • Elapsed time for this cycle Collect (milliseconds).
  • The threshold value Current threshold (KB).
  • The current heap size Current heap (KB).
  • Total size of the objects collected during this cycle Collected (KB).
  • Number of objects collected during this cycle Collected objects.
  • Number of objects currently active in the JVM Live objects.
  • This is the fourth GC cycle since the JVM started GC 4.

The current threshold is the value set for the initial heap size (512 MB in the example output).

The previous cycle allocation is normally close to this value, because the GC cycle is triggered when the amount of memory allocated since the last cycle began reaches the threshold value.

The example output shows that the GC cycle took more than four seconds to complete. During that time, the current cycle allocation reached more than 200 MB. This is about 40 percent of the threshold value, which suggests that the total time between the beginning of this cycle and the next cycle is around 10 seconds. This cycle collected nearly 5 million objects (collected objects), leaving only 2.5 million objects in the heap at the end of the cycle (live objects).

In general, it's best to have a low cycle time. One to two seconds is ideal, but times of five to 10 seconds are common.

It's also best to have some time between collection cycles (i.e., current cycle allocation should be less than the current threshold).

These two goals work against each other -- increasing the threshold value allows the heap to grow, resulting in more time between cycles, but this lengthens each cycle. Decreasing the threshold shortens each cycle, but also shortens the time between cycles.

The key to tuning GC is to find a balance between these two goals. This is why examining the CPU consumed by GC is generally better than looking at values like the current heap size.

If you don't have the Performance Tools licensed program product (PT1 LPP) installed on your system, you may want to experiment with the threshold value, using your application's throughput or response time as well as verbose GC output to determine how to further tune the threshold.

Even if you do have PT1, it may be useful to examine verbose GC output to understand how your application uses the heap and to watch for changes in the GC behavior as application and system loads change.