导读:JVM GC很容易成为性能问题的替罪羊,然而GC问题的实质在于GC的实现不能满足当前的工作负载或者没有选择正确的垃圾收集器。本文作者针对不同的GC实现做了有效测试,相信通过阅读本文可以对不同垃圾收集器的特性有深入的认识。
听说分配100 mb内存,也会导致JVM暂停几秒钟。
OpenJDK中的垃圾收集器
GC很容易成为性能问题的替罪羊,然而GC问题的实质在于GC的实现不能满足当前的工作负载。在很多情况下,这些工作负载本身就存在问题,也有很多时候,垃圾回收如此缓慢的原因只是因为使用了不适合的垃圾收集器。让我们看看OpenJDK中的GC:
黄色是STW阶段,绿色是并发阶段
这里需要注意垃圾收集器在常规GC循环中的暂停阶段。
实验
使用如下代码进行测试:
import java.util.*;
public class AL {
static List<Object> l;
public static void main(String... args) {
l = new ArrayList<>();
for (int c = 0; c < 100_000_000; c++) {
l.add(new Object());
}
}
}
即使是使用糟糕的基准测试也会告诉你有关被测系统的信息。 你需要细心分析测试的结果。 事实证明,上面的工作量突出了OpenJDK中不同收集器的GC设计选择。
使用JDK 9 + Shenandoah进行测试。 由于即将分配100M 16字节对象,因此将堆大小设置为4 GB即可,并且可以消除收集器之间的一些差异。
$ time java -Xms4G -Xmx4G -Xlog:gc AL
[0.030s][info][gc] Using G1
[1.525s][info][gc] GC(0) Pause Young (G1 Evacuation Pause) 370M->367M(4096M) 991.610ms
[2.808s][info][gc] GC(1) Pause Young (G1 Evacuation Pause) 745M->747M(4096M) 928.510ms
[3.918s][info][gc] GC(2) Pause Young (G1 Evacuation Pause) 1105M->1107M(4096M) 764.967ms
[5.061s][info][gc] GC(3) Pause Young (G1 Evacuation Pause) 1553M->1555M(4096M) 601.680ms
[5.835s][info][gc] GC(4) Pause Young (G1 Evacuation Pause) 1733M->1735M(4096M) 465.216ms
[6.459s][info][gc] GC(5) Pause Initial Mark (G1 Humongous Allocation) 1894M->1897M(4096M) 398.453ms
[6.459s][info][gc] GC(6) Concurrent Cycle
[7.790s][info][gc] GC(7) Pause Young (G1 Evacuation Pause) 2477M->2478M(4096M) 472.079ms
[8.524s][info][gc] GC(8) Pause Young (G1 Evacuation Pause) 2656M->2659M(4096M) 434.435ms
[11.104s][info][gc] GC(6) Pause Remark 2761M->2761M(4096M) 1.020ms
[11.979s][info][gc] GC(6) Pause Cleanup 2761M->2215M(4096M) 2.446ms
[11.988s][info][gc] GC(6) Concurrent Cycle 5529.427ms
real 0m12.016s
user 0m34.588s
sys 0m0.964s
对于G1来说,新生代G1都在500-1000ms之间完成,达到稳定状态之后,GC时间会进一步减少,并且使用启发式算法根据设定的暂停目标计算出需要收集的目标。一段时间后,并发GC循环开始,并一直持续到结束(请注意新生代collections如何与并发阶段重叠)。本来应该有个混合收集暂停的阶段,但是在此之前VM就已退出。这些非稳态的暂停,导致了运行时间这么久。
需要注意的是,“user”时间大于“real”时间。这是因为GC工作是并行的,因此当应用程序在单个线程中运行时,GC会使用多线程保证收集的速度很快。
$ time java -XX:+UseParallelOldGC -Xms4G -Xmx4G -Xlog:gc AL
[0.023s][info][gc] Using Parallel
[1.579s][info][gc] GC(0) Pause Young (Allocation Failure) 878M->714M(3925M) 1144.518ms
[3.619s][info][gc] GC(1) Pause Young (Allocation Failure) 1738M->1442M(3925M) 1739.009ms
real 0m3.882s
user 0m11.032s
sys 0m1.516s
在Parallel GC中,我们看到类似的新生代暂停,这应该是重新调整 Eden/Survivors保证足以接受更多内存分配。 因此,只有两个大的GC暂停,JVM很快就完成了工作。 在稳定状态下,该收集器可能会保持类似频率的大停顿。 “user”>>“real”的原因也是跟G1类似。
$ time java -XX:+UseConcMarkSweepGC -Xms4G -Xmx4G -Xlog:gc AL
[0.012s][info][gc] Using Concurrent Mark Sweep
[1.984s][info][gc] GC(0) Pause Young (Allocation Failure) 259M->231M(4062M) 1788.983ms
[2.938s][info][gc] GC(1) Pause Young (Allocation Failure) 497M->511M(4062M) 871.435ms
[3.970s][info][gc] GC(2) Pause Young (Allocation Failure) 777M->850M(4062M) 949.590ms
[4.779s][info][gc] GC(3) Pause Young (Allocation Failure) 1117M->1161M(4062M) 732.888ms
[6.604s][info][gc] GC(4) Pause Young (Allocation Failure) 1694M->1964M(4062M) 1662.255ms
[6.619s][info][gc] GC(5) Pause Initial Mark 1969M->1969M(4062M) 14.831ms
[6.619s][info][gc] GC(5) Concurrent Mark
[8.373s][info][gc] GC(6) Pause Young (Allocation Failure) 2230M->2365M(4062M) 1656.866ms
[10.397s][info][gc] GC(7) Pause Young (Allocation Failure) 3032M->3167M(4062M) 1761.868ms
[16.323s][info][gc] GC(5) Concurrent Mark 9704.075ms
[16.323s][info][gc] GC(5) Concurrent Preclean
[16.365s][info][gc] GC(5) Concurrent Preclean 41.998ms
[16.365s][info][gc] GC(5) Concurrent Abortable Preclean
[16.365s][info][gc] GC(5) Concurrent Abortable Preclean 0.022ms
[16.478s][info][gc] GC(5) Pause Remark 3390M->3390M(4062M) 113.598ms
[16.479s][info][gc] GC(5) Concurrent Sweep
[17.696s][info][gc] GC(5) Concurrent Sweep 1217.415ms
[17.696s][info][gc] GC(5) Concurrent Reset
[17.701s][info][gc] GC(5) Concurrent Reset 5.439ms
real 0m17.719s
user 0m45.692s
sys 0m0.588s
在CMS中,“并发”意味着老生代的并发收集。 正如我们在这里看到,新生代仍然在使用STW。 从GC日志上看看有点像G1:新生代暂停,并发标记/收集。 不同之处在于,“并发标记”可以在不停止应用的情况下清除垃圾(与G1混合暂停相反)。 无论如何,较长的Young GC暂停,也没有启发式算法可以改善,导致CMS算法的垃圾收集时间较长。
$ time java -XX:+UseShenandoahGC -Xms4G -Xmx4G -Xlog:gc AL
[0.026s][info][gc] Using Shenandoah
[0.808s][info][gc] GC(0) Pause Init Mark 0.839ms
[1.883s][info][gc] GC(0) Concurrent marking 2076M->3326M(4096M) 1074.924ms
[1.893s][info][gc] GC(0) Pause Final Mark 3326M->2784M(4096M) 10.240ms
[1.894s][info][gc] GC(0) Concurrent evacuation 2786M->2792M(4096M) 0.759ms
[1.894s][info][gc] GC(0) Concurrent reset bitmaps 0.153ms
[1.895s][info][gc] GC(1) Pause Init Mark 0.920ms
[1.998s][info][gc] Cancelling concurrent GC: Stopping VM
[2.000s][info][gc] GC(1) Concurrent marking 2794M->2982M(4096M) 104.697ms
real 0m2.021s
user 0m5.172s
sys 0m0.420s
Shenandoah是不分代的垃圾收集器(迄今为止,也有一些在不引入分代的情况下进行快速部分垃圾收集的想法,但是即使没有分代也死不人)。并发GC循环与应用程序一起运行,通过两次段时间暂停来完成并发标记。 并发复制什么都不做,因为所有对象都无需收集,而且还没有碎片化。 由于VM关闭,第二个GC周期提前终止。 没有像其他垃圾收集器那样的暂停,这就解释了为什么消耗时间如此之短。
$ time java -XX:+UnlockExperimentalVMOptions -XX:+UseEpsilonGC -Xms4G -Xmx4G -Xlog:gc AL
[0.031s][info][gc] Initialized with 4096M non-resizable heap.
[0.031s][info][gc] Using Epsilon GC
[1.361s][info][gc] Total allocated: 2834042 KB.
[1.361s][info][gc] Average allocation rate: 2081990 KB/sec
real 0m1.415s
user 0m1.240s
sys 0m0.304s
运行实验性的“无操作”Epsilon GC可以帮助估算GC开销。 4 GB堆内存可以保证内存足够,所以应用程序运行时不会有任何暂停(实际上就是不进行任何垃圾收集)。 请注意,“real”和“user”+“sys”时间几乎相等,说明只有一个用户线程在运行。
结论
不同的GC算法在其实现中具有不同的权衡。 将GC刷掉是“糟糕的主意”是一个延伸。 通过了解工作负载、可用的GC实现和性能要求,从而选择合适的垃圾收集器。 即使使用没有GC的平台,你仍然需要知道(并选择)内存分配器。 运行测试工作负载时,请尝试了解告这些内容。
原文链接:
https://shipilev.net/jvm/anatomy-quarks/3-gc-design-and-pauses/
本文作者 Aleksey Shipilёv ,由方圆翻译。转载本文请注明出处,欢迎更多小伙伴加入翻译及投稿文章的行列,详情请戳公众号菜单「联系我们」。
GIAC全球互联网架构大会深圳站将于2019年6月举行,届时有更多Java、JVM等国内外专家 相 关 演讲。参加 2019年GIAC深圳站,可以了解业界动态,和业界专家近距离接触。
参加 GIAC,盘点2019年最新技术,目前 购买8折优惠 ,多人购买有更多优惠。识别二维码 了解大会更多详情。