這個(gè)是之前處理過的一個(gè)線上問題,處理過程斷斷續(xù)續(xù),經(jīng)歷了兩周多的時(shí)間,中間各種嘗試,總結(jié)如下。這篇文章分三部分:
1、問題的場景和處理過程;2、GC的一些理論東西;3、看懂GC的日志
先說一下問題吧
問題場景:線上機(jī)器在半夜會(huì)推送一個(gè)700M左右的數(shù)據(jù),這個(gè)時(shí)候有個(gè)數(shù)據(jù)置換的過程,也就是說有700M*2的數(shù)據(jù)在heap區(qū)域中,線上系統(tǒng)超時(shí)比較多,導(dǎo)致了很嚴(yán)重(嚴(yán)重程度就不說了)的問題。
問題原因:看日志,系統(tǒng)接口超時(shí)的時(shí)候,系統(tǒng)出現(xiàn)了FullGC,這個(gè)時(shí)候stop-the-world了,也就停機(jī)了。分析gc的日志,發(fā)現(xiàn)有promotion failed,根據(jù)FullGC觸發(fā)的條件,這個(gè)時(shí)候就會(huì)出現(xiàn)FullGC了。日志如下:
1
2 |
2013 - 11 -27T03: 00 : 53.638 + 0800 : 35333.562 : [GC 35333.562 : [ParNew (promotion failed): 1877376K->1877376K(1877376K), 15.7989680 secs] 35349.361 : [CMS: 2144171K->2129287K(2146304K), 10.4200280 sec
s] 3514052K->2129287K(4023680K), [CMS Perm : 119979K->118652K(190132K)], 26.2193500 secs] [Times: user= 30.35 sys= 5.19 , real= 26.22 secs]
|
問題解決:中間調(diào)整過幾次,先搞了幾臺(tái)機(jī)器做了驗(yàn)證,后來逐步推廣的。
1、調(diào)大heap區(qū),由原來的4g,調(diào)整到5g,young區(qū)的大小不變,還是2g,這時(shí)候old區(qū)就由2g變?yōu)?g了(這樣保證old區(qū)有足夠的空間);
2、設(shè)置-XX:UseCMSInitiatingOccupancyOnly,其實(shí)這個(gè)不關(guān)這個(gè)問題,只是發(fā)現(xiàn)半夜CMS進(jìn)行的有點(diǎn)頻繁,就禁止掉了悲觀策略;
3、設(shè)置CMS區(qū)回收的比例,從80%調(diào)整到75%,讓old區(qū)盡早的進(jìn)行,有足夠的空間剩余;
為什么要有GC(垃圾回收)?
JVM通過GC來回收堆和方法區(qū)中的內(nèi)存,GC的基本原理就是找到程序中不再被使用的對象,然后回收掉這些對象占用的內(nèi)存。
主要的收集器有哪些?
引用計(jì)數(shù)器和跟蹤計(jì)數(shù)器兩種。
引用計(jì)數(shù)器記錄對象是否被引用,當(dāng)計(jì)數(shù)器為零時(shí),說明對象已經(jīng)不再被使用,可以進(jìn)行回收。java中的對象有復(fù)雜的引用關(guān)系,不是很適合引用計(jì)數(shù)器,所以sun jdk中并沒有實(shí)現(xiàn)這種GC方式。
跟蹤收集器,全局記錄數(shù)據(jù)的引用狀態(tài),基于一定的條件觸發(fā)。執(zhí)行的時(shí)候,從根集合開始掃描對象的引用關(guān)系,主要有復(fù)制(copying)、標(biāo)記-清除(Mark-Sweep)、標(biāo)記-壓縮(Mark-Compact)那種算法。
跟蹤計(jì)數(shù)器的三種算法簡介?
復(fù)制:從根集合搜掃描出存活的對象,然后將存活的對象復(fù)制到一塊新的未使用的空間中,當(dāng)要回收的空間中存活的對象較少時(shí),比較高效;
標(biāo)記清除:從根集合開始掃描,對存活的對象進(jìn)行標(biāo)記,比較完畢后,再掃描整個(gè)空間中未標(biāo)記的對象,然后進(jìn)行回收,不需要對對象進(jìn)行移動(dòng);
標(biāo)記壓縮:標(biāo)記形式和“標(biāo)記清除”一樣,但是回收不存活的對象后,會(huì)把所有存活的對象在內(nèi)存空間中進(jìn)行移動(dòng),好處是減少了內(nèi)存碎片,缺點(diǎn)是成本比較高;
java內(nèi)存區(qū)域的形式是啥樣的?
這里就不再介紹了,之前有一篇文章中專門介紹這個(gè)的( http://iamzhongyong.iteye.com/blog/1333100)。
新生代可用的GC?
新生代中對象存活的時(shí)間比較短,因此給予Copying算法實(shí)現(xiàn),Eden區(qū)域存放新創(chuàng)建的對象,S0和S1區(qū)其中一塊用于存放在Minor GC的時(shí)候作為復(fù)制存活對象的目標(biāo)空間,另外一塊清空。
串行GC(Serial GC)比較適合單CPU的情況,可以通過-XX:UseSerialGC來強(qiáng)行制定;
并行回收GC(Parallel Scavenge),啟動(dòng)的時(shí)候按照設(shè)置的參數(shù)來劃定Eden/S0/S1區(qū)域的大小,但是在運(yùn)行時(shí),會(huì)根據(jù)Minor GC的頻率、消耗時(shí)間來動(dòng)態(tài)調(diào)整三個(gè)區(qū)域的大小,可以用過-XX:UseAdaptiveSizePolicy來固定大小,不進(jìn)行動(dòng)態(tài)調(diào)整;
并行GC(ParNew)劃分Eden、S1、S0的區(qū)域上和串行GC一樣。并行GC需要配合舊生代使用CMS GC(這是他和并行回收GC的不同)(如果配置了CMS GC的方式,那么新生代默認(rèn)采取的就是并行GC的方式);
啥時(shí)候會(huì)觸發(fā)Minor GC?
當(dāng)Eden區(qū)域分配內(nèi)存時(shí),發(fā)現(xiàn)空間不足,JVM就會(huì)觸發(fā)Minor GC,程序中System.gc()也可以來觸發(fā)。
舊生代可用的GC方式有哪幾種?
串行GC(Serial MSC)、并行GC(Parallel MSC)、并發(fā)GC(CMS);
關(guān)于CMS?
采用CMS時(shí)候,新生代必須使用Serial GC或者ParNew GC兩種。CMS共有七個(gè)步驟,只有Initial Marking和Final Marking兩個(gè)階段是stop-the-world的,其他步驟均和應(yīng)用并行進(jìn)行。持久代的GC也采用CMS,通過-XX:CMSPermGenSweepingEnabled -XX:CMSClassUnloadingEnabled來制定。在采用cms gc的情況下,ygc變慢的原因通常是由于old gen出現(xiàn)了大量的碎片。
為啥CMS會(huì)有內(nèi)存碎片,如何避免?
由于在CMS的回收步驟中,沒有對內(nèi)存進(jìn)行壓縮,所以會(huì)有內(nèi)存碎片出現(xiàn),CMS提供了一個(gè)整理碎片的功能,通過-XX:UseCompactAtFullCollection來啟動(dòng)此功能,啟動(dòng)這個(gè)功能后,默認(rèn)每次執(zhí)行Full GC的時(shí)候會(huì)進(jìn)行整理(也可以通過-XX:CMSFullGCsBeforeCompaction=n來制定多少次Full GC之后來執(zhí)行整理),整理碎片會(huì)stop-the-world.
啥時(shí)候會(huì)觸發(fā)CMS GC?
1、舊生代或者持久代已經(jīng)使用的空間達(dá)到設(shè)定的百分比時(shí)(CMSInitiatingOccupancyFraction這個(gè)設(shè)置old區(qū),perm區(qū)也可以設(shè)置);
2、JVM自動(dòng)觸發(fā)(JVM的動(dòng)態(tài)策略,也就是悲觀策略)(基于之前GC的頻率以及舊生代的增長趨勢來評估決定什么時(shí)候開始執(zhí)行),如果不希望JVM自行決定,可以通過-XX:UseCMSInitiatingOccupancyOnly=true來制定;
3、設(shè)置了 -XX:CMSClassUnloadingE考慮nabled 這個(gè)則考慮Perm區(qū);
啥時(shí)候會(huì)觸發(fā)Full GC?
一、舊生代空間不足:java.lang.outOfMemoryError:java heap space;
二、Perm空間滿:java.lang.outOfMemoryError:PermGen space;
三、CMS GC時(shí)出現(xiàn)promotion failed 和concurrent mode failure(Concurrent mode failure發(fā)生的原因一般是CMS正在進(jìn)行,但是由于old區(qū)內(nèi)存不足,需要盡快回收old區(qū)里面的死的java對象,這個(gè)時(shí)候foreground gc需要被觸發(fā),停止所有的java線程,同時(shí)終止CMS,直接進(jìn)行MSC。);
四、統(tǒng)計(jì)得到的minor GC晉升到舊生代的平均大小大于舊生代的剩余空間;
五、主動(dòng)觸發(fā)Full GC(執(zhí)行jmap -histo:live [pid])來避免碎片問題;
為啥heap小于3g不建議使用CMS GC這種方式?
http://hellojava.info/?p=142 畢大師的這篇文章講的很清楚。
1、觸發(fā)比例不好設(shè)置,設(shè)置大了,那么剩余的空間就少了很多,設(shè)置小了,那old區(qū)還沒放置多少東西,就要進(jìn)行回收了;
2、CMS進(jìn)行的時(shí)候,是并行的,也就意味著如果過于頻繁的話,會(huì)和應(yīng)用的強(qiáng)占CPU;
3、CMS會(huì)有內(nèi)存 碎片問題;
4、YGC的速率變慢(由于CMS GC的實(shí)現(xiàn)原理,導(dǎo)致對象從新生代晉升到舊生代時(shí),尋找哪里能放下的這個(gè)步驟比ParallelOld GC是慢一些的,因此就導(dǎo)致了YGC速度會(huì)有一定程度的下降。);
JVM的悲觀策略是啥?
所謂的悲觀策略( http://tmalltesting.com/archives/663 我們性能測試團(tuán)隊(duì)一個(gè)同學(xué)分析的案例),就是JVM不按照J(rèn)VM指定的參數(shù)來進(jìn)行CMS GC,而是根據(jù)內(nèi)存情況以及之前回收的方式動(dòng)態(tài)調(diào)整,自行進(jìn)行GC。舊生代剩余的空間(available)大于新生代中使用的空間(max_promotion_in_bytes),或者大于之前平均晉升的old的大?。╝v_promo),返回false。cms gc是每隔一個(gè)周期(默認(rèn)2s)就會(huì)做一次這個(gè)檢查,如果為false,則不執(zhí)行YGC,而觸發(fā)cms gc。
我們經(jīng)常使用的是啥GC方式?
針對目前線上機(jī)器的情況(8G的物流內(nèi)存),heap區(qū)一般設(shè)置在4g或者5g左右,一般是使用CMS GC,這時(shí)候:
young區(qū)使用ParNew(并行GC),Old+Perm(需要單獨(dú)設(shè)置)使用CMS,整個(gè)堆(young+old+perm)使用MSC((Mark Sweep Compact)是CMS GC算法的Full GC算法,單線程回收整個(gè)堆,回收過程有嚴(yán)格的步驟。壓縮,所以回收完理論上任何Generation都不會(huì)有內(nèi)存碎片)壓縮回收的方式。
讀懂GC日志?
基本上都是這種格式:回收前區(qū)域占用的大小->回收后區(qū)域占用的大小(區(qū)域設(shè)置的大小),占用的時(shí)間
1、promotion failed的一段日志
1
2 |
2013 - 11 -27T03: 00 : 53.638 + 0800 : 35333.562 : [GC 35333.562 : [ParNew (promotion failed): 1877376K->1877376K(1877376K), 15.7989680 secs] 35349.361 : [CMS: 2144171K->2129287K(2146304K), 10.4200280 sec
s] 3514052K->2129287K(4023680K), [CMS Perm : 119979K->118652K(190132K)], 26.2193500 secs] [Times: user= 30.35 sys= 5.19 , real= 26.22 secs]
|
解釋如下:
1
2
3
4
5 |
1877376K->1877376K(1877376K), 15.7989680 secs young區(qū)
2144171K->2129287K(2146304K), 10.4200280 sec old區(qū)情況
3514052K->2129287K(4023680K) heap區(qū)情況
119979K->118652K(190132K)], 26.2193500 secs perm區(qū)情況
[Times: user= 30.35 sys= 5.19 , real= 26.22 secs] 整個(gè)過程的時(shí)間消耗
|
2、一段正常的CMS的日志
1
2
3
4
5
6
7
8
9
10
11
12
13
14 |
2013 - 11 -27T04: 00 : 12.819 + 0800 : 38892.743 : [GC [ 1 CMS-initial-mark: 1547313K(2146304K)] 1734957K(4023680K), 0.1390860 secs] [Times: user= 0.14 sys= 0.00 , real= 0.14 secs]
2013 - 11 -27T04: 00 : 12.958 + 0800 : 38892.883 : [CMS-concurrent-mark-start]
2013 - 11 -27T04: 00 : 19.231 + 0800 : 38899.155 : [CMS-concurrent-mark: 6.255 / 6.272 secs] [Times: user= 8.49 sys= 1.57 , real= 6.27 secs]
2013 - 11 -27T04: 00 : 19.231 + 0800 : 38899.155 : [CMS-concurrent-preclean-start]
2013 - 11 -27T04: 00 : 19.250 + 0800 : 38899.175 : [CMS-concurrent-preclean: 0.018 / 0.019 secs] [Times: user= 0.02 sys= 0.00 , real= 0.02 secs]
2013 - 11 -27T04: 00 : 19.250 + 0800 : 38899.175 : [CMS-concurrent-abortable-preclean-start]
CMS: abort preclean due to time 2013 - 11 -27T04: 00 : 25.252 + 0800 : 38905.176 : [CMS-concurrent-abortable-preclean: 5.993 / 6.002 secs] [Times: user= 6.97 sys= 2.16 , real= 6.00 secs]
2013 - 11 -27T04: 00 : 25.253 + 0800 : 38905.177 : [GC[YG occupancy: 573705 K ( 1877376 K)] 38905.177 : [Rescan (parallel) , 0.3685690 secs] 38905.546 : [weak refs processing, 0.0024100 secs] 38905.548 : [cla
ss unloading, 0.0177600 secs] 38905.566 : [scrub symbol & string tables, 0.0154090 secs] [ 1 CMS-remark: 1547313K(2146304K)] 2121018K(4023680K), 0.4229380 secs] [Times: user= 1.41 sys= 0.01 , real=
0.43 secs]
2013 - 11 -27T04: 00 : 25.676 + 0800 : 38905.601 : [CMS-concurrent-sweep-start]
2013 - 11 -27T04: 00 : 26.436 + 0800 : 38906.360 : [CMS-concurrent-sweep: 0.759 / 0.760 secs] [Times: user= 1.06 sys= 0.48 , real= 0.76 secs]
2013 - 11 -27T04: 00 : 26.436 + 0800 : 38906.360 : [CMS-concurrent-reset-start]
2013 - 11 -27T04: 00 : 26.441 + 0800 : 38906.365 : [CMS-concurrent-reset: 0.005 / 0.005 secs] [Times: user= 0.00 sys= 0.00 , real= 0.00 secs]
|
這個(gè)是一個(gè)正常的CMS的日志,共分為七個(gè)步驟,重點(diǎn)關(guān)注initial-mark和remark這兩個(gè)階段,因?yàn)檫@兩個(gè)是停機(jī)的。
A、[GC [1 CMS-initial-mark: 1547313K(2146304K)] 1734957K(4023680K), 0.1390860 secs] [Times: user=0.14 sys=0.00, real=0.14 secs]
各個(gè)數(shù)據(jù)依次表示標(biāo)記前后old區(qū)的所有對象占內(nèi)存大小和old的capacity,整個(gè)JavaHeap(不包括perm)所有對象占內(nèi)存總的大小和JavaHeap的capacity。
B、2013-11-27T04:00:25.253+0800: 38905.177: [GC[YG occupancy: 573705 K (1877376 K)]38905.177: [Rescan (parallel) , 0.3685690 secs]38905.546: [weak refs processing, 0.0024100 secs]38905.548: [class unloading, 0.0177600 secs]38905.566: [scrub symbol & string tables, 0.0154090 secs] [1 CMS-remark: 1547313K(2146304K)] 2121018K(4023680K), 0.4229380 secs] [Times: user=1.41 sys=0.01, real=0.43 secs]
Rescan (parallel)表示的是多線程處理young區(qū)和多線程掃描old+perm的卡表的總時(shí)間, parallel 表示多GC線程并行。
weak refs processing 處理old區(qū)的弱引用的總時(shí)間,用于回收native memory。
class unloading 回收SystemDictionary消耗的總時(shí)間。
3、一段正常的Young GC的日志
1
2 |
2013 - 11 -27T04: 00 : 07.345 + 0800 : 38887.270 : [GC 38887.270 : [ParNew: 1791076K->170624K(1877376K), 0.2324440 secs] 2988366K->1413629K(4023680K), 0.2326470 secs] [Times: user= 0.80 sys= 0.00 , real= 0 .
23 secs]
|
ParNew這個(gè)表明是并行的回收方式,具體的分別是young區(qū)、整個(gè)heap區(qū)的情況;
4、一段通過system.gc產(chǎn)生的FullGC日志
1 |
2013 - 07 -21T17: 44 : 01.554 + 0800 : 50.568 : [Full GC (System) 50.568 : [CMS: 943772K->220K(2596864K), 2.3424070 secs] 1477000K->220K(4061184K), [CMS Perm : 3361K->3361K(98304K)], 2.3425410 secs] [Times: user= 2.33 sys= 0.01 , real= 2.34 secs]
|
解釋如下:
Full GC (System)意味著這是個(gè)system.gc調(diào)用產(chǎn)生的MSC。
“943772K->220K(2596864K), 2.3424070 secs”表示:這次MSC前后old區(qū)內(nèi)總對象大小,old的capacity及這次MSC耗時(shí)。
“1477000K->220K(4061184K)”表示:這次MSC前后JavaHeap內(nèi)總對象大小,JavaHeap的capacity。
“3361K->3361K(98304K)], 2.3425410 secs”表示:這次MSC前后Perm區(qū)內(nèi)總對象大小,Perm區(qū)的capacity。
5、一個(gè)特殊的GC日志,根據(jù)動(dòng)態(tài)計(jì)算直接進(jìn)行的FullGC(MSC的方式)
1 |
2013 - 03 -13T13: 48 : 06.349 + 0800 : 7.092 : [GC 7.092 : [ParNew: 471872K->471872K(471872K), 0.0000420 secs] 7.092 : [CMS: 366666K->524287K(524288K), 27.0023450 secs] 838538K->829914K(996160K), [CMS Perm : 3196K->3195K(131072K)], 27.0025170 secs]
|
ParNew的時(shí)間特別短,jvm在minor gc前會(huì)首先確認(rèn)old是不是足夠大,如果不夠大,這次young gc直接返回,進(jìn)行MSC。
參考文章:
http://kenwublog.com/docs/java6-jvm-options-chinese-edition.htm JVM參數(shù)大全
http://tmalltesting.com/archives/663 悲觀策略
http://hellojava.info/?p=142 CMS GC不建議3G的原因
畢玄的《分布式j(luò)ava基礎(chǔ)》