CMS收集器产生的问题和解决方案

垃圾收集器长时间停顿，表现在 Web 页面上可能是页面响应码 500 之类的服务器错误问题，如果是个支付过程可能会导致支付失败，将造成公司的直接经济损失，程序员要尽量避免或者说减少此类情况发生。

提升失败（promotion failed）

在 Minor GC 过程中，Survivor Unused 可能不足以容纳 Eden 和另一个 Survivor 中的存活对象， 那么多余的存货对象将被移到老年代， 称为过早提升（Premature Promotion）。 这会导致老年代中短期存活对象的增长， 可能会引发严重的性能问题。

再进一步，如果老年代没有足够的空间放下这些存活对象，或者老年代有足够的空间，但是由于碎片较多，这时如果新生代要转移到老年带的对象比较大，所以，必须尽可能提早触发老年代的CMS回收来避免这个问题（promotion failed时老年代CMS还没有机会进行回收，又放不下转移到老年带的对象，因此会出现下一个问题concurrent mode failure，需要stop-the-wold GC- Serail Old）。

提升失败日志：

2016-01-07T18:54:26.948+0800: 18782.967: [GC2016-04-07T18:54:26.948+0800: 18782.967: [ParNew (promotion failed)? 
Desired survivor size 117833728 bytes, new threshold 10 (max 10)? 
- age?? 1:??? 6141680 bytes,??? 6141680 total? 
- age?? 2:??? 6337936 bytes,?? 12479616 total? 
- age?? 3:???? 549120 bytes,?? 13028736 total? 
- age?? 4:????? 87768 bytes,?? 13116504 total? 
- age?? 5:???? 221384 bytes,?? 13337888 total? 
- age?? 6:???? 934168 bytes,?? 14272056 total? 
- age?? 7:???? 146072 bytes,?? 14418128 total? 
- age?? 8:???? 626064 bytes,?? 15044192 total? 
- age?? 9:???? 398000 bytes,?? 15442192 total? 
- age? 10:???? 429616 bytes,?? 15871808 total? 
: 1969227K->1929200K(2071808K), 0.7452140 secs]2016-01-07T18:54:27.693+0800: 18783.713: [CMS: 1394703K->632845K(2097152K), 4.0993640 secs] 3301676K->632845K(4168960K), [CMS Perm : 77485K->77473K(159744K)], 4.8450240 secs] [Times: user=5.18 sys=0.56, real=4.84 secs]? 
Heap after GC invocations=5847 (full 7):? 
?par new generation?? total 2071808K, used 0K [0x00000006e9c00000, 0x0000000776400000, 0x0000000776400000)? 
??eden space 1841664K,?? 0% used [0x00000006e9c00000, 0x00000006e9c00000, 0x000000075a280000)? 
??from space 230144K,?? 0% used [0x0000000768340000, 0x0000000768340000, 0x0000000776400000)? 
??to?? space 230144K,?? 0% used [0x000000075a280000, 0x000000075a280000, 0x0000000768340000)? 
?concurrent mark-sweep generation total 2097152K, used 632845K [0x0000000776400000, 0x00000007f6400000, 0x00000007f6400000)? 
?concurrent-mark-sweep perm gen total 159744K, used 77473K [0x00000007f6400000, 0x0000000800000000, 0x0000000800000000)? 
}

解决方案：

• 针对一些大的朝生熄灭的对象，Surivor空间存放不下，就会存放到老年代，针对这种情况，可以扩大Survivor空间。
• 老年代空间碎片，无法放下大对象，就在进行一定次数的Full GC（标记清除）的时候进行一次标记整理算法。

并发模式失败（concurrent mode failure）

由于cms的无法处理浮动垃圾（Floating Garbage）引起的。这个跟cms的机制有关。cms的并发清理阶段，用户线程还在运行，因此不断有新的垃圾产生，而这些垃圾不在这次清理标记的范畴里头，cms无法在本次gc清除掉，这些就是浮动垃圾。由于这种机制，cms年老代回收的阈值不能太高，否则就容易预留的内存空间很可能不够(因为本次gc同时还有浮动垃圾产生)，从而导致concurrent mode failure发生。可以通过-XX:CMSInitiatingOccupancyFraction的值来调优。

日志：

