分析串行GC日志

26 Jun 2021 | Java |

测试环境：

jdk1.8，win10，4核8线程，16G内存

演示代码：程序在1秒内生成许多对象，每个对象随机放在数组里。有的位置就会被重置，就会存在未被使用的对象，等待被回收。

import java.util.Random;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.LongAdder;
/*
演示GC日志生成与解读
*/
public class GCLogAnalysis {
    private static Random random = new Random();
    public static void main(String[] args) {
        // 当前毫秒时间戳
        long startMillis = System.currentTimeMillis();
        // 持续运行毫秒数; 可根据需要进行修改
        long timeoutMillis = TimeUnit.SECONDS.toMillis(1);
        // 结束时间戳
        long endMillis = startMillis + timeoutMillis;
        LongAdder counter = new LongAdder();
        System.out.println("正在执行...");
        // 缓存一部分对象; 进入老年代
        int cacheSize = 2000;
        Object[] cachedGarbage = new Object[cacheSize];
        // 在此时间范围内,持续循环
        while (System.currentTimeMillis() < endMillis) {
            // 生成垃圾对象
            Object garbage = generateGarbage(100*1024);
            counter.increment();
            int randomIndex = random.nextInt(2 * cacheSize);
            if (randomIndex < cacheSize) {
                cachedGarbage[randomIndex] = garbage;
            }
        }
        System.out.println("执行结束!共生成对象次数:" + counter.longValue());
    }

    // 生成对象
    private static Object generateGarbage(int max) {
        int randomSize = random.nextInt(max);
        int type = randomSize % 4;
        Object result = null;
        switch (type) {
            case 0:
                result = new int[randomSize];
                break;
            case 1:
                result = new byte[randomSize];
                break;
            case 2:
                result = new double[randomSize];
                break;
            default:
                StringBuilder builder = new StringBuilder();
                String randomString = "randomString-Anything";
                while (builder.length() < randomSize) {
                    builder.append(randomString);
                    builder.append(max);
                    builder.append(randomSize);
                }
                result = builder.toString();
                break;
        }
        return result;
    }
}

编译代码：

javac GCLogAnalysis.java

串行GC在年轻代使用标记复制算法，在老年代使用标记整理算法。都是单线程，不能并行处理，不能利用多核CPU的优势，只会使用一个核心进行垃圾收集。都会发生STW（Stop The World），暂停应用线程。

案例一（`-Xms128m -Xmx128m`）：

