Full GC是否真的存在

标签： full gc 存在 | 发表时间：2015-03-03 19:28 | 作者：
出处：http://it.deepinmind.com

在Plumbr这和GC暂停检测打交道的这段日子里，我查阅了与这个主题相关的大量文章，书籍以及资料。在这当中，我经常会对新生代GC, 年老代GC以及Full GC的事件的使用（滥用）感到困惑。于是便有了这篇文章，希望能够清除一些困惑。

本文需要读者对JVM内建的GC相关的常用原理有一定的了解。像eden区，Survivor区以及年老区空间的划分，分代假设（generational hypothesis）以及不同的GC算法就不在本文的讨论范围之内了。

image

新生代GC（Minor GC）

新生代垃圾的回收被称作 Minor GC。这个定义非常清晰，理解起来也不会有什么歧义。不过当处理新生代GC事件时，还是有一些有意思的东西值得注意的：

  1. 只要JVM无法为新创建的对象分配空间，就肯定会触发新生代GC，比方说Eden区满了。因此对象创建得越频繁，新生代GC肯定也更频繁。
  2. 一旦内存池满了，它的所有内容就会被拷贝走，指针又将重新归零。因此和经典的标记(Mark)，清除(Sweep)，整理(Compact)的过程不同的是，Eden区和Survivor区的清理只涉及到标记和拷贝。在它们中是不会出现碎片的。写指针始终在当前使用区的顶部。
  3. 在一次新生代GC事件中，通常不涉及到年老代。年老代到年轻代的引用被认为是GC的根对象。而在标记阶段中，从年轻代到年老代的引用则会被忽略掉。
  4. 和通常所理解的不一样的是，所有的新生代GC都会触发“stop-the-world”暂停，这会中断应用程序的线程。对绝大多数应用而言，暂停的时间是可以忽略不计的。如果Eden区中的大多数对象都是垃圾对象并且永远不会被拷贝到Survivor区/年老代中的话，这么做是合理的。如果恰好相反的话，那么绝大多数的新生对象都不应该被回收，新生代GC的暂停时间就会变得相对较长了。

现在来看新生代GC还是很清晰的—— 每一次新生代GC都会对年轻代进行垃圾清除。

年老代GC（ajor GC）与Full GC

你会发现关于这两种GC其实并没有明确的定义。JVM规范或者垃圾回收相关的论文中都没有提及。不过从直觉来说，根据新生代GC(Minor GC)清理的是年轻代空间的认识来看，不难得出以下推论（这里应当从英文出发来理解，Minor, Major与Full GC，翻译过来的名称已经带有明显的释义了）：

  • Major GC清理的是年老代的空间。
  • Full GC清理的是整个堆——包括年轻代与年老代空间

不幸的是这么理解会有一点复杂与困惑。首先——许多年老代GC其实是由新生代GC触发的，因此在很多情况下两者无法孤立来看待。另一方面——许多现代的垃圾回收器会对年老代进行部分清理，因此，使用“清理”这个术语则显得有点牵强。

那么问题就来了，先别再纠结某次GC到底是年老代GC还是Full GC了， 你应该关注的是这次GC是否中断了应用线程还是能够和应用线程并发地执行。

即便是在JVM的官方工具中，也存在着这一困扰。通过一个例子来说明应该更容易理解一些。我们用两款工具来跟踪某个运行着CMS回收器的JVM，来比较下它们的输出有什么不同：

首先通过 jstat的输出来查看下GC的信息：

   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.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次新生代GC后出现了两次Full GC，共耗时50ms。通过GUI的工具也可以获取到同样的信息，比如说 jsonsole或者是 jvisualvm。

在接受这一结论前，我们再来看下同样是这次JVM启动后所输出的GC日志。很明显-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后的确出现了一些“不太寻常”的事情。但并不是执行了两次Full GC，这个“不寻常”的事情其实只是在年老代中执行了一次包含了数个阶段的GC而已：

  • 初始标记阶段，从0.0041705 秒或者说4ms的时候开始。这一阶段是一次“stop-the-world”事件，所有的应用线程都被暂停以便进行初始标记。
  • 并发地执行标记和预清理(Preclean)的阶段。这是和应用线程一起并发执行的。
  • 最终标记阶段，从0.0462010秒或者说46毫秒的时候开始。这一阶段也同样是“stop-the-world”的。
  • 并发地进行清除操作。正如名字所说的，这一阶段也无需中断应用线程，可以并发地执行。

因此我们从实际的GC日志中所看到的是这样——其实没有什么两次所谓的Full GC,只有一次清理年老代空间的Major GC而已。

如果你再想想jstat所输出的结果再下结论的话，就能得出正确的结论了。它明确地列出了两次stop-the-world事件，总耗时50ms，这是影响到活跃线程的总的延迟时间。不过如果你想依据这来优化吞吐量的话，你可能就被误导了——jstat只列出了两次stop-the-world的初始标记和最终标记的阶段，它把并发执行的那部分工作给隐藏掉了。

结论

基于上述事实来看，最好就是不要再考虑什么新生代GC，年老代GC，Full GC。你应该做的是监控应用的时延和吞吐量，并把GC事件与之结合来看。从这些事件中，你便能得知某个GC事件是否中断了应用程序或者只是并发地执行而已。

