Slowness in Java Application Due To Increased FullGC Events: G1GC

In this blog, we will see one of the issues and solutions which I found in one of our production servers: our Java application became slow due to more GC pauses.  I will explain a particular approach that can be one of the reasons for initiating more GC pauses.

To understand this article, one must have basic knowledge of the G1GC algorithm of Java for garbage collection. Don’t worry if you don’t have knowledge of G1GC: I will write other articles on the basics of G1GC later, and then you can read this article again. 

Let's start with the issue we are facing: applications become unresponsive very frequently. 

Analysis  

• After debugging JVM level stats from JMX bean dumping, it was clear that GC collection time was greatly increased in between.
• Heap also increasing 

After that, we enabled GC log by using -Xlog:gc=debug:file=/tmp/gc.log in JVM arguments while starting the application. 

Upon analyzing gc.log, we found that full GC is triggered many times. Additionally, whenever full GC triggers, it generally stops the application for some time. In the Java language, we call this STW (Stop the World). 

Generally there are the following type of events in G1GC: 

• Minor: Eden + Survivor From -> Survivor To
• Mixed: Minor + (# reclaimable Tenured regions / -XX:G1MixedGCCountTarget) regions of Tenured
• Full GC: All regions evacuated
• Minor/Mixed + To-space exhaustion: Minor/Mixed + rollback + Full GC

In a smoothly running application, only batches of minor events alternating with batches of mixed events should be there. Full GC events and to-space exhaustion are things you absolutely don’t want to see when running G1GC. They need to be detected and eliminated, and if they are running, they should be run by some external events such as jstack, jmap, etc.

For in-depth details of these events, as already stated, I will make a blog series explaining G1GC concepts. For now, you can do an independent search. 

Now, let's get back to our debugging.

We checked that no external command for taking a thread dump, heap dump, or histogram was made that can possibly initiate a Full GC event. The question now is: why is this full GC triggering Upon further research, we found that humongous objects can be one of the reasons for triggering the Full GC event. 

Now, what are humongous objects?

A brief definition is: any single data allocation ≥ G1HeapRegionSize/2 is considered a humongous object, which is allocated out of contiguous regions of free space, which are then added to tenured. As humongous objects are allocated out of free space, allocation failures trigger GC events. If an allocation failure from free space triggers GC, the GC event will be a Full GC, which is very undesirable in most circumstances. To avoid Full GC events in an application with lots of humongous objects, one must ensure the free space pool is large enough as compared to Eden so that Eden will always fill up first. 

So we started checking if our application is generating humongous objects, and from gc.log, we found that lots of humongous objects are created. These were the reasons for triggering Full GC events. 

Commands for Humongous Object Check

The following are commands to check the humongous objects, especially in Linux : 

Run the following command on your gc.log.

Command 1:

grep "source: concurrent humongous allocation" /tmp/gc.log | sed 's/.*allocation request: \([0-9]*\) bytes.*/\1/' > humoungous_humongoud_size.txt

Command 2:

awk -F',' '{sum+=$1} END{print sum;}' humoungous_humongoud_size.txt

This will give you the size of humongous objects generated in the application.

We have Java less than Oracle JDK 8u45 version. For Java greater than this, it is written in the release notes that these humongous objects also get collected in minor events. 

Search for: “G1 now collects unreachable Humongous objects during young collections” in the Release Notes JDK.

We upgraded our JDK, and the issue frequency was minimized too much as these objects are now not triggering any major event like FullGC. But one should also care about generating these large objects. We also checked and analyzed one of the heaps and corrected the code not to generate these big objects if unneeded. 

I hope this blog will be helpful.  Please comment and share!