一内存回收与分配策略

对象的内存分配，从概念上讲，应该都是在堆上分配（而实际上也有可能经过即时编译后被拆散为标量类型并间接地在栈上分配）。在经典分代的设计下，新生对象通常会分配在新生代中，少数情况下（例如对象大小超过一定阈值）也可能会直接分配在老年代。对象分配的规则并不是固定的，《Java虚拟机规范》并未规定新对象的创建和存储细节，这取决于虚拟机当前使用的是哪一种垃圾收集器，以及虚拟机中与内存相关的参数的设定

本文验证的实际是使用Serial加Serial Old客户端默认收集器组合下的内存分配和回收的策略，这种配置和收集器组合也许是开发人员做研发时的默认组合（其实现在研发时很多也默认用服务端虚拟机了）

Serial收集器: 最基础、历史最悠久的收集器，曾经（在JDK 1.3.1之前）是HotSpot虚拟机新生代收集器的唯一选择。这个收集器是一个单线程工作的收集器

Serial Old收集器:Serial Old是Serial收集器的老年代版本，它同样是一个单线程收集器，使用标记-整理算法。这个收集器的主要意义也是供客户端模式下的HotSpot虚拟机使用。如果在服务端模式下，它也可能有两种用途：一种是在JDK 5以及之前的版本中与Parallel Scavenge收集器搭配使用[1]，另外一种就是作为CMS收集器发生失败时的后备预案，在并发收集发生Concurrent Mode Failure时使用

jvm区域总体分两类，heap区和非heap区。heap区又分：Eden Space（伊甸园）、Survivor Space(幸存者区)、Tenured Gen（老年代-养老区）。非heap区又分：Code Cache(代码缓存区)、Perm Gen（永久代）、Jvm Stack(java虚拟机栈)、Local Method Statck(本地方法栈)。

1.1 对象优先在Eden分配

大多数情况下，对象在新生代Eden区中分配。当Eden区没有足够空间进行分配时，虚拟机将发起一次Minor GC。

HotSpot虚拟机提供了-XX：+PrintGCDetails这个收集器日志参数，告诉虚拟机在发生垃圾收集行。为时打印内存回收日志，并且在进程退出的时候输出当前的内存各区域分配情况

VM参数：-verbose:gc -Xms20M -Xmx20M -Xmn10M -XX:+PrintGCDetails -XX:SurvivorRatio=8 -XX:+UseSerialGC

在下面代码中，尝试分配三个2MB大小和一个4MB大小的对象，在运行时通过-Xms20M、-Xmx20M、-Xmn10M这三个参数限制了Java堆大小为20MB，不可扩展，其中10MB分配给新生代，剩下的10MB分配给老年代。-XX：Survivor-Ratio=8决定了新生代中Eden区与一个Survivor区的空间比例是8∶1，从输出的结果也清晰地看到“eden space 8192K、from space 1024K、to space 1024K”的信息，新生代总可用空间为9216KB（Eden区+1个Survivor区的总容量）

public class TestAllocation {
    private static final int _1MB = 1024 * 1024;

    /**
     * VM参数：-verbose:gc -Xms20M -Xmx20M -Xmn10M -XX:+PrintGCDetails -XX:SurvivorRatio=8 -XX:+UseSerialGC
     */
    public static void main(String[] args) {
        byte[] allocation1, allocation2, allocation3, allocation4;
        allocation1 = new byte[2 * _1MB];
        allocation2 = new byte[2 * _1MB];
        allocation3 = new byte[2 * _1MB];
        allocation4 = new byte[4 * _1MB]; // 出现一次Minor GC
    }
}

日志结果如下:

[0.006s][warning][gc] -XX:+PrintGCDetails is deprecated. Will use -Xlog:gc* instead.
[0.017s][info   ][gc] Using Serial
[0.017s][info   ][gc,heap,coops] Heap address: 0x00000000fec00000, size: 20 MB, Compressed Oops mode: 32-bit
Connected to the target VM, address: '127.0.0.1:53052', transport: 'socket'
[0.226s][info   ][gc,start     ] GC(0) Pause Young (Allocation Failure)
[0.230s][info   ][gc,heap      ] GC(0) DefNew: 6812K->1024K(9216K)
[0.230s][info   ][gc,heap      ] GC(0) Tenured: 0K->4107K(10240K)
[0.230s][info   ][gc,metaspace ] GC(0) Metaspace: 5500K->5500K(1056768K)
[0.230s][info   ][gc           ] GC(0) Pause Young (Allocation Failure) 6M->5M(19M) 3.554ms
[0.230s][info   ][gc,cpu       ] GC(0) User=0.00s Sys=0.00s Real=0.00s
[0.231s][info   ][gc,heap,exit ] Heap
[0.231s][info   ][gc,heap,exit ]  def new generation   total 9216K, used 7378K [0x00000000fec00000, 0x00000000ff600000, 0x00000000ff600000)
[0.231s][info   ][gc,heap,exit ]   eden space 8192K,  77% used [0x00000000fec00000, 0x00000000ff2349e0, 0x00000000ff400000)
[0.231s][info   ][gc,heap,exit ]   from space 1024K, 100% used [0x00000000ff500000, 0x00000000ff600000, 0x00000000ff600000)
[0.231s][info   ][gc,heap,exit ]   to   space 1024K,   0% used [0x00000000ff400000, 0x00000000ff400000, 0x00000000ff500000)
[0.231s][info   ][gc,heap,exit ]  tenured generation   total 10240K, used 4107K [0x00000000ff600000, 0x0000000100000000, 0x0000000100000000)
[0.231s][info   ][gc,heap,exit ]    the space 10240K,  40% used [0x00000000ff600000, 0x00000000ffa02fe0, 0x00000000ffa03000, 0x0000000100000000)
[0.231s][info   ][gc,heap,exit ]  Metaspace       used 5510K, capacity 5573K, committed 5632K, reserved 1056768K
[0.231s][info   ][gc,heap,exit ]   class space    used 458K, capacity 472K, committed 512K, reserved 1048576K

在上述日志中参数含义如下:

def new generation:指新生代，新创建的对象都在这部分内存中。
eden space:伊甸园，通过new创建的对象首先存放在这里。
from space和to space是幸存区，从伊甸园创建的对象在GC的时候首先会分配的幸存区，如果幸存区放不下则会放到老年区，幸存区两部分的内存分配大小是一样的。
tenured generation：老年代，对于长时间被引用的对象会从新生代转移到老年代中，这里的对象存在的时间一般都比较长。

中括号中的三个数分别是

低边界：内存中分配区域的最低位置，
当前边界：现在已经分配的内存地址，
最高边界：可以被分配的最高内存地址。

如果当前边界和最高边界相同，则内存已经分配完毕，不能够再进行扩展，反之这可以进行进一步扩展。

新生代(def new generation)被分配的内存大小计算公式.

(0x00000000ff400000 - 0x00000000fec00000) / 1024 / 1024=8k

位（bit，Binary Digits）：存放一位二进制数，即0或1，为最小的存储单位，8个二进制位为一个字节单位
1字节(Byte)=8位(bit) [6]
1KB( Kilobyte，千字节)=1024B [6]
1MB( Megabyte，兆字节)=1024KB [6]
1GB( Gigabyte，吉字节，千兆)=1024MB

分配allocation4对象的语句时会发生一次Minor GC，这次回收的结果是新生代6812K变为1024K，而总内存占用量则几乎没有减少（因为allocation1、2、3三个对象都是存活的，虚拟机几乎没有找到可回收的对象）。产生这次垃圾收集的原因是为allocation4分配内存时，发现Eden已经被占用了6MB，剩余空间已不足以分配allocation4所需的4MB内存，因此发生Minor GC。垃圾收集期间虚拟机又发现已有的三个2MB大小的对象全部无法放入Survivor空间（Survivor空间只有1MB大小），所以只好通过分配担保机制提前转移到老年代去。

这次收集结束后，4MB的allocation4对象顺利分配在Eden中。因此程序执行完的结果是Eden占用4MB（被allocation4占用），Survivor空闲，老年代被占用6MB（被allocation1、2、3占用）。通过GC日志可以证实这一点。

1.2 大对象直接进入老年代

大对象就是指需要大量连续内存空间的Java对象，最典型的大对象便是那种很长的字符串，或者元素数量很庞大的数组。大对象对虚拟机的内存分配来说就是一个不折不扣的坏消息，比遇到一个大对象更加坏的消息就是遇到一群“朝生夕灭”的“短命大对象”，我们写程序的时候应注意避免。在Java虚拟机中要避免大对象的原因是，在分配空间时，它容易导致内存明明还有不少空间时就提前触发垃圾收集，以获取足够的连续空间才能安置好它们，而当复制对象时，大对象就意味着高额的内存复制开销。HotSpot虚拟机提供了-XX：PretenureSizeThreshold参数，指定大于该设置值的对象直接在老年代分配，这样做的目的就是避免在Eden区及两个Survivor区之间来回复制，产生大量的内存复制操作

注意 -XX：PretenureSizeThreshold参数只对Serial和ParNew两款新生代收集器有效，HotSpot的其他新生代收集器，如Parallel Scavenge并不支持这个参数。如果必须使用此参数进行调优，可考虑ParNew加CMS的收集器组合

-verbose:gc -Xms20M -Xmx20M -Xmn10M -XX:+PrintGCDetails -XX:SurvivorRatio=8 -XX:PretenureSizeThreshold=3145728 -XX:+UseSerialGC

public class TestPretenureSizeThreshold {
    private static final int _1MB = 1024 * 1024;

    /**
     * VM参数：-verbose:gc -Xms20M -Xmx20M -Xmn10M -XX:+PrintGCDetails -XX:SurvivorRatio=8
     * -XX:PretenureSizeThreshold=3145728 -XX:+UseSerialGC
     * @param args
     */
    public static void main(String[] args) {
        byte[] allocation;
        allocation = new byte[4 * _1MB]; //直接分配在老年代中
    }
}

日志为

[0.005s][warning][gc] -XX:+PrintGCDetails is deprecated. Will use -Xlog:gc* instead.
[0.013s][info   ][gc] Using Serial
[0.013s][info   ][gc,heap,coops] Heap address: 0x00000000fec00000, size: 20 MB, Compressed Oops mode: 32-bit
[0.233s][info   ][gc,heap,exit ] Heap
[0.233s][info   ][gc,heap,exit ]  def new generation   total 9216K, used 5843K [0x00000000fec00000, 0x00000000ff600000, 0x00000000ff600000)
[0.233s][info   ][gc,heap,exit ]   eden space 8192K,  71% used [0x00000000fec00000, 0x00000000ff1b4c08, 0x00000000ff400000)
[0.233s][info   ][gc,heap,exit ]   from space 1024K,   0% used [0x00000000ff400000, 0x00000000ff400000, 0x00000000ff500000)
[0.233s][info   ][gc,heap,exit ]   to   space 1024K,   0% used [0x00000000ff500000, 0x00000000ff500000, 0x00000000ff600000)
[0.233s][info   ][gc,heap,exit ]  tenured generation   total 10240K, used 4096K [0x00000000ff600000, 0x0000000100000000, 0x0000000100000000)
[0.233s][info   ][gc,heap,exit ]    the space 10240K,  40% used [0x00000000ff600000, 0x00000000ffa00010, 0x00000000ffa00200, 0x0000000100000000)
[0.233s][info   ][gc,heap,exit ]  Metaspace       used 6405K, capacity 6443K, committed 6528K, reserved 1056768K
[0.233s][info   ][gc,heap,exit ]   class space    used 543K, capacity 570K, committed 640K, reserved 1048576K

我们看到Eden空间几乎没有被使用，而老年代的10MB空间被使用了40%，也就是4MB的allocation对象直接就分配在老年代中，这是因为-XX：PretenureSizeThreshold被设置为3MB（就是3145728，这个参数不能与-Xmx之类的参数一样直接写3MB），因此超过3MB的对象都会直接在老年代进行分配

1.3 长期存活的对象将进入老年代

HotSpot虚拟机中多数收集器都采用了分代收集来管理堆内存，那内存回收时就必须能决策哪些存活对象应当放在新生代，哪些存活对象放在老年代中。为做到这点，虚拟机给每个对象定义了一个对象年龄（Age）计数器，存储在对象头中。对象通常在Eden区里诞生，如果经过第一次Minor GC后仍然存活，并且能被Survivor容纳的话，该对象会被移动到Survivor空间中，并且将其对象年龄设为1岁。对象在Survivor区中每熬过一次Minor GC，年龄就增加1岁，当它的年龄增加到一定程度（默认为15），就会被晋升到老年代中。对象晋升老年代的年龄阈值，可以通过参数-XX：MaxTenuringThreshold设置。

public class TestTenuringThreshold {
    private static final int _1MB = 1024 * 1024;

