CMS GC 垃圾回收详解

前言

转载请注明来源

      本篇不是一篇详细的教学,不会去介绍JVM内存模型相关的知识点,虽然这是理解GC必须的知识点,学习了解GC算法前,可以先吃一波我的安利:<深入理解Java虚拟机>,这本书作为对Java虚拟机的入门书是非常非常好的,同时,本篇也偏向于个人的一个笔记(目前个人水平有限,做不到对CMS GC 以及 JVM相关知识做系统性的详细解读),仅提供一种直观的方式去展示以及解析CMS GC是如何运作的.

      HotSpot JVM的并发标记清理收集器(CMS收集器)的主要目标就是:低应用停顿时间。该目标对于大多数交互式应用很重要,比如web应用.CMS GC收集器被设计成了大部分时间可与应用程序线程并行执行,只会停顿一小会时间(停止整个应用,下面会用Stop The World(STW)代替).

CMS GC 的 6个过程:

1.初始标记:为了收集应用程序的对象引用需要暂停应用程序线程,该阶段完成后,应用程序线程再次启动。
2.并发标记:从第一阶段收集到的对象引用开始,遍历所有其他的对象引用。
3.并发预清理:改变当运行第二阶段时,由应用程序线程产生的对象引用,以更新第二阶段的结果。
4.重标记:由于第三阶段是并发的,对象引用可能会发生进一步改变。因此,应用程序线程会再一次
被暂停以更新这些变化,并且在进行实际的清理之前确保一个正确的对象引用视图。
这一阶段十分重要,因为必须避免收集到仍被引用的对象。
5.并发清理:所有不再被应用的对象将从堆里清除掉。
6.并发重置:收集器做一些收尾的工作,以便下一次GC周期能有一个干净的状态。

其中4个阶段(名字以Concurrent开始的)与实际的应用程序是并发执行的,
而其他2个阶段需要暂停应用程序线程(STW).

接下来就通过一段代码来触发并展示CMS GC的过程.

public class GCTest {

    private static final int _10MB = 10 * 1024 * 1024;

    /**
     * @param args
     * @throws InterruptedException
     */
    public static void main(String[] args) throws Exception {
        test();

    }

    /**
     * VM arg: -Xms100m(设置最大堆内存) -Xmx100m(设置初始堆内存) 
     * -Xmn50m(设置新生代大小)
     * -XX:+PrintGCDetails(打印GC日志详细信息) 
     * -XX:+UseConcMarkSweepGC (采用 cms gc算法)
     * -XX:+UseParNewGC (新生代采用并行GC方式,
     * 高版本的jdk使用了UseConcMarkSweepGC参数时 这个参数会自动开启)
     * -XX:SurvivorRatio=8 (新生代eden区与survivor区空间比例8:1,
     * eden:fromsurvivor:tosurvivor -->8:1:1)
     * -XX:MaxTenuringThreshold=1 (用于控制对象能经历多少次
     * Minor GC(young gc)才晋升到老年代,默认15次)
     * -XX:+PrintTenuringDistribution(输出survivor区幸存对象的年龄分布)
     * -XX:CMSInitiatingOccupancyFraction=68 *(设置老年代空间使用率多少时触发第一次cms *gc,默认68%)
     * @throws InterruptedException
     */
    public static void test() throws InterruptedException {
        List<byte[]> list = new ArrayList<>();
        for (int n = 1; n < 8; n++) {
            byte[] alloc = new byte[_10MB];
            list.add(alloc);
        }
        Thread.sleep(Integer.MAX_VALUE);

    }

}

执行展示