2016-02-21T13:53:07.974+0800: 171467.254: [GC [1 CMS-initial-mark: 1436199K(1560576K)] 1512927K(2504320K), 0.0618140 secs] [Times: user=0.06 sys=0.00, real=0.07 secs]? 
2016-02-21T13:53:08.036+0800: 171467.316: [CMS-concurrent-mark-start]? 
2016-02-21T13:53:08.377+0800: 171467.657: [CMS-concurrent-mark: 0.340/0.340 secs] [Times: user=2.11 sys=0.15, real=0.34 secs]? 
2016-02-21T13:53:08.377+0800: 171467.657: [CMS-concurrent-preclean-start]? 
2016-02-21T13:53:08.385+0800: 171467.665: [CMS-concurrent-preclean: 0.008/0.008 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]? 
2016-02-21T13:53:08.385+0800: 171467.665: [CMS-concurrent-abortable-preclean-start]? 
{Heap before GC invocations=88667 (full 45):? 
?par new generation?? total 943744K, used 914399K [0x0000000757000000, 0x0000000797000000, 0x0000000797000000)? 
??eden space 838912K, 100% used [0x0000000757000000, 0x000000078a340000, 0x000000078a340000)? 
??from space 104832K,? 72% used [0x000000078a340000, 0x000000078ecf7d98, 0x00000007909a0000)? 
??to?? space 104832K,?? 0% used [0x00000007909a0000, 0x00000007909a0000, 0x0000000797000000)? 
?concurrent mark-sweep generation total 1560576K, used 1436199K [0x0000000797000000, 0x00000007f6400000, 0x00000007f6400000)? 
?concurrent-mark-sweep perm gen total 159744K, used 78413K [0x00000007f6400000, 0x0000000800000000, 0x0000000800000000)? 
2016-02-21T13:53:09.535+0800: 171468.815: [GC2016-02-21T13:53:09.535+0800: 171468.815: [ParNew? 
Desired survivor size 53673984 bytes, new threshold 6 (max 6)? 
- age?? 1:??? 7100568 bytes,??? 7100568 total? 
- age?? 2:??? 4676456 bytes,?? 11777024 total? 
- age?? 3:??? 8773736 bytes,?? 20550760 total? 
- age?? 4:??? 7709744 bytes,?? 28260504 total? 
- age?? 5:?? 10891960 bytes,?? 39152464 total? 
- age?? 6:?? 11735032 bytes,?? 50887496 total? 
: 914399K->75616K(943744K), 0.0414860 secs] 2350599K->1517225K(2504320K), 0.0417710 secs] [Times: user=0.32 sys=0.05, real=0.05 secs]? 
Heap after GC invocations=88668 (full 45):? 
?par new generation?? total 943744K, used 75616K [0x0000000757000000, 0x0000000797000000, 0x0000000797000000)? 
??eden space 838912K,?? 0% used [0x0000000757000000, 0x0000000757000000, 0x000000078a340000)? 
??from space 104832K,? 72% used [0x00000007909a0000, 0x0000000795378128, 0x0000000797000000)? 
??to?? space 104832K,?? 0% used [0x000000078a340000, 0x000000078a340000, 0x00000007909a0000)? 
?concurrent mark-sweep generation total 1560576K, used 1441609K [0x0000000797000000, 0x00000007f6400000, 0x00000007f6400000)? 
?concurrent-mark-sweep perm gen total 159744K, used 78413K [0x00000007f6400000, 0x0000000800000000, 0x0000000800000000)? 
}? 
2016-02-21T13:53:10.202+0800: 171469.482: [CMS-concurrent-abortable-preclean: 1.772/1.817 secs] [Times: user=4.94 sys=0.06, real=1.81 secs]? 
2016-02-21T13:53:10.204+0800: 171469.483: [GC[YG occupancy: 497152 K (943744 K)]2016-02-21T13:53:10.204+0800: 171469.483: [Rescan (parallel) , 1.3691900 secs]2016-02-21T13:53:11.573+0800: 171470.853: [weak refs processing, 0.1009300 secs]2016-02-21T13:53:11.674+0800: 1714? 
70.954: [class unloading, 0.0153470 secs]2016-02-21T13:53:11.689+0800: 171470.969: [scrub symbol table, 0.0110770 secs]2016-02-21T13:53:11.700+0800: 171470.980: [scrub string table, 0.0016360 secs] [1 CMS-remark: 1441609K(1560576K)] 1938761K(2504320K), 1.5079530 secs] [Ti? 
mes: user=13.01 sys=0.08, real=1.51 secs]? 
2016-02-21T13:53:11.712+0800: 171470.992: [CMS-concurrent-sweep-start]? 
{Heap before GC invocations=88668 (full 45):? 
?par new generation?? total 943744K, used 914528K [0x0000000757000000, 0x0000000797000000, 0x0000000797000000)? 
??eden space 838912K, 100% used [0x0000000757000000, 0x000000078a340000, 0x000000078a340000)? 
??from space 104832K,? 72% used [0x00000007909a0000, 0x0000000795378128, 0x0000000797000000)? 
??to?? space 104832K,?? 0% used [0x000000078a340000, 0x000000078a340000, 0x00000007909a0000)? 
?concurrent mark-sweep generation total 1560576K, used 1441606K [0x0000000797000000, 0x00000007f6400000, 0x00000007f6400000)? 
?concurrent-mark-sweep perm gen total 159744K, used 78413K [0x00000007f6400000, 0x0000000800000000, 0x0000000800000000)? 
2016-02-21T13:53:11.775+0800: 171471.055: [GC2016-02-21T13:53:11.775+0800: 171471.055: [ParNew (promotion failed)? 
Desired survivor size 53673984 bytes, new threshold 6 (max 6)? 
- age?? 1:??? 4030872 bytes,??? 4030872 total? 
- age?? 2:??? 5959704 bytes,??? 9990576 total? 
- age?? 3:??? 4628680 bytes,?? 14619256 total? 
- age?? 4:??? 8773080 bytes,?? 23392336 total? 
- age?? 5:??? 7707144 bytes,?? 31099480 total? 
- age?? 6:?? 10890224 bytes,?? 41989704 total? 
: 914528K->907344K(943744K), 1.0312010 secs]2016-02-21T13:53:12.807+0800: 171472.086: [CMS2016-02-21T13:53:14.455+0800: 171473.735: [CMS-concurrent-sweep: 1.684/2.743 secs] [Times: user=3.69 sys=0.36, real=2.74 secs]? 
?(concurrent mode failure): 1451903K->475795K(1560576K), 3.9644230 secs] 2356134K->475795K(2504320K), [CMS Perm : 78413K->78413K(159744K)], 4.9959570 secs] [Times: user=5.65 sys=0.34, real=5.00 secs]? 
Heap after GC invocations=88669 (full 46):? 
?par new generation?? total 943744K, used 0K [0x0000000757000000, 0x0000000797000000, 0x0000000797000000)? 
??eden space 838912K,?? 0% used [0x0000000757000000, 0x0000000757000000, 0x000000078a340000)? 
??from space 104832K,?? 0% used [0x000000078a340000, 0x000000078a340000, 0x00000007909a0000)? 
??to?? space 104832K,?? 0% used [0x00000007909a0000, 0x00000007909a0000, 0x0000000797000000)? 
?concurrent mark-sweep generation total 1560576K, used 475795K [0x0000000797000000, 0x00000007f6400000, 0x00000007f6400000)? 
?concurrent-mark-sweep perm gen total 159744K, used 78413K [0x00000007f6400000, 0x0000000800000000, 0x0000000800000000)? 
}

