WebSphere Application Server (both Traditional and Liberty profiles) runs inside a Java Virtual Machine (JVM) and thus WebSphere performance depends first and foremost on the healthy operation of the JVM. The performance of the JVM in turn depends on the health of the Java heap – the memory area where the JVM allocates objects created by the running Java code.
The Java heap is managed by the JVM’s automatic memory management capability, which consists of a memory allocation component operating largely out of scope of observability tooling, and the more visible heap cleanup component referred to as garbage collection (GC).
Java programmers are not required to explicitly manage the memory required for the execution of their program – there are, for example, no “malloc” and “free” operations in Java as there are for C. Rather, the programmer can just create an instance of a Java object with the “new” keyword, without specifying the size of the object or the memory address it will occupy. When an object is no longer needed, the Java program also does not have to clear the memory area occupied by the object (though the programmer must still make sure to leave no live references to the object, to avoid the dreaded “memory leak”.)
The JVM’s GC subsystem frees the Java programmer from detailed memory management duties by providing these functions:
- finding space for “new” objects in the Java heap
- freeing heap space when the occupying object is no longer needed
A running Java application constantly creates and releases many many objects, so efficient operation of the GC subsystem is crucial to Java performance. If the Java heap becomes too full, or if the free space in the heap is excessively fragmented, finding a suitable memory location to place a new object will take longer. This sort of Java heap problem (insufficient or fragmented free space) can cause the running apps to slow down because object creation takes longer, affecting system throughput.
Also, some of the GC’s cleanup operations require the application threads to suspend operation temporarily, so that surviving objects can be relocated as part of tidying up the heap to maximize contiguous free spaces. These “GC pauses” of the application threads manifest as response time delays in user applications; excessively long GC pauses can cause serious performance issues for interactive use cases such as websites. Further, even when individual GC pauses are acceptably short, if the heap becomes too full the GC pauses will be very frequent, which can in aggregate cause unacceptable reduction in system throughput.
Since GC subsystem performance is fundamental to JVM performance, which is essential to WebSphere performance, Java system administrators must be able to monitor the GC subsystem behavior. This requires visibility into the Java heap activity and state. From the OS perspective, the Java heap is just a block of memory that has been requested by the JVM – the OS cannot see what is going on inside the Java heap. So OS performance monitoring tools like Top (on Linux or AIX) or perfmon (Windows) cannot provide the necessary information to assess JVM heap health.
Insight to the health of the Java heap and the performance of the JVM’s automatic memory management is provided by GC logging. GC logging records information about GC operations, including the state of the heap before and after any “collection” event.
There is a great deal of detail provided in an IBM Java GC log, but the key points for a general understanding of the Java heap health are:
- When each GC collection occurred
- Free heap after GC – how much room there is for object allocation going forward
- Pause duration – how long the application threads were unable to run, due to the GC
- Interval since last GC pause – how long the app threads were able to run, since the prior GC pause ended
The GC log provides those data points for every GC event, enabling the system administrator to assess key indicators of GC performance:
- Whether the JVM is running too low on free heap
- Whether the heap usage is showing a memory leak pattern
- How long individual GC pauses are
- Whether GC pauses are occurring close together
- Proportion of time spent in GC pause as the workload runs
The GC log is written in XML format, and each GC event generates several KB of data into the log. Fortunately there is a tool called Garbage Collection and Memory Visualizer (GCMV) which ingests the GC log and provides a graphical view of the GC data over time. Use of GCMV will be discussed in a future blog post.
All of this useful Java heap health information is available for very little overhead. Although the GC log is enabled by the unfortunately named JVM argument “-verbosegc”, GC logging has very low impact on JVM performance, typically adding only 0.1-0.2% to JVM CPU usage. Because the information that appears in the GC log is already gathered by the JVM, the only additional work required to produce the log is to format the data and push it out to the file system.
The GC log has very high diagnostic value and very low performance cost, so the WebSphere Performance Engineering Team recommends that GC logging be enabled in all Java deployments, in both test and production environments.
Below are some links to additional information about IBM Java Garbage Collection, which will be helpful if you want to learn more about how GC works. In future blog posts, we plan to share more about how to analyze and interpret the contents of the IBM Java GC log, and how to use that data to guide WebSphere performance tuning and troubleshooting efforts.
IBM Java Heap Allocation
IBM Java Garbage Collection
IBM Java Garbage Collection Logging
#websphere-performance