D:\platform\svn\demo>java -Xms100m -Xmx100m -Xmn50m -XX:+PrintGCDetails 
-XX:+UseConcMarkSweepGC -XX:SurvivorRatio=8 -XX:MaxTenuringThreshold=1 
-XX:+PrintTenuringDistribution GCTest
[GC (Allocation Failure) 
[ParNew Desired survivor size 2621440 bytes, new threshold 1 (max 1)
- age   1:     636784 bytes,     636784 total: 33997K->632K(46080K), 0.0105313 secs] 
33997K->31354K(97280K), 0.0107013 secs]
[Times: user=0.01 sys=0.00, real=0.01 secs]
//step 1,young gc,新生代没有空间存入新对象,则发生young gc(也叫 minor gc),
//33997K->632K(46080K), 0.0105313 secs]新生代由33997K gc后变成了632K,
//整个heap区情况: 33997K->31354K(97280K)
//新生代的对象copy(新生代采用的是复制算法收集内存)到survivor区,
//但此处survivor容纳不下,则直接copy到了老年代中大小(可以设置多大的对象直接升级到老年代中,
//参数XX:PretenureSizeThreshold=<value>)
[GC (Allocation Failure) [ParNew: 32961K->32961K(46080K), 0.0001067 secs]
[CMS: 30722K->40960K(51200K), 0.0111639 secs] 63683K->62060K(97280K), 
[Metaspace: 2509K->2509K(1056768K)], 0.0118014 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]
//step 2,老年代空间占用大小占比达到阈值,触发第一次老年代GC,即CMS GC
//CMS: 30722K->40960K(51200K): 老年代由30722K变为40960K,总大小51200K
[GC (CMS Initial Mark) [1 CMS-initial-mark: 40960K(51200K)] 72995K(97280K), 0.0004270 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
//step 3 初始标记
[CMS-concurrent-mark-start]
[CMS-concurrent-mark: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
//step 4 并发标记
[CMS-concurrent-preclean-start]
[CMS-concurrent-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
//step 5 并发预清理
[CMS-concurrent-abortable-preclean-start]
[CMS-concurrent-abortable-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
[GC (CMS Final Remark) [YG occupancy: 32035 K (46080 K)][Rescan (parallel) , 0.0003930 secs]
//step 6重标记 
[weak refs processing, 0.0000436 secs][class unloading, 0.0001861 secs]
[scrub symbol table, 0.0003188 secs]
[scrub string table, 0.0000946 secs]
//weak refs processing 处理old区的弱引用,用于回收native memory
class unloading 回收SystemDictionary
[1 CMS-remark:40960K(51200K)] 72995K(97280K), 0.0013492 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
[CMS-concurrent-sweep-start]
[CMS-concurrent-sweep: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
//step 7 并发清理
[CMS-concurrent-reset-start]
[CMS-concurrent-reset: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
//step 8 并发重置
Heap
 par new generation   total 46080K, used 32445K [0x00000000f9c00000, 0x00000000fce00000, 0x00000000fce00000)
  eden space 40960K,  79% used [0x00000000f9c00000, 0x00000000fbbaf5b0, 0x00000000fc400000)
  from space 5120K,   0% used [0x00000000fc900000, 0x00000000fc900000, 0x00000000fce00000)
  to   space 5120K,   0% used [0x00000000fc400000, 0x00000000fc400000, 0x00000000fc900000)
 concurrent mark-sweep generation total 51200K, used 40960K [0x00000000fce00000, 0x0000000100000000, 0x0000000100000000)
 Metaspace       used 2515K, capacity 4486K, committed 4864K, reserved 1056768K
  class space    used 269K, capacity 386K, committed 512K, reserved 1048576K

相应的注释都详细标注了,现在解读一下GC日志:
基本上都是这种格式:回收前区域占用的大小->回收后区域占用的大小(区域设置的大小),耗时.
现在取step2 这部分日志做一个全面的分析作为解读GC日志的典型:

[GC (Allocation Failure) [ParNew: 32961K->32961K(46080K), 0.0001067 secs]
[CMS: 30722K->40960K(51200K), 0.0111639 secs] 63683K->62060K(97280K), 
[Metaspace: 2509K->2509K(1056768K)], 0.0118014 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]
[ParNew: 32961K->32961K(46080K), 0.0001067 secs]

ParNew 表明新生代是并行方式进行GC,

串行收集器:
DefNew:是使用-XX:+UseSerialGC(新生代,老年代都使用串行回收收集器)。
并行收集器:
ParNew:是使用-XX:+UseParNewGC(新生代使用并行收集器,老年代使用串行回收收集器)或者-XX:+UseConcMarkSweepGC(新生代使用并行收集器,老年代使用CMS)。
PSYoungGen:是使用-XX:+UseParallelOldGC(新生代,老年代都使用并行回收收集器)或者-XX:+UseParallelGC(新生代使用并行回收收集器,老年代使用串行收集器)
garbage-first heap:是使用-XX:+UseG1GC(G1收集器)

32961K->32961K(46080K) 新生代大小由32961K变成32961K,总大小为46080K,young gc 耗时 0.0001067 secs.

[CMS: 30722K->40960K(51200K), 0.0111639 secs]

CMS:表明是老年代堆区(因为CMS只作用于老年代),

 63683K->62060K(97280K)

heap 区情况,

[Metaspace: 2509K->2509K(1056768K)]

Metaspace :元空间是jdk 8 的新特性,可简单理解为其替换了8 之前的永久代PermGen Space(方法区).
方法区是JVM的规范,而永久代则是JVM规范的一种实现,元空间也是方法区的一种实现.

[Times: user=0.02 sys=0.00, real=0.02 secs]

这里的user,sys,real 与 linux的time 命令所输出的时间含义一致,分别代表用户太消耗的CPU时间,内核态消耗的CPU时间,和操作从开始到结束所经过的墙钟时间---引用自<深入理解Java虚拟机> 3.5.8 理解GC日志.

实际上到这里整个过程就完成的差不多了,但是我在执行过程中,又发现了一个有趣的东西,就是concurrent mode failure情况,当我new 出的对象超过了堆内存的最大内存后会发生OOM时,就出现concurrent mode failure,GC日志如下:

[GC [ParNew: 31539K->496K(46080K), 0.0137601 secs] 31539K->31218K(97280K), 0.0152885 secs] 
[Times: user=0.02 sys=0.00, real=0.02 secs]
[GC [ParNew: 33275K->33275K(46080K), 0.0003866 secs][CMS: 30722K->40960K(51200K), 0.0217084 secs]
63997K->61912K(97280K), [CMS Perm : 2534K->2532K(21248K)], 0.0231226 secs] 
[Times: user=0.02 sys=0.00, real=0.02 secs]
[GC [1 CMS-initial-mark: 40960K(51200K)] 72152K(97280K), 0.0004554 secs]
 [Times: user=0.00 sys=0.00, real=0.00 secs]
[Full GC [CMS[CMS-concurrent-mark: 0.010/0.011 secs] 
[Times: user=0.00 sys=0.00, real=0.01 secs]
 (concurrent mode failure): 40960K->40960K(51200K), 0.0159043 secs] 72152K->72152K(97280K), [CMS Perm : 2532K->2532K(21248K)], 0.0165056 secs] [Times: user=0.01 sys=0.00, real=0.02 secs]
[Full GC [CMS: 40960K->40960K(51200K), 0.0075621 secs] 
72152K->72138K(97280K), [CMS Perm : 2532K->2532K(21248K)], 0.0084089 secs]
[Times: user=0.00 sys=0.00, real=0.01 secs]
Exception in thread "main" java.lang.OutOfMemoryError: Java heap space
        at GCTest.test(GCTest.java:19)
        at GCTest.main(GCTest.java:12)

造成这种情况的原因是:在执行CMS GC的过程中同时有对象要放入旧生代,而此时老年代空间不足造成的。
同样的情况还有promotion failed这种情形,这是由于在进行Minor GC(young gc)时,survivor space放不下、对象只能放入老年代,而此时老年代也放不下造成的.

结束

Java 9 也出来了一段时间了,Java9的默认gc算法是G1算法,之前有学习过G1 gc,但没有真正的使用过,时间充裕的话,接下来的一篇应该会是G1 gc 的学习笔记.

最后编辑于
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 203,324评论 5 476
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 85,303评论 2 381
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 150,192评论 0 337
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 54,555评论 1 273
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 63,569评论 5 365
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 48,566评论 1 281
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 37,927评论 3 395
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 36,583评论 0 257
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 40,827评论 1 297
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 35,590评论 2 320
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 37,669评论 1 329
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 33,365评论 4 318
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 38,941评论 3 307
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 29,928评论 0 19
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 31,159评论 1 259
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 42,880评论 2 349
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 42,399评论 2 342

推荐阅读更多精彩内容