How to Analyze and Tune Java GC Logs for Parallel, G1, and CMS Collectors

1. Preparation

Configure the JVM to write detailed GC information to gc.log for later analysis:

-XX:+DisableExplicitGC -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=./logs -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintGCDateStamps -Xloggc:./logs/gc.log

Use the open‑source GCViewer tool (clone https://github.com/chewiebug/GCViewer, run mvn clean package -Dmaven.test.skip=true, then execute the generated gcviewer-*.jar) to visualize the logs.

Example machine information:

JDK version:

Java HotSpot(TM) 64-Bit Server VM (25.172-b11) for windows-amd64 JRE (1.8.0_172-b11)

Test program: a custom Flink application that heavily allocates memory.

2. Parallel Collector

When no collector is specified and sufficient heap is available, the JVM selects the ParallelGC collector. Sample GC log excerpt (young collection):

2019-10-24T15:33:42.076+0800: 2.164: [GC (Allocation Failure) [PSYoungGen: 65536K->7875K(76288K)] 65536K->7891K(251392K), 0.0275982 secs] [Times: user=0.17 sys=0.00, real=0.03 secs]

2.1 Young GC

Key fields in a young‑generation GC entry:

Timestamp (UTC)

JVM uptime (seconds)

GC type (Young vs Full)

Cause (e.g., Allocation Failure)

Collector name (PSYoungGen)

Memory before → after for the young generation

Total young generation size

Heap before → after (young + old)

Available heap after GC

GC pause duration (seconds)

CPU times: user, sys, real

Interpretation example: before GC the heap used 71,711 KB (young 65,536 KB, old 6,175 KB). After GC the young generation freed 54,798 KB, but total heap decreased by only 7,231 KB, meaning 47,567 KB of objects were promoted to the old generation.

2.2 Full GC

Sample Full GC log entry:

2019-10-24T15:33:46.099+0800: 8.749: [Full GC (Metadata GC Threshold) [PSYoungGen: 172709K->0K(544768K)] [ParOldGen: 230678K->398712K(628224K)] 403387K->398712K(1172992K), 0.2291498 secs] [Times: user=0.20 sys=1.25, real=0.23 secs]

During this Full GC the young generation was cleared, while the old generation and metaspace expanded to accommodate more data.

3. G1 Collector

Enable G1 with -XX:+UseG1GC (or CMS with -XX:+UseConcMarkSweepGC if desired). Example G1 log snippet (young evacuation pause):

2019-10-24T16:52:43.377+0800: 7.865: [GC pause (G1 Evacuation Pause) (young), 0.0197774 secs]
[Parallel Time: 10.9 ms, GC Workers: 8]
[Eden: 161.0M(161.0M)->0.0B(182.0M) Survivors: 13.0M->21.0M Heap: 626.5M(1066.0M)->474.0M(1066.0M)] [Times: user=0.05 sys=0.00, real=0.02 secs]

Key observations:

Pause duration reported by the GC is 0.0197774 s; the actual wall‑clock pause was 10.9 ms with 8 worker threads.

Eden memory was completely reclaimed; some objects moved to the survivor space, reducing overall heap usage.

Mixed GC entries are not shown in this sample; for larger workloads mixed GC analysis is recommended.

4. Performance Optimization

Because raw GC logs can be very large, export them to GCViewer for aggregated statistics. When tuning, focus on:

Throughput (percentage of time spent doing useful work)

Number of GC pauses

Accumulated pause time

4.1 Parallel Collector Tuning

-XX:MetaspaceSize

: set an appropriate metaspace size to avoid early metaspace‑threshold GCs. -XX:MaxGCPauseMillis: soft target for maximum pause duration; the JVM will try to stay below this value. -XX:GCTimeRatio: defines the desired ratio of GC time to total time (GC time = 1/(1+GCTimeRatio)).

Parallel collector is adaptive; setting MaxGCPauseMillis and GCTimeRatio lets the JVM adjust parameters automatically based on observed logs.

4.2 G1 Collector Tuning

Avoid fixing the young generation size with -Xmn or -XX:NewRatio, as this interferes with G1’s adaptive sizing.

Set a realistic pause‑time goal; G1 aims for roughly 90 % application time and 10 % GC time, so overly strict targets can degrade throughput.

Example full‑set of G1 options (often used for aggressive performance requirements):

-Xmx30g -Xms30g
-XX:MaxDirectMemorySize=30g
-XX:+UseG1GC
-XX:+UnlockExperimentalVMOptions
-XX:MaxGCPauseMillis=90
-XX:G1NewSizePercent=8
-XX:InitiatingHeapOccupancyPercent=30
-XX:+ParallelRefProcEnabled
-XX:ConcGCThreads=4
-XX:ParallelGCThreads=16
-XX:MaxTenuringThreshold=1
-XX:G1HeapRegionSize=32m
-XX:G1MixedGCCountTarget=64
-XX:G1OldCSetRegionThresholdPercent=5

Important parameters: G1NewSizePercent: minimum percentage of the heap allocated to the young generation; G1 adjusts this based on recent pause times. InitiatingHeapOccupancyPercent: when heap usage exceeds this percent, G1 starts mixed GCs to compact the old generation. G1MixedGCCountTarget: maximum number of mixed GCs to run after the occupancy threshold is crossed. MaxTenuringThreshold: number of young‑generation collections an object can survive before promotion to old. G1HeapRegionSize: size of each G1 region (must include a unit, e.g., 32m).

Iteratively adjust these flags, collect new GC logs, and evaluate the metrics in GCViewer until the desired pause‑time and throughput balance is achieved.