D:\>java -XX:+UseSerialGC -Xms128m -Xmx128m -XX:+PrintGCDetails GCLogAnalysis
正在执行...
[GC (Allocation Failure) [DefNew: 34764K->4352K(39296K), 0.0047306 secs] 34764K->11281K(126720K), 0.0050491 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
[GC (Allocation Failure) [DefNew: 39132K->4350K(39296K), 0.0057493 secs] 46062K->24412K(126720K), 0.0059074 secs] [Times: user=0.00 sys=0.02, real=0.01 secs]
[GC (Allocation Failure) [DefNew: 38894K->4350K(39296K), 0.0061968 secs] 58956K->36298K(126720K), 0.0064120 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
[GC (Allocation Failure) [DefNew: 38890K->4338K(39296K), 0.0042303 secs] 70839K->47521K(126720K), 0.0049833 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
[GC (Allocation Failure) [DefNew: 39282K->4350K(39296K), 0.0048158 secs] 82465K->60594K(126720K), 0.0050332 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
[GC (Allocation Failure) [DefNew: 38959K->4347K(39296K), 0.0054938 secs] 95203K->72362K(126720K), 0.0056512 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
[GC (Allocation Failure) [DefNew: 39291K->4344K(39296K), 0.0052938 secs] 107306K->86767K(126720K), 0.0055081 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
[GC (Allocation Failure) [DefNew: 39063K->39063K(39296K), 0.0002362 secs][Tenured: 82422K->86879K(87424K), 0.0071027 secs] 121486K->95746K(126720K), [Metaspace: 2613K->2613K(1056768K)], 0.0078279 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
[Full GC (Allocation Failure) [Tenured: 87366K->87356K(87424K), 0.0120194 secs] 126429K->102427K(126720K), [Metaspace: 2613K->2613K(1056768K)], 0.0127868 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
[Full GC (Allocation Failure) [Tenured: 87356K->87285K(87424K), 0.0172295 secs] 126105K->109247K(126720K), [Metaspace: 2613K->2613K(1056768K)], 0.0302168 secs] [Times: user=0.02 sys=0.00, real=0.03 secs]
[Full GC (Allocation Failure) [Tenured: 87414K->87406K(87424K), 0.0200069 secs] 126682K->108997K(126720K), [Metaspace: 2613K->2613K(1056768K)], 0.0207435 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]
[Full GC (Allocation Failure) [Tenured: 87406K->87406K(87424K), 0.0036416 secs] 126653K->114393K(126720K), [Metaspace: 2613K->2613K(1056768K)], 0.0041416 secs] [Times: user=0.02 sys=0.00, real=0.00 secs]
[Full GC (Allocation Failure) [Tenured: 87406K->87406K(87424K), 0.0054763 secs] 126491K->119369K(126720K), [Metaspace: 2613K->2613K(1056768K)], 0.0073075 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
[Full GC (Allocation Failure) [Tenured: 87406K->87406K(87424K), 0.0020103 secs] 126700K->121661K(126720K), [Metaspace: 2613K->2613K(1056768K)], 0.0032594 secs] [Times: user=0.02 sys=0.00, real=0.00 secs]
[Full GC (Allocation Failure) [Tenured: 87406K->87394K(87424K), 0.0201265 secs] 126671K->120003K(126720K), [Metaspace: 2613K->2613K(1056768K)], 0.0313952 secs] [Times: user=0.03 sys=0.00, real=0.03 secs]
[Full GC (Allocation Failure) [Tenured: 87394K->87394K(87424K), 0.0016258 secs] 126587K->123028K(126720K), [Metaspace: 2613K->2613K(1056768K)], 0.0021521 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
[Full GC (Allocation Failure) [Tenured: 87394K->87394K(87424K), 0.0061530 secs] 126125K->124056K(126720K), [Metaspace: 2613K->2613K(1056768K)], 0.0067304 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
[Full GC (Allocation Failure) [Tenured: 87394K->87394K(87424K), 0.0015619 secs] 126670K->124861K(126720K), [Metaspace: 2613K->2613K(1056768K)], 0.0073016 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
[Full GC (Allocation Failure) [Tenured: 87394K->87000K(87424K), 0.0183339 secs] 126308K->124371K(126720K), [Metaspace: 2613K->2613K(1056768K)], 0.0203635 secs] [Times: user=0.01 sys=0.00, real=0.02 secs]
[Full GC (Allocation Failure) [Tenured: 87000K->87000K(87424K), 0.0022133 secs] 125969K->125300K(126720K), [Metaspace: 2613K->2613K(1056768K)], 0.0031001 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
[Full GC (Allocation Failure) [Tenured: 87319K->87319K(87424K), 0.0013100 secs] 126506K->126331K(126720K), [Metaspace: 2613K->2613K(1056768K)], 0.0026087 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
[Full GC (Allocation Failure) [Tenured: 87319K->87257K(87424K), 0.0200753 secs] 126331K->125740K(126720K), [Metaspace: 2613K->2613K(1056768K)], 0.0207463 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]
[Full GC (Allocation Failure) [Tenured: 87397K->87316K(87424K), 0.0013764 secs] 126690K->126182K(126720K), [Metaspace: 2613K->2613K(1056768K)], 0.0018680 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
[Full GC (Allocation Failure) [Tenured: 87316K->87316K(87424K), 0.0012834 secs] 126513K->126342K(126720K), [Metaspace: 2613K->2613K(1056768K)], 0.0017306 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
[Full GC (Allocation Failure) [Tenured: 87358K->87358K(87424K), 0.0023136 secs] 126641K->126312K(126720K), [Metaspace: 2613K->2613K(1056768K)], 0.0028844 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
[Full GC (Allocation Failure) [Tenured: 87358K->87358K(87424K), 0.0032867 secs] 126540K->126468K(126720K), [Metaspace: 2613K->2613K(1056768K)], 0.0037958 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
[Full GC (Allocation Failure) [Tenured: 87358K->87316K(87424K), 0.0020602 secs] 126612K->126497K(126720K), [Metaspace: 2613K->2613K(1056768K)], 0.0077848 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
[Full GC (Allocation Failure) [Tenured: 87316K->87316K(87424K), 0.0024295 secs] 126497K->126497K(126720K), [Metaspace: 2613K->2613K(1056768K)], 0.0118297 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
Exception in thread "main" java.lang.OutOfMemoryError: Java heap space
        at java.util.Arrays.copyOf(Unknown Source)
        at java.lang.AbstractStringBuilder.ensureCapacityInternal(Unknown Source)
        at java.lang.AbstractStringBuilder.append(Unknown Source)
        at java.lang.StringBuilder.append(Unknown Source)
        at GCLogAnalysis.generateGarbage(GCLogAnalysis.java:56)
        at GCLogAnalysis.main(GCLogAnalysis.java:25)
Heap
 def new generation   total 39296K, used 39192K [0x00000000f8000000, 0x00000000faaa0000, 0x00000000faaa0000)
  eden space 34944K, 100% used [0x00000000f8000000, 0x00000000fa220000, 0x00000000fa220000)
  from space 4352K,  97% used [0x00000000fa660000, 0x00000000faa86050, 0x00000000faaa0000)
  to   space 4352K,   0% used [0x00000000fa220000, 0x00000000fa220000, 0x00000000fa660000)
 tenured generation   total 87424K, used 87316K [0x00000000faaa0000, 0x0000000100000000, 0x0000000100000000)
   the space 87424K,  99% used [0x00000000faaa0000, 0x00000000fffe5000, 0x00000000fffe5000, 0x0000000100000000)
 Metaspace       used 2643K, capacity 4486K, committed 4864K, reserved 1056768K
  class space    used 291K, capacity 386K, committed 512K, reserved 1048576K

当前配置的初始堆内存（-Xms）是128M，最大堆内存（-Xmx）也是128M。这对当前应用程序来说是比较小的内存，所以最终会内存溢出（OutOfMemoryError）。

详细解释一下GC日志中的关键信息，以第一条为例：

[GC (Allocation Failure) [DefNew: 34764K->4352K(39296K), 0.0047306 secs] 34764K->11281K(126720K), 0.0050491 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]

GC (Allocation Failure) ：在年轻代发生了一次minor gc，发生的原因是Young区没有足够的内存，存放新的数据，内存分配失败。
DefNew: 34764K->4352K(39296K), 0.0047306 secs：垃圾收集器的名称叫DefNew（基于标记-复制算法）。在gc前年轻代使用了34764K，在gc后年轻代的内存是4352K，年轻代总共使用39296K。此次gc使用时间是0.0047306秒。可以计算出这一次gc回收内存大约有：(34764-4352)/39296=77%。
34764K->11281K(126720K)：34764K->11281K表示整个堆在gc前后的使用量，126720K表示可用堆的总空间大小。
0.0050491 secs：gc使用的时间。
[Times: user=0.00 sys=0.00, real=0.01 secs]: 分别表示用户线程占用时间（这里主要是gc耗时），系统占用时间，此次停顿时间。

从日志信息中，可以看到，在年轻代中，GC回收了内存有：34764K-4352K=30412k。而整个堆的回收情况是：34764K->11281K=23483k，这说明了有30412k-23483k=6929k内存对象进入到了老年代。另外，因为一开始老年代还没有使用，所以在GC前年轻代的使用量就是堆的使用量34764k。

日志中其他字段含义是一样的。在后面发生了Full GC (Allocation Failure)，在老年代的垃圾收集器是Tenured（基于标记-整理算法）。

案例二（`-Xms256m -Xmx256m`）：

D:\>java -XX:+UseSerialGC -Xms256m -Xmx256m -XX:+PrintGCDetails GCLogAnalysis
正在执行...
[GC (Allocation Failure) [DefNew: 69952K->8703K(78656K), 0.0097565 secs] 69952K->24866K(253440K), 0.0102402 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
[GC (Allocation Failure) [DefNew: 78366K->8701K(78656K), 0.0123995 secs] 94529K->47525K(253440K), 0.0126920 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
[GC (Allocation Failure) [DefNew: 78653K->8698K(78656K), 0.0089781 secs] 117477K->68240K(253440K), 0.0093191 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
[GC (Allocation Failure) [DefNew: 78503K->8703K(78656K), 0.0095831 secs] 138045K->93878K(253440K), 0.0099495 secs] [Times: user=0.00 sys=0.02, real=0.01 secs]
[GC (Allocation Failure) [DefNew: 78638K->8703K(78656K), 0.0094579 secs] 163813K->113496K(253440K), 0.0096384 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
[GC (Allocation Failure) [DefNew: 78251K->8703K(78656K), 0.0090190 secs] 183044K->135148K(253440K), 0.0093462 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
[GC (Allocation Failure) [DefNew: 78557K->8701K(78656K), 0.0109435 secs] 205002K->164375K(253440K), 0.0116513 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
[GC (Allocation Failure) [DefNew: 78653K->78653K(78656K), 0.0002535 secs][Tenured: 155674K->158789K(174784K), 0.0207991 secs] 234327K->158789K(253440K), [Metaspace: 2613K->2613K(1056768K)], 0.0222370 secs] [Times: user=0.03 sys=0.00, real=0.02 secs]
[GC (Allocation Failure) [DefNew: 69952K->69952K(78656K), 0.0002448 secs][Tenured: 158789K->164659K(174784K), 0.0235148 secs] 228741K->164659K(253440K), [Metaspace: 2613K->2613K(1056768K)], 0.0249595 secs] [Times: user=0.02 sys=0.00, real=0.03 secs]
[GC (Allocation Failure) [DefNew: 69952K->69952K(78656K), 0.0001411 secs][Tenured: 164659K->174670K(174784K), 0.0250073 secs] 234611K->178363K(253440K), [Metaspace: 2613K->2613K(1056768K)], 0.0263389 secs] [Times: user=0.02 sys=0.00, real=0.03 secs]
[Full GC (Allocation Failure) [Tenured: 174670K->174712K(174784K), 0.0303998 secs] 253011K->186422K(253440K), [Metaspace: 2613K->2613K(1056768K)], 0.0312608 secs] [Times: user=0.03 sys=0.00, real=0.03 secs]
[Full GC (Allocation Failure) [Tenured: 174712K->174522K(174784K), 0.0128326 secs] 253337K->206255K(253440K), [Metaspace: 2613K->2613K(1056768K)], 0.0150980 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]
[Full GC (Allocation Failure) [Tenured: 174522K->174710K(174784K), 0.0186135 secs] 252876K->215746K(253440K), [Metaspace: 2613K->2613K(1056768K)], 0.0195909 secs] [Times: user=0.01 sys=0.00, real=0.02 secs]
[Full GC (Allocation Failure) [Tenured: 174710K->174734K(174784K), 0.0220202 secs] 252797K->222061K(253440K), [Metaspace: 2613K->2613K(1056768K)], 0.0230878 secs] [Times: user=0.01 sys=0.00, real=0.02 secs]
[Full GC (Allocation Failure) [Tenured: 174734K->174745K(174784K), 0.0319161 secs] 253124K->216348K(253440K), [Metaspace: 2613K->2613K(1056768K)], 0.0327276 secs] [Times: user=0.03 sys=0.00, real=0.03 secs]
[Full GC (Allocation Failure) [Tenured: 174745K->174745K(174784K), 0.0085533 secs] 253309K->228345K(253440K), [Metaspace: 2613K->2613K(1056768K)], 0.0165057 secs] [Times: user=0.00 sys=0.00, real=0.02 secs]
[Full GC (Allocation Failure) [Tenured: 174745K->174773K(174784K), 0.0133595 secs] 253349K->234416K(253440K), [Metaspace: 2613K->2613K(1056768K)], 0.0140097 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
[Full GC (Allocation Failure) [Tenured: 174773K->174474K(174784K), 0.0168179 secs] 253417K->236804K(253440K), [Metaspace: 2613K->2613K(1056768K)], 0.0292995 secs] [Times: user=0.02 sys=0.00, real=0.03 secs]
[Full GC (Allocation Failure) [Tenured: 174618K->174332K(174784K), 0.0394010 secs] 253232K->231695K(253440K), [Metaspace: 2613K->2613K(1056768K)], 0.0399098 secs] [Times: user=0.05 sys=0.00, real=0.04 secs]
[Full GC (Allocation Failure) [Tenured: 174332K->174332K(174784K), 0.0110215 secs] 252325K->237166K(253440K), [Metaspace: 2613K->2613K(1056768K)], 0.0206104 secs] [Times: user=0.01 sys=0.00, real=0.02 secs]
[Full GC (Allocation Failure) [Tenured: 174332K->174332K(174784K), 0.0117216 secs] 252966K->243903K(253440K), [Metaspace: 2613K->2613K(1056768K)], 0.0124997 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
[Full GC (Allocation Failure) [Tenured: 174332K->174429K(174784K), 0.0126842 secs] 252469K->247362K(253440K), [Metaspace: 2613K->2613K(1056768K)], 0.0202157 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]
[Full GC (Allocation Failure) [Tenured: 174756K->174510K(174784K), 0.0346842 secs] 253387K->239952K(253440K), [Metaspace: 2613K->2613K(1056768K)], 0.0441785 secs] [Times: user=0.05 sys=0.00, real=0.04 secs]
[Full GC (Allocation Failure) [Tenured: 174510K->174510K(174784K), 0.0087470 secs] 253155K->244909K(253440K), [Metaspace: 2613K->2613K(1056768K)], 0.0095264 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
[Full GC (Allocation Failure) [Tenured: 174599K->174599K(174784K), 0.0066105 secs] 253229K->247033K(253440K), [Metaspace: 2613K->2613K(1056768K)], 0.0130625 secs] [Times: user=0.00 sys=0.00, real=0.02 secs]
[Full GC (Allocation Failure) [Tenured: 174599K->174599K(174784K), 0.0117250 secs] 253123K->248629K(253440K), [Metaspace: 2613K->2613K(1056768K)], 0.0126458 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
[Full GC (Allocation Failure) [Tenured: 174778K->174778K(174784K), 0.0338238 secs] 253412K->245128K(253440K), [Metaspace: 2613K->2613K(1056768K)], 0.0414770 secs] [Times: user=0.03 sys=0.00, real=0.04 secs]
[Full GC (Allocation Failure) [Tenured: 174778K->174778K(174784K), 0.0098128 secs] 253270K->246365K(253440K), [Metaspace: 2613K->2613K(1056768K)], 0.0105843 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
[Full GC (Allocation Failure) [Tenured: 174778K->174778K(174784K), 0.0053007 secs] 253344K->249086K(253440K), [Metaspace: 2613K->2613K(1056768K)], 0.0139627 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
[Full GC (Allocation Failure) [Tenured: 174778K->174778K(174784K), 0.0120832 secs] 253277K->250125K(253440K), [Metaspace: 2613K->2613K(1056768K)], 0.0210114 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]
[Full GC (Allocation Failure) [Tenured: 174778K->174251K(174784K), 0.0353347 secs] 252871K->247582K(253440K), [Metaspace: 2613K->2613K(1056768K)], 0.0447751 secs] [Times: user=0.05 sys=0.00, real=0.04 secs]
[Full GC (Allocation Failure) [Tenured: 174251K->174251K(174784K), 0.0108172 secs] 252863K->248753K(253440K), [Metaspace: 2613K->2613K(1056768K)], 0.0114180 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
[Full GC (Allocation Failure) [Tenured: 174762K->174762K(174784K), 0.0044149 secs] 253392K->251108K(253440K), [Metaspace: 2613K->2613K(1056768K)], 0.0190374 secs] [Times: user=0.00 sys=0.00, real=0.02 secs]
[Full GC (Allocation Failure) [Tenured: 174762K->174762K(174784K), 0.0153088 secs] 253415K->251968K(253440K), [Metaspace: 2613K->2613K(1056768K)], 0.0159621 secs] [Times: user=0.01 sys=0.00, real=0.02 secs]
[Full GC (Allocation Failure) [Tenured: 174762K->174499K(174784K), 0.0325001 secs] 253349K->249815K(253440K), [Metaspace: 2613K->2613K(1056768K)], 0.0421176 secs] [Times: user=0.03 sys=0.00, real=0.04 secs]
[Full GC (Allocation Failure) [Tenured: 174741K->174741K(174784K), 0.0089539 secs] 253392K->251294K(253440K), [Metaspace: 2613K->2613K(1056768K)], 0.0095564 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
[Full GC (Allocation Failure) [Tenured: 174741K->174741K(174784K), 0.0070162 secs] 253337K->250993K(253440K), [Metaspace: 2613K->2613K(1056768K)], 0.0161804 secs] [Times: user=0.00 sys=0.00, real=0.02 secs]
[Full GC (Allocation Failure) [Tenured: 174741K->174741K(174784K), 0.0028436 secs] 252753K->251508K(253440K), [Metaspace: 2613K->2613K(1056768K)], 0.0118574 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
[Full GC (Allocation Failure) [Tenured: 174741K->174538K(174784K), 0.0303192 secs] 252951K->251739K(253440K), [Metaspace: 2613K->2613K(1056768K)], 0.0385329 secs] [Times: user=0.02 sys=0.00, real=0.04 secs]
执行结束!共生成对象次数:4482
Heap
 def new generation   total 78656K, used 77767K [0x00000000f0000000, 0x00000000f5550000, 0x00000000f5550000)
  eden space 69952K, 100% used [0x00000000f0000000, 0x00000000f4450000, 0x00000000f4450000)
  from space 8704K,  89% used [0x00000000f4cd0000, 0x00000000f5471ce8, 0x00000000f5550000)
  to   space 8704K,   0% used [0x00000000f4450000, 0x00000000f4450000, 0x00000000f4cd0000)
 tenured generation   total 174784K, used 174538K [0x00000000f5550000, 0x0000000100000000, 0x0000000100000000)
   the space 174784K,  99% used [0x00000000f5550000, 0x00000000fffc29b0, 0x00000000fffc2a00, 0x0000000100000000)
 Metaspace       used 2619K, capacity 4486K, committed 4864K, reserved 1056768K
  class space    used 288K, capacity 386K, committed 512K, reserved 1048576K

案例三（`-Xms512m -Xmx512m`）：

D:\>java -XX:+UseSerialGC -Xms512m -Xmx512m -XX:+PrintGCDetails GCLogAnalysis
正在执行...
[GC (Allocation Failure) [DefNew: 139776K->17472K(157248K), 0.0320139 secs] 139776K->43166K(506816K), 0.0322926 secs] [Times: user=0.01 sys=0.02, real=0.03 secs]
[GC (Allocation Failure) [DefNew: 157117K->17470K(157248K), 0.0293402 secs] 182812K->90393K(506816K), 0.0294984 secs] [Times: user=0.01 sys=0.02, real=0.03 secs]
[GC (Allocation Failure) [DefNew: 157246K->17469K(157248K), 0.0190698 secs] 230169K->132524K(506816K), 0.0192439 secs] [Times: user=0.00 sys=0.01, real=0.02 secs]
[GC (Allocation Failure) [DefNew: 157245K->17471K(157248K), 0.0191730 secs] 272300K->174138K(506816K), 0.0195399 secs] [Times: user=0.02 sys=0.02, real=0.02 secs]
[GC (Allocation Failure) [DefNew: 157247K->17471K(157248K), 0.0193048 secs] 313914K->215704K(506816K), 0.0194564 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]
[GC (Allocation Failure) [DefNew: 157247K->17471K(157248K), 0.0211645 secs] 355480K->260011K(506816K), 0.0215438 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]
[GC (Allocation Failure) [DefNew: 157247K->17471K(157248K), 0.0190800 secs] 399787K->303079K(506816K), 0.0194231 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]
[GC (Allocation Failure) [DefNew: 157247K->17471K(157248K), 0.0163864 secs] 442855K->344316K(506816K), 0.0166085 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]
[GC (Allocation Failure) [DefNew: 157247K->157247K(157248K), 0.0006452 secs][Tenured: 326844K->273638K(349568K), 0.0329581 secs] 484092K->273638K(506816K), [Metaspace: 2613K->2613K(1056768K)], 0.0348695 secs] [Times: user=0.03 sys=0.00, real=0.04 secs]
[GC (Allocation Failure) [DefNew: 139776K->17471K(157248K), 0.0072768 secs] 413414K->315550K(506816K), 0.0076043 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
[GC (Allocation Failure) [DefNew: 157247K->17470K(157248K), 0.0126462 secs] 455326K->361635K(506816K), 0.0128757 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
[GC (Allocation Failure) [DefNew: 157246K->157246K(157248K), 0.0004033 secs][Tenured: 344165K->313645K(349568K), 0.0383527 secs] 501411K->313645K(506816K), [Metaspace: 2613K->2613K(1056768K)], 0.0399101 secs] [Times: user=0.03 sys=0.00, real=0.04 secs]
[GC (Allocation Failure) [DefNew: 139631K->139631K(157248K), 0.0004263 secs][Tenured: 313645K->323128K(349568K), 0.0389438 secs] 453277K->323128K(506816K), [Metaspace: 2613K->2613K(1056768K)], 0.0404867 secs] [Times: user=0.03 sys=0.00, real=0.04 secs]
[GC (Allocation Failure) [DefNew: 139776K->139776K(157248K), 0.0002775 secs][Tenured: 323128K->317897K(349568K), 0.0434062 secs] 462904K->317897K(506816K), [Metaspace: 2613K->2613K(1056768K)], 0.0447298 secs] [Times: user=0.05 sys=0.00, real=0.05 secs]
[GC (Allocation Failure) [DefNew: 139096K->139096K(157248K), 0.0003314 secs][Tenured: 317897K->335489K(349568K), 0.0225404 secs] 456994K->335489K(506816K), [Metaspace: 2613K->2613K(1056768K)], 0.0239900 secs] [Times: user=0.01 sys=0.00, real=0.02 secs]
[GC (Allocation Failure) [DefNew: 139776K->139776K(157248K), 0.0002469 secs][Tenured: 335489K->345625K(349568K), 0.0415287 secs] 475265K->345625K(506816K), [Metaspace: 2613K->2613K(1056768K)], 0.0427386 secs] [Times: user=0.05 sys=0.00, real=0.04 secs]
[GC (Allocation Failure) [DefNew: 139776K->139776K(157248K), 0.0001684 secs][Tenured: 345625K->349345K(349568K), 0.0409780 secs] 485401K->351539K(506816K), [Metaspace: 2613K->2613K(1056768K)], 0.0434839 secs] [Times: user=0.05 sys=0.00, real=0.04 secs]
[Full GC (Allocation Failure) [Tenured: 349345K->342265K(349568K), 0.0460241 secs] 506168K->342265K(506816K), [Metaspace: 2613K->2613K(1056768K)], 0.0470453 secs] [Times: user=0.05 sys=0.00, real=0.05 secs]
[GC (Allocation Failure) [DefNew: 139776K->139776K(157248K), 0.0002614 secs][Tenured: 342265K->349159K(349568K), 0.0305656 secs] 482041K->368839K(506816K), [Metaspace: 2613K->2613K(1056768K)], 0.0317684 secs] [Times: user=0.03 sys=0.00, real=0.03 secs]
[Full GC (Allocation Failure) [Tenured: 349456K->349414K(349568K), 0.0433216 secs] 506623K->374469K(506816K), [Metaspace: 2613K->2613K(1056768K)], 0.0440407 secs] [Times: user=0.05 sys=0.00, real=0.04 secs]
执行结束!共生成对象次数:10660
Heap
 def new generation   total 157248K, used 39122K [0x00000000e0000000, 0x00000000eaaa0000, 0x00000000eaaa0000)
  eden space 139776K,  27% used [0x00000000e0000000, 0x00000000e2634858, 0x00000000e8880000)
  from space 17472K,   0% used [0x00000000e8880000, 0x00000000e8880000, 0x00000000e9990000)
  to   space 17472K,   0% used [0x00000000e9990000, 0x00000000e9990000, 0x00000000eaaa0000)
 tenured generation   total 349568K, used 349414K [0x00000000eaaa0000, 0x0000000100000000, 0x0000000100000000)
   the space 349568K,  99% used [0x00000000eaaa0000, 0x00000000fffd9878, 0x00000000fffd9a00, 0x0000000100000000)
 Metaspace       used 2619K, capacity 4486K, committed 4864K, reserved 1056768K
  class space    used 288K, capacity 386K, committed 512K, reserved 1048576K

案例四（`-Xms1g -Xmx1g`）：

D:\>java -XX:+UseSerialGC -Xms1g -Xmx1g -XX:+PrintGCDetails GCLogAnalysis
正在执行...
[GC (Allocation Failure) [DefNew: 279534K->34944K(314560K), 0.0258260 secs] 279534K->84050K(1013632K), 0.0261899 secs] [Times: user=0.00 sys=0.02, real=0.03 secs]
[GC (Allocation Failure) [DefNew: 314560K->34943K(314560K), 0.0339486 secs] 363666K->163176K(1013632K), 0.0341207 secs] [Times: user=0.02 sys=0.02, real=0.03 secs]
[GC (Allocation Failure) [DefNew: 314559K->34943K(314560K), 0.0323238 secs] 442792K->243056K(1013632K), 0.0326154 secs] [Times: user=0.02 sys=0.01, real=0.03 secs]
[GC (Allocation Failure) [DefNew: 314105K->34942K(314560K), 0.0302813 secs] 522218K->317155K(1013632K), 0.0306010 secs] [Times: user=0.01 sys=0.02, real=0.03 secs]
[GC (Allocation Failure) [DefNew: 314558K->34943K(314560K), 0.0321500 secs] 596771K->395696K(1013632K), 0.0324712 secs] [Times: user=0.03 sys=0.00, real=0.03 secs]
[GC (Allocation Failure) [DefNew: 314559K->34943K(314560K), 0.0332325 secs] 675312K->477836K(1013632K), 0.0336039 secs] [Times: user=0.02 sys=0.02, real=0.03 secs]
[GC (Allocation Failure) [DefNew: 314559K->34944K(314560K), 0.0314314 secs] 757452K->553663K(1013632K), 0.0316246 secs] [Times: user=0.02 sys=0.02, real=0.03 secs]
[GC (Allocation Failure) [DefNew: 314560K->34943K(314560K), 0.0338595 secs] 833279K->640738K(1013632K), 0.0340344 secs] [Times: user=0.02 sys=0.02, real=0.03 secs]
[GC (Allocation Failure) [DefNew: 314437K->314437K(314560K), 0.0004803 secs][Tenured: 605794K->380615K(699072K), 0.0444502 secs] 920231K->380615K(1013632K), [Metaspace: 2613K->2613K(1056768K)], 0.0459032 secs] [Times: user=0.05 sys=0.00, real=0.05 secs]
[GC (Allocation Failure) [DefNew: 279616K->34943K(314560K), 0.0131446 secs] 660231K->466683K(1013632K), 0.0134274 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
[GC (Allocation Failure) [DefNew: 314559K->34943K(314560K), 0.0143578 secs] 746299K->544236K(1013632K), 0.0145414 secs] [Times: user=0.01 sys=0.00, real=0.02 secs]
[GC (Allocation Failure) [DefNew: 314559K->34943K(314560K), 0.0147676 secs] 823852K->617920K(1013632K), 0.0151750 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
[GC (Allocation Failure) [DefNew: 314559K->34943K(314560K), 0.0261911 secs] 897536K->691055K(1013632K), 0.0265216 secs] [Times: user=0.01 sys=0.02, real=0.03 secs]
[GC (Allocation Failure) [DefNew: 314559K->314559K(314560K), 0.0004336 secs][Tenured: 656111K->407861K(699072K), 0.0486656 secs] 970671K->407861K(1013632K), [Metaspace: 2613K->2613K(1056768K)], 0.0501344 secs] [Times: user=0.05 sys=0.00, real=0.05 secs]
执行结束!共生成对象次数:15211
Heap
 def new generation   total 314560K, used 127779K [0x00000000c0000000, 0x00000000d5550000, 0x00000000d5550000)
  eden space 279616K,  45% used [0x00000000c0000000, 0x00000000c7cc8ee8, 0x00000000d1110000)
  from space 34944K,   0% used [0x00000000d1110000, 0x00000000d1110000, 0x00000000d3330000)
  to   space 34944K,   0% used [0x00000000d3330000, 0x00000000d3330000, 0x00000000d5550000)
 tenured generation   total 699072K, used 407861K [0x00000000d5550000, 0x0000000100000000, 0x0000000100000000)
   the space 699072K,  58% used [0x00000000d5550000, 0x00000000ee39d618, 0x00000000ee39d800, 0x0000000100000000)
 Metaspace       used 2619K, capacity 4486K, committed 4864K, reserved 1056768K
  class space    used 288K, capacity 386K, committed 512K, reserved 1048576K

案例五（`-Xms2g -Xmx2g`）：

D:\>java -XX:+UseSerialGC -Xms2g -Xmx2g -XX:+PrintGCDetails GCLogAnalysis
正在执行...
[GC (Allocation Failure) [DefNew: 559232K->69888K(629120K), 0.0423904 secs] 559232K->143612K(2027264K), 0.0427476 secs] [Times: user=0.02 sys=0.03, real=0.04 secs]
[GC (Allocation Failure) [DefNew: 629120K->69887K(629120K), 0.0602143 secs] 702844K->273125K(2027264K), 0.0603847 secs] [Times: user=0.03 sys=0.03, real=0.06 secs]
[GC (Allocation Failure) [DefNew: 629119K->69887K(629120K), 0.0526613 secs] 832357K->402090K(2027264K), 0.0528743 secs] [Times: user=0.05 sys=0.02, real=0.05 secs]
[GC (Allocation Failure) [DefNew: 629119K->69888K(629120K), 0.0528390 secs] 961322K->537153K(2027264K), 0.0530111 secs] [Times: user=0.03 sys=0.02, real=0.05 secs]
[GC (Allocation Failure) [DefNew: 629120K->69888K(629120K), 0.0550856 secs] 1096385K->672467K(2027264K), 0.0554154 secs] [Times: user=0.03 sys=0.03, real=0.06 secs]
[GC (Allocation Failure) [DefNew: 629120K->69887K(629120K), 0.0484408 secs] 1231699K->791933K(2027264K), 0.0486370 secs] [Times: user=0.03 sys=0.01, real=0.05 secs]
[GC (Allocation Failure) [DefNew: 629119K->69887K(629120K), 0.0514293 secs] 1351165K->917837K(2027264K), 0.0519458 secs] [Times: user=0.03 sys=0.03, real=0.05 secs]
[GC (Allocation Failure) [DefNew: 629119K->69887K(629120K), 0.0474890 secs] 1477069K->1031605K(2027264K), 0.0476871 secs] [Times: user=0.03 sys=0.02, real=0.05 secs]
执行结束!共生成对象次数:17061
Heap
 def new generation   total 629120K, used 92445K [0x0000000080000000, 0x00000000aaaa0000, 0x00000000aaaa0000)
  eden space 559232K,   4% used [0x0000000080000000, 0x0000000081607660, 0x00000000a2220000)
  from space 69888K,  99% used [0x00000000a2220000, 0x00000000a665fff0, 0x00000000a6660000)
  to   space 69888K,   0% used [0x00000000a6660000, 0x00000000a6660000, 0x00000000aaaa0000)
 tenured generation   total 1398144K, used 961717K [0x00000000aaaa0000, 0x0000000100000000, 0x0000000100000000)
   the space 1398144K,  68% used [0x00000000aaaa0000, 0x00000000e55cd448, 0x00000000e55cd600, 0x0000000100000000)
 Metaspace       used 2619K, capacity 4486K, committed 4864K, reserved 1056768K
  class space    used 288K, capacity 386K, committed 512K, reserved 1048576K

案例六（`-Xms4g -Xmx4g`）：

D:\>java -XX:+UseSerialGC -Xms4g -Xmx4g -XX:+PrintGCDetails GCLogAnalysis
正在执行...
[GC (Allocation Failure) [DefNew: 1118528K->139776K(1258304K), 0.0682293 secs] 1118528K->236820K(4054528K), 0.0684769 secs] [Times: user=0.05 sys=0.03, real=0.07 secs]
[GC (Allocation Failure) [DefNew: 1258304K->139775K(1258304K), 0.0899142 secs] 1355348K->398707K(4054528K), 0.0902513 secs] [Times: user=0.06 sys=0.03, real=0.09 secs]
[GC (Allocation Failure) [DefNew: 1258303K->139775K(1258304K), 0.0718516 secs] 1517235K->567743K(4054528K), 0.0721616 secs] [Times: user=0.05 sys=0.03, real=0.07 secs]
[GC (Allocation Failure) [DefNew: 1258303K->139775K(1258304K), 0.0705470 secs] 1686271K->723587K(4054528K), 0.0707853 secs] [Times: user=0.03 sys=0.05, real=0.07 secs]
执行结束!共生成对象次数:16755
Heap
 def new generation   total 1258304K, used 184710K [0x00000006c0000000, 0x0000000715550000, 0x0000000715550000)
  eden space 1118528K,   4% used [0x00000006c0000000, 0x00000006c2be1b80, 0x0000000704450000)
  from space 139776K,  99% used [0x0000000704450000, 0x000000070cccfff8, 0x000000070ccd0000)
  to   space 139776K,   0% used [0x000000070ccd0000, 0x000000070ccd0000, 0x0000000715550000)
 tenured generation   total 2796224K, used 583811K [0x0000000715550000, 0x00000007c0000000, 0x00000007c0000000)
   the space 2796224K,  20% used [0x0000000715550000, 0x0000000738f70d98, 0x0000000738f70e00, 0x00000007c0000000)
 Metaspace       used 2619K, capacity 4486K, committed 4864K, reserved 1056768K
  class space    used 288K, capacity 386K, committed 512K, reserved 1048576K

案例七（`-Xms512m -Xmx4g`）：

D:\>java -XX:+UseSerialGC -Xms512m -Xmx4g -XX:+PrintGCDetails GCLogAnalysis
正在执行...
[GC (Allocation Failure) [DefNew: 139776K->17471K(157248K), 0.0158409 secs] 139776K->44697K(506816K), 0.0161511 secs] [Times: user=0.00 sys=0.02, real=0.02 secs]
[GC (Allocation Failure) [DefNew: 157247K->17470K(157248K), 0.0232240 secs] 184473K->96218K(506816K), 0.0235964 secs] [Times: user=0.03 sys=0.00, real=0.02 secs]
[GC (Allocation Failure) [DefNew: 157231K->17471K(157248K), 0.0198687 secs] 235980K->143273K(506816K), 0.0201783 secs] [Times: user=0.00 sys=0.02, real=0.02 secs]
[GC (Allocation Failure) [DefNew: 157247K->17471K(157248K), 0.0175572 secs] 283049K->187388K(506816K), 0.0178746 secs] [Times: user=0.01 sys=0.00, real=0.02 secs]
[GC (Allocation Failure) [DefNew: 157247K->17470K(157248K), 0.0183265 secs] 327164K->227734K(506816K), 0.0186434 secs] [Times: user=0.00 sys=0.01, real=0.02 secs]
[GC (Allocation Failure) [DefNew: 157246K->17470K(157248K), 0.0162814 secs] 367510K->269706K(506816K), 0.0166708 secs] [Times: user=0.00 sys=0.02, real=0.02 secs]
[GC (Allocation Failure) [DefNew: 157246K->17471K(157248K), 0.0190609 secs] 409482K->321864K(506816K), 0.0193785 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]
[GC (Allocation Failure) [DefNew: 157247K->17469K(157248K), 0.0211953 secs][Tenured: 354918K->273861K(354956K), 0.0308036 secs] 461640K->273861K(512204K), [Metaspace: 2613K->2613K(1056768K)], 0.0535300 secs] [Times: user=0.05 sys=0.01, real=0.05 secs]
[GC (Allocation Failure) [DefNew: 182656K->22783K(205440K), 0.0128010 secs] 456517K->333911K(661876K), 0.0132203 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
[GC (Allocation Failure) [DefNew: 205439K->22782K(205440K), 0.0184139 secs] 516567K->393777K(661876K), 0.0187534 secs] [Times: user=0.00 sys=0.02, real=0.02 secs]
[GC (Allocation Failure) [DefNew: 205438K->22784K(205440K), 0.0224352 secs] 576433K->449380K(661876K), 0.0227988 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]
[GC (Allocation Failure) [DefNew: 205035K->22783K(205440K), 0.0204890 secs][Tenured: 478389K->341569K(478528K), 0.0400969 secs] 631632K->341569K(683968K), [Metaspace: 2613K->2613K(1056768K)], 0.0618706 secs] [Times: user=0.05 sys=0.02, real=0.06 secs]
[GC (Allocation Failure) [DefNew: 227840K->28416K(256256K), 0.0179324 secs] 569409K->419221K(825540K), 0.0181128 secs] [Times: user=0.00 sys=0.02, real=0.02 secs]
[GC (Allocation Failure) [DefNew: 256256K->28415K(256256K), 0.0171297 secs] 647061K->478798K(825540K), 0.0174653 secs] [Times: user=0.00 sys=0.02, real=0.02 secs]
[GC (Allocation Failure) [DefNew: 256255K->28415K(256256K), 0.0224755 secs] 706638K->548806K(825540K), 0.0228648 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]
[GC (Allocation Failure) [DefNew: 256255K->28415K(256256K), 0.0282753 secs][Tenured: 594258K->386411K(594364K), 0.0459395 secs] 776646K->386411K(850620K), [Metaspace: 2613K->2613K(1056768K)], 0.0756578 secs] [Times: user=0.05 sys=0.03, real=0.08 secs]
[GC (Allocation Failure) [DefNew: 257664K->32191K(289856K), 0.0187775 secs] 644075K->468932K(933876K), 0.0190838 secs] [Times: user=0.01 sys=0.00, real=0.02 secs]
[GC (Allocation Failure) [DefNew: 289813K->32191K(289856K), 0.0158623 secs] 726554K->545256K(933876K), 0.0162082 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]
[GC (Allocation Failure) [DefNew: 289855K->32191K(289856K), 0.0145976 secs] 802920K->620222K(933876K), 0.0149842 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
执行结束!共生成对象次数:13608
Heap
 def new generation   total 289856K, used 42562K [0x00000006c0000000, 0x00000006d3a80000, 0x0000000715550000)
  eden space 257664K,   4% used [0x00000006c0000000, 0x00000006c0a20ab0, 0x00000006cfba0000)
  from space 32192K,  99% used [0x00000006d1b10000, 0x00000006d3a7fdf0, 0x00000006d3a80000)
  to   space 32192K,   0% used [0x00000006cfba0000, 0x00000006cfba0000, 0x00000006d1b10000)
 tenured generation   total 644020K, used 588030K [0x0000000715550000, 0x000000073ca3d000, 0x00000007c0000000)
   the space 644020K,  91% used [0x0000000715550000, 0x000000073938fbf0, 0x000000073938fc00, 0x000000073ca3d000)
 Metaspace       used 2619K, capacity 4486K, committed 4864K, reserved 1056768K
  class space    used 288K, capacity 386K, committed 512K, reserved 1048576K

小结：从上述案例可以看到，随着可用内存的增加，GC次数越来越少，在相同时间内（上述案例都是执行 1 秒）生成对象更多，效率更高。一般需要保持 –Xms 和 –Xmx 一致，否则应用刚启动可能就有好几个 FullGC。当两者配置不一致时，堆内存会不断扩容，可能会导致性能抖动，会影响效率的，如上述案例七所示。

Midnight