Understanding and Analyzing JVM Garbage Collection Logs: Young and Full GC Cases

JVM theoretical knowledge is widely documented, but practical experience such as GC log analysis, GC pause anomalies, OOM and other JVM exceptions is increasingly important for daily work and interviews. This article shares hands‑on examples, including a small program that triggers GC and detailed parsing of young and full GC logs.

First, a sample program creates several 2 MB objects and sets JVM options ( -Xms20M -Xmx20M -XX:NewSize=10M -XX:+PrintGCDetails -XX:SurvivorRatio=8 ) to make the young generation 10 MB (Eden 8 MB, each Survivor 1 MB). When the fourth object is allocated, Eden overflows, causing a young GC followed by a full GC.

private static final int _1MB = 1024 * 1024;

public static void main(String[] args) {
    MyObject ob1, ob2, ob3, ob4, ob5;
    ob1 = new MyObject("ob1", 2 * _1MB);
    ob2 = new MyObject("ob2", 2 * _1MB);
    ob3 = new MyObject("ob3", 2 * _1MB);
    ob4 = new MyObject("ob4", 2 * _1MB);
}

private static class MyObject {
    private String name;
    private byte[] space;
    public MyObject(String name, int size) {
        this.name = name;
        this.space = new byte[size];
        System.out.println(name + " init ~");
    }
}

The JVM options used are:

-Xms20M
-Xmx20M
-XX:NewSize=10M
-XX:+PrintGCDetails
-XX:SurvivorRatio=8

The young GC log shows an Allocation Failure, the memory before and after GC in the young generation, total heap change, and the time spent (user, sys, real):

ob1 init ~
ob2 init ~
ob3 init ~
[GC (Allocation Failure) [PSYoungGen: 8046K->594K(9216K)] 8046K->6746K(19456K), 0.0030729 secs][times: user=0.01 sys=0.01, real=0.00 secs]
[Full GC (Ergonomics) [PSYoungGen: 594K->0K(9216K)] [ParOldGen: 6152K->6642K(10240K)] 6746K->6642K(19456K), [Metaspace: 3088K->3088K(1056768K)], 0.0080044 secs][times: user=0.00 sys=0.00, real=0.01 secs]
ob4 init ~
Heap
PSYoungGen total 9216K, used 2289K [...]

The full GC log contains similar information for both young and old generations, metaspace usage, and overall pause time:

[Full GC (Ergonomics) [PSYoungGen: 594K->0K(9216K)] [ParOldGen: 6152K->6642K(10240K)] 6746K->6642K(19456K), [Metaspace: 3088K->3088K(1056768K)], 0.0080044 secs][times: user=0.00 sys=0.00, real=0.01 secs]

Understanding these logs helps diagnose JVM issues: rapid old‑generation growth without Survivor changes may indicate promotion problems; frequent full GCs with little heap reduction can suggest memory leaks; and GC pause times are crucial for performance tuning when monitoring tools are unavailable.

Additional notes explain why a full GC often follows a young GC under the Parallel Scavenge collector’s guarantee policy, and list other possible GC causes found in the JDK source (e.g., "gc/shared/gcCause.hpp").