学习JVM，或许你已经看了一大堆概念：新生代、老年代、GC、CMS...，可能你已经背的滚瓜烂熟，牢记于心，只等谁来考你。
但是，知识，永远只是知识；文字，只能是文字。我们人类的最佳理解方式是经验，只有我们经验到了，才能叫我们掌握了这个知识，看懂了这段文字。也就是所谓的知行合一。
那么，怎么做到知行合一呢？
在学习编程的过程中，对一个概念有了感性的认识就可以叫知行合一。
什么叫感性的认识呢？
比如，甜味，你尝一下糖，就算感性认识到了什么叫甜。同理，你看一下GC日志，就可以感性认识到JVM的GC过程。
软件就是这么个东西，全都不是实物，很难感性认识到，所以也就很难学习。每次过年回家我都会和亲戚进行一场这样的对话。你那个工作是不是做一些电脑零件啊什么的？不是，我做的是软件，是运行在电脑上的。那还是电脑上的东西吧？嗯...额，算是吧，是存到电脑上，运行在电脑上的。那不还是电脑的一部分，还是电脑零件啊。嗯...额，是，是电脑零件。
好了，言归正传，我们一起来看GC日志吧。
首先，是一段正常运行的GC日志：
# 注意GC日志的格式
2017-11-29T06:20:08.854+0800: 136737.156: [GC2017-11-29T06:20:08.854+0800: 136737.156:[ParNew: 3892864K->432512K(3892864K), 4.4839200 secs] 18183136K->16699325K(21194368K), 4.4841330 secs] [Times: user=81.77 sys=3.94, real=4.48 secs]
# NO.1 GC event开始的时间点 : GC时间的开始时间,相对于JVM的启动时间,单位是秒
# NO.2 新生代使用 ParNew 并行回收器，GC回收后被占用空间从3892864K降到432512K，新生代总容量为3892864K，耗时4秒
# NO.3 垃圾收集前整个heap区内存空间使用情况->垃圾收集后整个heap区内存空间使用情况, 回收时间
# NO.4 GC事件的持续时间Times
user=垃圾收集线程消耗的所有CPU时间
sys=操作系统调用(OS call) 以及等待系统事件的时间
real=应用程序暂停的时间(Clock time), 所以 real time 等于 user 以及 sys的总和
GC日志一般都是这样的格式，精简至极，但该有的内容都有。
再看一段异常日志：
# 注意，下面出现异常(concurrent mode failure)
2017-11-29T06:20:15.538+0800: 136743.840: [GC2017-11-29T06:20:15.538+0800: 136743.841: [ParNew: 3892864K->3892864K(3892864K)3.7G, 0.0000330 secs]2017-11-29T06:20:15.538+0800: 136743.841: [CMS2017-11-29T06:20:34.452+0800: 136762.754: [CMS-concurrent-sweep: 19.039/19.042 secs] [Times: user=15.39 sys=4.18, real=19.05 secs](concurrent mode failure): 16210334K->10864227K(17301504K), 100.7676160 secs] 20103198K->10864227K(21194368K), [CMS Perm : 80725K->80722K(262144K)], 100.7678560 secs][Times: user=68.79 sys=31.64, real=100.77 secs]
# 让我们来分析下这段日志
# [ParNew: young区回收情况, 回收前3892864K, 回收后依然是3892864K, 显然, Young区已无内存可以分配，此时便会发生Full GC。
# 还有一种情况也会引发 Full GC : CMS采用多线程和应用线程并发执行, 以减少应用停顿时间, 但是, 当 old区内存不足, 没办法回收无引用的对象时, 自然也会发生Full GC
无论哪种情况, 都需要合理设置各代大小。若像当前这种由于young区空间不足以满足
# [CMS-concurrent-sweep: (concurrent mode failure):
一般情况下，单次YGCT<0.020 s，FGCT <0.040 s
看CMS回收器怎么进行老年代回收：
# 开始使用CMS回收器进行老年代回收
2017-11-29T06:21:56.349+0800: 136844.651: [GC [1 CMS-initial-mark: 10864227K(17301504K)] 10938969K(21194368K), 0.0303920 secs] [Times: user=0.03 sys=0.00, real=0.03 secs]
# 初始标记阶段, 标记由根可以直接到达的对象，标记期间整个应用线程会暂停。老年代总量为17301504K，被占用10864227K；整个heap总量为21194368K，被占用10938969K
2017-11-29T06:21:56.379+0800: 136844.682: [CMS-concurrent-mark-start]
# 并发标记，在第一个阶段被暂停的线程重新开始运行，由前一阶段标记过的对象出发，所有可到达的对象都在本阶段中标记
2017-11-29T06:22:03.147+0800: 136851.449: [CMS-concurrent-mark: 6.734/6.768 secs] [Times: user=52.26 sys=5.69, real=6.77 secs]
# 并发标记阶段结束, 占用 6.734秒CPU时间, 6.768秒墙钟时间(也包含线程让出CPU给其他线程执行的时间)
2017-11-29T06:22:03.147+0800: 136851.449: [CMS-concurrent-preclean-start]
# 并发预清理阶段, 预清理也是一个并发执行的阶段。在本阶段, 会查找前一阶段执行过程中, 从新生代晋升或新分配或被更新的对象。通过并发地重新扫描这些对象, 预清理阶段可以减少下一个stop-the-world 重新标记阶段的工作量。
2017-11-29T06:22:03.383+0800: 136851.685: [CMS-concurrent-preclean: 0.227/0.235 secs] [Times: user=0.56 sys=0.14, real=0.24 secs]
# 预清理阶段费时 0.017秒CPU时间，0.018秒墙钟时间。
2017-11-29T06:22:03.383+0800: 136851.685: [CMS-concurrent-abortable-preclean-start]
# 并发可中止预清理阶段。 可中止预清理阶段，运行在并行预清理和重新标记之间，直到获得所期望的eden空间占用率。增加这个阶段是为了避免在重新标记阶段后紧跟着发生一次垃圾清除。为了尽可能区分开垃圾清除和重新标记 ，我们尽量安排在两次垃圾清除之间运行重新标记阶段。
2017-11-29T06:22:04.099+0800: 136852.401: [GC2017-11-29T06:22:04.099+0800: 136852.401: [ParNew: 3460352K->432512K(3892864K), 1.1155530 secs] 14324579K->11784267K(21194368K), 1.1158800 secs] [Times: user=22.26 sys=0.85, real=1.13 secs]
# 竟然发生了一次ParNew GC
CMS: abort preclean due to time 2017-11-29T06:22:05.226+0800: 136853.528: [CMS-concurrent-abortable-preclean: 0.215/1.843 secs] [Times: user=23.59 sys=1.14, real=1.84secs]
# 并发可中止预清理阶段费时 0.215秒CPU时间，1.843秒墙钟时间。
2017-11-29T06:22:05.230+0800: 136853.532: [GC[YG occupancy: 456818 K (3892864 K)]2017-11-29T06:22:05.230+0800: 136853.532: [Rescan (parallel), 0.2224280 secs]2017-11-29T06:22:05.452+0800: 136853.755: [weak refs processing, 0.0002010 secs]2017-11-29T06:22:05.452+0800: 136853.755: [class unloading, 0.0199850 secs]2017-11-29T06:22:05.472+0800: 136853.775: [scrub symbol table, 0.0098660 secs]2017-11-29T06:22:05.482+0800: 136853.785: [scrub string table, 0.0016960 secs] [1 CMS-remark: 11351755K(17301504K)] 11808574K(21194368K), 0.2586050 secs] [Times: user=4.98 sys=0.06, real=0.26 secs]
# 重新标记, Stop-the-world 阶段,从根及被其引用对象开始，重新扫描 CMS 堆中残留的更新过的对象。这里重新扫描费时0.1790103秒，处理弱引用对象费时0.0100966秒，本阶段费时0.1897792 秒。
# Rescan (parallel)表示的是多线程处理young区和多线程扫描old+perm的卡表的总时间
# weak refs processing 处理old区的弱引用的总时间, 用于回收native memory
# class unloading 回收SystemDictionary消耗的总时间
2017-11-29T06:22:05.489+0800: 136853.791: [CMS-concurrent-sweep-start]
# 并发清理开始, 在清理阶段，应用线程还在运行。
2017-11-29T06:22:17.665+0800: 136865.967: [CMS-concurrent-sweep: 12.113/12.176 secs] [Times: user=18.13 sys=5.14, real=12.18 secs]
# 并发清理阶段耗时12.18秒
2017-11-29T06:22:17.665+0800: 136865.967: [CMS-concurrent-reset-start]
# 并发重置开始
2017-11-29T06:22:17.772+0800: 136866.074: [CMS-concurrent-reset: 0.107/0.107 secs] [Times: user=0.05 sys=0.06, real=0.10 secs]
# 并发重置阶段耗时
2017-11-29T06:22:19.775+0800: 136868.078: [GC [1 CMS-initial-mark: 11335708K(17301504K)]14506257K(21194368K), 5.3840860 secs] [Times: user=4.87 sys=0.50, real=5.38 secs]
# 在本阶段，重新初始化CMS内部数据结构，以备下一轮 GC 使用
2017-11-29T06:22:25.160+0800: 136873.462: [CMS-concurrent-mark-start]
2017-11-29T06:22:32.594+0800: 136880.896: [CMS-concurrent-mark: 7.434/7.434 secs] [Times: user=40.03 sys=4.51, real=7.44 secs]
2017-11-29T06:22:32.594+0800: 136880.896: [CMS-concurrent-preclean-start]
2017-11-29T06:22:32.681+0800: 136880.984: [CMS-concurrent-preclean: 0.087/0.087 secs] [Times: user=0.08 sys=0.01, real=0.08 secs]
2017-11-29T06:22:32.681+0800: 136880.984: [CMS-concurrent-abortable-preclean-start]
CMS: abort preclean due to time 2017-11-29T06:22:38.443+0800: 136886.745: [CMS-concurrent-abortable-preclean: 5.761/5.761 secs] [Times: user=5.50 sys=0.29, real=5.77secs]
CMS大讲堂：
CMS(Concurrent Mark-Sweep)是以牺牲吞吐量为代价来获得最短回收停顿时间的垃圾回收器。对于要求服务器响应速度的应用上，这种垃圾回收器非常适合。在启动JVM参数加上-XX:+UseConcMarkSweepGC ，这个参数表示对于老年代的回收采用CMS。CMS采用的基础算法是：标记—清除。
CMS过程
1. 初始标记：在这个阶段，需要虚拟机停顿正在执行的任务，官方的叫法STW(Stop The Word)。这个过程从垃圾回收的”根对象”开始，只扫描到能够和”根对象”直接关联的对象，并作标记。所以这个过程虽然暂停了整个JVM，但是很快就完成了。
- 并发标记：这个阶段紧随初始标记阶段，在初始标记的基础上继续向下追溯标记。并发标记阶段，应用程序的线程和并发标记的线程并发执行，所以用户不会感受到停顿。
3. 并发预清理：并发预清理阶段仍然是并发的。在这个阶段，虚拟机查找在执行并发标记阶段新进入老年代的对象(可能会有一些对象从新生代晋升到老年代， 或者有一些对象被分配到老年代)。通过重新扫描，减少下一个阶段”重新标记”的工作，因为下一个阶段会Stop The World。
4. 重新标记：这个阶段会暂停虚拟机，收集器线程扫描在CMS堆中剩余的对象。扫描从”跟对象”开始向下追溯，并处理对象关联。
5. 并发清理：清理垃圾对象，这个阶段收集器线程和应用程序线程并发执行。
6. 并发重置：这个阶段，重置CMS收集器的数据结构，等待下一次垃圾回收。
CMS执行过程：
图
CMS缺点
CMS回收器采用的基础算法是Mark-Sweep。所有CMS不会整理、压缩堆空间。这样就会有一个问题：经过CMS收集的堆会产生空间碎片。
下面博客中 Jon 详细讨论了如何处理碎片问题：https://blogs.oracle.com/jonthecollector/entry/when_the_sum_of_the
需要更多的CPU资源。从上面的图可以看到，为了让应用程序不停顿，CMS线程和应用程序线程并发执行，这样就需要有更多的CPU，单纯靠线程切换是不靠谱的。
什么时候用CMS
如果你的应用程序对停顿比较敏感，并且在应用程序运行的时候可以提供更大的内存和更多的CPU(也就是硬件牛逼)，那么使用CMS来收集会给你带来好处。还有，如果在JVM中，有相对较多存活时间较长的对象(老年代比较大)会更适合使用CMS。