    /**
     * VM参数：-verbose:gc -Xms20M -Xmx20M -Xmn10M -XX:+PrintGCDetails -XX:Survivor Ratio=8 -XX:MaxTenuringThreshold=1  -XX:+UseSerialGC 
     * -XX:+PrintTenuringDistribution
     */
    public static void main(String[] args) {
        byte[] allocation1, allocation2, allocation3;
        allocation1 = new byte[_1MB / 4]; // 什么时候进入老年代决定于XX:MaxTenuringThreshold设置
        allocation2 = new byte[4 * _1MB];
        allocation3 = new byte[4 * _1MB];
        allocation3 = null;
        allocation3 = new byte[4 * _1MB];
    }
}

在以参数

-verbose:gc -Xms20M -Xmx20M -XX:+PrintGCDetails -XX:SurvivorRatio=8 -XX:MaxTenuringThreshold=1 -XX:+UseSerialGC

运行上面的代码得日志如下:

[0.005s][warning][gc] -XX:+PrintGCDetails is deprecated. Will use -Xlog:gc* instead.
[0.014s][info   ][gc] Using Serial
[0.014s][info   ][gc,heap,coops] Heap address: 0x00000000fec00000, size: 20 MB, Compressed Oops mode: 32-bit
Connected to the target VM, address: '127.0.0.1:58480', transport: 'socket'
[0.237s][info   ][gc,start     ] GC(0) Pause Young (Allocation Failure)
[0.238s][info   ][gc,heap      ] GC(0) DefNew: 2892K->640K(6144K)
[0.238s][info   ][gc,heap      ] GC(0) Tenured: 0K->653K(13696K)
[0.238s][info   ][gc,metaspace ] GC(0) Metaspace: 5501K->5501K(1056768K)
[0.238s][info   ][gc           ] GC(0) Pause Young (Allocation Failure) 2M->1M(19M) 1.672ms
[0.238s][info   ][gc,cpu       ] GC(0) User=0.00s Sys=0.00s Real=0.00s
[0.239s][info   ][gc,start     ] GC(1) Pause Young (Allocation Failure)
[0.242s][info   ][gc,heap      ] GC(1) DefNew: 4736K->0K(6144K)
[0.242s][info   ][gc,heap      ] GC(1) Tenured: 653K->5389K(13696K)
[0.242s][info   ][gc,metaspace ] GC(1) Metaspace: 5501K->5501K(1056768K)
[0.242s][info   ][gc           ] GC(1) Pause Young (Allocation Failure) 5M->5M(19M) 2.679ms
[0.242s][info   ][gc,cpu       ] GC(1) User=0.00s Sys=0.00s Real=0.00s
[0.242s][info   ][gc,start     ] GC(2) Pause Young (Allocation Failure)
[0.242s][info   ][gc,heap      ] GC(2) DefNew: 4096K->0K(6144K)
[0.242s][info   ][gc,heap      ] GC(2) Tenured: 5389K->5389K(13696K)
[0.242s][info   ][gc,metaspace ] GC(2) Metaspace: 5501K->5501K(1056768K)
[0.242s][info   ][gc           ] GC(2) Pause Young (Allocation Failure) 9M->5M(19M) 0.121ms
[0.242s][info   ][gc,cpu       ] GC(2) User=0.00s Sys=0.00s Real=0.00s
[0.243s][info   ][gc,heap,exit ] Heap
[0.243s][info   ][gc,heap,exit ]  def new generation   total 6144K, used 4229K [0x00000000fec00000, 0x00000000ff2a0000, 0x00000000ff2a0000)
[0.243s][info   ][gc,heap,exit ]   eden space 5504K,  76% used [0x00000000fec00000, 0x00000000ff021658, 0x00000000ff160000)
[0.243s][info   ][gc,heap,exit ]   from space 640K,   0% used [0x00000000ff200000, 0x00000000ff200000, 0x00000000ff2a0000)
[0.243s][info   ][gc,heap,exit ]   to   space 640K,   0% used [0x00000000ff160000, 0x00000000ff160000, 0x00000000ff200000)
[0.243s][info   ][gc,heap,exit ]  tenured generation   total 13696K, used 5389K [0x00000000ff2a0000, 0x0000000100000000, 0x0000000100000000)
[0.243s][info   ][gc,heap,exit ]    the space 13696K,  39% used [0x00000000ff2a0000, 0x00000000ff7e36b8, 0x00000000ff7e3800, 0x0000000100000000)
[0.243s][info   ][gc,heap,exit ]  Metaspace       used 5510K, capacity 5573K, committed 5632K, reserved 1056768K
[0.243s][info   ][gc,heap,exit ]   class space    used 458K, capacity 472K, committed 512K, reserved 1048576K

在以参数

-verbose:gc -Xms20M -Xmx20M -XX:+PrintGCDetails -XX:SurvivorRatio=8 -XX:MaxTenuringThreshold=15 -XX:+UseSerialGC

运行上面的代码得日志如下:

[0.197s][info   ][gc,start     ] GC(0) Pause Young (Allocation Failure)
[0.199s][info   ][gc,heap      ] GC(0) DefNew: 2892K->640K(6144K)
[0.199s][info   ][gc,heap      ] GC(0) Tenured: 0K->653K(13696K)
[0.199s][info   ][gc,metaspace ] GC(0) Metaspace: 5493K->5493K(1056768K)
[0.199s][info   ][gc           ] GC(0) Pause Young (Allocation Failure) 2M->1M(19M) 1.882ms
[0.199s][info   ][gc,cpu       ] GC(0) User=0.00s Sys=0.00s Real=0.00s
[0.199s][info   ][gc,start     ] GC(1) Pause Young (Allocation Failure)
[0.202s][info   ][gc,heap      ] GC(1) DefNew: 4736K->0K(6144K)
[0.202s][info   ][gc,heap      ] GC(1) Tenured: 653K->5389K(13696K)
[0.202s][info   ][gc,metaspace ] GC(1) Metaspace: 5493K->5493K(1056768K)
[0.202s][info   ][gc           ] GC(1) Pause Young (Allocation Failure) 5M->5M(19M) 2.841ms
[0.202s][info   ][gc,cpu       ] GC(1) User=0.00s Sys=0.00s Real=0.00s
[0.203s][info   ][gc,start     ] GC(2) Pause Young (Allocation Failure)
[0.203s][info   ][gc,heap      ] GC(2) DefNew: 4096K->0K(6144K)
[0.203s][info   ][gc,heap      ] GC(2) Tenured: 5389K->5389K(13696K)
[0.203s][info   ][gc,metaspace ] GC(2) Metaspace: 5493K->5493K(1056768K)
[0.203s][info   ][gc           ] GC(2) Pause Young (Allocation Failure) 9M->5M(19M) 0.242ms
[0.203s][info   ][gc,cpu       ] GC(2) User=0.00s Sys=0.00s Real=0.00s
[0.205s][info   ][gc,heap,exit ] Heap
[0.205s][info   ][gc,heap,exit ]  def new generation   total 6144K, used 4229K [0x00000000fec00000, 0x00000000ff2a0000, 0x00000000ff2a0000)
[0.205s][info   ][gc,heap,exit ]   eden space 5504K,  76% used [0x00000000fec00000, 0x00000000ff021658, 0x00000000ff160000)
[0.205s][info   ][gc,heap,exit ]   from space 640K,   0% used [0x00000000ff200000, 0x00000000ff200000, 0x00000000ff2a0000)
[0.205s][info   ][gc,heap,exit ]   to   space 640K,   0% used [0x00000000ff160000, 0x00000000ff160000, 0x00000000ff200000)
[0.205s][info   ][gc,heap,exit ]  tenured generation   total 13696K, used 5389K [0x00000000ff2a0000, 0x0000000100000000, 0x0000000100000000)
[0.205s][info   ][gc,heap,exit ]    the space 13696K,  39% used [0x00000000ff2a0000, 0x00000000ff7e36b8, 0x00000000ff7e3800, 0x0000000100000000)
[0.205s][info   ][gc,heap,exit ]  Metaspace       used 5502K, capacity 5573K, committed 5632K, reserved 1056768K
[0.205s][info   ][gc,heap,exit ]   class space    used 458K, capacity 472K, committed 512K, reserved 1048576K

1.4 动态对象年龄判定

为了能更好地适应不同程序的内存状况，HotSpot虚拟机并不是永远要求对象的年龄必须达到-XX：MaxTenuringThreshold才能晋升老年代，如果在Survivor空间中相同年龄所有对象大小的总和大于Survivor空间的一半，年龄大于或等于该年龄的对象就可以直接进入老年代，无须等到-XX：MaxTenuringThreshold中要求的年龄。

1.5 空间分配担保

在发生Minor GC之前，虚拟机必须先检查老年代最大可用的连续空间是否大于新生代所有对象总空间，如果这个条件成立，那这一次Minor GC可以确保是安全的。如果不成立，则虚拟机会先查看-XX：HandlePromotionFailure参数的设置值是否允许担保失败（Handle Promotion Failure）；如果允许，那会继续检查老年代最大可用的连续空间是否大于历次晋升到老年代对象的平均大小，如果大于，将尝试进行一次Minor GC，尽管这次Minor GC是有风险的；如果小于，或者-XX：HandlePromotionFailure设置不允许冒险，那这时就要改为进行一次Full GC。

解释一下“冒险”是冒了什么风险：

新生代使用复制收集算法，但为了内存利用率，只使用其中一个Survivor空间来作为轮换备份，因此当出现大量对象在Minor GC后仍然存活的情况——最极端的情况就是内存回收后新生代中所有对象都存活，需要老年代进行分配担保，把Survivor无法容纳的对象直接送入老年代，这与生活中贷款担保类似。老年代要进行这样的担保，前提是老年代本身还有容纳这些对象的剩余空间，但一共有多少对象会在这次回收中活下来在实际完成内存回收之前是无法明确知道的，所以只能取之前每一次回收晋升到老年代对象容量的平均大小作为经验值，与老年代的剩余空间进行比较，决定是否进行Full GC来让老年代腾出更多空间。

取历史平均值来比较其实仍然是一种赌概率的解决办法，也就是说假如某次Minor GC存活后的对象突增，远远高于历史平均值的话，依然会导致担保失败。如果出现了担保失败，那就只好老老实实地重新发起一次Full GC，这样停顿时间就很长了。虽然担保失败时绕的圈子是最大的，但通常情况下都还是会将-XX：HandlePromotionFailure开关打开，避免Full GC过于频繁。

public class TestHandlePromotion {
    private static final int _1MB = 1024 * 1024;


    /**
     * VM参数：-Xms20M -Xmx20M -Xmn10M -XX:+PrintGCDetails -XX:SurvivorRatio=8 -XX:HandlePromotionFailure  -XX:+UseSerialGC
     */
    public static void main(String[] args) {
        byte[] allocation1, allocation2, allocation3, allocation4, allocation5, allocation6, allocation7;
        allocation1 = new byte[2 * _1MB];
        allocation2 = new byte[2 * _1MB];
        allocation3 = new byte[2 * _1MB];
        allocation1 = null;
        allocation4 = new byte[2 * _1MB];
        allocation5 = new byte[2 * _1MB];
        allocation6 = new byte[2 * _1MB];
        allocation4 = null;
        allocation5 = null;
        allocation6 = null;
        allocation7 = new byte[2 * _1MB];
    }


}

VM参数：-Xms20M -Xmx20M -Xmn10M -XX:+PrintGCDetails -XX:SurvivorRatio=8 -XX:HandlePromotionFailure -XX:+UseSerialGC

注意在新版中此参数变为了 PromotionFailureALot，同时“VM option ‘PromotionFailureALot’ is notproduct and is available only in debug version of VM.”

二虚拟机及垃圾收集器日志

阅读分析虚拟机和垃圾收集器的日志是处理Java虚拟机内存问题必备的基础技能，垃圾收集器日志是一系列人为设定的规则，多少有点随开发者编码时的心情而定，没有任何的“业界标准”可言，换句话说，每个收集器的日志格式都可能不一样。除此以外还有一个麻烦，在JDK 9以前，HotSpot并没有提供统一的日志处理框架，虚拟机各个功能模块的日志开关分布在不同的参数上，日志级别、循环日志大小、输出格式、重定向等设置在不同功能上都要单独解决。直到JDK 9，这种混乱不堪的局面才终于消失，HotSpot所有功能的日志都收归到了“-Xlog”参数上，这个参数的能力也相应被极大拓展了。

-Xlog[:[selector][:[output][:[decorators][:output-options]]]]

命令行中最关键的参数是选择器（Selector），它由标签（Tag）和日志级别（Level）共同组成。标签可理解为虚拟机中某个功能模块的名字，它告诉日志框架用户希望得到虚拟机哪些功能的日志输出。垃圾收集器的标签名称为“gc”，由此可见，垃圾收集器日志只是HotSpot众多功能日志的其中一项，全部支持的功能模块标签名如下所示：

add，age，alloc，annotation，aot，arguments，attach，barrier，biasedlocking，blocks，bot，breakpoint，bytecod

日志级别从低到高，共有Trace，Debug，Info，Warning，Error，Off六种级别，日志级别决定了输出信息的详细程度，默认级别为Info，HotSpot的日志规则与Log4j、SLF4j这类Java日志框架大体上是一致的。另外，还可以使用修饰器（Decorator）来要求每行日志输出都附加上额外的内容，支持附加在日志行上的信息包括：