解决方案：

• CMS并发清理阶段，用户线程在年轻代中产生大量对象，大量年轻代中的对象要提升到老年代，老年代的清理速度赶不上年轻代的提升速度，就会造成concurrent mode failure,针对这个问题，
  • 扩大年轻代的空间，提升年轻代的晋升阈值
  • 扩大老年代的空间存放年轻代要晋升的对象，设置 CMS 垃圾收集在老年代占比达到多少时启动来减少问题发生频率（越早启动问题发生频率越低，但是会降低吞吐量，具体得多调整几次找到平衡点）
• CMS并发清理阶段，年轻代提升上来的大对象，老年代碎片化严重，存放不下，针对这个问题，
  • 一定次数的Full GC（标记清除）的时候进行一次标记整理算法。

总结：

1. promotion failed造成Full GC，也可能会进一步造成 concurrent mode failure

2. 注意要尽量避免concurrent mode failure，因为这样会是 CMS收集器转化为Serial Old收集器,Serial Old收集器虽然会压缩老年代空间，但是这个收集器整个过程都是STOP THE World

参考：

JVM 调优 —— GC 长时间停顿问题及解决方法

使用CMS垃圾收集器产生的问题和解决方案

CMS收集器产生的问题和解决方案

原文：https://www.cnblogs.com/hongdada/p/10489643.html