JVM Tuning Practice: Analyzing GC Logs with JDK Commands and Visualization Tools

JVM Tuning Practice

After a recent interview where a candidate struggled with GC log analysis, this article walks through the complete process of collecting, parsing, and visualizing JVM Garbage Collection logs using built‑in JDK options and external tools.

JVM Tuning Main Steps

Monitor and analyze GC logs.

Determine whether JVM performance issues exist (e.g., GC frequency, pause time, or GC duration >1‑3 seconds).

Define tuning objectives (memory usage, latency, throughput).

Adjust JVM parameters accordingly.

Compare performance before and after tuning.

Iterate steps 1‑5 until optimal settings are found.

Apply the final JVM parameters to all production servers and continue monitoring.

Initial Parameter Settings

Machine environment

Metric

Value

CPU

12 cores

Memory

16 GB

Cluster size

Single machine

Application version

1.0

Database

4 cores, 16 GB

Typical JVM tuning flags:

-Xms : minimum heap size (starts increasing when free heap < 40 %).

-Xmx : maximum heap size (default is total memory/64, capped at 1 GB).

-Xmn : maximum young generation size (Eden + two Survivor spaces), e.g., -Xmn1024m .

-Xss : thread stack size (default 1 MB, usually unchanged).

In production the -Xms and -Xmx values should be identical to avoid heap size fluctuations.

It is a common best practice to set -Xms and -Xmx to the same value.

Enabling Detailed GC Logging

-XX:+PrintGCDetails – prints detailed GC information.

-XX:+PrintGCTimeStamps and -XX:+PrintGCDateStamps – add timestamps.

-XX:+PrintHeapAtGC – prints heap state after each GC.

-Xloggc:/path/to/gc.log – writes the log to a file.

Example IDEA VM options (Windows):

-XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps -XX:+PrintHeapAtGC -Xloggc:E:/logs/gc-default.log

The log file gc-default.log will be created under E:/logs .

GC Log Interpretation

Young GC example

2022-08-05T13:45:23.336+0800: 4.866: [GC (Metadata GC Threshold) [PSYoungGen: 136353K->20975K(405504K)] 160049K->48437K(720384K), 0.0092260 secs] [Times: user=0.00 sys=0.02, real=0.02 secs]

The line shows the timestamp, pause duration, memory reclaimed in the young generation, total heap change, and CPU time spent.

Full GC example

2022-08-05T20:24:47.815+0800: 6.955: [Full GC (Metadata GC Threshold) [PSYoungGen: 701K->0K(72704K)] [ParOldGen: 38678K->35960K(175104K)] 39380K->35960K(247808K), [Metaspace: 56706K->56706K(1099776K)], 0.1921975 secs] [Times: user=1.03 sys=0.00, real=0.19 secs]

This indicates a full heap collection triggered by Metaspace threshold, showing both young and old generation reclamation.

GC Log Visualization

The log file can be uploaded to gceasy.io for automatic parsing, chart generation, and downloadable reports.

Memory Usage Overview (gceasy report)

Generation

Allocated (max)

Peak Usage

Young Generation

74.5 MB

74.47 MB

Old Generation

171 MB

95.62 MB

Metaspace

1.05 GB

55.38 MB

Overall

1.3 GB

212.64 MB

Key Performance Indicators

Throughput : 97.043 % (higher means less GC overhead).

Average GC Pause : 7.80 ms.

Maximum GC Pause : 190 ms.

GC Causes Statistics

Cause

Count

Avg Time

Max Time

Total Time

Metadata GC Threshold

6

43.3 ms

190 ms

260 ms

Allocation Failure

53

3.77 ms

10.0 ms

200 ms

Additional possible causes include Ergonomics , which balances pause time and throughput automatically.

Conclusion

Using a visual analysis tool like gceasy.io dramatically simplifies GC log interpretation, allowing developers to quickly identify problematic GC events (e.g., frequent Full GCs) and adjust JVM parameters for better performance.

Further detailed case studies are planned for future articles.