time：当前日期和时间。
uptime：虚拟机启动到现在经过的时间，以秒为单位。
timemillis：当前时间的毫秒数，相当于System.currentTimeMillis()的输出。
uptimemillis：虚拟机启动到现在经过的毫秒数。
timenanos：当前时间的纳秒数，相当于System.nanoTime()的输出。
uptimenanos：虚拟机启动到现在经过的纳秒数。
pid：进程ID。
tid：线程ID。
level：日志级别。
tags：日志输出的标签集。

如果不指定，默认值是uptime、level、tags这三个，此时日志输出类似于以下形式

[3.080s][info][gc,cpu] GC(5) User=0.03s Sys=0.00s Real=0.01s

2.1 基本示例

2.1.1 查看GC基本信息

查看GC基本信息，在JDK 9之前使用-XX：+PrintGC，JDK 9后使用-Xlog:gc

public class TestAllocation {
    private static final int _1MB = 1024 * 1024;

    /**
     * VM参数：-Xlog:gc
     */
    public static void main(String[] args) {
        byte[] allocation1, allocation2, allocation3, allocation4;
        allocation1 = new byte[2 * _1MB];
        allocation2 = new byte[2 * _1MB];
        allocation3 = new byte[2 * _1MB];
        allocation4 = new byte[4 * _1MB]; // 出现一次Minor GC
    }
}

日志为

[0.020s][info][gc] Using G1

2.1.2 查看GC详细信息

查看GC详细信息，在JDK 9之前使用-XX：+PrintGCDetails，在JDK 9之后使用-Xlog:gc*，用通配符*将GC标签下所有细分过程都打印出来，如果把日志级别调整到Debug或者Trace，还将获得更多细节信息:

[0.016s][info][gc,heap] Heap region size: 1M
[0.021s][info][gc     ] Using G1
[0.021s][info][gc,heap,coops] Heap address: 0x0000000701e00000, size: 4066 MB, Compressed Oops mode: Zero based, Oop shift amount: 3
[0.208s][info][gc,heap,exit ] Heap
[0.208s][info][gc,heap,exit ]  garbage-first heap   total 262144K, used 17408K [0x0000000701e00000, 0x0000000800000000)
[0.208s][info][gc,heap,exit ]   region size 1024K, 4 young (4096K), 0 survivors (0K)
[0.208s][info][gc,heap,exit ]  Metaspace       used 5510K, capacity 5573K, committed 5632K, reserved 1056768K
[0.208s][info][gc,heap,exit ]   class space    used 458K, capacity 472K, committed 512K, reserved 1048576K

2.1.3 查看GC前后的堆、方法区可用容量变化

查看GC前后的堆、方法区可用容量变化，在JDK 9之前使用-XX：+PrintHeapAtGC，JDK 9之后使用-Xlog:gc+heap=debug

[0.016s][info][gc,heap] Heap region size: 1M
[0.016s][debug][gc,heap] Minimum heap 8388608  Initial heap 268435456  Maximum heap 4263510016

2.1.4 查看GC过程中用户线程并发时间以及停顿的时间

查看GC过程中用户线程并发时间以及停顿的时间，在JDK 9之前使用-XX：+Print GCApplicationConcurrentTime以及-XX:+PrintGCApplicationStoppedTime，JDK 9之后使用-Xlog：safepoint

[0.190s][info][safepoint] Entering safepoint region: ThreadsSuspendJVMTI
[0.190s][info][safepoint] Leaving safepoint region
[0.190s][info][safepoint] Total time for which application threads were stopped: 0.0001205 seconds, Stopping threads took: 0.0000595 seconds
[0.190s][info][safepoint] Application time: 0.0000325 seconds
[0.190s][info][safepoint] Entering safepoint region: ChangeBreakpoints
[0.191s][info][safepoint] Leaving safepoint region
[0.191s][info][safepoint] Total time for which application threads were stopped: 0.0000614 seconds, Stopping threads took: 0.0000072 seconds
Connected to the target VM, address: '127.0.0.1:65170', transport: 'socket'
[0.197s][info][safepoint] Application time: 0.0069071 seconds
[0.197s][info][safepoint] Entering safepoint region: ChangeBreakpoints
[0.198s][info][safepoint] Leaving safepoint region
[0.198s][info][safepoint] Total time for which application threads were stopped: 0.0000765 seconds, Stopping threads took: 0.0000073 seconds
[0.198s][info][safepoint] Application time: 0.0002917 seconds
[0.198s][info][safepoint] Entering safepoint region: ChangeBreakpoints
[0.198s][info][safepoint] Leaving safepoint region
[0.198s][info][safepoint] Total time for which application threads were stopped: 0.0000582 seconds, Stopping threads took: 0.0000047 seconds
[0.209s][info][safepoint] Application time: 0.0112265 seconds
[0.209s][info][safepoint] Entering safepoint region: EnableBiasedLocking
[0.209s][info][safepoint] Leaving safepoint region
[0.209s][info][safepoint] Total time for which application threads were stopped: 0.0000693 seconds, Stopping threads took: 0.0000073 seconds
Disconnected from the target VM, address: '127.0.0.1:65170', transport: 'socket'
[0.219s][info][safepoint] Application time: 0.0096850 seconds
[0.219s][info][safepoint] Entering safepoint region: Halt

2.1.5 查看收集器Ergonomics机制

查看收集器Ergonomics机制（自动设置堆空间各分代区域大小、收集目标等内容，从Parallel收集器开始支持）自动调节的相关信息。在JDK 9之前使用-XX:+PrintAdaptive-SizePolicy，JDK 9之后

使用-Xlog:gc+ergo*=trace

[0.014s][debug][gc,ergo,heap] Expand the heap. requested expansion amount: 268435456B expansion amount: 268435456B
[0.019s][debug][gc,ergo,refine] Initial Refinement Zones: green: 6, yellow: 18, red: 30, min yellow size: 12

2.2 垃圾收集器参数总结

三 OpenJDK 11 JVM日志相关参数解析与使用

public class TestAllocation {
    private static final int _1MB = 1024 * 1024;

    /**
     * VM参数：-verbose:gc -Xms20M -Xmx20M -Xmn10M -XX:+PrintGCDetails -XX:SurvivorRatio=8
     */
    public static void main(String[] args) {
        byte[] allocation1, allocation2, allocation3, allocation4;
        allocation1 = new byte[2 * _1MB];
        allocation2 = new byte[2 * _1MB];
        allocation3 = new byte[2 * _1MB];
        allocation4 = new byte[4 * _1MB]; // 出现一次Minor GC
    }
}

日志结果为:

[0.005s][warning][gc] -XX:+PrintGCDetails is deprecated. Will use -Xlog:gc* instead.
[0.018s][info   ][gc,heap] Heap region size: 1M
[0.018s][info   ][gc     ] Using G1
[0.018s][info   ][gc,heap,coops] Heap address: 0x00000000fec00000, size: 20 MB, Compressed Oops mode: 32-bit
Connected to the target VM, address: '127.0.0.1:49199', transport: 'socket'
[0.219s][info   ][gc,start     ] GC(0) Pause Young (Concurrent Start) (G1 Humongous Allocation)
[0.219s][info   ][gc,task      ] GC(0) Using 2 workers of 6 for evacuation
[0.221s][info   ][gc,phases    ] GC(0)   Pre Evacuate Collection Set: 0.0ms
[0.221s][info   ][gc,phases    ] GC(0)   Evacuate Collection Set: 2.0ms
[0.221s][info   ][gc,phases    ] GC(0)   Post Evacuate Collection Set: 0.2ms
[0.221s][info   ][gc,phases    ] GC(0)   Other: 0.2ms
[0.221s][info   ][gc,heap      ] GC(0) Eden regions: 3->0(8)
[0.221s][info   ][gc,heap      ] GC(0) Survivor regions: 0->2(2)
[0.221s][info   ][gc,heap      ] GC(0) Old regions: 0->0
[0.221s][info   ][gc,heap      ] GC(0) Humongous regions: 9->9
[0.221s][info   ][gc,metaspace ] GC(0) Metaspace: 5507K->5507K(1056768K)
[0.222s][info   ][gc           ] GC(0) Pause Young (Concurrent Start) (G1 Humongous Allocation) 11M->10M(20M) 2.380ms
[0.222s][info   ][gc,cpu       ] GC(0) User=0.00s Sys=0.00s Real=0.00s
[0.222s][info   ][gc           ] GC(1) Concurrent Cycle
[0.222s][info   ][gc,marking   ] GC(1) Concurrent Clear Claimed Marks
[0.222s][info   ][gc,marking   ] GC(1) Concurrent Clear Claimed Marks 0.006ms
[0.222s][info   ][gc,marking   ] GC(1) Concurrent Scan Root Regions
[0.222s][info   ][gc,marking   ] GC(1) Concurrent Scan Root Regions 0.550ms
[0.222s][info   ][gc,marking   ] GC(1) Concurrent Mark (0.222s)
[0.222s][info   ][gc,marking   ] GC(1) Concurrent Mark From Roots
[0.222s][info   ][gc,task      ] GC(1) Using 2 workers of 2 for marking
[0.222s][info   ][gc,marking   ] GC(1) Concurrent Mark From Roots 0.092ms
[0.222s][info   ][gc,marking   ] GC(1) Concurrent Preclean
[0.222s][info   ][gc,marking   ] GC(1) Concurrent Preclean 0.030ms
[0.222s][info   ][gc,marking   ] GC(1) Concurrent Mark (0.222s, 0.222s) 0.139ms
[0.223s][info   ][gc,start     ] GC(1) Pause Remark
[0.223s][info   ][gc,stringtable] GC(1) Cleaned string and symbol table, strings: 3463 processed, 0 removed, symbols: 23878 processed, 0 removed
[0.224s][info   ][gc            ] GC(1) Pause Remark 15M->15M(20M) 0.661ms
[0.224s][info   ][gc,cpu        ] GC(1) User=0.00s Sys=0.00s Real=0.00s
[0.224s][info   ][gc,marking    ] GC(1) Concurrent Rebuild Remembered Sets
[0.224s][info   ][gc,marking    ] GC(1) Concurrent Rebuild Remembered Sets 0.033ms
[0.224s][info   ][gc,start      ] GC(1) Pause Cleanup
[0.224s][info   ][gc            ] GC(1) Pause Cleanup 15M->15M(20M) 0.023ms
[0.224s][info   ][gc,cpu        ] GC(1) User=0.00s Sys=0.00s Real=0.00s
[0.224s][info   ][gc,marking    ] GC(1) Concurrent Cleanup for Next Mark
[0.224s][info   ][gc,marking    ] GC(1) Concurrent Cleanup for Next Mark 0.029ms
[0.224s][info   ][gc            ] GC(1) Concurrent Cycle 2.189ms
[0.224s][info   ][gc,heap,exit  ] Heap
[0.224s][info   ][gc,heap,exit  ]  garbage-first heap   total 20480K, used 15392K [0x00000000fec00000, 0x0000000100000000)
[0.224s][info   ][gc,heap,exit  ]   region size 1024K, 3 young (3072K), 2 survivors (2048K)
[0.224s][info   ][gc,heap,exit  ]  Metaspace       used 5514K, capacity 5573K, committed 5632K, reserved 1056768K
[0.224s][info   ][gc,heap,exit  ]   class space    used 458K, capacity 472K, committed 512K, reserved 1048576K

可以看出，默认的 JVM 日志包括：

[启动经过时间][日志级别][日志标签，可能包含多个] 日志内容

3.1 gc相关

gc日志有很多标签与组合，大部分以 gc 标签为开始，混合搭配其他一些标签。一般，有如下几个标签我们会经常用到：

3.1.1 标签`gc`

gc总体描述日志，一般设置info级别查看gc的发生时间，消耗时间还有内存大小。例如：Pause Young (Normal) (g1 Evacuation Pause) 3480M->1565M(5120M) 15.968ms 包含了gc类型，gc原因，收集内存大小，持续时间等信息

3.1.2 标签`gc,age`

gc 中 age 相关信息，age比较高的对象会进入老年代。如果是 trace 级别，会输出每一个 age 的所有对象占用总大小，以及比这个 age 低的所有 age 的大小，debug 级别只会输出最高级别的 age 以及期望大小，不是当前总大小，例如：

[2020-02-26T08:34:12.823+0000][debug][gc,age         ] gc(1661) Desired survivor size 167772160 bytes, new threshold 6 (max threshold 6)
[2020-02-26T08:34:12.823+0000][trace][gc,age         ] age   1:   16125960 bytes,   16125960 total
[2020-02-26T08:34:12.823+0000][trace][gc,age         ] age   2:   16259512 bytes,   32385472 total
[2020-02-26T08:34:12.823+0000][trace][gc,age         ] age   3:    2435240 bytes,   34820712 total
[2020-02-26T08:34:12.823+0000][trace][gc,age         ] age   4:   17179320 bytes,   52000032 total
[2020-02-26T08:34:12.823+0000][trace][gc,age         ] age   5:   43986952 bytes,   95986984 total
[2020-02-26T08:34:12.823+0000][trace][gc,age         ] age   6:   20858328 bytes,  116845312 total

