zoukankan      html  css  js  c++  java

  • 【转】深入理解Major GC, Full GC, CMS

    声明：本文转自http://blog.csdn.net/iter_zc/article/details/41825395，转载务必声明。

     

    很多人都分不清Major GC, Full GC的概念，事实上我查了下资料，也没有查到非常精确的Major GC和Full GC的概念定义。分不清这两个概念可能就会对这个问题疑惑：Full GC会引起Minor GC吗？

    经过一系列的查找和对JVM表现的分析，基本可以给Full GC和Major GC下一个定义了，这篇说一说概念和理由。

     

    这篇文章Major GCs – Separating Myth from Reality 基本讨论的也是这个问题，但是它没有给出实际的证明。

     

    我们可以认为Major GC == Full GC，他们是一个概念，就是针对老年代/永久代进行GC。因为取名叫Full就会让人疑惑，到底会不会先Minor GC。事实上Full GC本身不会先进行Minor GC，我们可以配置，让Full GC之前先进行一次Minor GC，因为老年代很多对象都会引用到新生代的对象，先进行一次Minor GC可以提高老年代GC的速度。比如老年代使用CMS时，设置CMSScavengeBeforeRemark优化，让CMS remark之前先进行一次Minor GC。

     

    弄清楚了Full GC本意单纯就是针对老年代了之后，我们再进一步深入理解Full GC的含义。因为CMS主要可以分为initial mark(stop the world), concurrent mark, remark(stop the world), concurrent sweep几个阶段，其中initial mark和remark会stop the world。

    在这篇聊聊JVM（二）说说GC的一些常见概念 我们说了一次CMS至少会给Full GC的次数 + 2，因为Full GC的次数是按照老年代GC时stop the world的次数而定的。

     

    再来看Full GC的Time的定义，可以理解它也指的是老年代GC时stop the world的时间。我们看一个实例来证明一下。

     

    这段日志是我从一个tomcat的JVM GC日志中抓取的，老年代使用了CMS收集器

     

    [html] view plain copy
     
    1. 2014-12-08T17:24:18.514+0800: 77443.326: [GC [1 <strong><span style="color:#FF0000;">CMS-initial-mark: 1382782K(1843200K)] 1978934K(4710400K), 0.0702700 secs] [Times: user=0.07 sys=0.00, real=0.07 secs]</span></strong>   
    2. 2014-12-08T17:24:18.586+0800: 77443.398: [CMS-concurrent-mark-start]  
    3. 2014-12-08T17:24:19.890+0800: 77444.702: [CMS-concurrent-mark: 1.206/1.303 secs] [Times: user=2.80 sys=0.07, real=1.30 secs]   
    4. 2014-12-08T17:24:19.890+0800: 77444.702: [CMS-concurrent-preclean-start]  
    5. 2014-12-08T17:24:19.906+0800: 77444.718: [CMS-concurrent-preclean: 0.015/0.015 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]   
    6. 2014-12-08T17:24:19.906+0800: 77444.718: [CMS-concurrent-abortable-preclean-start]  
    7.  CMS: abort preclean due to time 2014-12-08T17:24:25.181+0800: 77449.993: [CMS-concurrent-abortable-preclean: 5.241/5.275 secs] [Times: user=6.03 sys=0.09, real=5.27 secs]   
    8. 2014-12-08T17:24:25.187+0800: 77449.999: [GC[YG occupancy: 749244 K (2867200 K)]77450.000: [Rescan (parallel) , 0.0276780 secs]77450.028: [weak refs processing, 0.2029030 secs]  
    9.  [<span style="color:#FF0000;"><strong>1 CMS-remark: 1382782K(1843200K)] 2132027K(4710400K), 0.2340660 secs] [Times: user=0.43 sys=0.00, real=0.23 secs</strong></span>]   
    10. 2014-12-08T17:24:25.424+0800: 77450.236: [CMS-concurrent-sweep-start]  
    11. 2014-12-08T17:24:27.420+0800: 77452.232: [CMS-concurrent-sweep: 1.918/1.996 secs] [Times: user=2.61 sys=0.05, real=2.00 secs]   
    12. 2014-12-08T17:24:27.421+0800: 77452.233: [CMS-concurrent-reset-start]  
    13. 2014-12-08T17:24:27.430+0800: 77452.242: [CMS-concurrent-reset: 0.010/0.010 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]   
    14. 2014-12-09T12:45:05.545+0800: 147090.358: [GC [<span style="color:#FF0000;"><strong>1 CMS-initial-mark: 1384080K(1843200K)] 2013429K(4710400K), 0.0656230 secs] [Times: user=0.06 sys=0.00, real=0.07 secs</strong></span>]   
    15. 2014-12-09T12:45:05.613+0800: 147090.425: [CMS-concurrent-mark-start]  
    16. 2014-12-09T12:45:06.848+0800: 147091.660: [CMS-concurrent-mark: 1.196/1.235 secs] [Times: user=2.77 sys=0.03, real=1.23 secs]   
    17. 2014-12-09T12:45:06.849+0800: 147091.661: [CMS-concurrent-preclean-start]  
    18. 2014-12-09T12:45:06.862+0800: 147091.674: [CMS-concurrent-preclean: 0.013/0.013 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]   
    19. 2014-12-09T12:45:06.862+0800: 147091.674: [CMS-concurrent-abortable-preclean-start]  
    20.  CMS: abort preclean due to time 2014-12-09T12:45:11.874+0800: 147096.686: [CMS-concurrent-abortable-preclean: 4.948/5.012 secs] [Times: user=6.04 sys=0.10, real=5.01 secs]   
    21. 2014-12-09T12:45:11.882+0800: 147096.694: [GC[YG occupancy: 815312 K (2867200 K)]147096.695: [Rescan (parallel) , 0.0476710 secs]147096.743: [weak refs processing, 0.1565260 secs]   
    22. [1 <span style="color:#FF0000;"><strong>CMS-remark: 1384080K(1843200K)] 2199393K(4710400K), 0.2064660 secs] [Times: user=0.48 sys=0.00, real=0.20 secs</strong></span>]   
    23. 2014-12-09T12:45:12.091+0800: 147096.903: [CMS-concurrent-sweep-start]  
    24. 2014-12-09T12:45:14.078+0800: 147098.890: [CMS-concurrent-sweep: 1.934/1.986 secs] [Times: user=2.43 sys=0.04, real=1.99 secs]   
    25. 2014-12-09T12:45:14.078+0800: 147098.890: [CMS-concurrent-reset-start]  
    26. 2014-12-09T12:45:14.084+0800: 147098.896: [CMS-concurrent-reset: 0.006/0.006 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]  

     

    我把CMS的initial mark和remark的日志都标记了。

    我们可以看到总共发生了两次CMS，所以Full GC的次数应该是4

    Full GC的时间 = 0.07 secs(第一次initial mark)+ 0.23 secs(第一次remark) + 0.07 secs(第二次initial mark) + 0.20 secs(第二次remark) = 0.57s

     

    用jstat -gc 得到的时间Full GC的次数和时间也是吻合的。

     

    所以jstat是Java官方提供的工具，所以我们可以说得出的结论是和官方的一致的。

    下面是Visual GC的截图，看Old Gen的统计数据： 4 collections, 576.421ms

    再来看一个更加直接的例子，从OpenJDK里面找线索：

    这段代码来自openjdk/hotspot/src/share/vm/services/memoryService.cpp，从代码中可以看到JVM使用了一个_fullGC的布尔值来表示是否是Full GC

    DefNew, ParNew, ASParNew都是新生代的收集器算法，当使用它们时，_fullGC = false

    MarkSweepCompact(Serial Old收集器)， ConcurrentMarkSweep(CMS), ASConcurrentMarkSweep时_fullGC = true。所以只有收集老年代的时候，才算Full GC

     

     

    我们可以安全的说：

    1. Full GC == Major GC指的是对老年代/永久代的stop the world的GC

    2. Full GC的次数 = 老年代GC时 stop the world的次数

    3. Full GC的时间 = 老年代GC时 stop the world的总时间

    4. CMS 不等于Full GC，我们可以看到CMS分为多个阶段，只有stop the world的阶段被计算到了Full GC的次数和时间，而和业务线程并发的GC的次数和时间则不被认为是Full GC

     

    我们可以看到正常的CMS的stop the world的时间很短，都是在几十到几百ms的级别，对Full GC的时间影响很小。但是有时候我们用jstat看到的Full GC的时间很长。比如下面这个例子，和上面的Tomcat是同一个应用，只是是我调优之前的数据。

     

    我们看到调优之前的Full GC的评价时间 = 1188 / 223 = 5秒，也就是说单次Full GC的stop the world的时间达到了5s! 进一步分析日志，得到如下日志：

     

    [html] view plain copy
     
    1. 54090.152: [Full GC (System) 54090.153: [CMS: 1211220K->1428569K(4096000K), 5.4936890 secs] 3483935K->1428569K(7168000K),   
    2. [CMS Perm : 148045K->147921K(262144K)], 5.4963160 secs] [Times: user=5.50 sys=0.00, real=5.50 secs]   
    3. 57696.218: [Full GC (System) 57696.219: [CMS: 1513461K->1213731K(4096000K), 4.7293810 secs] 3283076K->1213731K(7168000K),   
    4. [CMS Perm : 148019K->147881K(262144K)], 4.7317730 secs] [Times: user=4.73 sys=0.00, real=4.74 secs]   
    5. 61301.483: [Full GC (System) 61301.484: [CMS: 1288630K->968887K(4096000K), 4.5720170 secs] 2466308K->968887K(7168000K),   
    6. [CMS Perm : 147996K->147835K(262144K)], 4.5743720 secs] [Times: user=4.57 sys=0.00, real=4.57 secs]   
    7. 64906.588: [Full GC (System) 64906.590: [CMS: 1026456K->1568407K(4096000K), 5.0347600 secs] 3769961K->1568407K(7168000K),   
    8. [CMS Perm : 148004K->147903K(262144K)], 5.0373410 secs] [Times: user=5.02 sys=0.00, real=5.04 secs]   
    9. 68512.160: [Full GC (System) 68512.161: [CMS: 1631217K->838700K(4096000K), 4.7239290 secs] 2552874K->838700K(7168000K),   
    10. [CMS Perm : 148017K->147829K(262144K)], 4.7261610 secs] [Times: user=4.72 sys=0.00, real=4.72 secs]   
    11. 72117.421: [Full GC (System) 72117.423: [CMS: 905025K->1529502K(4096000K), 5.3562640 secs] 3556285K->1529502K(7168000K),   
    12. [CMS Perm : 148049K->147945K(262144K)], 5.3587790 secs] [Times: user=5.36 sys=0.00, real=5.36 secs]   


    我们看到是System.gc引起的Full GC，而老年代的GC时间到达了5秒多，它显示的是CMS，但是实际上不是CMS并发的收集器，而是CMS发生了concurrent mode fail之后退化成了Serial Old收集器，它是单线程的标记-压缩收集器，所以耗时非常的长。

     

     

    最后再次强调一下结论:

     

    1. Full GC == Major GC指的是对老年代/永久代的stop the world的GC

    2. Full GC的次数 = 老年代GC时 stop the world的次数

    3. Full GC的时间 = 老年代GC时 stop the world的总时间

    4. CMS 不等于Full GC，我们可以看到CMS分为多个阶段，只有stop the world的阶段被计算到了Full GC的次数和时间，而和业务线程并发的GC的次数和时间则不被认为是Full GC

    5. Full GC本身不会先进行Minor GC，我们可以配置，让Full GC之前先进行一次Minor GC，因为老年代很多对象都会引用到新生代的对象，先进行一次Minor GC可以提高老年代GC的速度。比如老年代使用CMS时，设置CMSScavengeBeforeRemark优化，让CMS remark之前先进行一次Minor GC。

    京东技术
  • 相关阅读:
    ASP.NET Web API 控制器执行过程(一)
    ASP.NET Web API 控制器创建过程(二)
    ASP.NET Web API 控制器创建过程(一)
    ASP.NET Web API WebHost宿主环境中管道、路由
    ASP.NET Web API Selfhost宿主环境中管道、路由
    ASP.NET Web API 管道模型
    ASP.NET Web API 路由对象介绍
    ASP.NET Web API 开篇示例介绍
    ASP.NET MVC 视图(五)
    ASP.NET MVC 视图(四)
  • 原文地址：https://www.cnblogs.com/wely/p/6198654.html
Copyright © 2011-2022 走看看