之前的文章
最近實在太忙,更新文章速度慢了不少,但是不管多忙,這個系列我還是會堅持寫完的,關注jvm的人請放心哈~
上篇我們說了幾個比較基礎的垃圾回收器,從這篇開始,我們來說說當下用的比較多的垃圾回收器,並且會教大家怎麼去看垃圾回收的日誌,這些也常常涉及到工作面試中各種各樣的問題,當然,這篇開始文章難度會偏大,不建議跳著看或者是這個領域剛剛入門的人來看這裡。
一、簡介
CMS全稱Concurrent Mark Sweep,是一款以低停頓為目標的垃圾回收器,這個回收器是一款真正意義的併發收集器。我們知道,通常基於B/S的服務端會對低停頓有著較高的要求,因為這樣能夠提高使用者的互動體驗,因此,CMS可以說正好滿足了這樣的要求,也正是因為這一點,它目前被廣泛的使用在各種應用的服務端。
我們在學習這款收集器的時候,一定要注意的一個是CMS是針對老年代的回收器,當我們使用jdk1.8的時候開啟了-XX:+UseConcMarkSweepGC這個引數,在年輕代就只能使用ParNew了,這也是為什麼當開啟CMS之後gc日誌中會有ParNew的日誌的原因。
二、工作過程
1、主要工作流程
CMS的回收用的是標記清除演算法,它的回收會經歷以下幾個階段:
- 初始標記(Initial Mark) (STW)
- 併發標記(Concurrent Mark)
- 併發預清理(Concurrent Preclean)
- 併發可取消的預清理(Concurrent Abortable Preclean)
- 最終標記(Final Remark) (STW)
- 併發清除(Concurrent Sweep)
- 併發重置(Concurrent Reset)
我們一個一個的來說下:
- 初始標記(Initial Mark)
這個階段所做的事情是從GC Root出發,標記所有GC Root直接關聯的老年代存活的物件,其實也會掃描到新生代去(這是因為掃描之前並不知道這個GC Root引用的物件是不是老年代),你可以把這個階段理解成我在演算法那篇說三色標記的時狀態1到狀態2做的事情。這個階段是STW的,原因也很簡單,如果這個階段是和使用者執行緒一起執行的話,那麼準確性就會大大收到影響。
這個階段還有一個名字,就是叫做根結點列舉,以後還要講的收集器如G1,ZGC也有這個階段,並且它們的這個階段也都是STW的,
STW目的也都是為了保證這個階段所做工作的準確性。
複製程式碼
這個階段的速度是非常快的,所以即使是STW的,停頓時間也不會很長,我們還可以通過使用CMSParallelInitialMarkEnabled這個引數來使這個階段變成多執行緒進行。
- 併發標記(Concurrent Mark)
這個階段是從上個階段找出的物件出發,遍歷整個物件引用鏈,這個階段是耗時比較長的,但是它是可以和使用者執行緒併發執行的,因此不會造成停頓。但是,需要注意的是,這個階段由於是和應用執行緒併發進行,應用執行緒此時還在不斷的分配物件,因此CMS在觸發GC之前是需要保留一定的空間來支援應用執行緒分配物件,如果此時空間不夠,就會觸發“concurrent mode failure”,這是一個非常嚴重的問題,此時cms會退化成Serial old來進行gc,從而引發非常長的停頓時間。
- 併發預清理(Concurrent Preclean)
這個階段GC執行緒和應用執行緒也是併發執行,因為階段2是與應用執行緒併發執行,可能有些引用關係已經發生改變。 通過卡片標記(Card Marking),提前把老年代空間邏輯劃分為相等大小的區域(Card),如果引用關係發生改變,JVM會將發生改變的區域標記位“髒區”(Dirty Card),然後在本階段,這些髒區會被找出來,重新整理引用關係,清除“髒區”標記。
- 併發可取消的預清理(Concurrent Abortable Preclean)
這個階段也不停止應用執行緒. 本階段嘗試在 STW 的 最終標記階段(Final Remark)之前儘可能地多做一些工作,以減少應用暫停時間 在該階段不斷迴圈處理:標記老年代的可達物件、掃描處理Dirty Card區域中的物件,迴圈的終止條件有: 1 達到迴圈次數 2 達到迴圈執行時間閾值 3 新生代記憶體使用率達到閾值。這個階段最大持續時間(條件2)為5秒,之所以可以持續5秒,有個原因也是為了期待這5秒內能夠發生一次young gc,清理年輕帶的引用,減少下個階段的重新標記階段掃描年輕帶指向老年代的引用的時間。
- 最終標記(Final Remark)
這個階段是STW的,目標是完成老年代中所有存活物件的標記。在此階段執行: 1、遍歷新生代物件,重新標記 2、根據GC Roots,重新標記 3 遍歷老年代的Dirty Card,重新標記。
- 併發清除(Concurrent Sweep)
這個階段與應用程式併發執行,不需要STW停頓,根據標記結果清除垃圾物件。
- 併發重置(Concurrent Reset)
此階段與應用程式併發執行,重置CMS演算法相關的內部資料, 為下一次GC迴圈做準備。
2、CMS的background和foreground模式
這塊是關於CMS比較重要但是很多人卻都不知道的點,做GC優化的人用CMS的時候可能經常會奇怪,為什麼明明還沒到CMSInitiatingOccupancyFraction引數的值卻發生了GC,這是因為CMS GC發生的情況其實並不僅僅只有這一個。
a、foreground模式:這個模式是比較好理解的,就是當給物件分配記憶體但是空間不夠的時候就會觸發,這時候用的是標記清除演算法,不會進行壓縮
b、background模式:這個模式比較複雜,這個模式主要是由於CMS的後臺執行緒不停的掃描,一旦發現符合觸發條件,便會觸發一次background模式的gc。我們來看看具體的條件
I、當呼叫是System.gc()並且配置了 ExplicitGCInvokesConcurrent 引數或者觸發原因是gc locker且配置了 GCLockerInvokesConcurrent 引數。
我們一個一個來說下兩種情況,當我們使用CMS的時候,並且在執行到了System.gc()這裡,我們知道,System.gc()觸發的是一次full gc,一般的full gc都是整個流程都是暫停的,但是如果配置了ExplicitGCInvokesConcurrent這個引數後,有的過程是可以併發執行的(這時候是background gc),這樣就提高了效率。
至於gc locker,這貨是個非常複雜的東西。簡單來說就是在執行JNI的時候不允許發生gc,這是因為這時候執行緒是執行在臨界區的,人家執行緒還沒跑完gc把人家需要的資料清除掉了那樣會有問題(一個典型的場景是使用本地方法JNI函式訪問JVM中的字串或陣列資料),所以這個時候不允許gc。那麼當執行緒執行在臨界區的時候又需要gc 怎麼辦呢?這時候會把這次gc block住(這就是gc locker做的事情),在所有臨界區的執行緒都執行完畢之後,再由gc locker觸發一次gc,這時候的gc就是background gc。
II、根據統計資料動態計算(僅未配置 UseCMSInitiatingOccupancyOnly 時) 未配置 UseCMSInitiatingOccupancyOnly 時,會根據統計資料動態判斷是否需要進行一次 CMS GC。
判斷邏輯是,如果預測 CMS GC 完成所需要的時間大於預計的老年代將要填滿的時間,則進行 GC。 這些判斷是需要基於歷史的 CMS GC 統計指標,然而,第一次 CMS GC 時,統計資料還沒有形成,是無效的,這時會跟據 Old Gen 的使用佔比來判斷是否要進行 GC。
III、根據老年代的使用情況,這裡有兩種情況,第一種是配置了UseCMSInitiatingOccupancyOnly,並且當老年代使用的比例比我們設定的CMSInitiatingOccupancyFraction(沒設定就是預設值的92%)大的時候,就會觸發。另外一種情況是沒有配UseCMSInitiatingOccupancyOnly,這時候又有兩種小的分支情況,一個是當老年代是因為分配物件而成功擴容的,這時候會觸發background gc(足以看出-xmx 和 -xms設定成一樣的重要性),第二個是一個非常複雜的情況,這個和CMS老年代的空閒連結串列有關係,複雜的原因是freeList這玩意本身的複雜度就是非常高的,簡單的說此時CMS的後臺執行緒判斷FreeList中的空間不足以分配新的下一次晉升到老年代的物件時候,就會觸發background gc。
IV、young gc是否會失敗(類似於之前說的parllel gc的悲觀策略,CMS這貨也有這樣的行為) 當young gc失敗的時候會觸發background gc,為什麼young gc會失敗呢,大多數的原因是因為老年代的空間不夠;還有一個是統計之前晉升的平均大小,如果老年代空間不夠,也會觸發老年代gc,這時候的gc也是background gc。
V、根據meta space使用情況來判斷 當meta space擴容的時候,我們如果配置了CMSClassUnloadingEnabled(這個引數是用來控制是否允許CMS回收元空間的),就會觸發一次CMS GC,這個情況如果表現出來是非常詭異的,這時候你可以看到明明老年代沒用多少,但是卻發生了gc。
3、回收和壓縮之間的權衡
我們知道,CMS回收用的是標記清除演算法,也就是說它平時並不對空間進行整理,這樣會造成過多的記憶體碎片,這些記憶體碎片會降低物件分配的效率,如果空間碎片太多導致無法分配大物件,這時候就不得不進行一次full gc,這時候會有一個引數-XX:+UseCMSComPackAtFullCollection來控制在full gc的時候來壓縮物件,這樣雖然解決了碎片問題,但是停頓時間卻變長了,並且這是一種被動的解決方案,容易造成停頓時間不可控制或是不容易預測,為了更容易預測或是控制停頓的時間,CMS提供了另外一個引數-XX:CMSFullGCsBeforeCompaction來解決這個問題,這個引數的含義是要求CMS在進行了若干次不整理空間的full gc之後下次進入full gc會對碎片進行整理,預設值是0,表示每次full gc都會整理空間,這個值太小會導致空間整理太過於頻繁從而降低效率,太大又會造成太多記憶體碎片,降低分配物件的效率,在實際使用中,若想精準的控制這個值,必須經過壓測綜合觀察吞吐量和停頓時間,以取得一個最合適的值。
三、CMS回收器的缺點
CMS無論在哪個jdk的版本都不是預設的回收器,原因是他有著比較明顯的幾個缺點
1、記憶體碎片
記憶體碎片是由於使用標記整理法導致,上面已說過,這裡不在贅述。
2、浮動垃圾
這是因為CMS是和使用者執行緒併發執行的,在程式執行過程中自然還會產生新的垃圾,但是這部分垃圾是CMS這次回收無法處理的,只能等到下個回收再處理,這部分垃圾就是浮動垃圾。
3、併發標記失敗
正是因為使用者程式還在執行,因此CMS不能在老年代空間使用百分之百的時候再去回收,這也是配置CMSFullGCsBeforeCompaction的原因,這裡值得一提的是,在回收的過程中,如果老年代的空間不足以存放使用者程式產生的物件資料,那麼就會觸發併發標記失敗,這時候會導致一次full gc。設定CMSFullGCsBeforeCompaction也是需要權衡的,因為設定的太大,容易觸發併發標記失敗,設定的太小,則會頻繁的回收,增大停頓時間的同時還會降低吞吐量。
四、常見引數
除過文中提到的引數之外,還有下面的引數比較常用
1、XX:+UseConcMarkSweepGC
預設是false 老年代採用CMS回收器,1.8的時候來使用,在新生代預設會使用ParNew
2、-XX:+CMSScavengeBeforeRemark
預設是false,重新標記之前,先執行一次ygc,回收掉年輕帶的物件無用的物件,並將物件放入倖存帶或晉升到老年代,這樣再進行年輕帶掃描時,只需要掃描倖存區的物件即可,一般倖存帶非常小,這大大減少了掃描時間,從而減少STW的時間
3、-XX:+UseCMSCompactAtFullCollection
預設是true,開啟之後是CMS在full gc 之後可不可以對老年代內物件佈局進行壓縮,它和第4個引數是搭配使用的
4、-XX:CMSFullGCsBeforeCompaction=n
如果第3個引數是true,那麼在n次full gc之後會對物件佈局進行壓縮,如果是0的話,會在每次gc之後都進行壓縮
5、–XX:ParallelGCThreads=n
這是併發回收的執行緒數量,一般使用預設值即可
6、-XX:CMSInitiatingOccupancyFraction=n
這個引數是和第7個引數搭配使用的,這個引數的意思是當老年代空間被佔用百分之n的時候觸發一次major gc,也就是old gc,1.8這個引數預設值是92,但是如果應用併發量較大(意味著分配物件速度快),這個值是需要設定的低一些的。
7、-XX:+UseCMSInitiatingOccupancyOnly
CMS會自動調整觸發major gc的閾值,如果僅僅想使用我們設定的值,還需要使用這個引數
五、日誌解讀
1、gc日誌關注點
這裡主要是教大家去讀CMS的日誌,另外也會教大家使用一款gc視覺化的分析工具,GC Viewer。我們讀gc日誌,首先要明白讀gc日誌需要關注的點都有哪些,否則真的還不如別看。讀GC需要關注的幾個基本的點:
- 一定時間內gc的次數
- 單次gc耗時
- full gc的次數
- 發生gc的原因
另外,需要我們注意的一點是,由於jvm對於gc日誌這裡沒有一個規範(目前在規劃中),因此不同的垃圾回收器打出來的日誌是不一樣的,這也是讀gc日誌非常頭疼的一點。
2、ParNew日誌
用我們測試環境的資料來舉個例子,我們測試環境的jvm引數如下:
-Xms1024m
-Xmx1024m
-XX:NewRatio=1
-XX:+UseConcMarkSweepGC
-XX:+CMSParallelRemarkEnabled
-XX:+UseParNewGC
-XX:+PrintGCDetails
-XX:+PrintGCDateStamps
-XX:+PrintGC
-Xloggc:/export/Logs/gc.log
-XX:+PrintHeapAtGC
-XX:+HeapDumpOnOutOfMemoryError
-XX:HeapDumpPath=/export/Logs/oom_error.hprof
複製程式碼
由於配置了PrintHeapAtGC,所以在每次gc前後都會打出來堆的大小,日誌會顯得比較長,這裡不需要擔心,都是紙老虎,沒什麼好害怕的。另外需要知道的是,使用了CMS的話,年輕代用的是ParNew,因此年輕代日誌是都會有ParNew,我們來看個例子:
我用紅色數字表示出來的123456分別是回收前後的堆記憶體的使用情況,這裡注意,1處的總的大小等於2+3的,這是因為from和to空間只用一個,1這裡很有意思,因為我們用的是parnew回收器,因此這裡叫做par new generation,5這裡是老年代,同理因為用的是CMS,所以這裡也叫做concurrent mark-sweep generation,6則是metaspace空間使用情況以及其中的class存放區的使用情況,這些相信是很容易看懂的,我就不對數字標記的地方做更多解釋了。
我們來看下兩個紅框中比較長的這個框,為了便於講解,我再把這裡的日誌貼出來:
我把每個部分用紅框拆分出來,用藍色數字標記,我們一個一個來看下:
第1個部分中的“GC (Allocation Failure) 45.679:”表示在jvm啟動45.679秒之後,由於為物件分配記憶體空間失敗而導致了這次gc;
第2個部分中“455889K->31600K(471872K), 0.3074756 secs”,455889K表示年輕代一共使用了這麼大空間,這裡和上個圖的1中的used值是一樣的,回收之後佔用了31600K,471872K說的是年輕代的總容量,和上面圖的1中的total值是一樣的,0.3074756是回收耗時;
第3部分“464536K->46851K(996160K)”中,464536k是回收之前整個堆使用了這麼大,46851k是回收之後整個堆用了這麼大空間,括號裡的996160k是整個堆的大小;
第4部分“ 0.3076113 secs”(其實這個和第3部分是一起的),這是整個堆回收工作的耗時,雖說回收的是年輕代,但是可能涉及到把物件升級到老年代等工作,所以這個時間比第2部分中的耗時的值大一些;
第5部分“Times: user=0.63 sys=0.02, real=0.31 secs”,這裡面涉及到三種時間型別,含義是: user:GC 執行緒在垃圾收集期間所使用的 CPU 總時間; sys:系統呼叫或者等待系統事件花費的時間; real:應用被暫停的時鐘時間,由於 GC 執行緒是多執行緒的,導致了 real 小於 (user+real),如果是 gc 執行緒是單執行緒的話,real 是接近於 (user+real) 時間。
再看看看第一個圖的短框:
這個框內容很少,主要是兩個部分,第一個是invocations=5,這個是從jvm啟動到現在發生了5次gc(這裡沒有包括老年代gc,也就是說年輕代gc了5次,full gc回收的是全堆,因此在full gc的時候,這個值也會加1),full=2是說full gc發生了兩次,我們通過觀察這個可以看出來一定時間發生gc的次數和full gc的次數。
3、CMS日誌
引數還是和上面的引數一樣,來看一段CMS的日誌
這裡之所以沒有截圖的原因是CMS的日誌和ParNew是交替輸出的,並且CMS一個回收週期持續時間比較長,所以很難找到一個完整的圖,但是你如果是認真看到這裡來的,這個日誌對你來說應該也只是小意思了。
含義見裡面的漢語註釋
// 1、這裡是第一個階段初始標記,0是老年代使用大小,524288K是整個老年代大小,268461K是整個堆使用大小,996160K是整個堆的大小,0.0369037 secs是這個階段耗時,這個階段是STW的,Times含義和上面一樣
2021-01-15T15:10:22.071+0800: 4.271: [GC (CMS Initial Mark) [1 CMS-initial-mark: 0K(524288K)] 268461K(996160K), 0.0369037 secs] [Times: user=0.10 sys=0.00, real=0.04 secs]
// 2、併發標記開始
2021-01-15T15:10:22.109+0800: 4.308: [CMS-concurrent-mark-start]
2021-01-15T15:10:22.109+0800: 4.308: [CMS-concurrent-mark: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
// 3、併發預清理開始
2021-01-15T15:10:22.109+0800: 4.308: [CMS-concurrent-preclean-start]
2021-01-15T15:10:22.111+0800: 4.310: [CMS-concurrent-preclean: 0.002/0.002 secs] [Times: user=0.02 sys=0.00, real=0.00 secs]
// 4、可被終止的併發預清理開始
2021-01-15T15:10:22.111+0800: 4.310: [CMS-concurrent-abortable-preclean-start]
// 5、最終標記,這裡寫到文章裡,因為太長了
2021-01-15T15:10:24.601+0800: 6.800: [GC (CMS Final Remark) [YG occupancy: 26035 K (471872 K)]6.800: [Rescan (parallel) , 0.0727898 secs]6.873: [weak refs processing, 0.0000510 secs]6.873: [class unloading, 0.0168876 secs]6.890: [scrub symbol table, 0.0033340 secs]6.893: [scrub string table, 0.0005541 secs][ CMS-remark: 0K(524288K)] 26035K(996160K), 0.0968042 secs] [Times: user=0.20 sys=0.01, real=0.10 secs]
// 6、併發清理開始
2021-01-15T15:10:24.698+0800: 6.897: [CMS-concurrent-sweep-start]
2021-01-15T15:10:24.698+0800: 6.897: [CMS-concurrent-sweep: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
// 7、併發重置
2021-01-15T15:10:24.698+0800: 6.897: [CMS-concurrent-reset-start]
2021-01-15T15:10:24.771+0800: 6.970: [CMS-concurrent-reset: 0.007/0.073 secs] [Times: user=0.08 sys=0.01, real=0.07 secs]
複製程式碼
第5部分最終標記:
YG occupancy是年輕代佔用大小,26035是年輕代當前使用大小,471872是年輕代總大小,和之前說parnew的時候這兩個值是一樣的;
Rescan (parallel)是當應用暫停的情況下完成對所有存活物件的標記,這個階段是並行處理的,這裡花了0.0727898 secs;
weak refs processing, 0.0000510 secs:第一個子階段,它的工作是處理弱引用;
class unloading, 0.0168876 secs:第二個子階段,它的工作是:unloading the unused classes;
scrub symbol table, 0.0033340 secs 到 scrub string table, 0.0005541 secs:最後一個子階段,它的目的是:清理類級元資料和內部字串的符號對應在string table的引用;
CMS-remark: 0K(524288K),0是這個階段之後的老年代佔用大小,524288K是這個階段之後的老年代佔用大小;
26035K(996160K)0.0968042 secs:26035K這個階段之後的堆記憶體使用情況,996160K是整個堆的大小;0.0968042 secs是這個階段所花費的時間。
細心的讀者會注意到老年代的使用是0k,但是這裡卻發生了一次老年代的GC,這裡是因為元空間的大小在此時發生變化導致的。這個也是我需要解釋的一點,這個gc是發生在我們的springboot專案剛剛啟動的時候的,這次gc其實是full gc的一部分,我之前也說過,full gc包含了old gc和young gc,這時候因為在載入各種各樣的類,並且頻繁呼叫asm生成新的類導致元空間大小發生變化。這點可以通過觀察類的圖來證明。
4、GC Viewer
統計整個日誌中gc次數是件很麻煩的事情,這裡有個比較好用的視覺化工具GC Viewer,這玩意下載安裝的過程我就不在這裡說了,我們來看看一些基礎的玩法,下面是我把我們的gc日誌用GC Viewer開啟的介面:
第1部分是記憶體隨著時間變化的折線圖,我一般都不看這個的(不是說沒用);第2部分各項資料的統計,我看的最多的是下面這個介面的東西:
這裡面是這個gc日誌檔案裡面所有的gc暫停以及full gc次數以及併發日誌的一些資料,隨著gc日誌格式的不一樣這裡的資料也會有一些不一樣,很熟悉CMS的看到這個介面應該也是不需要多少解釋就能看明白的,關於GC Viewer的具體用法,請參考https://github.com/chewiebug/GCViewer