3.1.3 标签`gc,alloc`，`gc,alloc,region`

这两个参数仅对 g1 gc 有效 gc,alloc 在 gc 完成的时候，打印 trace 级别日志记录触发 gc 的线程是哪一个以及返回的 gc 结果地址;这个一般是在调试 gc 的时候才需要看这个日志。 gc,alloc,region 统计每次 gc 的 Regions 信息，打印 debug 级别日志。

[2020-02-28T02:14:02.694+0000][trace][gc,alloc                    ] sdk-27692-2-amqp-t-4: Successfully scheduled collection returning 0x00000007ffc00000
[2020-02-28T02:16:00.372+0000][debug][gc,alloc,region             ] gc(7848) Mutator Allocation stats, regions: 677, wasted size: 63832B ( 0.0%)

3.1.4 标签`gc,cpu`

标签gc,cpu 这个是大多数 gc 问题定位需要查看的日志， info 级别打印每次gc真正耗时：

[2020-02-28T01:59:46.406+0000][info ][gc,cpu                      ] gc(7841) User=0.10s Sys=0.00s Real=0.04s
[2020-02-28T02:01:20.148+0000][info ][gc,cpu                      ] gc(7842) User=0.04s Sys=0.06s Real=0.04s

注意这个和 JFR 的统计可能会有差异，JFR 统计的 gc 时间是从开始 schedule gc 就认为开始 gc ，而这里的时间是从开始标记开始。

3.1.5 标签`gc,ergo`，`gc,ergo,cset`，`gc,ergo,ihop`，`gc,ergo,refine`

这是 Adaptive Size Policy 相关的日志，如果想详细学习算法，可以用 trace 级别，一般的 debug 级别信息就够了

[2020-02-28T01:59:46.367+0000][trace][gc,ergo,cset                ] gc(7841) Start choosing CSet. pending cards: 26996 predicted base time: 13.34ms remaining time: 186.66ms target pause time: 200.00ms
[2020-02-28T01:59:46.367+0000][trace][gc,ergo,cset                ] gc(7841) Add young regions to CSet. eden: 676 regions, survivors: 6 regions, predicted young region time: 19.02ms, target pause time: 200.00ms
[2020-02-28T01:59:46.367+0000][debug][gc,ergo,cset                ] gc(7841) Finish choosing CSet. old: 0 regions, predicted old region time: 0.00ms, time remaining: 167.64
[2020-02-28T01:59:46.389+0000][debug][gc,ergo                     ] gc(7841) Running g1 Clear Card Table Task using 4 workers for 7 units of work for 895 regions.
[2020-02-28T01:59:46.391+0000][debug][gc,ergo                     ] gc(7841) Running g1 Free Collection Set using 4 workers for collection set length 682
[2020-02-28T01:59:46.391+0000][trace][gc,ergo,refine              ] gc(7841) Updating Refinement Zones: update_rs time: 6.800ms, update_rs buffers: 397, update_rs goal time: 19.998ms
[2020-02-28T01:59:46.391+0000][debug][gc,ergo,refine              ] gc(7841) Updated Refinement Zones: green: 572, yellow: 1716, red: 2860
[2020-02-28T02:01:20.108+0000][trace][gc,ergo,cset                ] gc(7842) Start choosing CSet. pending cards: 25786 predicted base time: 12.87ms remaining time: 187.13ms target pause time: 200.00ms
[2020-02-28T02:01:20.108+0000][trace][gc,ergo,cset                ] gc(7842) Add young regions to CSet. eden: 677 regions, survivors: 5 regions, predicted young region time: 14.43ms, target pause time: 200.00ms
[2020-02-28T02:01:20.108+0000][debug][gc,ergo,cset                ] gc(7842) Finish choosing CSet. old: 0 regions, predicted old region time: 0.00ms, time remaining: 172.70
[2020-02-28T02:01:20.132+0000][debug][gc,ergo                     ] gc(7842) Running g1 Clear Card Table Task using 4 workers for 8 units of work for 903 regions.
[2020-02-28T02:01:20.133+0000][debug][gc,ergo                     ] gc(7842) Running g1 Free Collection Set using 4 workers for collection set length 682
[2020-02-28T02:01:20.133+0000][trace][gc,ergo,refine              ] gc(7842) Updating Refinement Zones: update_rs time: 6.303ms, update_rs buffers: 305, update_rs goal time: 19.997ms
[2020-02-28T02:01:20.133+0000][debug][gc,ergo,refine              ] gc(7842) Updated Refinement Zones: green: 572, yellow: 1716, red: 2860
[2020-02-28T02:04:36.095+0000][trace][gc,ergo,cset                ] gc(7843) Start choosing CSet. pending cards: 26115 predicted base time: 12.85ms remaining time: 187.15ms target pause time: 200.00ms
[2020-02-28T02:04:36.095+0000][trace][gc,ergo,cset                ] gc(7843) Add young regions to CSet. eden: 676 regions, survivors: 6 regions, predicted young region time: 69.11ms, target pause time: 200.00ms
[2020-02-28T02:04:36.095+0000][debug][gc,ergo,cset                ] gc(7843) Finish choosing CSet. old: 0 regions, predicted old region time: 0.00ms, time remaining: 118.04
[2020-02-28T02:04:36.118+0000][debug][gc,ergo                     ] gc(7843) Running g1 Clear Card Table Task using 4 workers for 7 units of work for 894 regions.
[2020-02-28T02:04:36.120+0000][debug][gc,ergo                     ] gc(7843) Running g1 Free Collection Set using 4 workers for collection set length 682
[2020-02-28T02:04:36.121+0000][trace][gc,ergo,refine              ] gc(7843) Updating Refinement Zones: update_rs time: 6.929ms, update_rs buffers: 364, update_rs goal time: 19.997ms
[2020-02-28T02:04:36.121+0000][debug][gc,ergo,refine              ] gc(7843) Updated Refinement Zones: green: 572, yellow: 1716, red: 2860

3.1.6 标签`gc,heap`，`gc,heap,region`

gc,heap的 debug 级别会显示 gc 的时候堆的概况，对于 g1 gc gc,heap,region的 trace 级别，会打印每一个 region 的详细情况，这个一般供 gc 调试使用。

我们一般只需要关心gc,heap的日志就行了

这些标签是在

[2020-02-28T06:01:20.787+0000][debug][gc,heap                     ] gc(7922) Heap before gc invocations=7922 (full 0): garbage-first heap   total 8388608K, used 4076387K [0x0000000600000000, 0x0000000800000000)
[2020-02-28T06:01:20.787+0000][debug][gc,heap                     ] gc(7922)   region size 4096K, 682 young (2793472K), 5 survivors (20480K)
[2020-02-28T06:01:20.787+0000][debug][gc,heap                     ] gc(7922)  Metaspace       used 163068K, capacity 166731K, committed 169728K, reserved 1198080K[2020-02-28T06:01:20.787+0000][debug][gc,heap                     ] gc(7922)   class space    used 18180K, capacity 19580K, committed 20480K, reserved 1048576K
[2020-02-28T06:01:20.787+0000][trace][gc,heap,region              ] gc(7922) Heap Regions: E=young(eden), S=young(survivor), O=old, HS=humongous(starts), HC=humongous(continues), CS=collection set, F=free, A=archive, TAMS=top-at-mark-start (previous, next)[2020-02-28T06:01:20.787+0000][trace][gc,heap,region              ] gc(7922) |   0|0x0000000600000000, 0x0000000600400000, 0x0000000600400000|100%| O|  |TAMS 0x0000000600400000, 0x0000000600000000| Untracked
[2020-02-28T06:01:20.787+0000][trace][gc,heap,region              ] gc(7922) |   1|0x0000000600400000, 0x0000000600800000, 0x0000000600800000|100%| O|  |TAMS 0x0000000600800000, 0x0000000600400000| Untracked
[2020-02-28T06:01:20.787+0000][trace][gc,heap,region              ] gc(7922) |   2|0x0000000600800000, 0x0000000600c00000, 0x0000000600c00000|100%| O|  |TAMS 0x0000000600c00000, 0x0000000600800000| Untracked
[2020-02-28T06:01:20.787+0000][trace][gc,heap,region              ] gc(7922) |   3|0x0000000600c00000, 0x0000000601000000, 0x0000000601000000|100%| O|  |TAMS 0x0000000601000000, 0x0000000600c00000| Untracked
[2020-02-28T06:01:20.787+0000][trace][gc,heap,region              ] gc(7922) |   4|0x0000000601000000, 0x0000000601400000, 0x0000000601400000|100%| O|  |TAMS 0x0000000601400000, 0x0000000601000000| Untracked
[2020-02-28T06:01:20.787+0000][trace][gc,heap,region              ] gc(7922) |   5|0x0000000601400000, 0x0000000601800000, 0x0000000601800000|100%| O|  |TAMS 0x0000000601800000, 0x0000000601400000| Untracked
[2020-02-28T06:01:20.787+0000][trace][gc,heap,region              ] gc(7922) |   6|0x0000000601800000, 0x0000000601c00000, 0x0000000601c00000|100%| O|  |TAMS 0x0000000601c00000, 0x0000000601800000| Untracked

3.1.7 标签`gc,humongous`

标签gc,humongous 如果你使用的是g1 gc，并且经常出现 Evacuation Failure 或者 Humongous Allocation ，并且不知道是什么原因的话，可以考虑看看这个标签相关的日志：

[2020-02-28T06:01:20.831+0000][debug][gc,humongous                ] gc(7922) Live humongous region 219 object size 2160888 start 0x0000000636c00000  with remset 1 code roots 0 is marked 0 reclaim candidate 0 type array 0
[2020-02-28T06:01:20.831+0000][debug][gc,humongous                ] gc(7922) Live humongous region 412 object size 2160888 start 0x0000000667000000  with remset 1 code roots 0 is marked 0 reclaim candidate 0 type array 0
[2020-02-28T06:01:20.831+0000][debug][gc,humongous                ] gc(7922) Live humongous region 443 object size 3241320 start 0x000000066ec00000  with remset 1 code roots 0 is marked 0 reclaim candidate 0 type array 0
[2020-02-28T06:01:20.831+0000][debug][gc,humongous                ] gc(7922) Live humongous region 489 object size 2160888 start 0x000000067a400000  with remset 2 code roots 0 is marked 0 reclaim candidate 0 type array 0
[2020-02-28T06:01:20.831+0000][debug][gc,humongous                ] gc(7922) Live humongous region 490 object size 2160888 start 0x000000067a800000  with remset 1 code roots 0 is marked 0 reclaim candidate 0 type array 0
[2020-02-28T06:01:20.831+0000][debug][gc,humongous                ] gc(7922) Live humongous region 499 object size 7292936 start 0x000000067cc00000  with remset 2 code roots 0 is marked 0 reclaim candidate 0 type array 0
[2020-02-28T06:01:20.831+0000][debug][gc,humongous                ] gc(7922) Live humongous region 536 object size 2160888 start 0x0000000686000000  with remset 2 code roots 0 is marked 0 reclaim candidate 0 type array 0
[2020-02-28T06:01:20.831+0000][debug][gc,humongous                ] gc(7922) Live humongous region 656 object size 2160888 start 0x00000006a4000000  with remset 1 code roots 0 is marked 0 reclaim candidate 0 type array 0
[2020-02-28T06:01:20.831+0000][debug][gc,humongous                ] gc(7922) Live humongous region 768 object size 2160888 start 0x00000006c0000000  with remset 1 code roots 0 is marked 0 reclaim candidate 0 type array 0
[2020-02-28T06:01:20.831+0000][debug][gc,humongous                ] gc(7922) Live humongous region 786 object size 2160888 start 0x00000006c4800000  with remset 1 code roots 0 is marked 0 reclaim candidate 0 type array 0

3.1.8 标签`gc,metaspace`，`gc,metaspace,freelist`，`gc,metaspace,freelist,blocks`

标签gc,metaspace，gc,metaspace,freelist，gc,metaspace,freelist,blocks查看 metaspace 相关的 gc 日志，gc,metaspace的 info 级别会输出每次 gc 涉及的 metaspace 内存变化，如果有变化，详细变化会通过gc,metaspace,freelist，gc,metaspace,freelist,blocks的 trace 级别输出。

