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垃圾收集器產生的問題和解決方案