JVM Garbage Collection Log Parameters

Garbage Collection logs provide insights into JVM memory management and cleanup strategies. Key parameters include:

• -XX:+PrintGC - Enables basic GC logging (similar to -verbose:gc)
• -XX:+PrintGCDetails - Provides detailed GC information
• -XX:+PrintGCTimeStamps - Adds timestamps in relative format
• -XX:+PrintGCDateStamps - Includes absolute date/time stamps
• -XX:+PrintHeapAtGC - Shows heap information before and after GC
• -Xloggc:../logs/gc.log - Specifies log file output path

Basic GC Output with PrintGC

Using -verbose:gc displays overall heap changes:

[GC (Allocation Failure) 80832K->19298K(227840K), 0.0084018 secs]
[GC (Metadata GC Threshold) 109499K->21465K(228352K), 0.0184066 secs]
[Full GC (Metadata GC Threshold) 21465K->16716K(201728K), 0.0619261 secs]

Log field explanations:

• GC/Full GC - Collection type (minor/major)
• Allocation Failure - Trigger reason
• 80832K->19298K - Heap usage before/after GC
• (227840K) - Current heap capacity
• 0.0084018 secs - Duration of collection

Detailed Logging with PrintGCDetails

Using -verbose:gc -XX:+PrintGCDetails provides granular breakdown:

[GC (Allocation Failure) [PSYoungGen: 70640K->10116K(141312K)] 80541K->20017K(227328K), 0.0172573 secs] [Times: user=0.03 sys=0.00, real=0.02 secs]
[GC (Metadata GC Threshold) [PSYoungGen: 98859K->8154K(142336K)] 108760K->21261K(228352K), 0.0151573 secs] [Times: user=0.00 sys=0.01, real=0.02 secs]
[Full GC (Metadata GC Threshold) [PSYoungGen: 8154K->0K(142336K)] [ParOldGen: 13107K->16809K(62464K)] 21261K->16809K(204800K), [Metaspace: 20599K->20599K(1067008K)], 0.0639732 secs] [Times: user=0.14 sys=0.00, real=0.06 secs]

Additional field meanings:

• PSYoungGen - Young generation using Parallel Scavenge collector
• ParOldGen - Old generation using Parallel Old collector
• Metaspace - Metadata area (replaces PermGen in JDK 8)
• Times - user: total CPU time, sys: system call time, real: wall clock time

Timestamped Logs

Comibning timestamp parameters adds temporal context:

2019-09-24T22:15:24.518+0800: 3.287: [GC (Allocation Failure) [PSYoungGen: 136162K->5113K(136192K)] 141425K->17632K(222208K), 0.0248249 secs] [Times: user=0.05 sys=0.00, real=0.03 secs]
2019-09-24T22:15:25.559+0800: 4.329: [GC (Metadata GC Threshold) [PSYoungGen: 97578K->10068K(274944K)] 110096K->22658K(360960K), 0.0094071 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]

Log Interpretation Guidelines

• [GC] vs [Full GC] - Full GC indicates "Stop-The-World" pause
• Collector naming - DefNew (Serial), ParNew (Parallel New), PSYoungGen (Parallel Scavenge)
• Allocation Failure - Insufficietn young generation space for new allocations
• Memory brackets - Inner brackets show generation-specific data, outer show heap totals
• Time metrics - user/sys times may exceed real time due to multi-core processing

Memory Allocation Example

public class MemoryAllocationTest {
    private static final int MB = 1024 * 1024;
    
    public static void allocateMemory() {
        byte[] block1, block2, block3, block4;
        block1 = new byte[2 * MB];
        block2 = new byte[2 * MB];
        block3 = new byte[2 * MB];
        block4 = new byte[4 * MB];
    }
    
    public static void main(String[] args) {
        allocateMemory();
    }
}

Execution parameters: -verbose:gc -Xms20M -Xmx20M -Xmn10M -XX:+PrintGCDetails -XX:SurvivorRatio=8 -XX:+UseSerialGC

GC Log Analysis Tools

Common tools for parsing GC logs include GCViewer, GCEasy, GCHisto, GCLogViewer, Hpjmeter, and garbagecat.