[2020-02-28T04:32:13.123+0000][info ][gc,metaspace                ] gc(7896) Metaspace: 163062K->163062K(1198080K)
[2020-02-28T04:35:44.956+0000][trace][gc,metaspace,freelist       ] SpaceManager::grow_and_allocate for 49 words 109 words used 19 words left
[2020-02-28T04:35:44.956+0000][trace][gc,metaspace,freelist       ] ChunkManager::free_chunks_get: free_list: 0x00007fddccb89770 chunks left: 433.
[2020-02-28T04:35:44.956+0000][trace][gc,metaspace,freelist       ] ChunkManager::chunk_freelist_allocate: 0x00007fddccb89770 chunk 0x00007fdc74221000  size 128 count 433 Free chunk total 255616  count 824
[2020-02-28T04:35:44.956+0000][trace][gc,metaspace,freelist,blocks] returning block at 0x00007fdd95575b68 size = 19
[2020-02-28T04:35:44.956+0000][trace][gc,metaspace,freelist       ] SpaceManager::added chunk: 
[2020-02-28T04:35:44.956+0000][trace][gc,metaspace,freelist       ] Metachunk: bottom 0x00007fdc74221000 top 0x00007fdc74221040 end 0x00007fdc74221400 size 128 (specialized)
[2020-02-28T04:35:44.956+0000][trace][gc,metaspace,freelist       ] Free chunk total 255616  count 824
[2020-02-28T04:36:35.367+0000][info ][gc,metaspace                ] gc(7897) Metaspace: 163065K->163065K(1198080K)

3.1.9 标签`gc,phases`，`gc,phases,ref`，`gc,phases,task`，`gc,ref`，`gc,start`,`gc,ref,start`

标签gc,phases，gc,phases,ref，gc,phases,task，gc,ref，gc,start,gc,ref,start这些标签与 gc 步骤相关，如果想学习 gc 算法，可以查看这些标签的日志，来了解 gc 的步骤以及原理

3.1.10 标签`safepoint`

我们知道只有到达 safepoint，我们才可以进行 gc，如果我们对这些 safepoint 感兴趣，可以查看这个标签的 debug 级别的日志

3. 2. 类加载与运行时编译相关

3.2.1 标签`class,preorder`，`class,init`，`class,load`,`class,unload`

标签class,preorder，class,init，class,load,** **class,unload 顾名思义，这是类初始化，类加载与类卸载的日志，info 级别的信息就以足够。如果你想学习 JVM 类加载过程，可以查看 class 标签的 trace 级别日志。

[8.931s][debug][class,preorder  ] com.fasterxml.jackson.core.PrettyPrinter source: file:/D:/Repositories/maven/com/fasterxml/jackson/core/jackson-core/2.10.0/jackson-core-2.10.0.jar
[8.931s][info][class,init              ] 2740 Initializing 'com/fasterxml/jackson/core/PrettyPrinter' (0x0000000801399220)
[8.934s][info][class,load              ] com.fasterxml.jackson.core.PrettyPrinter source: file:/D:/Repositories/maven/com/fasterxml/jackson/core/jackson-core/2.10.0/jackson-core-2.10.0.jar

3.1.2 标签`jit,compilation`

标签jit,compilation 一般我们对于即时编译优化，只用看 jit 编译日志即可，对应的标签是jit,compilation，日志级别是 debug

[2020-02-28T03:01:51.619+0000][debug][jit,compilation] 153756   !   4       jdk.internal.reflect.GeneratedConstructorAccessor161::newInstance (49 bytes)   made zombie
[2020-02-28T03:01:51.620+0000][debug][jit,compilation] 153219       4       io.lettuce.core.protocol.CommandArgs$IntegerArgument::encode (12 bytes)   made zombie
[2020-02-28T03:01:51.623+0000][debug][jit,compilation] 153192       4       io.lettuce.core.protocol.CommandArgs$StringArgument::writeString (60 bytes)   made zombie
[2020-02-28T03:01:54.911+0000][debug][jit,compilation] 157252   !   4       jdk.internal.reflect.GeneratedConstructorAccessor161::newInstance (49 bytes)

3.3. 其他运行时相关

3.3.1 标签`monitorinflation`

标签monitorinflation同步锁相关日志, 一般查看 debug 级别的，可以用于定位死锁

[5.033s][debug][monitorinflation] Deflating object 0x0000000708310378 , mark 0x0000021cef446002 , type java.lang.ref.ReferenceQueue$Lock
[5.033s][debug][monitorinflation] Inflating object 0x0000000708310378 , mark 0x0000021cf085c002 , type java.lang.ref.ReferenceQueue$Lock
[5.035s][debug][monitorinflation] Deflating object 0x0000000708310378 , mark 0x0000021cf085c002 , type java.lang.ref.ReferenceQueue$Lock
[5.035s][debug][monitorinflation] Inflating object 0x0000000708310378 , mark 0x0000021cef445e02 , type java.lang.ref.ReferenceQueue$Lock

3.3.2 标签`biasedlocking`

标签biasedlocking 偏向锁相关日志，一般查看 info 级别即可，trace 级别显示更详细的偏向锁争用细节，可以用于学习偏向锁实现原理

[7.273s][info ][biasedlocking] Revoking bias by walking my own stack:
[7.273s][info ][biasedlocking] Revoking bias of object 0x0000000711b1ca40, mark 0x000001c6d0acc905, type sun.net.www.protocol.jar.URLJarFile, prototype header 0x0000000000000105, allow rebias 0, requesting thread 0x000001c6d0acc800
[7.273s][info ][biasedlocking]   Revoked bias of object biased toward live thread (0x000001c6d0acc800)
[7.273s][trace][biasedlocking]    mon_info->owner (0x00000007022634d8) != obj (0x0000000711b1ca40)
[7.273s][trace][biasedlocking]    mon_info->owner (0x0000000711b200d8) != obj (0x0000000711b1ca40)
[7.273s][trace][biasedlocking]    mon_info->owner (0x0000000711b200d8) != obj (0x0000000711b1ca40)
[7.273s][trace][biasedlocking]    mon_info->owner (0x0000000702970260) != obj (0x0000000711b1ca40)
[7.273s][info ][biasedlocking]   Revoked bias of currently-unlocked object

四垃圾回收器

这个关系不是一成不变的，由于维护和兼容性测试的成本，在JDK 8时将Serial+CMS、ParNew+Serial Old这两个组合声明为废弃（JEP 173），并在JDK 9中完全取消了这些组合的支持（JEP214）

经典的垃圾回收器如下：

Serial 单线程新生代复制算法的垃圾回收器；
ParNew 垃圾回收器，是 Serial 的多线程实现，采用复制算法实现；
Parallel Scavenge 垃圾回收器，是一种高效的多线程复制算法；
SerialOld 垃圾回收器，是一种单线程老年代标记整理算法；
ParallelOld 垃圾回收器，是 Parallel Scavenge 的一种老年代的多线程标记整理算法；
CMS 垃圾回收器，是一种多线程标记清除算法，后面会详细介绍；
G1 垃圾回收器，是一种高吞吐量的垃圾回收器。

4.1 Serial收集器

Serial收集器是最基础、历史最悠久的收集器，曾经（在JDK 1.3.1之前）是HotSpot虚拟机新生代收集器的唯一选择。大家只看名字就能够猜到，这个收集器是一个单线程工作的收集器，但它的“单线程”的意义并不仅仅是说明它只会使用一个处理器或一条收集线程去完成垃圾收集工作，更重要的是强调在它进行垃圾收集时，必须暂停其他所有工作线程，直到它收集结束。“Stop The World”这个词语也许听起来很酷，但这项工作是由虚拟机在后台自动发起和自动完成的，在用户不可知、不可控的情况下把用户的正常工作的线程全部停掉，这对很多应用来说都是不能接受的。

4.2 ParNew收集器

ParNew收集器实质上是Serial收集器的多线程并行版本，除了同时使用多条线程进行垃圾收集之外，其余的行为包括Serial收集器可用的所有控制参数（例如：-XX：SurvivorRatio、-XX：PretenureSizeThreshold、-XX：HandlePromotionFailure等）、收集算法、Stop The World、对象分配规则、回收策略等都与Serial收集器完全一致，在实现上这两种收集器也共用了相当多的代码

4.3 Parallel Scavenge收集器

Parallel Scavenge收集器也是一款新生代收集器，它同样是基于标记-复制算法实现的收集器，也是能够并行收集的多线程收集器。Parallel Scavenge的诸多特性从表面上看和ParNew非常相似，但Parallel Scavenge收集器的特点是它的关注点与其他收集器不同，CMS等收集器的关注点是尽可能地缩短垃圾收集时用户线程的停顿时间，而Parallel Scavenge收集器的目标则是达到一个可控制的吞吐量（Throughput）。所谓吞吐量就是处理器用于运行用户代码的时间与处理器总消耗时间的比值。

如果虚拟机完成某个任务，用户代码加上垃圾收集总共耗费了100分钟，其中垃圾收集花掉1分钟，那吞吐量就是99%。停顿时间越短就越适合需要与用户交互或需要保证服务响应质量的程序，良好的响应速度能提升用户体验；而高吞吐量则可以最高效率地利用处理器资源，尽快完成程序的运算任务，主要适合在后台运算而不需要太多交互的分析任务

需要说明一下，Parallel Scavenge收集器架构中本身有PS MarkSweep收集器来进行老年代收集，并非直接调用Serial Old收集器，但是这个PS MarkSweep收集器与Serial Old的实现几乎是一样的，所以在官方的许多资料中都是直接以Serial Old代替PS MarkSweep进行讲解

4.4 Serial Old收集器

Serial Old是Serial收集器的老年代版本，它同样是一个单线程收集器，使用标记-整理算法。这个收集器的主要意义也是供客户端模式下的HotSpot虚拟机使用。如果在服务端模式下，它也可能有两种用途：一种是在JDK 5以及之前的版本中与Parallel Scavenge收集器搭配使用[1]，另外一种就是作为CMS收集器发生失败时的后备预案，在并发收集发生Concurrent Mode Failure时使用

4.5 Parallel Old收集器

Parallel Old是Parallel Scavenge收集器的老年代版本，支持多线程并发收集，基于标记-整理算法实现。这个收集器是直到JDK 6时才开始提供的，在此之前，新生代的Parallel Scavenge收集器一直处于相当尴尬的状态，原因是如果新生代选择了Parallel Scavenge收集器，老年代除了Serial Old（PS MarkSweep）收集器以外别无选择，其他表现良好的老年代收集器，如CMS无法与它配合工作。由于老年代Serial Old收集器在服务端应用性能上的“拖累”，使用Parallel Scavenge收集器也未必能在整体上获得吞吐量最大化的效果。同样，由于单线程的老年代收集中无法充分利用服务器多处理器的并行处理能力，在老年代内存空间很大而且硬件规格比较高级的运行环境中，这种组合的总吞吐量甚至不一定比ParNew加CMS的组合来得优秀。

直到Parallel Old收集器出现后，“吞吐量优先”收集器终于有了比较名副其实的搭配组合，在注重吞吐量或者处理器资源较为稀缺的场合，都可以优先考虑Parallel Scavenge加Parallel Old收集器这个组合

4.6 CMS收集器

CMS（Concurrent Mark Sweep）收集器是一种以获取最短回收停顿时间为目标的收集器。目前很大一部分的Java应用集中在互联网网站或者基于浏览器的B/S系统的服务端上，这类应用通常都会较为关注服务的响应速度，希望系统停顿时间尽可能短，以给用户带来良好的交互体验。CMS收集器就非常符合这类应用的需求。

从名字（包含“Mark Sweep”）上就可以看出CMS收集器是基于标记-清除算法实现的，它的运作过程相对于前面几种收集器来说要更复杂一些，整个过程分为四个步骤，包括：

1）初始标记（CMS initial mark）
2）并发标记（CMS concurrent mark）
3）重新标记（CMS remark）
4）并发清除（CMS concurrent sweep）

其中初始标记、重新标记这两个步骤仍然需要“Stop The World”。初始标记仅仅只是标记一下GC Roots能直接关联到的对象，速度很快；并发标记阶段就是从GC Roots的直接关联对象开始遍历整个对象图的过程，这个过程耗时较长但是不需要停顿用户线程，可以与垃圾收集线程一起并发运行；而重新标记阶段则是为了修正并发标记期间，因用户程序继续运作而导致标记产生变动的那一部分对象的标记记录，这个阶段的停顿时间通常会比初始标记阶段稍长一些，但也远比并发标记阶段的时间短；最后是并发清除阶段，清理删除掉标记阶段判断的已经死亡的对象，由于不需要移动存活对象，所以这个阶段也是可以与用户线程同时并发的。

CMS是一款优秀的收集器，它最主要的优点在名字上已经体现出来：并发收集、低停顿，一些官方公开文档里面也称之为“并发低停顿收集器”（Concurrent Low Pause Collector）。CMS收集器是HotSpot虚拟机追求低停顿的第一次成功尝试，但是它还远达不到完美的程度，至少有以下三个明显的缺点：

