在使用Plumbr中的GC暂停检测功能时,我被迫通过大量有关该主题的文章,书籍和演示工作。 在整个旅程中,我多次对次要,主要和完全GC事件的使用(误用)感到困惑。 这导致了这篇博客文章,我希望我设法消除一些困惑。
该帖子希望读者熟悉JVM中内置的通用垃圾收集原理。 将堆划分为Eden,幸存者和终身/旧空间,世代假设和不同的GC算法不在本文范围之内。
次要GC
从年轻空间(由Eden和Survivor空间组成)收集垃圾称为次要GC 。 这个定义既清晰又统一。 但是,在处理次要垃圾回收事件时,您仍然应该注意一些有趣的注意事项:
- 当JVM无法为新对象分配空间时(例如,伊甸园已满),总是会触发次要GC。 因此,分配率越高,次要GC的执行频率就越高。
- 只要池已满,就将复制其全部内容,并且指针可以再次从零开始跟踪可用内存。 因此,代替经典的Mark,Sweep和Compact,使用Mark and Copy来清理Eden和Survivor空间。 因此,在伊甸园或幸存者空间内实际上没有发生碎片。 写指针始终位于使用的池的顶部。
- 在次要GC事件中,有效生成将被忽略。 从终身代到年轻代的参考实际上被认为是GC的根源。 在标记阶段,从年轻一代到终身代的引用都将被忽略。
- 与通常的看法相反,所有次要GC都会触发世界暂停 ,从而停止应用程序线程。 对于大多数应用程序,暂停的长度在延迟方面可以忽略不计。 如果可以将Eden中的大多数对象视为垃圾,并且永远不要将其复制到Survivor / Old空间,则为true。 如果相反的情况是正确的,并且大多数新生对象都不符合GC的条件,则次要GC暂停将开始花费更多时间。
因此,对于Minor GC而言,情况非常清楚- 每个Minor GC都会清洗年轻一代 。
主GC与全GC
应该注意的是,这些术语没有正式的定义。 JVM规范和垃圾收集研究论文中都没有。 但乍看之下,在我们认为对次要GC清洁年轻空间的正确认识之上建立这些定义应该很简单:
- 主要GC正在清理使用权空间。
- Full GC正在清洁整个堆堆–年轻的和终身使用的空间。
不幸的是,它有点复杂和混乱。 首先-许多主要GC由次要GC触发,因此在很多情况下不可能将两者分开。 另一方面,许多现代垃圾收集仅对部分使用权空间进行清理,因此,再次使用术语“清理”仅部分正确。
这就引出了一个点,您不必担心GC是被称为Major GC还是Full GC,而应专注于确定当前的GC是停止了所有应用程序线程还是能够与应用程序线程同时进行 。
JVM标准工具中甚至内置了这种混淆。 我的意思最好通过一个例子来解释。 让我们比较在运行并发标记和清除收集器( -XX:+ UseConcMarkSweepGC )的JVM上跟踪GC的两种不同工具的输出
首先尝试通过jstat输出获得洞察力:
my-precious: me$ jstat -gc -t 4235 1s
Time S0C S1C S0U S1U EC EU OC OU MC MU CCSC CCSU YGC YGCT FGC FGCT GCT 5.7 34048.0 34048.0 0.0 34048.0 272640.0 194699.7 1756416.0 181419.9 18304.0 17865.1 2688.0 2497.6 3 0.275 0 0.000 0.2756.7 34048.0 34048.0 34048.0 0.0 272640.0 247555.4 1756416.0 263447.9 18816.0 18123.3 2688.0 2523.1 4 0.359 0 0.000 0.3597.7 34048.0 34048.0 0.0 34048.0 272640.0 257729.3 1756416.0 345109.8 19072.0 18396.6 2688.0 2550.3 5 0.451 0 0.000 0.4518.7 34048.0 34048.0 34048.0 34048.0 272640.0 272640.0 1756416.0 444982.5 19456.0 18681.3 2816.0 2575.8 7 0.550 0 0.000 0.5509.7 34048.0 34048.0 34046.7 0.0 272640.0 16777.0 1756416.0 587906.3 20096.0 19235.1 2944.0 2631.8 8 0.720 0 0.000 0.720
10.7 34048.0 34048.0 0.0 34046.2 272640.0 80171.6 1756416.0 664913.4 20352.0 19495.9 2944.0 2657.4 9 0.810 0 0.000 0.810
11.7 34048.0 34048.0 34048.0 0.0 272640.0 129480.8 1756416.0 745100.2 20608.0 19704.5 2944.0 2678.4 10 0.896 0 0.000 0.896
12.7 34048.0 34048.0 0.0 34046.6 272640.0 164070.7 1756416.0 822073.7 20992.0 19937.1 3072.0 2702.8 11 0.978 0 0.000 0.978
13.7 34048.0 34048.0 34048.0 0.0 272640.0 211949.9 1756416.0 897364.4 21248.0 20179.6 3072.0 2728.1 12 1.087 1 0.004 1.091
14.7 34048.0 34048.0 0.0 34047.1 272640.0 245801.5 1756416.0 597362.6 21504.0 20390.6 3072.0 2750.3 13 1.183 2 0.050 1.233
15.7 34048.0 34048.0 0.0 34048.0 272640.0 21474.1 1756416.0 757347.0 22012.0 20792.0 3200.0 2791.0 15 1.336 2 0.050 1.386
16.7 34048.0 34048.0 34047.0 0.0 272640.0 48378.0 1756416.0 838594.4 22268.0 21003.5 3200.0 2813.2 16 1.433 2 0.050 1.484
此片段是从JVM启动后的前17秒中提取的。 根据此信息,我们可以得出结论,在12次次要GC运行之后,执行了两次完整GC运行,总共运行了50毫秒 。 您将通过基于GUI的工具(例如jconsole或jvisualvm)得到相同的确认。
在点此结论之前,让我们看一下从同一JVM启动收集的垃圾收集日志的输出。 显然-XX:+ PrintGCDetails告诉了我们一个不同而更详细的故事:
java -XX:+PrintGCDetails -XX:+UseConcMarkSweepGC eu.plumbr.demo.GarbageProducer
3.157: [GC (Allocation Failure) 3.157: [ParNew: 272640K->34048K(306688K), 0.0844702 secs] 272640K->69574K(2063104K), 0.0845560 secs] [Times: user=0.23 sys=0.03, real=0.09 secs]
4.092: [GC (Allocation Failure) 4.092: [ParNew: 306688K->34048K(306688K), 0.1013723 secs] 342214K->136584K(2063104K), 0.1014307 secs] [Times: user=0.25 sys=0.05, real=0.10 secs]
... cut for brevity ...
11.292: [GC (Allocation Failure) 11.292: [ParNew: 306686K->34048K(306688K), 0.0857219 secs] 971599K->779148K(2063104K), 0.0857875 secs] [Times: user=0.26 sys=0.04, real=0.09 secs]
12.140: [GC (Allocation Failure) 12.140: [ParNew: 306688K->34046K(306688K), 0.0821774 secs] 1051788K->856120K(2063104K), 0.0822400 secs] [Times: user=0.25 sys=0.03, real=0.08 secs]
12.989: [GC (Allocation Failure) 12.989: [ParNew: 306686K->34048K(306688K), 0.1086667 secs] 1128760K->931412K(2063104K), 0.1087416 secs] [Times: user=0.24 sys=0.04, real=0.11 secs]
13.098: [GC (CMS Initial Mark) [1 CMS-initial-mark: 897364K(1756416K)] 936667K(2063104K), 0.0041705 secs] [Times: user=0.02 sys=0.00, real=0.00 secs]
13.102: [CMS-concurrent-mark-start]
13.341: [CMS-concurrent-mark: 0.238/0.238 secs] [Times: user=0.36 sys=0.01, real=0.24 secs]
13.341: [CMS-concurrent-preclean-start]
13.350: [CMS-concurrent-preclean: 0.009/0.009 secs] [Times: user=0.03 sys=0.00, real=0.01 secs]
13.350: [CMS-concurrent-abortable-preclean-start]
13.878: [GC (Allocation Failure) 13.878: [ParNew: 306688K->34047K(306688K), 0.0960456 secs] 1204052K->1010638K(2063104K), 0.0961542 secs] [Times: user=0.29 sys=0.04, real=0.09 secs]
14.366: [CMS-concurrent-abortable-preclean: 0.917/1.016 secs] [Times: user=2.22 sys=0.07, real=1.01 secs]
14.366: [GC (CMS Final Remark) [YG occupancy: 182593 K (306688 K)]14.366: [Rescan (parallel) , 0.0291598 secs]14.395: [weak refs processing, 0.0000232 secs]14.395: [class unloading, 0.0117661 secs]14.407: [scrub symbol table, 0.0015323 secs]14.409: [scrub string table, 0.0003221 secs][1 CMS-remark: 976591K(1756416K)] 1159184K(2063104K), 0.0462010 secs] [Times: user=0.14 sys=0.00, real=0.05 secs]
14.412: [CMS-concurrent-sweep-start]
14.633: [CMS-concurrent-sweep: 0.221/0.221 secs] [Times: user=0.37 sys=0.00, real=0.22 secs]
14.633: [CMS-concurrent-reset-start]
14.636: [CMS-concurrent-reset: 0.002/0.002 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
根据这些信息,我们可以看到,确实在12次次要GC运行之后,“情况有所不同”开始发生。 但是实际上,这是两个完全GC运行,而实际上,这“不同的事情”只是一个在Tenured一代中运行的GC,它由不同的阶段组成:
- 初始标记阶段,跨度为0.0041705秒或约4ms。 此阶段是一个世界停止事件,它将停止所有应用程序线程以进行初始标记。
- 同时执行Markup和Preclean阶段。 这些与应用程序线程并发运行
- 最终备注阶段,范围为0.0462010秒或大约46ms。 此阶段再次是世界停止事件。
- 并发执行Sweep操作。 顾名思义,此阶段也可以并发执行,而无需停止应用程序线程。
因此,我们从实际的垃圾收集日志中看到的是–代替了两次Full GC操作,实际上只执行了一次Main GC Cleaning Old空间。
如果您在等待时间之后,那么根据jstat揭示的数据做出决策将使您朝着正确的决策方向迈进。 它正确地列出了两个总计为50ms的世界停止事件,这些事件当时影响了所有活动线程的延迟。 但是,如果您尝试针对吞吐量进行优化,那么您可能会被误导-仅列出世界末日的初始标记和最终标记阶段,而jstat输出将完全隐藏正在完成的并发工作。
结论
考虑到这种情况,最好甚至避免以次要,主要或完全GC的方式进行思考。 而是监视您的应用程序的延迟或吞吐量,并将GC事件链接到结果。 除了这些事件之外,您还需要了解特定的GC事件是强制所有应用程序线程停止还是是并发处理的事件的一部分。
如果您喜欢这些内容-这是我们垃圾收集手册中的示例章节。 整个手册将于2015年3月发行。
翻译自: https://www.javacodegeeks.com/2015/03/minor-gc-vs-major-gc-vs-full-gc.html