JVM垃圾回收三-各种GC

315 阅读6分钟

Minor GC vs Major GC vs Full GC

清除堆内存中不同部分的垃圾收集事件通常称为Minor GC vs Major GC vs Full GC。在本节中,我们将讨论这些事件之间的差异。沿着这条路,我们希望能看到这个区别实际上不是太相关。通常相关的是应用程序是否满足其SLA,以及是否监视应用程序的延迟或吞吐量。只有到那时,才会将GC事件链接到结果。关于这些事件,重要的是它们是否停止了应用程序,以及它花费了多长时间。但是由于术语Minor、Major和FullGC被广泛使用,而且没有正确的定义,所以让我们更详细地研究一下这个主题。

Minor GC

Minor GC指的是针对年轻代的垃圾回收。这个定义看起来既清晰又明确。然而,在进行 Minor GC 时,仍然需要注意一些有趣的事情:

  • 触发时机:当JVM无法为新对象分配空间时就会触发Minor GC,例如当Eden区已经满了。因此,分配速率越高,发生 Minor GC的频率就越高。
  • 在Minor GC期间,永久代是被忽略的。从永久代到年轻代的引用被认为是GC根。在标记阶段,从年轻代到永久代的引用则直接忽略。
  • 与直觉相反,Minor GC确实会触发“停止一切”暂停(stop-the-world pause),暂停应用程序线程。对于大多数应用程序,如果Eden区中的大多数对象可以被认为是垃圾,并且从不复制到Survivor区或者老年代空间,则暂停的时间长度可以忽略不计。如果情况正好相反,并且大多数新生对象都不适合收集,那么Minor GC暂停将花费更多的时间。

所以定义Minor GC很简单——Minor GC清除新生代对象。

Major GC vs Full GC

需要指出的是,这些术语没有正式的定义——JVM规范和垃圾收集研究论文中都没有。但是在我们已知的关于Minor GC清理新生代空间的定义的基础上,对他们定义则变得简单:

  • Major GC负责清理老年代空间。
  • Full GC负责清理整个堆——包括新生代空间和老年代空间。

不过实际情况是有点复杂和让人困惑的。首先,许多 Major GCs是由Minor GCs触发的,所以在很多情况下,将它们分开是不可能的。另一方面,像G1这样的现代垃圾收集算法执行部分垃圾清理,所以,使用术语“清理”也不是很精确。

因此我们的关注点不是GC是否被称为Major GC或Full GC,而是应该关注GC是否停止了所有应用程序线程,或者是否能够与应用程序线程并发进行。

这种混乱甚至直接影响到了JVM标准工具中。可以通过一个例子来解释:让我们比较使用并发的标记和清除收集器(-XX:+UseConcMarkSweepGC)在运行JVM上跟踪GC的两种不同工具的输出

第一个尝试是通过jstat输出来了解

$ 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.275
 6.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.359
 7.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.451
 8.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.550
 9.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次Minor GC运行之后,执行了两次Full GC,总共跨越50ms。通过基于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次Minor GC之后,确实开始发生“一些不同的事情”。但是,这个“不同的东西”并不是两个Full GC的运行,实际上只是一个运行在老年代的GC,由不同的阶段组成:

  • Initial Mark即初始标记阶段,持续0.0041705秒=4ms。此阶段是一个STW事件,停止所有应用程序线程以进行初始标记。
  • Markup and Preclean即标记和预清理阶段。与应用程序线程并发执行。
  • Final Remark 即最终标记阶段,持续0.0462010秒约46ms。这一阶段又是一个STW的阶段。
  • 在不停止应用程序线程的情况下,并行执行清除操作。

因此,我们从实际的垃圾收集日志中看到,实际上只执行了一个Major GC清理老年代空间,而不是两个Full GC操作。

如果应用程序在意延迟时间,那么jstat显示的数据将引导您做出正确的决策。它正确地列出了两个总共50ms的stop-the-world事件,它们影响了当时所有活动线程的延迟。但是,如果您试图优化吞吐量,您可能会被误导——只列出STW的初始标记和最终注释阶段,jstat输出完全隐藏了正在执行的并发工作。