首先，CMS收集器对处理器资源非常敏感。事实上，面向并发设计的程序都对处理器资源比较敏感。在并发阶段，它虽然不会导致用户线程停顿，但却会因为占用了一部分线程（或者说处理器的计算能力）而导致应用程序变慢，降低总吞吐量。CMS默认启动的回收线程数是（处理器核心数量+3）/4，也就是说，如果处理器核心数在四个或以上，并发回收时垃圾收集线程只占用不超过25%的处理器运算资源，并且会随着处理器核心数量的增加而下降。但是当处理器核心数量不足四个时，CMS对用户程序的影响就可能变得很大。如果应用本来的处理器负载就很高，还要分出一半的运算能力去执行收集器线程，就可能导致用户程序的执行速度忽然大幅降低。为了缓解这种情况，虚拟机提供了一种称为“增量式并发收集器”（Incremental Concurrent Mark Sweep/i-CMS）的CMS收集器变种，所做的事情和以前单核处理器年代PC机操作系统靠抢占式多任务来模拟多核并行多任务的思想一样，是在并发标记、清理的时候让收集器线程、用户线程交替运行，尽量减少垃圾收集线程的独占资源的时间，这样整个垃圾收集的过程会更长，但对用户程序的影响就会显得较少一些，直观感受是速度变慢的时间更多了，但速度下降幅度就没有那么明显。实践证明增量式的CMS收集器效果很一般，从JDK 7开始，i-CMS模式已经被声明为“deprecated”，即已过时不再提倡用户使用，到JDK 9发布后CMS模式被完全废弃。

然后，由于CMS收集器无法处理“浮动垃圾”（Floating Garbage），有可能出现“Con-current Mode Failure”失败进而导致另一次完全“Stop The World”的Full GC的产生。在CMS的并发标记和并发清理阶段，用户线程是还在继续运行的，程序在运行自然就还会伴随有新的垃圾对象不断产生，但这一部分垃圾对象是出现在标记过程结束以后，CMS无法在当次收集中处理掉它们，只好留待下一次垃圾收集时再清理掉。这一部分垃圾就称为“浮动垃圾”。同样也是由于在垃圾收集阶段用户线程还需要持续运行，那就还需要预留足够内存空间提供给用户线程使用，因此CMS收集器不能像其他收集器那样等待到老年代几乎完全被填满了再进行收集，必须预留一部分空间供并发收集时的程序运作使用。在JDK 5的默认设置下，CMS收集器当老年代使用了68%的空间后就会被激活，这是一个偏保守的设置，如果在实际应用中老年代增长并不是太快，可以适当调高参数-XX：CMSInitiatingOccu-pancyFraction的值来提高CMS的触发百分比，降低内存回收频率，获取更好的性能。到了JDK 6时，CMS收集器的启动阈值就已经默认提升至92%。但这又会更容易面临另一种风险：要是CMS运行期间预留的内存无法满足程序分配新对象的需要，就会出现一次“并发失败”（Concurrent Mode Failure），这时候虚拟机将不得不启动后备预案：冻结用户线程的执行，临时启用Serial Old收集器来重新进行老年代的垃圾收集，但这样停顿时间就很长了。所以参数-XX：CMSInitiatingOccupancyFraction设置得太高将会很容易导致大量的并发失败产生，性能反而降低，用户应在生产环境中根据实际应用情况来权衡设置。

还有最后一个缺点，在本节的开头曾提到，CMS是一款基于“标记-清除”算法实现的收集器，如果读者对前面这部分介绍还有印象的话，就可能想到这意味着收集结束时会有大量空间碎片产生。空间碎片过多时，将会给大对象分配带来很大麻烦，往往会出现老年代还有很多剩余空间，但就是无法找到足够大的连续空间来分配当前对象，而不得不提前触发一次Full GC的情况。为了解决这个问题，CMS收集器提供了一个-XX：+UseCMS-CompactAtFullCollection开关参数（默认是开启的，此参数从JDK 9开始废弃），用于在CMS收集器不得不进行Full GC时开启内存碎片的合并整理过程，由于这个内存整理必须移动存活对象，（在Shenandoah和ZGC出现前）是无法并发的。这样空间碎片问题是解决了，但停顿时间又会变长，因此虚拟机设计者们还提供了另外一个参数-XX：CMSFullGCsBeforeCompaction（此参数从JDK 9开始废弃），这个参数的作用是要求CMS收集器在执行过若干次（数量由参数值决定）不整理空间的Full GC之后，下一次进入Full GC前会先进行碎片整理（默认值为0，表示每次进入Full GC时都进行碎片整理）。

4.7 Garbage First收集器

Garbage First（简称G1）收集器是垃圾收集器技术发展历史上的里程碑式的成果，它开创了收集器面向局部收集的设计思路和基于Region的内存布局形式。早在JDK 7刚刚确立项目目标、Oracle公司制定的JDK 7 RoadMap里面，G1收集器就被视作JDK 7中HotSpot虚拟机的一项重要进化特征。从JDK6 Update 14开始就有Early Access版本的G1收集器供开发人员实验和试用，但由此开始G1收集器的“实验状态”（Experimental）持续了数年时间，直至JDK 7 Update 4，Oracle才认为它达到足够成熟的商用程度，移除了“Experimental”的标识；到了JDK 8 Update 40的时候，G1提供并发的类卸载的支持，补全了其计划功能的最后一块拼图。这个版本以后的G1收集器才被Oracle官方称为“全功能的垃圾收集器”（Fully-Featured Garbage Collector）。