原创文章转载请注明出处： Full GC是否真的存在

英文原文链接

相关 [full gc 存在] 推荐：

Full GC是否真的存在

- - Java译站
在Plumbr这和GC暂停检测打交道的这段日子里，我查阅了与这个主题相关的大量文章，书籍以及资料. 在这当中，我经常会对新生代GC, 年老代GC以及Full GC的事件的使用（滥用）感到困惑. 于是便有了这篇文章，希望能够清除一些困惑. 本文需要读者对JVM内建的GC相关的常用原理有一定的了解. 像eden区，Survivor区以及年老区空间的划分，分代假设（generational hypothesis）以及不同的GC算法就不在本文的讨论范围之内了.

触发Full GC执行的情况

- - Web前端 - ITeye博客
除直接调用System.gc外，触发Full GC执行的情况有如下四种. 旧生代空间只有在新生代对象转入及创建为大对象、大数组时才会出现不足的现象，当执行Full GC后空间仍然不足，则抛出如下错误：. 为避免以上两种状况引起的Full GC，调优时应尽量做到让对象在Minor GC阶段被回收、让对象在新生代多存活一段时间及不要创建过大的对象及数组.

利用Arena Allocation避免HBase触发Full GC

- Adam - 淘宝JAVA中间件团队博客
Arena Allocation，是一种GC优化技术，它可以有效地减少因内存碎片导致的Full GC，从而提高系统的整体性能. 本文介绍Arena Allocation的原理及其在Hbase中的应用-MSLAB. 假设有1G内存，我顺序创建了1百万个对象，每个对象大小1K，Heap会被渐渐充满且每个对象以创建顺序相邻.

FULL GC有可能导致JVM暂停1分钟以上吗?

- - 高级语言虚拟机
作者: qianhd . 链接： http://hllvm.group.iteye.com/group/topic/28745 . 发表时间: 2011年12月30日. 声明：本文系ITeye网站发布的原创文章，未经作者书面许可，严禁任何网站转载本文，否则必将追究法律责任. 与另外个程序交互有个心跳检测, 15s/次, 31s没有收到心跳检测的返回消息就认为连接断了,.

Tomcat的JreMemoryLeakPreventionListener监听周期性频繁执行full gc

- -
网上还是有蛮多解决方案，还是说说我最比较喜欢且常用的吧，. 1、添加gcDaemonProtection="false"参数禁用JreMemoryLeakPreventionListener监听. 2、直接删除JreMemoryLeakPreventionListener监听. 已有 0 人发表留言，猛击->> 这里<<-参与讨论.

系统频繁Full gc问题分析及解决办法

- - JavaRanger - 专注JAVA高性能程序开发、JVM、Mysql优化、算法
上周开始系统在业务高峰期一直收到Full gc报警，监控显示fgc频繁，下图是监控图，左边红框是优化前效果，右边是优化后，优化后fgc基本为0. 1.查看gc日志，发现old区fgc后大小没有变化，如下图：. 2.去线上dump内存看是什么对象，用memory analyzer分析，Retained Size竟然有2.4G，全是sun.awt.SunToolkit这个对象，其实到这一步已经可以确定是什么问题了，只是自己对系统不是很熟悉，导致定位具体的问题代码花了一些时间.

(转)关于施用full gc频繁的分析及解决

- - Java - 编程语言 - ITeye博客
当频繁full gc时，jstack打印出堆栈信息如下：. 可以看到的确是在跑低价信息. 另外在应用频繁full gc时和应用正常时，也执行了如下2种命令：. sudo -u admin -H /opt/taobao/java/bin/jmap -histo:live `pgrep` > #your file path#（live会产生full gc）.

JVM初探——使用堆外内存减少Full GC

- - ImportNew
GCIH可以联想到:  将长期存活的对象(如Local Cache)移入堆外内存(off-heap, 又名. 直接内存/direct-memory), 从而减少CMS管理的对象数量, 以降低Full GC的次数和频率, 达到提高系统响应速度的目的.. 这个idea最初来源于TaobaoJVM对OpenJDK定制开发的GCIH部分(详见 撒迦的分享- JVM定制改进@淘宝), 其中GCIH就是将CMS Old Heap区的一部分划分出来, 这部分内存虽然还在堆内, 但已不被GC所管理.

Full Circle 51期发布

- PT - Wow! Ubuntu
How-to:Part 25 Python编程, Part 6 LibreOffice , Part 3 Ubuntu 开发, Part 2 使用KDE (4.6). Linux实验室:创建自己的源. 还有:Ubuntu 游戏,我的Ubuntu故事,等等更多. # 本文采用CC协议进行授权，转载本文请注明本文链接.

Java GC 调优

- - Darktea
关于 Java GC 已经有很多好的文档了, 比如这些:. 但是这里还是想再重点整理一下 Java GC 日志的格式, 可以作为实战时的备忘录.. 同时也会再整理一下各种概念. 一, JDK 6 提供的各种垃圾收集器. 先整理一下各种垃圾收集器.. 新生代收集器: Serial, ParNew, Parallel Scavenge (MaxGCPauseMillis vs.