Choice of the Java GC algorithm heavily influences your application’s performance. G1 GC is the default GC algorithm since JDK 9 and the most widely used GC algorithm. In this post let’s discuss how to read and analyze G1 GC log files. The GC log file contains a wealth of information such as:

a. At what time G1 GC event ran

b. How long the G1 GC event took to complete the event

c. How many objects were reclaimed from each JVM Memory region

d. Reason why the G1 GC event was triggered

This information is not only helpful to optimize JVM’s performance but also provide deeper insights to debug memory problems. 

If you are new to Java GC Concepts, we recommend you to learn about Java Garbage Collection fundamentals first from this post.

Video

Here is the short video clip from which you can understand how to read and analyse G1 GC Logs:

How to enable G1 GC Log?

You can configure G1 GC algorithm and generate GC log file, by passing following JVM arguments to your application:

-XX:+UseG1GC -Xlog:gc*:file=<gc-log-file-path>

This will generate the GC log in the specified file path. 

If time permits, we recommend you to read GC logging best practices post, to capture G1 GC log events in a pristine format.

G1 GC Log Format

Whenever a G1 GC event is triggered in the JVM, it will be logged into the GC log file. In the GC log file, you are going to notice two types of GC events reported:

  1. Young GC: This Event runs only on the Young Generation of the JVM
  2. Full GC: This Event runs only Young Generation, Old Generation and MetaSpace regions of the JVM. 

The log format varies based on the GC event type. Let’s see them in detail.

Young GC Event Log Format

Below is the excerpt of a single Young GC event from the GC log file: 

Fig: Young G1 GC Event in the Log File

One single Young GC event information is printed across several lines. Let’s review the important fields in the Young GC event:

1. Timestamp field indicates the time at which this Young G1 GC event ran. From the excerpt you can notice that this event ran at ‘2025-02-11T01:14:47.372’ and the time zone is +0000 (i.e. UTC). 

2. GC Type field indicates that this event was the Young GC Event. If it’s a Full GC event, you will see the text ‘Full GC’ printed in this field. 

3. GC Worker Thread Count: Indicates the number GC worker threads that are used for this GC Event. For this application 2 GC worker threads are used. You may visit this post to learn more on how to change GC worker threads count. 

4. Memory Size field shows the internal memory region sizes before and after the event. 

  1. Young Gen is made of two regions: Eden and Survivor:
    1. Before the GC event, the Eden region size was 2560MB. After the event, it became 0MB (i.e. all the objects from the Eden region have been removed during this GC event). The allocated Eden Generation size is 2560MB
    2. Before the GC event, Survivor region size was 0MB. After the event, it became 302MB i.e. objects are promoted from Eden Region to Survivor Region, that’s why this region size has grown during this event.
  2. Overall Heap Size is also printed. Before the GC event, the overall Heap size was 2560MB. After the GC event it became 201.8MB. Total Overall allocated Heap Size is 5120MB

5. Time Taken to Complete field indicates the amount of time taken by this GC event to complete. You can see this GC event took 0.32 seconds (i.e. refer ‘real’ field) to complete. If you like, you can learn about user and sys time fields from this post.

Full GC Event Log Format

Below is the excerpt of a single Full GC event from the GC log file: 

Fig: Full G1 GC Event in the Log File

1. Timestamp field indicates the time at which this Full GC event ran. From the excerpt you can notice that this event ran at ‘2025-02-11T04:53:59.765’ and the time zone is +0000 (i.e. UTC). 

2. GC Type field indicates that this event was the Full GC Event. 

3. Memory Size field shows the internal memory region sizes before and after the event. 

  1. Young Gen is made of two regions: Eden and Survivor. Here you can see these two regions’ sizes.
    1. Before the GC event, the Eden region size was 0MB. After the event, Eden region size became 0MB and allocated size of Eden Generation size is 2560MB
    2. Before the GC event, Survivor region size was 0MB. After the event Survivor region size became 0MB. There was no change in this region
  2. Overall Heap Size is also printed. Before the GC event, the overall heap size was 4596.9MB. After the GC event it became 498.3MB. Total allocated Heap Size is 5120MB

4. Time Taken to Complete field indicates the amount of time taken by this GC event to complete. You can see this GC event took 1.47 seconds (i.e. refer ‘real’ field) to complete. If you like, you can learn about user and sys time fields from this post.

GCeasy Tool to Analyze G1 GC Log

You can notice, just trying to read and digest one single G1 GC event turns out to be a tedious task. Needless to say the complexity that arises when you try to read thousands of GC events that are present in the GC log file. Thus, you can use GC log analysis tools like GCeasy which can analyze all formats of GC logs including G1 GC log file format.

G1 GC Log Analysis: Here is the sample GC log report generated by the GCeasy tool by analyzing a G1 GC log file. 

G1 GC Metrics and Graphs

GCeasy tool’s report provides several graphs and fine-grained metrics to study the G1 GC behavior in your application. Below are some of the excerpts from the G1 GC log analysis report:

Fig: G1 GC Key Performance Indicators by GCeasy

There is a famous saying: “You can’t optimize, what you can’t measure”. Thus, when it comes to G1 GC tuning you need to be aware of the Key Performance Indicators that you are trying to tune. The above figure shows the G1 GC KPIs that are sourced from the GC log file.

Fig: Heap Usage Graph generated by GCeasy

In the above graph you can notice the Heap usage trend after every G1 GC event. You can notice that after every GC event, memory size drops. In fact it may not be visible from the above image; however you can zoom-in in the real GCeasy report to see what’s actually happening.

Fig: GC Pause Duration Time

Above ‘Pause GC Duration Time’ graph shows the Pause time of each G1 GC event. You can notice that the Full GC events (i.e. red triangle) , taking more time than Young GC events (i.e. blue squares). You can see that most of the Young GC events are completing under 400 milliseconds, whereas Full GC events are taking around 1000 milliseconds. This is because Full GC events runs all the 3 regions of the JVM Memory (i.e., Young Gen, Old Gen and Metaspace), whereas Young GC runs only on 1 region (i.e., Young Gen).

Fig: Recommendations given by GCeasy to optimize G1 GC performance

Besides the metrics and visuals, the tool also gives recommendations and JVM settings to optimize the G1 GC performance as shown in the above figure.

Tune G1 GC Performance

If you are looking to tune G1 GC performance, I would like to share few pointers:

  1. 9 Tips to Reduce GC Pause Time: This post gives general 9 tips to reduce any GC algorithm’s pause time (including G1 GC)
  2. JVM arguments to tune G1 GC Performance: This post talks about important G1 GC arguments that you can use for tuning the GC performance.

Conclusion

Hopefully in this post, you learnt how to enable GC log, how to interpret G1 GC events and how to analyze them. If you would like to learn more about G1 GC Tuning, please check out my online ‘JVM Performance Engineering & Troubleshooting Master Class’.