关于GC之四-垃圾收集器实战
2019-01-29 本文已影响2人
AlanKim
JVM 垃圾回收器分类
新生代串行收集器
串行收集器主要有两个特点：第一，它仅仅使用单线程进行垃圾回收；第二，它独占式的垃圾回收。
在串行收集器进行垃圾回收时，Java 应用程序中的线程都需要暂停，等待垃圾回收的完成，这样给用户体验造成较差效果。虽然如此，串行收集器却是一个成熟、经过长时间生产环境考验的极为高效的收集器。新生代串行处理器使用复制算法，实现相对简单，逻辑处理特别高效，且没有线程切换的开销。在诸如单 CPU 处理器或者较小的应用内存等硬件平台不是特别优越的场合，它的性能表现可以超过并行回收器和并发回收器。在 HotSpot 虚拟机中，使用-XX：+UseSerialGC 参数可以指定使用新生代串行收集器和老年代串行收集器。当 JVM 在 Client 模式下运行时，它是默认的垃圾收集器。一次新生代串行收集器的工作输出日志类似如清单 1 信息 (使用-XX:+PrintGCDetails 开关) 所示。
清单 1. 一次新生代串行收集器的工作输出日志
[GC [DefNew: 3468K->150K(9216K), 0.0028638 secs][Tenured:
1562K->1712K(10240K), 0.0084220 secs] 3468K->1712K(19456K),
[Perm : 377K->377K(12288K)],
0.0113816 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
它显示了一次垃圾回收前的新生代的内存占用量和垃圾回收后的新生代内存占用量，以及垃圾回收所消耗的时间。
老年代串行收集器
老年代串行收集器使用的是标记-压缩算法。和新生代串行收集器一样，它也是一个串行的、独占式的垃圾回收器。由于老年代垃圾回收通常会使用比新生代垃圾回收更长的时间，因此，在堆空间较大的应用程序中，一旦老年代串行收集器启动，应用程序很可能会因此停顿几秒甚至更长时间。虽然如此，老年代串行回收器可以和多种新生代回收器配合使用，同时它也可以作为 CMS 回收器的备用回收器。若要启用老年代串行回收器，可以尝试使用以下参数：-XX:+UseSerialGC: 新生代、老年代都使用串行回收器。
清单 2. 一次老年代串行收集器的工作输出日志
Heap
def new generation total 4928K, used 1373K [0x27010000, 0x27560000, 0x2c560000)
eden space 4416K, 31% used [0x27010000, 0x27167628, 0x27460000)
from space 512K, 0% used [0x27460000, 0x27460000, 0x274e0000)
to space 512K, 0% used [0x274e0000, 0x274e0000, 0x27560000)
tenured generation total 10944K, used 0K [0x2c560000, 0x2d010000, 0x37010000)
the space 10944K, 0% used [0x2c560000, 0x2c560000, 0x2c560200, 0x2d010000)
compacting perm gen total 12288K, used 376K [0x37010000, 0x37c10000, 0x3b010000)
the space 12288K, 3% used [0x37010000, 0x3706e0b8, 0x3706e200, 0x37c10000)
ro space 10240K, 51% used [0x3b010000, 0x3b543000, 0x3b543000, 0x3ba10000)
rw space 12288K, 55% used [0x3ba10000, 0x3c0ae4f8, 0x3c0ae600, 0x3c610000)
如果使用-XX:+UseParNewGC 参数设置，表示新生代使用并行收集器，老年代使用串行收集器，如清单 3 所示。
清单 3. 一次串并行收集器混合使用的工作输出日志
Heap
par new generation total 4928K, used 1373K [0x0f010000, 0x0f560000, 0x14560000)
eden space 4416K, 31% used [0x0f010000, 0x0f167620, 0x0f460000)
from space 512K, 0% used [0x0f460000, 0x0f460000, 0x0f4e0000)
to space 512K, 0% used [0x0f4e0000, 0x0f4e0000, 0x0f560000)
tenured generation total 10944K, used 0K [0x14560000, 0x15010000, 0x1f010000)
the space 10944K, 0% used [0x14560000, 0x14560000, 0x14560200, 0x15010000)
compacting perm gen total 12288K, used 2056K [0x1f010000, 0x1fc10000, 0x23010000)
the space 12288K, 16% used [0x1f010000, 0x1f2121d0, 0x1f212200, 0x1fc10000)
No shared spaces configured.
如果使用-XX:+UseParallelGC 参数设置，表示新生代和老年代均使用并行回收收集器。如清单 4 所示。
清单 4. 一次老年代并行回收器的工作输出日志
[Full GC [Tenured: 1712K->1699K(10240K), 0.0071963 secs] 1712K->1699K(19456K),
[Perm : 377K->372K(12288K)], 0.0072393 secs] [Times: user=0.00 sys=0.00,
real=0.01 secs]
它显示了垃圾回收前老年代和永久区的内存占用量，以及垃圾回收后老年代和永久区的内存使用量。
并行收集器
并行收集器是工作在新生代的垃圾收集器，它只简单地将串行回收器多线程化。它的回收策略、算法以及参数和串行回收器一样。
并行回收器也是独占式的回收器，在收集过程中，应用程序会全部暂停。但由于并行回收器使用多线程进行垃圾回收，因此，在并发能力比较强的 CPU 上，它产生的停顿时间要短于串行回收器，而在单 CPU 或者并发能力较弱的系统中，并行回收器的效果不会比串行回收器好，由于多线程的压力，它的实际表现很可能比串行回收器差。
开启并行回收器可以使用参数-XX:+UseParNewGC，该参数设置新生代使用并行收集器，老年代使用串行收集器。
清单 5. 设置参数-XX:+UseParNewGC 的输出日志
[GC [ParNew: 825K->161K(4928K), 0.0155258 secs][Tenured: 8704K->661K(10944K),
0.0071964 secs] 9017K->661K(15872K),
[Perm : 2049K->2049K(12288K)], 0.0228090 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
Heap
par new generation total 4992K, used 179K [0x0f010000, 0x0f570000, 0x14560000)
eden space 4480K, 4% used [0x0f010000, 0x0f03cda8, 0x0f470000)
from space 512K, 0% used [0x0f470000, 0x0f470000, 0x0f4f0000)
to space 512K, 0% used [0x0f4f0000, 0x0f4f0000, 0x0f570000)
tenured generation total 10944K, used 8853K [0x14560000, 0x15010000, 0x1f010000)
the space 10944K, 80% used [0x14560000, 0x14e057c0, 0x14e05800, 0x15010000)
compacting perm gen total 12288K, used 2060K [0x1f010000, 0x1fc10000, 0x23010000)
the space 12288K, 16% used [0x1f010000, 0x1f213228, 0x1f213400, 0x1fc10000)
No shared spaces configured.
设置参数-XX:+UseConcMarkSweepGC 可以要求新生代使用并行收集器，老年代使用 CMS。
清单 6. 设置参数-XX:+UseConcMarkSweepGC 的输出日志
[GC [ParNew: 8967K->669K(14784K), 0.0040895 secs] 8967K->669K(63936K),
0.0043255 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
Heap
par new generation total 14784K, used 9389K [0x03f50000, 0x04f50000, 0x04f50000)
eden space 13184K, 66% used [0x03f50000, 0x047d3e58, 0x04c30000)
from space 1600K, 41% used [0x04dc0000, 0x04e67738, 0x04f50000)
to space 1600K, 0% used [0x04c30000, 0x04c30000, 0x04dc0000)
concurrent mark-sweep generation total 49152K, used 0K [0x04f50000, 0x07f50000, 0x09f50000)
concurrent-mark-sweep perm gen total 12288K, used 2060K [0x09f50000, 0x0ab50000, 0x0df50000)
并行收集器工作时的线程数量可以使用-XX:ParallelGCThreads 参数指定。一般，最好与 CPU 数量相当，避免过多的线程数影响垃圾收集性能。在默认情况下，当 CPU 数量小于 8 个，ParallelGCThreads 的值等于 CPU 数量，大于 8 个，ParallelGCThreads 的值等于 3+[5*CPU_Count]/8]。以下测试显示了笔者笔记本上运行 8 个线程时耗时最短，本人笔记本是 8 核 IntelCPU。
清单 7. 设置为 8 个线程后 GC 输出
[GC [ParNew: 8967K->676K(14784K), 0.0036983 secs] 8967K->676K(63936K),
0.0037662 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
Heap
par new generation total 14784K, used 9395K [0x040e0000, 0x050e0000, 0x050e0000)
eden space 13184K, 66% used [0x040e0000, 0x04963e58, 0x04dc0000)
from space 1600K, 42% used [0x04f50000, 0x04ff9100, 0x050e0000)
to space 1600K, 0% used [0x04dc0000, 0x04dc0000, 0x04f50000)
concurrent mark-sweep generation total 49152K, used 0K [0x050e0000, 0x080e0000, 0x0a0e0000)
concurrent-mark-sweep perm gen total 12288K, used 2060K [0x0a0e0000, 0x0ace0000, 0x0e0e0000)
清单 8. 设置为 128 个线程后 GC 输出
[GC [ParNew: 8967K->664K(14784K), 0.0207327 secs] 8967K->664K(63936K),
0.0208077 secs] [Times: user=0.03 sys=0.00, real=0.02 secs]
清单 9. 设置为 640 个线程后 GC 输出
[GC [ParNew: 8967K->667K(14784K), 0.2323704 secs] 8967K->667K(63936K),
0.2324778 secs] [Times: user=0.34 sys=0.02, real=0.23 secs]
清单 10. 设置为 1280 个线程后 GC 输出
Error occurred during initialization of VM`
Too small new size specified`
新生代并行回收 (Parallel Scavenge) 收集器
新生代并行回收收集器也是使用复制算法的收集器。从表面上看，它和并行收集器一样都是多线程、独占式的收集器。但是，并行回收收集器有一个重要的特点：它非常关注系统的吞吐量。
新生代并行回收收集器可以使用以下参数启用：
-XX:+UseParallelGC:新生代使用并行回收收集器，老年代使用串行收集器。
-XX:+UseParallelOldGC:新生代和老年代都是用并行回收收集器。
清单 11. 设置为 24 个线程后 GC 输出
Heap
PSYoungGen total 4800K, used 893K [0x1dac0000, 0x1e010000, 0x23010000)
eden space 4160K, 21% used [0x1dac0000,0x1db9f570,0x1ded0000)
from space 640K, 0% used [0x1df70000,0x1df70000,0x1e010000)
to space 640K, 0% used [0x1ded0000,0x1ded0000,0x1df70000)
ParOldGen total 19200K, used 16384K [0x13010000, 0x142d0000, 0x1dac0000)
object space 19200K, 85% used [0x13010000,0x14010020,0x142d0000)
PSPermGen total 12288K, used 2054K [0x0f010000, 0x0fc10000, 0x13010000)
object space 12288K, 16% used [0x0f010000,0x0f2119c0,0x0fc10000)
新生代并行回收收集器可以使用以下参数启用：
-XX:+MaxGCPauseMills:设置最大垃圾收集停顿时间，它的值是一个大于 0 的整数。收集器在工作时会调整 Java 堆大小或者其他一些参数，尽可能地把停顿时间控制在 MaxGCPauseMills 以内。如果希望减少停顿时间，而把这个值设置得很小，为了达到预期的停顿时间，JVM 可能会使用一个较小的堆 (一个小堆比一个大堆回收快)，而这将导致垃圾回收变得很频繁，从而增加了垃圾回收总时间，降低了吞吐量。
-XX:+GCTimeRatio：设置吞吐量大小，它的值是一个 0-100 之间的整数。假设 GCTimeRatio 的值为 n，那么系统将花费不超过 1/(1+n) 的时间用于垃圾收集。比如 GCTimeRatio 等于 19，则系统用于垃圾收集的时间不超过 1/(1+19)=5%。默认情况下，它的取值是 99，即不超过 1%的时间用于垃圾收集。
除此之外，并行回收收集器与并行收集器另一个不同之处在于，它支持一种自适应的 GC 调节策略，使用-XX:+UseAdaptiveSizePolicy 可以打开自适应 GC 策略。在这种模式下，新生代的大小、eden 和 survivor 的比例、晋升老年代的对象年龄等参数会被自动调整，以达到在堆大小、吞吐量和停顿时间之间的平衡点。在手工调优比较困难的场合，可以直接使用这种自适应的方式，仅指定虚拟机的最大堆、目标的吞吐量 (GCTimeRatio) 和停顿时间 (MaxGCPauseMills)，让虚拟机自己完成调优工作。
清单 12. 新生代并行回收收集器 GC 输出
Heap
PSYoungGen total 4800K, used 893K [0x1dac0000, 0x1e010000, 0x23010000)
eden space 4160K, 21% used [0x1dac0000,0x1db9f570,0x1ded0000)
from space 640K, 0% used [0x1df70000,0x1df70000,0x1e010000)
to space 640K, 0% used [0x1ded0000,0x1ded0000,0x1df70000)
PSOldGen total 19200K, used 16384K [0x13010000, 0x142d0000, 0x1dac0000)
object space 19200K, 85% used [0x13010000,0x14010020,0x142d0000)
PSPermGen total 12288K, used 2054K [0x0f010000, 0x0fc10000, 0x13010000)
object space 12288K, 16% used [0x0f010000,0x0f2119c0,0x0fc10000)
它也显示了收集器的工作成果，也就是回收前的内存大小和回收后的内存大小，以及花费的时间。
老年代并行回收收集器
老年代的并行回收收集器也是一种多线程并发的收集器。和新生代并行回收收集器一样，它也是一种关注吞吐量的收集器。老年代并行回收收集器使用标记-压缩算法，JDK1.6 之后开始启用。
使用-XX:+UseParallelOldGC 可以在新生代和老生代都使用并行回收收集器，这是一对非常关注吞吐量的垃圾收集器组合，在对吞吐量敏感的系统中，可以考虑使用。参数-XX:ParallelGCThreads 也可以用于设置垃圾回收时的线程数量。
清单 13 是设置线程数量为 100 时老年代并行回收收集器输出日志：
清单 13. 老年代并行回收收集器设置 100 线程时 GC 输出
Heap
PSYoungGen total 4800K, used 893K [0x1dac0000, 0x1e010000, 0x23010000)
eden space 4160K, 21% used [0x1dac0000,0x1db9f570,0x1ded0000)
from space 640K, 0% used [0x1df70000,0x1df70000,0x1e010000)
to space 640K, 0% used [0x1ded0000,0x1ded0000,0x1df70000)
ParOldGen total 19200K, used 16384K [0x13010000, 0x142d0000, 0x1dac0000)
object space 19200K, 85% used [0x13010000,0x14010020,0x142d0000)
PSPermGen total 12288K, used 2054K [0x0f010000, 0x0fc10000, 0x13010000)
object space 12288K, 16% used [0x0f010000,0x0f2119c0,0x0fc10000)
CMS 收集器
与并行回收收集器不同，CMS 收集器主要关注于系统停顿时间。CMS 是 Concurrent Mark Sweep 的缩写，意为并发标记清除，从名称上可以得知，它使用的是标记-清除算法，同时它又是一个使用多线程并发回收的垃圾收集器。
CMS 工作时，主要步骤有：初始标记、并发标记、重新标记、并发清除和并发重置。其中初始标记和重新标记是独占系统资源的，而并发标记、并发清除和并发重置是可以和用户线程一起执行的。因此，从整体上来说，CMS 收集不是独占式的，它可以在应用程序运行过程中进行垃圾回收。
根据标记-清除算法，初始标记、并发标记和重新标记都是为了标记出需要回收的对象。并发清理则是在标记完成后，正式回收垃圾对象；并发重置是指在垃圾回收完成后，重新初始化 CMS 数据结构和数据，为下一次垃圾回收做好准备。并发标记、并发清理和并发重置都是可以和应用程序线程一起执行的。
CMS 收集器在其主要的工作阶段虽然没有暴力地彻底暂停应用程序线程，但是由于它和应用程序线程并发执行，相互抢占 CPU，所以在 CMS 执行期内对应用程序吞吐量造成一定影响。CMS 默认启动的线程数是 (ParallelGCThreads+3)/4),ParallelGCThreads 是新生代并行收集器的线程数，也可以通过-XX:ParallelCMSThreads 参数手工设定 CMS 的线程数量。当 CPU 资源比较紧张时，受到 CMS 收集器线程的影响，应用程序的性能在垃圾回收阶段可能会非常糟糕。
由于 CMS 收集器不是独占式的回收器，在 CMS 回收过程中，应用程序仍然在不停地工作。在应用程序工作过程中，又会不断地产生垃圾。这些新生成的垃圾在当前 CMS 回收过程中是无法清除的。同时，因为应用程序没有中断，所以在 CMS 回收过程中，还应该确保应用程序有足够的内存可用。因此，CMS 收集器不会等待堆内存饱和时才进行垃圾回收，而是当前堆内存使用率达到某一阈值时，便开始进行回收，以确保应用程序在 CMS 工作过程中依然有足够的空间支持应用程序运行。
这个回收阈值可以使用-XX:CMSInitiatingOccupancyFraction 来指定，默认是 68。即当老年代的空间使用率达到 68%时，会执行一次 CMS 回收。如果应用程序的内存使用率增长很快，在 CMS 的执行过程中，已经出现了内存不足的情况，此时，CMS 回收将会失败，JVM 将启动老年代串行收集器进行垃圾回收。如果这样，应用程序将完全中断，直到垃圾收集完成，这时，应用程序的停顿时间可能很长。因此，根据应用程序的特点，可以对-XX:CMSInitiatingOccupancyFraction 进行调优。如果内存增长缓慢，则可以设置一个稍大的值，大的阈值可以有效降低 CMS 的触发频率，减少老年代回收的次数可以较为明显地改善应用程序性能。反之，如果应用程序内存使用率增长很快，则应该降低这个阈值，以避免频繁触发老年代串行收集器。
标记-清除算法将会造成大量内存碎片，离散的可用空间无法分配较大的对象。在这种情况下，即使堆内存仍然有较大的剩余空间，也可能会被迫进行一次垃圾回收，以换取一块可用的连续内存，这种现象对系统性能是相当不利的，为了解决这个问题，CMS 收集器还提供了几个用于内存压缩整理的算法。
-XX:+UseCMSCompactAtFullCollection 参数可以使 CMS 在垃圾收集完成后，进行一次内存碎片整理。内存碎片的整理并不是并发进行的。-XX:CMSFullGCsBeforeCompaction 参数可以用于设定进行多少次 CMS 回收后，进行一次内存压缩。
-XX:CMSInitiatingOccupancyFraction 设置为 100，同时设置-XX:+UseCMSCompactAtFullCollection 和-XX:CMSFullGCsBeforeCompaction，日志输出如下：
清单 14.CMS 垃圾回收器 GC 输出
[GC [DefNew: 825K->149K(4928K), 0.0023384 secs][Tenured: 8704K->661K(10944K),
0.0587725 secs] 9017K->661K(15872K),
[Perm : 374K->374K(12288K)], 0.0612037 secs] [Times: user=0.01 sys=0.02, real=0.06 secs]
Heap
def new generation total 4992K, used 179K [0x27010000, 0x27570000, 0x2c560000)
eden space 4480K, 4% used [0x27010000, 0x2703cda8, 0x27470000)
from space 512K, 0% used [0x27470000, 0x27470000, 0x274f0000)
to space 512K, 0% used [0x274f0000, 0x274f0000, 0x27570000)
tenured generation total 10944K, used 8853K [0x2c560000, 0x2d010000, 0x37010000)
the space 10944K, 80% used [0x2c560000, 0x2ce057c8, 0x2ce05800, 0x2d010000)
compacting perm gen total 12288K, used 374K [0x37010000, 0x37c10000, 0x3b010000)
the space 12288K, 3% used [0x37010000, 0x3706db10, 0x3706dc00, 0x37c10000)
ro space 10240K, 51% used [0x3b010000, 0x3b543000, 0x3b543000, 0x3ba10000)
rw space 12288K, 55% used [0x3ba10000, 0x3c0ae4f8, 0x3c0ae600, 0x3c610000)
G1 收集器 (Garbage First)
G1 收集器的目标是作为一款服务器的垃圾收集器，因此，它在吞吐量和停顿控制上，预期要优于 CMS 收集器。
与 CMS 收集器相比，G1 收集器是基于标记-压缩算法的。因此，它不会产生空间碎片，也没有必要在收集完成后，进行一次独占式的碎片整理工作。G1 收集器还可以进行非常精确的停顿控制。它可以让开发人员指定当停顿时长为 M 时，垃圾回收时间不超过 N。使用参数-XX:+UnlockExperimentalVMOptions –XX:+UseG1GC 来启用 G1 回收器，设置 G1 回收器的目标停顿时间：-XX:MaxGCPauseMills=20,-XX:GCPauseIntervalMills=200。
收集器对系统性能的影响
通过清单 15 所示代码运行 1 万次循环，每次分配 512*100B 空间，采用不同的垃圾回收器，输出程序运行所消耗的时间。
清单 15. 性能测试代码
import java.util.HashMap;
import java.util.Map;
public class GCTimeTest {
static Map map = new HashMap();
public static void main(String[] args){
long beginTime = System.currentTimeMillis();
for (int i = 0; i < 100000; i++){
if(map.size() * 512 / 1024 / 1024 > 100 ){ // 需要计算map.size 不内存溢出
map.clear(); // 保护内存不溢出
System.out.println("clean map");
}
byte[] bytes;
for(int j = 0; j < 100; j++){
bytes = new byte[512];
map.put(System.nanoTime(),bytes);
}
}
long endTime = System.currentTimeMillis();
System.out.println("spendTime:" + (endTime - beginTime));
}
}
在指定128M的堆空间后，其分代数据如下：
Snip20180529_3.png
每次map.clear 之后，由于需要大量回收old区的空间，都需要进行一次full gc。下面使用不同的gc参数试验：
使用参数-Xmx128M -Xms128M -XX:+UseParNewGC -XX:+PrintGCDetails运行代码，输出如下：
Java HotSpot(TM) 64-Bit Server VM warning: Using the ParNew young collector with the Serial old collector is deprecated and will likely be removed in a future release
[GC (Allocation Failure) [ParNew: 34944K->4352K(39296K), 0.0447096 secs] 34944K->33418K(126720K), 0.0447417 secs] [Times: user=0.07 sys=0.03, real=0.04 secs]
[GC (Allocation Failure) [ParNew: 39296K->4352K(39296K), 0.0366802 secs] 68362K->68325K(126720K), 0.0367088 secs] [Times: user=0.07 sys=0.03, real=0.04 secs]
[GC (Allocation Failure) [ParNew: 39296K->39296K(39296K), 0.0000154 secs][Tenured: 63973K->87423K(87424K), 0.1034759 secs] 103269K->103257K(126720K), [Metaspace: 3310K->3310K(1056768K)], 0.1035723 secs] [Times: user=0.09 sys=0.01, real=0.11 secs]
clean map
[Full GC (Allocation Failure) [Tenured: 87423K->4769K(87424K), 0.0194451 secs] 126719K->4769K(126720K), [Metaspace: 3314K->3314K(1056768K)], 0.0194773 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]
.........多次gc & fullgc
[GC (Allocation Failure) [ParNew: 34944K->4350K(39296K), 0.0091677 secs] 43145K->43224K(126720K), 0.0091926 secs] [Times: user=0.04 sys=0.00, real=0.01 secs]
[GC (Allocation Failure) [ParNew: 39294K->4352K(39296K), 0.0112309 secs] 78168K->78249K(126720K), 0.0112541 secs] [Times: user=0.04 sys=0.00, real=0.01 secs]
[GC (Allocation Failure) [ParNew: 39296K->39296K(39296K), 0.0000211 secs][Tenured: 73897K->87423K(87424K), 0.0903542 secs] 113193K->113190K(126720K), [Metaspace: 3316K->3316K(1056768K)], 0.0904173 secs] [Times: user=0.09 sys=0.00, real=0.09 secs]
clean map
[Full GC (Allocation Failure) [Tenured: 87423K->8525K(87424K), 0.0231646 secs] 126719K->8525K(126720K), [Metaspace: 3316K->3316K(1056768K)], 0.0232335 secs] [Times: user=0.03 sys=0.00, real=0.03 secs]
spendTime:9499
Heap
par new generation total 39296K, used 34231K [0x00000007b8000000, 0x00000007baaa0000, 0x00000007baaa0000)
eden space 34944K, 97% used [0x00000007b8000000, 0x00000007ba16de98, 0x00000007ba220000)
from space 4352K, 0% used [0x00000007ba220000, 0x00000007ba220000, 0x00000007ba660000)
to space 4352K, 0% used [0x00000007ba660000, 0x00000007ba660000, 0x00000007baaa0000)
tenured generation total 87424K, used 8525K [0x00000007baaa0000, 0x00000007c0000000, 0x00000007c0000000)
the space 87424K, 9% used [0x00000007baaa0000, 0x00000007bb2f34f0, 0x00000007bb2f3600, 0x00000007c0000000)
Metaspace used 3322K, capacity 4500K, committed 4864K, reserved 1056768K
class space used 366K, capacity 388K, committed 512K, reserved 1048576K
可以看到
- serial old gc 已经不推荐使用。
- 共用了9499ms
- 前面两次gc，young代的对象都转移到了old代
- 第三次gc，young代的占用空间并没有见减小，old代的占用空间反而增大了，说明young代已经无法为新对象分配内存，而且由于存在跨代引用，young区原有对象无法被回收。此时整个old代的内存空间也已经占用了超过 68362/87424K = 80%
- 此时如果不执行map.clear，那么就会出现OOM的问题。而执行了map.clear，由于需要回收大量young&old代的内存，执行了一次fullgc。
使用参数-Xmx128M -Xms128M -XX:+UseParallelOldGC –XX:ParallelGCThreads=8 -XX:+PrintGCDetails运行代码，输出如下：
[GC (Allocation Failure) [PSYoungGen: 33280K->5104K(38400K)] 33280K->30576K(125952K), 0.0226151 secs] [Times: user=0.04 sys=0.02, real=0.02 secs]
[GC (Allocation Failure) [PSYoungGen: 38384K->5104K(38400K)] 63856K->63152K(125952K), 0.0259692 secs] [Times: user=0.06 sys=0.03, real=0.02 secs]
[Full GC (Ergonomics) [PSYoungGen: 5104K->0K(38400K)] [ParOldGen: 58048K->62865K(87552K)] 63152K->62865K(125952K), [Metaspace: 3310K->3310K(1056768K)], 0.0824536 secs] [Times: user=0.20 sys=0.00, real=0.08 secs]
[Full GC (Ergonomics) [PSYoungGen: 33280K->8186K(38400K)] [ParOldGen: 62865K->87271K(87552K)] 96145K->95458K(125952K), [Metaspace: 3310K->3310K(1056768K)], 0.0882627 secs] [Times: user=0.22 sys=0.03, real=0.09 secs]
clean map1659
[Full GC (Ergonomics) [PSYoungGen: 33280K->0K(38400K)] [ParOldGen: 87271K->25935K(87552K)] 120551K->25935K(125952K), [Metaspace: 3312K->3312K(1056768K)], 0.0375286 secs] [Times: user=0.07 sys=0.00, real=0.04 secs]
...... gc & fullgc
clean map99540
[Full GC (Ergonomics) [PSYoungGen: 14848K->0K(29184K)] [ParOldGen: 85192K->5496K(87552K)] 100040K->5496K(116736K), [Metaspace: 3318K->3318K(1056768K)], 0.0096408 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
[GC (Allocation Failure) [PSYoungGen: 14848K->14336K(29184K)] 20344K->20408K(116736K), 0.0063851 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
spendTime:14181
Heap
PSYoungGen total 29184K, used 22355K [0x00000007bd580000, 0x00000007c0000000, 0x00000007c0000000)
eden space 14848K, 54% used [0x00000007bd580000,0x00000007bdd54f00,0x00000007be400000)
from space 14336K, 100% used [0x00000007be400000,0x00000007bf200000,0x00000007bf200000)
to space 14336K, 0% used [0x00000007bf200000,0x00000007bf200000,0x00000007c0000000)
ParOldGen total 87552K, used 6072K [0x00000007b8000000, 0x00000007bd580000, 0x00000007bd580000)
object space 87552K, 6% used [0x00000007b8000000,0x00000007b85ee348,0x00000007bd580000)
Metaspace used 3325K, capacity 4500K, committed 4864K, reserved 1056768K
class space used 366K, capacity 388K, committed 512K, reserved 1048576K
可以看到
- young代默认是用了Parallel gc 算法
- 这里把 >100 改成了 > 80，不然会很快OOM ，说明在par old gc释放内存的速度满足不了分配的速度
- 这里由于map.clear执行次数比之前多，总体时间已经不具备太多参考性，不过总体看共耗时14181ms，比Serial old gc 耗时要长
使用参数-Xmx128M -Xms128M -XX:+UseSerialGC -XX:+PrintGCDetails运行代码，输出如下：
[GC (Allocation Failure) [DefNew: 34944K->4352K(39296K), 0.0594770 secs] 34944K->32056K(126720K), 0.0595147 secs] [Times: user=0.04 sys=0.01, real=0.06 secs]
[GC (Allocation Failure) [DefNew: 39296K->4351K(39296K), 0.0821899 secs] 67000K->66118K(126720K), 0.0822201 secs] [Times: user=0.06 sys=0.01, real=0.08 secs]
[GC (Allocation Failure) [DefNew: 39295K->39295K(39296K), 0.0000178 secs][Tenured: 61766K->87423K(87424K), 0.1293997 secs] 101062K->101052K(126720K), [Metaspace: 3310K->3310K(1056768K)], 0.1294609 secs] [Times: user=0.11 sys=0.01, real=0.13 secs]
clean map2069
[Full GC (Allocation Failure) [Tenured: 87423K->7672K(87424K), 0.0258848 secs] 126719K->7672K(126720K), [Metaspace: 3316K->3316K(1056768K)], 0.0259244 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]
...... gc & full gc
[GC (Allocation Failure) [DefNew: 34944K->4351K(39296K), 0.0299485 secs] 43661K->43649K(126720K), 0.0299941 secs] [Times: user=0.03 sys=0.00, real=0.03 secs]
[GC (Allocation Failure) [DefNew: 39295K->4351K(39296K), 0.0345476 secs] 78593K->78591K(126720K), 0.0345743 secs] [Times: user=0.03 sys=0.00, real=0.04 secs]
[GC (Allocation Failure) [DefNew: 39295K->39295K(39296K), 0.0000159 secs][Tenured: 74239K->87423K(87424K), 0.1011070 secs] 113535K->113507K(126720K), [Metaspace: 3318K->3318K(1056768K)], 0.1011625 secs] [Times: user=0.10 sys=0.00, real=0.10 secs]
clean map99312
[Full GC (Allocation Failure) [Tenured: 87423K->8717K(87424K), 0.0285509 secs] 126719K->8717K(126720K), [Metaspace: 3318K->3318K(1056768K)], 0.0285818 secs] [Times: user=0.03 sys=0.00, real=0.02 secs]
spendTime:11436
Heap
def new generation total 39296K, used 34108K [0x00000007b8000000, 0x00000007baaa0000, 0x00000007baaa0000)
eden space 34944K, 97% used [0x00000007b8000000, 0x00000007ba14f100, 0x00000007ba220000)
from space 4352K, 0% used [0x00000007ba220000, 0x00000007ba220000, 0x00000007ba660000)
to space 4352K, 0% used [0x00000007ba660000, 0x00000007ba660000, 0x00000007baaa0000)
tenured generation total 87424K, used 8717K [0x00000007baaa0000, 0x00000007c0000000, 0x00000007c0000000)
the space 87424K, 9% used [0x00000007baaa0000, 0x00000007bb323428, 0x00000007bb323600, 0x00000007c0000000)
Metaspace used 3324K, capacity 4500K, committed 4864K, reserved 1056768K
class space used 366K, capacity 388K, committed 512K, reserved 1048576K
说明：
- 依然把>100复原，并不会产生OOM
- 新生代关键字变成了DefNew，而不是ParNew，说明young代用的是串行回收
- 每次map.clear之后依然进行一次fullgc
- 共耗时 11436ms，比单纯的serial gc 耗时长
PS：补充下各种关键字的说明
串行收集器： DefNew：是使用-XX:+UseSerialGC（新生代，老年代都使用串行回收收集器）。
并行收集器： ParNew：是使用-XX:+UseParNewGC（新生代使用并行收集器，老年代使用串行回收收集器）或者-XX:+UseConcMarkSweepGC(新生代使用并行收集器，老年代使用CMS)。
PSYoungGen：是使用-XX:+UseParallelOldGC（新生代，老年代都使用并行回收收集器）或者-XX:+UseParallelGC（新生代使用并行回收收集器，老年代使用串行收集器）
garbage-first heap：是使用-XX:+UseG1GC（G1收集器）
使用参数-Xmx512M -Xms512M -XX:+UseConcMarkSweepGC -XX:+PrintGCDetails运行代码，输出如下：
[GC (Allocation Failure) [ParNew: 34944K->4352K(39296K), 0.0567471 secs] 34944K->32209K(126720K), 0.0567964 secs] [Times: user=0.12 sys=0.04, real=0.06 secs]
[GC (Allocation Failure) [ParNew: 39296K->4352K(39296K), 0.0403496 secs] 67153K->66132K(126720K), 0.0403796 secs] [Times: user=0.08 sys=0.03, real=0.04 secs]
[GC (CMS Initial Mark) [1 CMS-initial-mark: 61780K(87424K)] 66822K(126720K), 0.0028364 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
[CMS-concurrent-mark-start]
[GC (Allocation Failure) [ParNew: 39296K->39296K(39296K), 0.0000236 secs][CMS[CMS-concurrent-mark: 0.031/0.031 secs] [Times: user=0.05 sys=0.00, real=0.03 secs]
(concurrent mode failure): 61780K->87423K(87424K), 0.1991105 secs] 101076K->101043K(126720K), [Metaspace: 3311K->3311K(1056768K)], 0.1991834 secs] [Times: user=0.14 sys=0.01, real=0.20 secs]
clean map2069
[Full GC (Allocation Failure) [CMS: 87423K->6985K(87424K), 0.0341552 secs] 126719K->6985K(126720K), [Metaspace: 3316K->3316K(1056768K)], 0.0342075 secs] [Times: user=0.02 sys=0.00, real=0.04 secs]
[GC (Allocation Failure) [ParNew: 34944K->4352K(39296K), 0.0247864 secs] 41929K->41936K(126720K), 0.0248217 secs] [Times: user=0.05 sys=0.00, real=0.02 secs]
[GC (Allocation Failure) [ParNew: 39296K->4352K(39296K), 0.0250843 secs] 76880K->76870K(126720K), 0.0251154 secs] [Times: user=0.07 sys=0.00, real=0.02 secs]
[GC (CMS Initial Mark) [1 CMS-initial-mark: 72518K(87424K)] 77538K(126720K), 0.0007828 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
[CMS-concurrent-mark-start]
[GC (Allocation Failure) [ParNew: 39296K->39296K(39296K), 0.0000267 secs][CMS[CMS-concurrent-mark: 0.039/0.039 secs] [Times: user=0.05 sys=0.00, real=0.04 secs]
(concurrent mode failure): 72518K->87423K(87424K), 0.1825655 secs] 111814K->111783K(126720K), [Metaspace: 3316K->3316K(1056768K)], 0.1826484 secs] [Times: user=0.14 sys=0.00, real=0.19 secs]
clean map4138
[Full GC (Allocation Failure) [CMS: 87423K->8717K(87424K), 0.0251545 secs] 126719K->8717K(126720K), [Metaspace: 3316K->3316K(1056768K)], 0.0252056 secs] [Times: user=0.02 sys=0.00, real=0.03 secs]
...... gc & fullgc
[GC (Allocation Failure) [ParNew: 34944K->4350K(39296K), 0.0347229 secs] 43660K->44521K(126720K), 0.0347537 secs] [Times: user=0.08 sys=0.00, real=0.03 secs]
[GC (Allocation Failure) [ParNew: 39294K->4352K(39296K), 0.0328985 secs] 79465K->79655K(126720K), 0.0329299 secs] [Times: user=0.09 sys=0.00, real=0.03 secs]
[GC (CMS Initial Mark) [1 CMS-initial-mark: 75303K(87424K)] 80276K(126720K), 0.0007394 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
[CMS-concurrent-mark-start]
[GC (Allocation Failure) [ParNew: 39296K->39296K(39296K), 0.0000210 secs][CMS[CMS-concurrent-mark: 0.029/0.029 secs] [Times: user=0.04 sys=0.00, real=0.03 secs]
(concurrent mode failure): 75303K->87423K(87424K), 0.1324974 secs] 114599K->113496K(126720K), [Metaspace: 3318K->3318K(1056768K)], 0.1325644 secs] [Times: user=0.13 sys=0.01, real=0.14 secs]
clean map99312
[Full GC (Allocation Failure) [CMS: 87423K->8717K(87424K), 0.0350586 secs] 126719K->8717K(126720K), [Metaspace: 3318K->3318K(1056768K)], 0.0351243 secs] [Times: user=0.03 sys=0.00, real=0.03 secs]
spendTime:13169
Heap
par new generation total 39296K, used 34111K [0x00000007b8000000, 0x00000007baaa0000, 0x00000007baaa0000)
eden space 34944K, 97% used [0x00000007b8000000, 0x00000007ba14fd30, 0x00000007ba220000)
from space 4352K, 0% used [0x00000007ba220000, 0x00000007ba220000, 0x00000007ba660000)
to space 4352K, 0% used [0x00000007ba660000, 0x00000007ba660000, 0x00000007baaa0000)
concurrent mark-sweep generation total 87424K, used 8717K [0x00000007baaa0000, 0x00000007c0000000, 0x00000007c0000000)
Metaspace used 3324K, capacity 4500K, committed 4864K, reserved 1056768K
class space used 366K, capacity 388K, committed 512K, reserved 1048576K
说明：
-
总耗时13169 ，说明在堆空间比较小的时候，cms并不是好的选择
-
可以看到，young代的回收机制依然是parallel gc
-
concurrent mode failure出现了，说明old代在gc时留给程序运行的内存空间太小，这时会执行serial old，会比较耗时。应该调整触发full gc 的old区参数，默认是68%，比如可以设置为50%左右，耗时变为12957，不过full gc 触发的次数会变大。
-
-Xmx128M -Xms128M -XX:+UseConcMarkSweepGC -XX:+PrintGCDetails -XX:+UseCMSInitiatingOccupancyOnly -XX:CMSInitiatingOccupancyFraction=50 此时设置参数为这个
-
在小堆空间时，cms有以下三个步骤：
- CMS-initial-mark
- CMS-concurrent-mark
- Full gc(省略了remark，直接concurrent sweep)
-
如果设置为1G的堆空间，再执行一次，如下：
[GC (Allocation Failure) [ParNew: 306688K->34048K(306688K), 0.1501462 secs] 655589K->460064K(1014528K), 0.1501758 secs] [Times: user=0.23 sys=0.04, real=0.15 secs] [GC (CMS Initial Mark) [1 CMS-initial-mark: 426016K(707840K)] 465516K(1014528K), 0.0041295 secs] [Times: user=0.01 sys=0.00, real=0.01 secs] [CMS-concurrent-mark-start] clean map62070 clean map64139 [CMS-concurrent-mark: 0.052/0.052 secs] [Times: user=0.09 sys=0.01, real=0.05 secs] [CMS-concurrent-preclean-start] [CMS-concurrent-preclean: 0.009/0.009 secs] [Times: user=0.02 sys=0.00, real=0.01 secs] [CMS-concurrent-abortable-preclean-start] clean map66208 [GC (Allocation Failure) [ParNew: 306688K->34048K(306688K), 0.0219522 secs] 732704K->461842K(1014528K), 0.0219792 secs] [Times: user=0.04 sys=0.00, real=0.02 secs] clean map68277 [CMS-concurrent-abortable-preclean: 0.106/0.130 secs] [Times: user=0.21 sys=0.00, real=0.13 secs] [GC (CMS Final Remark) [YG occupancy: 230336 K (306688 K)][Rescan (parallel) , 0.0225974 secs][weak refs processing, 0.0000146 secs][class unloading, 0.0004391 secs][scrub symbol table, 0.0004257 secs][scrub string table, 0.0001903 secs][1 CMS-remark: 427794K(707840K)] 658131K(1014528K), 0.0237353 secs] [Times: user=0.08 sys=0.00, real=0.02 secs] [CMS-concurrent-sweep-start] clean map70346 [GC (Allocation Failure) [ParNew: 306688K->34048K(306688K), 0.0415566 secs] 651750K->403148K(1014528K), 0.0415949 secs] [Times: user=0.11 sys=0.01, real=0.04 secs] clean map72415 clean map74484 [GC (Allocation Failure) [ParNew: 306688K->34048K(306688K), 0.0723706 secs] 409986K->199788K(1014528K), 0.0724180 secs] [Times: user=0.19 sys=0.00, real=0.08 secs] clean map76553 [CMS-concurrent-sweep: 0.150/0.265 secs] [Times: user=0.58 sys=0.01, real=0.27 secs] [CMS-concurrent-reset-start] [CMS-concurrent-reset: 0.001/0.001 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]-
可以看到，这时候cms gc 需要以下几个过程：
- CMS-initial-mark 0.0041295 secs
- CMS-concurrent-mark-start 共耗时 0.052+0.009+-0.130 = 0.191 secs
- CMS-concurrent-mark 0.052 secs
- CMS-concurrent-preclean-start
- CMS-concurrent-preclean 0.009 secs
- CMS-concurrent-abortable-preclean-start
- CMS-concurrent-abortable-preclean 0.130 secs
- CMS-Remark 0.0237353 secs
- CMS-concurrent-sweep-start
- CMS-concurrent-sweep 0.265 secs
- CMS-concurrent-reset-start
- CMS-concurrent-reset 0.001 secs
五个大步骤，可以看到 共耗时：0.004 + 0.191 + 0.023 + 0.265 + 0.001 = 0.48 secs 其中两个stw的阶段：initial-mark 及remark均占用时间很短，而两个concurrent阶段则耗时较久。
-
使用-Xmx128m -Xms128m -XX:+UseG1GC -XX:+PrintGCDetails
由于G1 适用于大堆的情况，所以此时gc情况并不好：
[GC pause (G1 Evacuation Pause) (young), 0.0153427 secs] [Parallel Time: 14.4 ms, GC Workers: 4] [GC Worker Start (ms): Min: 242.0, Avg: 242.8, Max: 243.5, Diff: 1.5] [Ext Root Scanning (ms): Min: 0.0, Avg: 0.9, Max: 2.7, Diff: 2.7, Sum: 3.8] [Update RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0] [Processed Buffers: Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0] [Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0] [Code Root Scanning (ms): Min: 0.0, Avg: 0.2, Max: 0.8, Diff: 0.8, Sum: 0.8] [Object Copy (ms): Min: 10.4, Avg: 11.3, Max: 11.8, Diff: 1.4, Sum: 45.1] [Termination (ms): Min: 0.0, Avg: 0.6, Max: 0.8, Diff: 0.8, Sum: 2.3] [Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 4] [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0] [GC Worker Total (ms): Min: 12.3, Avg: 13.0, Max: 13.7, Diff: 1.4, Sum: 52.0] [GC Worker End (ms): Min: 255.7, Avg: 255.8, Max: 255.9, Diff: 0.2] [Code Root Fixup: 0.0 ms] [Code Root Purge: 0.0 ms] [Clear CT: 0.1 ms] [Other: 0.8 ms] [Choose CSet: 0.0 ms] [Ref Proc: 0.7 ms] [Ref Enq: 0.0 ms] [Redirty Cards: 0.1 ms] [Humongous Register: 0.0 ms] [Humongous Reclaim: 0.0 ms] [Free CSet: 0.0 ms] [Eden: 14.0M(14.0M)->0.0B(8192.0K) Survivors: 0.0B->2048.0K Heap: 14.0M(128.0M)->12.5M(128.0M)] [Times: user=0.03 sys=0.01, real=0.02 secs] ...... gc & fullgc [GC pause (G1 Evacuation Pause) (young) (to-space exhausted), 0.0054940 secs] [Parallel Time: 4.8 ms, GC Workers: 4] [GC Worker Start (ms): Min: 19175.3, Avg: 19175.4, Max: 19175.8, Diff: 0.6] [Ext Root Scanning (ms): Min: 0.0, Avg: 0.1, Max: 0.2, Diff: 0.2, Sum: 0.4] [Update RS (ms): Min: 1.4, Avg: 1.7, Max: 1.9, Diff: 0.5, Sum: 6.9] [Processed Buffers: Min: 14, Avg: 18.2, Max: 22, Diff: 8, Sum: 73] [Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0] [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0] [Object Copy (ms): Min: 2.1, Avg: 2.5, Max: 2.8, Diff: 0.7, Sum: 9.9] [Termination (ms): Min: 0.0, Avg: 0.3, Max: 0.7, Diff: 0.7, Sum: 1.3] [Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 4] [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0] [GC Worker Total (ms): Min: 4.2, Avg: 4.7, Max: 4.8, Diff: 0.6, Sum: 18.6] [GC Worker End (ms): Min: 19180.1, Avg: 19180.1, Max: 19180.1, Diff: 0.0] [Code Root Fixup: 0.0 ms] [Code Root Purge: 0.0 ms] [Clear CT: 0.0 ms] [Other: 0.6 ms] [Evacuation Failure: 0.4 ms] [Choose CSet: 0.0 ms] [Ref Proc: 0.1 ms] [Ref Enq: 0.0 ms] [Redirty Cards: 0.1 ms] [Humongous Register: 0.0 ms] [Humongous Reclaim: 0.0 ms] [Free CSet: 0.0 ms] [Eden: 0.0B(5120.0K)->0.0B(6144.0K) Survivors: 1024.0K->0.0B Heap: 126.1M(128.0M)->126.1M(128.0M)] [Times: user=0.01 sys=0.00, real=0.00 secs] [Full GC (Allocation Failure) 126M->5897K(128M), 0.0209053 secs] [Eden: 0.0B(6144.0K)->0.0B(54.0M) Survivors: 0.0B->0.0B Heap: 126.1M(128.0M)->5897.8K(128.0M)], [Metaspace: 3317K->3317K(1056768K)] [Times: user=0.02 sys=0.01, real=0.02 secs] [GC concurrent-mark-abort] spendTime:19005 Heap garbage-first heap total 131072K, used 41737K [0x00000007b8000000, 0x00000007b8100400, 0x00000007c0000000) region size 1024K, 36 young (36864K), 0 survivors (0K) Metaspace used 3323K, capacity 4500K, committed 4864K, reserved 1056768K class space used 366K, capacity 388K, committed 512K, reserved 1048576K说明：
- 总耗时19005ms，是上面gc算法中最慢的
- g1的gc日志跟之前的完全不同，增加了region的概念，每个region 1024K，也就是整个堆划分为了128个region
- young代有36个region，而且不存在survivors（from、to）
- old代是剩余的92个region
设置堆为1G，再看：
[GC pause (G1 Evacuation Pause) (young), 0.0138758 secs] [Parallel Time: 12.6 ms, GC Workers: 4] [GC Worker Start (ms): Min: 5508.6, Avg: 5509.2, Max: 5510.8, Diff: 2.1] [Ext Root Scanning (ms): Min: 0.0, Avg: 0.1, Max: 0.2, Diff: 0.2, Sum: 0.5] [Update RS (ms): Min: 0.5, Avg: 1.9, Max: 2.5, Diff: 1.9, Sum: 7.4] [Processed Buffers: Min: 2, Avg: 4.8, Max: 8, Diff: 6, Sum: 19] [Scan RS (ms): Min: 0.0, Avg: 0.1, Max: 0.3, Diff: 0.3, Sum: 0.4] [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0] [Object Copy (ms): Min: 9.8, Avg: 9.8, Max: 9.9, Diff: 0.1, Sum: 39.3] [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0] [Termination Attempts: Min: 1, Avg: 1.5, Max: 2, Diff: 1, Sum: 6] [GC Worker Other (ms): Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.0, Sum: 0.2] [GC Worker Total (ms): Min: 10.4, Avg: 12.0, Max: 12.5, Diff: 2.2, Sum: 47.9] [GC Worker End (ms): Min: 5521.2, Avg: 5521.2, Max: 5521.2, Diff: 0.0] [Code Root Fixup: 0.0 ms] [Code Root Purge: 0.0 ms] [Clear CT: 0.2 ms] [Other: 1.1 ms] [Choose CSet: 0.0 ms] [Ref Proc: 0.8 ms] [Ref Enq: 0.0 ms] [Redirty Cards: 0.0 ms] [Humongous Register: 0.0 ms] [Humongous Reclaim: 0.0 ms] [Free CSet: 0.2 ms] [Eden: 577.0M(577.0M)->0.0B(577.0M) Survivors: 37.0M->37.0M Heap: 774.5M(1024.0M)->197.5M(1024.0M)] [Times: user=0.05 sys=0.00, real=0.02 secs] clean map93105 clean map95174 clean map97243 clean map99312 spendTime:5506 Heap garbage-first heap total 1048576K, used 676352K [0x0000000780000000, 0x0000000780102000, 0x00000007c0000000) region size 1024K, 501 young (513024K), 37 survivors (37888K) Metaspace used 3324K, capacity 4500K, committed 4864K, reserved 1056768K class space used 366K, capacity 388K, committed 512K, reserved 1048576K可以看到，共耗时5506ms，耗时降了很多。
依然是1024k一个region，不过有501个是young代的region，其中37个是S区
-
上面例子的 GC 输出可以看出，采用不同的垃圾回收机制及设定不同的线程数，对于代码段的整体执行时间有较大的影响。需要根据情况有针对性地选用适合自己代码段的垃圾回收机制。