G1是一款主要面向服务端应用的垃圾收集器。HotSpot开发团队最初赋予它的期望是（在比较长期的）未来可以替换掉JDK 5中发布的CMS收集器。现在这个期望目标已经实现过半了，JDK 9发布之日，G1宣告取代Parallel Scavenge加Parallel Old组合，成为服务端模式下的默认垃圾收集器，而CMS则沦落至被声明为不推荐使用（Deprecate）的收集器[。如果对JDK 9及以上版本的HotSpot虚拟机使用参数-XX:+UseConcMarkSweepGC来开启CMS收集器的话，用户会收到一个警告信息，提示CMS未来将会被废弃

OpenJDK 64-Bit Server VM warning: Option UseConcMarkSweepGC was deprecated in version 9.0 and will likely be removed in a future release.

在G1收集器出现之前的所有其他收集器，包括CMS在内，垃圾收集的目标范围要么是整个新生代（Minor GC），要么就是整个老年代（Major GC），再要么就是整个Java堆（Full GC）。而G1跳出了这个樊笼，它可以面向堆内存任何部分来组成回收集（Collection Set，一般简称CSet）进行回收，衡量标准不再是它属于哪个分代，而是哪块内存中存放的垃圾数量最多，回收收益最大，这就是G1收集器的Mixed GC模式。

4.7.1 基本介绍

G1开创的基于Region的堆内存布局是它能够实现这个目标的关键。虽然G1也仍是遵循分代收集理论设计的，但其堆内存的布局与其他收集器有非常明显的差异：G1不再坚持固定大小以及固定数量的分代区域划分，而是把连续的Java堆划分为多个大小相等的独立区域（Region），每一个Region都可以根据需要，扮演新生代的Eden空间、Survivor空间，或者老年代空间。收集器能够对扮演不同角色的Region采用不同的策略去处理，这样无论是新创建的对象还是已经存活了一段时间、熬过多次收集的旧对象都能获取很好的收集效果。

Region中还有一类特殊的Humongous区域，专门用来存储大对象。G1认为只要大小超过了一个Region容量一半的对象即可判定为大对象。每个Region的大小可以通过参数-XX：G1HeapRegionSize设定，取值范围为1MB～32MB，且应为2的N次幂。而对于那些超过了整个Region容量的超级大对象，将会被存放在N个连续的Humongous Region之中，G1的大多数行为都把Humongous Region作为老年代的一部分来进行看待

虽然G1仍然保留新生代和老年代的概念，但新生代和老年代不再是固定的了，它们都是一系列区域（不需要连续）的动态集合。G1收集器之所以能建立可预测的停顿时间模型，是因为它将Region作为单次回收的最小单元，即每次收集到的内存空间都是Region大小的整数倍，这样可以有计划地避免在整个Java堆中进行全区域的垃圾收集。更具体的处理思路是让G1收集器去跟踪各个Region里面的垃圾堆积的“价值”大小，价值即回收所获得的空间大小以及回收所需时间的经验值，然后在后台维护一个优先级列表，每次根据用户设定允许的收集停顿时间（使用参数-XX：MaxGCPauseMillis指定，默认值是200毫秒），优先处理回收价值收益最大的那些Region，这也就是“Garbage First”名字的由来。这种使用Region划分内存空间，以及具有优先级的区域回收方式，保证了G1收集器在有限的时间内获取尽可能高的收集效率

G1收集器的运作过程大致可划分为以下四个步骤：

初始标记（Initial Marking）：仅仅只是标记一下GC Roots能直接关联到的对象，并且修改TAMS指针的值，让下一阶段用户线程并发运行时，能正确地在可用的Region中分配新对象。这个阶段需要停顿线程，但耗时很短，而且是借用进行Minor GC的时候同步完成的，所以G1收集器在这个阶段实际并没有额外的停顿。
并发标记（Concurrent Marking）：从GC Root开始对堆中对象进行可达性分析，递归扫描整个堆里的对象图，找出要回收的对象，这阶段耗时较长，但可与用户程序并发执行。当对象图扫描完成以后，还要重新处理SATB记录下的在并发时有引用变动的对象。
最终标记（Final Marking）：对用户线程做另一个短暂的暂停，用于处理并发阶段结束后仍遗留下来的最后那少量的SATB记录。
筛选回收（Live Data Counting and Evacuation）：负责更新Region的统计数据，对各个Region的回收价值和成本进行排序，根据用户所期望的停顿时间来制定回收计划，可以自由选择任意多个Region构成回收集，然后把决定回收的那一部分Region的存活对象复制到空的Region中，再清理掉整个旧Region的全部空间。这里的操作涉及存活对象的移动，是必须暂停用户线程，由多条收集器线程并行完成的

G1收集器至少有（不限于）以下这些关键的细节问题需要妥善解决：

譬如，将Java堆分成多个独立Region后，Region里面存在的跨Region引用对象如何解决？解决的思路我们已经知道：使用记忆集避免全堆作为GC Roots扫描，但在G1收集器上记忆集的应用其实要复杂很多，它的每个Region都维护有自己的记忆集，这些记忆集会记录下别的Region指向自己的指针，并标记这些指针分别在哪些卡页的范围之内。G1的记忆集在存储结构的本质上是一种哈希表，Key是别的Region的起始地址，Value是一个集合，里面存储的元素是卡表的索引号。这种“双向”的卡表结构（卡表是“我指向谁”，这种结构还记录了“谁指向我”）比原来的卡表实现起来更复杂，同时由于Region数量比传统收集器的分代数量明显要多得多，因此G1收集器要比其他的传统垃圾收集器有着更高的内存占用负担。根据经验，G1至少要耗费大约相当于Java堆容量10%至20%的额外内存来维持收集器工作。

·譬如，在并发标记阶段如何保证收集线程与用户线程互不干扰地运行？这里首先要解决的是用户线程改变对象引用关系时，必须保证其不能打破原本的对象图结构，导致标记结果出现错误：CMS收集器采用增量更新算法实现，而G1收集器则是通过原始快照（SATB）算法来实现的。此外，垃圾收集对用户线程的影响还体现在回收过程中新创建对象的内存分配上，程序要继续运行就肯定会持续有新对象被创建，G1为每一个Region设计了两个名为TAMS（Top at Mark Start）的指针，把Region中的一部分空间划分出来用于并发回收过程中的新对象分配，并发回收时新分配的对象地址都必须要在这两个指针位置以上。G1收集器默认在这个地址以上的对象是被隐式标记过的，即默认它们是存活的，不纳入回收范围。与CMS中的“Concurrent Mode Failure”失败会导致Full GC类似，如果内存回收的速度赶不上内存分配的速度，G1收集器也要被迫冻结用户线程执行，导致Full GC而产生长时间“Stop The World”。

·譬如，怎样建立起可靠的停顿预测模型？用户通过-XX：MaxGCPauseMillis参数指定的停顿时间只意味着垃圾收集发生之前的期望值，但G1收集器要怎么做才能满足用户的期望呢？G1收集器的停顿预测模型是以衰减均值（Decaying Average）为理论基础来实现的，在垃圾收集过程中，G1收集器会记录每个Region的回收耗时、每个Region记忆集里的脏卡数量等各个可测量的步骤花费的成本，并分析得出平均值、标准偏差、置信度等统计信息。这里强调的“衰减平均值”是指它会比普通的平均值更容易受到新数据的影响，平均值代表整体平均状态，但衰减平均值更准确地代表“最近的”平均状态。换句话说，Region的统计状态越新越能决定其回收的价值。然后通过这些信息预测现在开始回收的话，由哪些Region组成回收集才可以在不超过期望停顿时间的约束下获得最高的收益。

从上述阶段的描述可以看出，G1收集器除了并发标记外，其余阶段也是要完全暂停用户线程的，换言之，它并非纯粹地追求低延迟，官方给它设定的目标是在延迟可控的情况下获得尽可能高的吞吐量，所以才能担当起“全功能收集器”的重任与期望

4.7.2 内存模型

G1回收器的内存模型如上

堆内存会被切分成很多个固定大小的区域（Region），每个区域是连续范围的虚拟内存。堆内存中一个区域（Region）的大小可以通过-XX：G1HeapRegionSize参数指定，大小区间最小为1M，最大为32M，总之是2的幂次方。

默认把堆内存按照2048份均分

每个Region被标记了E、S、O和H，这些区域在逻辑上被映射为Eden，Survivor和老年代。
存活的对象从一个区域转移（即复制或移动）到另一个区域。区域被设计为并行收集垃圾，可能会暂停所有应用线程。
如上图所示，区域可以分配到Eden，survivor和老年代。此外，还有第四种类型，被称为巨型区域（Humongous Region）。Humongous区域是为了那些存储超过50%标准region大小的对象而设计的，它用来专门存放巨型对象。如果一个H区装不下一个巨型对象，那么G1会寻找连续的H分区来存储。为了能找到连续的H区，有时候不得不启动Full GC。

五 G1回收器日志解析

public class TestAllocation {
    private static final int _1MB = 1024 * 1024;

    /**
     * VM参数：-verbose:gc -Xms20M -Xmx20M -Xmn10M -XX:+PrintGCDetails
     */
    public static void main(String[] args) {
        byte[] allocation1, allocation2, allocation3, allocation4;
        allocation1 = new byte[2 * _1MB];
        allocation2 = new byte[2 * _1MB];
        allocation3 = new byte[2 * _1MB];
        allocation4 = new byte[4 * _1MB]; // 出现一次Minor GC
    }
}

日志如下:

[0.006s][warning][gc] -XX:+PrintGCDetails is deprecated. Will use -Xlog:gc* instead.
[0.015s][info   ][gc,heap] Heap region size: 1M
[0.015s][info   ][gc     ] Using G1
[0.015s][info   ][gc,heap,coops] Heap address: 0x00000000fec00000, size: 20 MB, Compressed Oops mode: 32-bit
Connected to the target VM, address: '127.0.0.1:49204', transport: 'socket'
[0.217s][info   ][gc,start     ] GC(0) Pause Young (Concurrent Start) (G1 Humongous Allocation)
[0.217s][info   ][gc,task      ] GC(0) Using 2 workers of 6 for evacuation
[0.218s][info   ][gc,phases    ] GC(0)   Pre Evacuate Collection Set: 0.0ms
[0.218s][info   ][gc,phases    ] GC(0)   Evacuate Collection Set: 1.4ms
[0.218s][info   ][gc,phases    ] GC(0)   Post Evacuate Collection Set: 0.2ms
[0.218s][info   ][gc,phases    ] GC(0)   Other: 0.2ms
[0.218s][info   ][gc,heap      ] GC(0) Eden regions: 3->0(8)
[0.218s][info   ][gc,heap      ] GC(0) Survivor regions: 0->2(2)
[0.218s][info   ][gc,heap      ] GC(0) Old regions: 0->0
[0.218s][info   ][gc,heap      ] GC(0) Humongous regions: 9->9
[0.218s][info   ][gc,metaspace ] GC(0) Metaspace: 5507K->5507K(1056768K)
[0.218s][info   ][gc           ] GC(0) Pause Young (Concurrent Start) (G1 Humongous Allocation) 11M->10M(20M) 1.843ms
[0.219s][info   ][gc,cpu       ] GC(0) User=0.00s Sys=0.00s Real=0.00s
[0.219s][info   ][gc           ] GC(1) Concurrent Cycle
[0.219s][info   ][gc,marking   ] GC(1) Concurrent Clear Claimed Marks
[0.219s][info   ][gc,marking   ] GC(1) Concurrent Clear Claimed Marks 0.006ms
[0.219s][info   ][gc,marking   ] GC(1) Concurrent Scan Root Regions
[0.219s][info   ][gc,marking   ] GC(1) Concurrent Scan Root Regions 0.520ms
[0.219s][info   ][gc,marking   ] GC(1) Concurrent Mark (0.219s)
[0.219s][info   ][gc,marking   ] GC(1) Concurrent Mark From Roots
[0.219s][info   ][gc,task      ] GC(1) Using 2 workers of 2 for marking
[0.219s][info   ][gc,marking   ] GC(1) Concurrent Mark From Roots 0.034ms
[0.219s][info   ][gc,marking   ] GC(1) Concurrent Preclean
[0.219s][info   ][gc,marking   ] GC(1) Concurrent Preclean 0.028ms
[0.219s][info   ][gc,marking   ] GC(1) Concurrent Mark (0.219s, 0.219s) 0.077ms
[0.220s][info   ][gc,start     ] GC(1) Pause Remark
[0.221s][info   ][gc,stringtable] GC(1) Cleaned string and symbol table, strings: 3463 processed, 0 removed, symbols: 23878 processed, 0 removed
[0.221s][info   ][gc            ] GC(1) Pause Remark 15M->15M(20M) 0.708ms
[0.221s][info   ][gc,cpu        ] GC(1) User=0.00s Sys=0.00s Real=0.00s
[0.221s][info   ][gc,marking    ] GC(1) Concurrent Rebuild Remembered Sets
[0.221s][info   ][gc,marking    ] GC(1) Concurrent Rebuild Remembered Sets 0.032ms
[0.221s][info   ][gc,start      ] GC(1) Pause Cleanup
[0.221s][info   ][gc            ] GC(1) Pause Cleanup 15M->15M(20M) 0.025ms
[0.221s][info   ][gc,cpu        ] GC(1) User=0.00s Sys=0.00s Real=0.00s
[0.221s][info   ][gc,marking    ] GC(1) Concurrent Cleanup for Next Mark
[0.221s][info   ][gc,marking    ] GC(1) Concurrent Cleanup for Next Mark 0.029ms
[0.221s][info   ][gc            ] GC(1) Concurrent Cycle 2.440ms
[0.221s][info   ][gc,heap,exit  ] Heap
[0.221s][info   ][gc,heap,exit  ]  garbage-first heap   total 20480K, used 15392K [0x00000000fec00000, 0x0000000100000000)
[0.221s][info   ][gc,heap,exit  ]   region size 1024K, 3 young (3072K), 2 survivors (2048K)
[0.222s][info   ][gc,heap,exit  ]  Metaspace       used 5513K, capacity 5573K, committed 5632K, reserved 1056768K
[0.222s][info   ][gc,heap,exit  ]   class space    used 458K, capacity 472K, committed 512K, reserved 1048576K

5.1 Heap region size: 1M

在G1垃圾收集器的日志中，"[gc,heap] Heap region size: 1M" 表示堆区域的大小为1MB。G1垃圾收集器将堆划分为一系列的区域，每个区域的大小可以根据应用程序的需求进行配置。这个日志信息告诉我们，每个区域的大小为1MB。

G1垃圾收集器使用了一种称为"区域化"的内存管理方式，将堆分成多个大小相等的区域。这种方式可以帮助G1更好地管理内存，并提供更好的垃圾收集性能。区域的大小可以通过调整JVM参数来进行配置，以满足应用程序的需求。

了解堆区域的大小对于分析和优化垃圾收集器的行为和性能非常重要。通过调整区域的大小，可以调整垃圾收集器的吞吐量、延迟和内存利用率等方面的性能。同时，区域的大小也会影响到垃圾收集器的负载均衡和内存分配等方面的行为

5.2 [gc,heap,coops] Heap address: 0x00000000fec00000, size: 20 MB, Compressed Oops mode: 32-bit

在G1垃圾收集器的日志中，"[gc,heap,coops] Heap address: 0x00000000fec00000, size: 20 MB, Compressed Oops mode: 32-bit" 表示堆的地址为0x00000000fec00000，大小为20MB，并且使用了32位的压缩指针模式。

在Java虚拟机中，堆是用于存储对象实例的内存区域。这条日志信息告诉我们堆的起始地址是0x00000000fec00000，占用了20MB的内存空间。

压缩指针是一种技术，用于减小指针的内存占用。在32位的压缩指针模式下，指针的大小被压缩到32位，从而减少了指针占用的内存空间。这种模式在堆较小的情况下可以节省内存，并且可以提高内存访问的效率。

了解堆的地址、大小和压缩指针模式对于分析和优化内存的使用和性能非常重要。通过调整堆的大小和压缩指针模式，可以根据应用程序的需求来平衡内存的使用和性能

5.3 GC(0) Pause Young (Concurrent Start) (G1 Humongous Allocation)

这条日志表示G1垃圾收集器在执行Young GC（年轻代垃圾收集）时发生了一次暂停。暂停的目的是为了执行垃圾收集操作，清理年轻代中的垃圾对象。

在这个日志中，"(Concurrent Start)" 表示该次垃圾收集是与并发标记阶段同时进行的。G1垃圾收集器采用了分代收集和并发垃圾收集的策略，其中并发标记阶段会与应用程序的执行同时进行，以减少垃圾收集对应用程序的影响。

另外，"(G1 Humongous Allocation)" 表示在这次垃圾收集过程中，G1垃圾收集器还进行了一个巨型对象（Humongous Object）的分配操作。巨型对象是指超过了一定大小阈值的对象，G1垃圾收集器会对其进行特殊处理。

这条日志提供了关于垃圾收集器执行的一些关键信息，包括垃圾收集的类型（Young GC），并发标记的启动，以及巨型对象的分配。这些信息对于分析和优化垃圾收集器的行为和性能非常有帮助。

5.4 GC(0) Using 2 workers of 6 for evacuation

这条日志表示在进行垃圾回收时，G1垃圾收集器使用了6个工作线程，并且在执行疏散（evacuation）操作时，只使用了其中的2个工作线程。

在进行垃圾回收时，G1垃圾收集器会将堆分成多个区域，并且会对这些区域进行独立的垃圾回收操作。在执行疏散操作时，G1垃圾收集器会将存活对象从一个区域复制到另一个区域。为了提高疏散操作的效率，G1垃圾收集器会使用多个工作线程来并行执行疏散操作。

这条日志告诉我们，在这次垃圾回收中，G1垃圾收集器使用了6个工作线程，但只有2个工作线程被用于执行疏散操作。这可能是由于当前系统负载较低，G1垃圾收集器认为使用更多的工作线程并不能提高垃圾回收的效率，因此只使用了部分工作线程来执行疏散操作。

了解G1垃圾收集器使用的工作线程数量和疏散操作的并行度对于分析和优化垃圾回收的性能非常重要。通过调整工作线程数量和并行度，可以根据应用程序的需求来平衡垃圾回收的效率和系统负载。

5.5 [gc,phases ] GC(0) Pre Evacuate Collection Set: 0.0ms

这条日志表示在进行垃圾回收之前，G1垃圾收集器执行了一个名为"Pre Evacuate Collection Set"的阶段，耗时为0.0毫秒。

在G1垃圾收集器的垃圾回收过程中，有多个阶段，这些阶段按照顺序依次执行，以完成整个垃圾回收的过程。其中，"Pre Evacuate Collection Set"阶段是在进行疏散（evacuation）操作之前的一个准备阶段。

在这个阶段，G1垃圾收集器会根据一些策略和算法，选择出一组即将被疏散的对象（Collection Set），并进行一些准备工作，以便后续的疏散操作能够高效地执行。

这条日志告诉我们，在当前的垃圾回收中，"Pre Evacuate Collection Set"阶段的执行时间非常短，仅为0.0毫秒。这可能是由于当前堆中的对象分布情况较好，没有太多需要被疏散的对象，或者是由于当前系统的负载较低，G1垃圾收集器认为不需要进行太多的准备工作。

了解G1垃圾收集器的各个阶段的执行时间对于分析和优化垃圾回收的性能非常重要。通过观察各个阶段的执行时间，可以发现垃圾回收过程中的瓶颈，并进行相应的优化。

5.6 [gc,phases ] GC(0) Evacuate Collection Set: 1.4ms

这条日志表示在进行垃圾回收之前，G1垃圾收集器执行了一个名为"Evacuate Collection Set"的阶段，耗时为1.4毫秒。

在G1垃圾收集器的垃圾回收过程中，有多个阶段，这些阶段按照顺序依次执行，以完成整个垃圾回收的过程。其中，"Evacuate Collection Set"阶段是进行疏散（evacuation）操作的主要阶段。

在这个阶段，G1垃圾收集器会将选定的对象从一个区域复制到另一个区域，以回收垃圾并整理内存。这个阶段的耗时取决于需要疏散的对象数量和复制的数据量。

这条日志告诉我们，在当前的垃圾回收中，"Evacuate Collection Set"阶段的执行时间为1.4毫秒。这个时间较短，说明疏散操作执行得相对快速。这可能是由于当前堆中的对象分布情况较好，没有太多需要被疏散的对象，或者是由于当前系统的负载较低，G1垃圾收集器能够高效地执行疏散操作。

5.7 [gc,phases ] GC(0) Post Evacuate Collection Set: 0.2ms

这条日志表示在进行垃圾回收之后，G1垃圾收集器执行了一个名为"Post Evacuate Collection Set"的阶段，耗时为0.2毫秒。

在G1垃圾收集器的垃圾回收过程中，有多个阶段，这些阶段按照顺序依次执行，以完成整个垃圾回收的过程。其中，"Post Evacuate Collection Set"阶段是在进行疏散（evacuation）操作之后的一个处理阶段。

在这个阶段，G1垃圾收集器会对疏散后的对象进行一些后续处理，例如更新引用、清理空间等。这个阶段的耗时取决于需要处理的对象数量和处理的操作复杂度。

这条日志告诉我们，在当前的垃圾回收中，"Post Evacuate Collection Set"阶段的执行时间为0.2毫秒。这个时间较短，说明后续处理操作执行得相对快速。这可能是由于当前堆中的对象分布情况较好，没有太多需要处理的对象，或者是由于当前系统的负载较低，G1垃圾收集器能够高效地执行后续处理操作。

了解G1垃圾收集器的垃圾回收过程和各个阶段的执行时间对于分析和优化垃圾回收的性能非常重要。通过观察各个阶段的执行时间，可以发现垃圾回收过程中的瓶颈，并进行相应的优化。

5.8 [gc,phases ] GC(0) Other: 0.2ms

这条日志表示在进行垃圾回收之后，G1垃圾收集器执行了一个名为"Other"的阶段，耗时为0.2毫秒。

在G1垃圾收集器的垃圾回收过程中，有多个阶段，这些阶段按照顺序依次执行，以完成整个垃圾回收的过程。其中，"Other"阶段是一个通用的阶段，用于记录一些不属于其他特定阶段的操作。

这个阶段的耗时可能包括一些额外的操作，例如处理引用、更新内部数据结构等。具体的操作和耗时取决于当前的垃圾回收情况和系统负载。

这条日志告诉我们，在当前的垃圾回收中，"Other"阶段的执行时间为0.2毫秒。这个时间较短，说明这个阶段执行得相对快速。这可能是由于当前的垃圾回收情况较好，没有太多需要处理的操作，或者是由于当前系统的负载较低，G1垃圾收集器能够高效地执行这些额外的操作。

5.9 [gc,heap ] GC(0) Eden regions: 3->0(8)

这条日志表示在进行垃圾回收之前，Eden区域的个数从3个减少到0个，占用的内存大小从8个区域减少到0个区域。

在G1垃圾收集器中，堆内存被划分为多个区域，其中包括Eden区域、存活对象区域和老年代区域等。Eden区域是用于分配新对象的区域，当Eden区域满时，会触发垃圾回收操作。

这条日志告诉我们，在进行垃圾回收之前，Eden区域的个数从3个减少到0个。这意味着在垃圾回收之前，Eden区域中的所有对象都被清理或转移到了其他区域。同时，占用的内存大小也从8个区域减少到0个区域，说明之前分配在Eden区域中的对象已经被回收或移动。

这种情况通常发生在进行Full GC（全局垃圾回收）操作之前，或者是在进行Young GC（年轻代垃圾回收）操作时，Eden区域中的对象被完全清理。

了解堆内存中各个区域的使用情况对于分析和优化垃圾回收的性能非常重要。通过观察各个区域的变化，可以了解对象的分配和回收情况，从而优化内存的使用和垃圾回收的效率。

5.10 [gc,heap ] GC(0) Survivor regions: 0->2(2)

这条日志表示在进行垃圾回收之前，Survivor区域的个数从0个增加到2个，占用的内存大小从0个区域增加到2个区域。

在G1垃圾收集器中，堆内存被划分为多个区域，其中包括Eden区域、Survivor区域和老年代区域等。Survivor区域用于存放从Eden区域中幸存的对象，以便在下一次垃圾回收时进行处理。

这条日志告诉我们，在进行垃圾回收之前，Survivor区域的个数从0个增加到2个。这意味着在垃圾回收之前，有一些对象从Eden区域幸存下来，并被移动到了Survivor区域。同时，占用的内存大小也从0个区域增加到2个区域，说明Survivor区域中的对象占用了一定的内存空间。

这种情况通常发生在进行Young GC（年轻代垃圾回收）操作时，部分对象从Eden区域幸存下来，并被移动到Survivor区域。Survivor区域的个数和内存大小的变化反映了垃圾回收过程中对象的分配和回收情况。

5.11 [gc,heap ] GC(0) Old regions: 0->0

0个区域。

在G1垃圾收集器中，堆内存被划分为多个区域，其中包括Eden区域、存活对象区域和老年代区域等。老年代区域是用于存放存活时间较长的对象的区域。

这条日志告诉我们，在进行垃圾回收之前，老年代区域的个数从0个保持不变。这意味着在垃圾回收之前，老年代区域中没有存活的对象。

这种情况通常发生在进行Young GC（年轻代垃圾回收）操作时，老年代区域中的对象已经被完全清理或移动到其他区域。

5.12 [gc,heap ] GC(0) Humongous regions: 9->9

这条日志表示在进行垃圾回收之前，Humongous区域的个数从9个保持不变。

在G1垃圾收集器中，Humongous区域是用于存放大对象的区域。大对象通常是指占用较大内存空间的对象，例如大数组或大型数据结构。

这条日志告诉我们，在进行垃圾回收之前，Humongous区域的个数从9个保持不变。这意味着在垃圾回收之前，Humongous区域中没有发生对象的分配或回收。

Humongous区域的个数和使用情况对于分析和优化垃圾回收的性能非常重要。如果Humongous区域的个数过多或占用的内存过大，可能会导致垃圾回收的效率下降。因此，需要根据实际情况来调整垃圾回收器的参数，以优化Humongous区域的使用。

5.13 [gc,metaspace ] GC(0) Metaspace: 5507K->5507K(1056768K)

这条日志表示在进行垃圾回收之前，Metaspace（元空间）的使用情况保持不变。

Metaspace是Java虚拟机中用于存储类元数据的区域。类元数据包括类的结构信息、方法信息、字段信息等。随着应用程序的运行，会不断加载和卸载类，因此Metaspace的使用情况会随着时间的推移而发生变化。

在这条日志中，5507K表示在进行垃圾回收之前，Metaspace使用了5507K的内存空间。后面的"->"表示回收之后的使用情况，而括号中的1056768K表示Metaspace的总容量。

通过观察Metaspace的使用情况，可以判断应用程序的类加载和卸载情况，以及是否需要调整Metaspace的大小来满足应用程序的需求。

5.14 [gc ] GC(0) Pause Young (Concurrent Start) (G1 Humongous Allocation) 11M->10M(20M) 1.843ms

这条日志表示进行了一次年轻代垃圾回收（Young GC），在回收前后，堆内存中的对象从11M减少到10M，总共的堆内存大小为20M。垃圾回收的暂停时间为1.843毫秒。

这是一次较小规模的垃圾回收，回收的对象数量相对较少。年轻代垃圾回收主要针对年轻代区域进行，年轻代区域是用于存放新创建的对象的区域。在回收过程中，不会涉及到老年代区域。

通过观察垃圾回收的频率、回收前后的对象数量变化以及回收的暂停时间，可以了解应用程序的内存使用情况和垃圾回收的效率。如果垃圾回收频率过高或暂停时间过长，可能需要调整堆内存的大小或调优垃圾回收器的参数，以提高应用程序的性能。

5.15 [gc,cpu ] GC(0) User=0.00s Sys=0.00s Real=0.00s

这条日志表示进行垃圾回收的用户时间、系统时间和实际时间都为0秒。

用户时间（User）是指垃圾回收过程中CPU执行用户代码的时间。系统时间（Sys）是指垃圾回收过程中CPU执行系统代码的时间。实际时间（Real）是指垃圾回收过程的实际耗时。

在这条日志中，所有的时间都为0秒，这意味着垃圾回收过程非常快速，几乎没有占用CPU资源或造成明显的延迟。

垃圾回收的耗时是衡量垃圾回收效率的重要指标之一。如果垃圾回收的耗时过长，可能会导致应用程序的性能下降。因此，需要根据实际情况来调整垃圾回收器的参数，以减少垃圾回收的耗时。

5.16 [gc ] GC(1) Concurrent Cycle

这条日志表示进行了一次并发垃圾回收（Concurrent Cycle），具体的回收信息没有在日志中给出。

并发垃圾回收是一种与应用程序并发执行的垃圾回收方式，它能够在应用程序运行的同时进行垃圾回收，减少了对应用程序的暂停时间。与传统的停顿式垃圾回收相比，并发垃圾回收能够提供更好的应用程序响应性能。

在并发垃圾回收过程中，垃圾收集器会在不同的阶段执行不同的任务，包括标记、清理、重置等。具体的回收信息可能会在其他的日志中给出，可以查看其他相关的日志来了解更多关于并发垃圾回收的详细信息。

5.17 [gc,marking ] GC(1) Concurrent Clear Claimed Marks

这条日志表示进行了一次并发标记（Concurrent Marking），具体的标记信息没有在日志中给出。

并发标记是垃圾回收过程中的一个阶段，用于标记所有存活的对象。在并发标记的过程中，垃圾收集器会遍历堆中的对象，标记出所有被引用的对象，以便后续的清理操作。

并发标记的过程是与应用程序并发执行的，可以减少对应用程序的暂停时间。在标记过程中，垃圾收集器会通过一些算法和数据结构来记录和管理对象的标记状态，以确保所有存活的对象都能被正确标记。

具体的标记信息可能会在其他的日志中给出，可以查看其他相关的日志来了解更多关于并发标记的详细信息。

5.18 [gc,marking 等

根据提供的日志信息，可以看到以下并发标记（Concurrent Marking）的过程：

[gc,marking] GC(1) Concurrent Clear Claimed Marks 0.006ms：清除已标记的对象。
[gc,marking] GC(1) Concurrent Scan Root Regions 0.520ms：扫描根区域，标记根对象。
[gc,marking] GC(1) Concurrent Mark (0.219s)：并发标记阶段开始。
[gc,marking] GC(1) Concurrent Mark From Roots 0.034ms：从根对象开始标记可达对象。
[gc,task] GC(1) Using 2 workers of 2 for marking：使用2个工作线程进行标记。
[gc,marking] GC(1) Concurrent Preclean 0.028ms：并发预清理阶段，清理未标记的对象。
[gc,marking] GC(1) Concurrent Mark (0.219s, 0.219s) 0.077ms：并发标记阶段结束。
[gc,start] GC(1) Pause Remark：开始暂停标记阶段。
[gc,stringtable] GC(1) Cleaned string and symbol table：清理字符串和符号表。
[gc] GC(1) Pause Remark 15M->15M(20M) 0.708ms：标记阶段暂停的时间和内存使用情况。
[gc,cpu] GC(1) User=0.00s Sys=0.00s Real=0.00s：标记阶段的CPU使用情况。
[gc,marking] GC(1) Concurrent Rebuild Remembered Sets：重建已记住的集合。
[gc,marking] GC(1) Concurrent Rebuild Remembered Sets 0.032ms：重建已记住的集合的耗时。
[gc,start] GC(1) Pause Cleanup：开始暂停清理阶段。
[gc] GC(1) Pause Cleanup 15M->15M(20M) 0.025ms：清理阶段暂停的时间和内存使用情况。
[gc,cpu] GC(1) User=0.00s Sys=0.00s Real=0.00s：清理阶段的CPU使用情况。
[gc,marking] GC(1) Concurrent Cleanup for Next Mark：为下一次标记进行并发清理。
[gc,marking] GC(1) Concurrent Cleanup for Next Mark 0.029ms：并发清理的耗时。
[gc] GC(1) Concurrent Cycle 2.440ms：并发循环的总耗时。

这些日志提供了并发标记过程中的一些关键步骤和耗时信息。具体的标记操作和对象信息可能在其他的日志中给出。

并发标记是垃圾回收的一部分，用于标记所有存活的对象。通过并发执行，它可以减少对应用程序的暂停时间，提高系统的响应性能。

5.19 gc,heap,exit

根据提供的日志信息，可以看到以下堆（Heap）相关的信息：

[gc,heap,exit] Heap：堆的信息。
[gc,heap,exit] garbage-first heap total 20480K, used 15392K [0x00000000fec00000, 0x0000000100000000)：垃圾优先堆的总大小为20480K，已使用的大小为15392K，堆的起始地址为0x00000000fec00000，结束地址为0x0000000100000000。
[gc,heap,exit] region size 1024K, 3 young (3072K), 2 survivors (2048K)：堆的区域大小为1024K，有3个年轻代区域（总大小为3072K），有2个幸存者区域（总大小为2048K）。
[gc,heap,exit] Metaspace used 5513K, capacity 5573K, committed 5632K, reserved 1056768K：元空间（Metaspace）的使用情况，已使用的大小为5513K，容量为5573K，已分配的大小为5632K，保留的大小为1056768K。
[gc,heap,exit] class space used 458K, capacity 472K, committed 512K, reserved 1048576K：类空间（class space）的使用情况，已使用的大小为458K，容量为472K，已分配的大小为512K，保留的大小为1048576K。

这些信息提供了堆和元空间的使用情况，包括总大小、已使用大小、已分配大小等。这些信息可以用于分析应用程序的内存使用情况和性能优化。

一 内存回收与分配策略