摘要：表示允許垃圾收集線程處理本次垃圾收集開始前沒有處理好的日志緩沖區(qū)，這可以確保當(dāng)前分區(qū)的是最新的。垃圾收集線程在完成其他任務(wù)的時(shí)間展示每個(gè)垃圾收集線程的最小最大平均差值和總共時(shí)間。

本文翻譯自：https://www.redhat.com/en/blog/collecting-and-reading-g1-garbage-collector-logs-part-2?source=author&term=22991

這篇文章將深入研究G1的日志和調(diào)優(yōu)參數(shù)。為了在實(shí)際工作中對(duì)G1進(jìn)行調(diào)優(yōu)，作為開發(fā)者的你需要理解G1垃圾收集器的每個(gè)步驟，以及每個(gè)步驟在整個(gè)垃圾收集周期中的作用。為了方便讀者學(xué)習(xí)，這篇文章將G1的日志參數(shù)分為等級(jí)遞增的三塊，這篇文章將會(huì)分別介紹每一部分參數(shù)的作用和調(diào)優(yōu)時(shí)候使用的場(chǎng)景。

基礎(chǔ)參數(shù) - 在生產(chǎn)中使用G1收集器，必須使用這些參數(shù)

高級(jí)參數(shù) - 隨著應(yīng)用的成熟或業(yè)務(wù)負(fù)載的增加，需要使用這些參數(shù)針對(duì)某些問題進(jìn)行調(diào)優(yōu)。

Debug參數(shù) - 這些參數(shù)是用來(lái)解決特定的性能問題，如果某個(gè)問題在非生產(chǎn)環(huán)境中無(wú)法復(fù)現(xiàn)，才會(huì)在生產(chǎn)環(huán)境中使用這些參數(shù)排查問題。

如果你要在生產(chǎn)環(huán)境中使用G1 GC，下面這些跟日志相關(guān)的參數(shù)是必備的，有了這些參數(shù)，你才能排查基本的垃圾回收問題。

使用-XX:GCLogFileSize設(shè)置合適的GC日志文件大小，使用-XX:NumberOfGCLogFiles設(shè)置要保留的GC日志文件個(gè)數(shù)，使用-Xloggc:/path/to/gc.log設(shè)置GC日志文件的位置，通過上面三個(gè)參數(shù)保留應(yīng)用在運(yùn)行過程中的GC日志信息，我建議最少保留一個(gè)星期的GC日志，這樣應(yīng)用的運(yùn)行時(shí)信息足夠多的，方便排查問題。

和其他垃圾收集器一樣，G1也使用-XX:PrintGCDetails打印出詳細(xì)的垃圾收集日志，下面這張圖是新生代收集的標(biāo)準(zhǔn)流程，我在這里將它分成了6個(gè)步驟：

四個(gè)關(guān)鍵信息

新生代垃圾收集發(fā)生的時(shí)間——2016-12-12T10:40:18.811-0500，通過設(shè)置-XX:+PrintGCDateStamps參數(shù)可以打印出這個(gè)時(shí)間；

JVM啟動(dòng)后的相對(duì)時(shí)間——25.959

這次收集的類型——新生代收集，只回收Eden分區(qū)

這次收集花費(fèi)的時(shí)間——0.0305171s，即30ms

列出了新生代收集中并行收集的詳細(xì)過程

Parallel Time：并行收集任務(wù)在運(yùn)行過程中引發(fā)的STW（Stop The World）時(shí)間，從新生代垃圾收集開始到最后一個(gè)任務(wù)結(jié)束，共花費(fèi)26.6ms

GC Workers：有4個(gè)線程負(fù)責(zé)垃圾收集，通過參數(shù)-XX:ParallelGCThreads設(shè)置，這個(gè)參數(shù)的值的設(shè)置，跟CPU有關(guān)，如果物理CPU支持的線程個(gè)數(shù)小于8，則最多設(shè)置為8；如果物理CPU支持的線程個(gè)數(shù)大于8，則默認(rèn)值為number * 5/8

GC Worker Start：第一個(gè)垃圾收集線程開始工作時(shí)JVM啟動(dòng)后經(jīng)過的時(shí)間（min）；最后一個(gè)垃圾收集線程開始工作時(shí)JVM啟動(dòng)后經(jīng)過的時(shí)間（max）；diff表示min和max之間的差值。理想情況下，你希望他們幾乎是同時(shí)開始，即diff趨近于0。

Ext Root Scanning：掃描root集合（線程棧、JNI、全局變量、系統(tǒng)表等等）花費(fèi)的時(shí)間，掃描root集合是垃圾收集的起點(diǎn)，嘗試找到是否有root集合中的節(jié)點(diǎn)指向當(dāng)前的收集集合（CSet）

Update RS(Remembered Set or RSet)：每個(gè)分區(qū)都有自己的RSet，用來(lái)記錄其他分區(qū)指向當(dāng)前分區(qū)的指針，如果RSet有更新，G1中會(huì)有一個(gè)post-write barrier管理跨分區(qū)的引用——新的被引用的card會(huì)被標(biāo)記為dirty，并放入一個(gè)日志緩沖區(qū)，如果這個(gè)日志緩沖區(qū)滿了會(huì)被加入到一個(gè)全局的緩沖區(qū)，在JVM運(yùn)行的過程中還有線程在并發(fā)處理這個(gè)全局日志緩沖區(qū)的dirty card。Update RS表示允許垃圾收集線程處理本次垃圾收集開始前沒有處理好的日志緩沖區(qū)，這可以確保當(dāng)前分區(qū)的RSet是最新的。

Processed Buffers，這表示在Update RS這個(gè)過程中處理多少個(gè)日志緩沖區(qū)。

Scan RS：掃描每個(gè)新生代分區(qū)的RSet，找出有多少指向當(dāng)前分區(qū)的引用來(lái)自CSet。

Code Root Scanning：掃描代碼中的root節(jié)點(diǎn)（局部變量）花費(fèi)的時(shí)間

Object Copy：在疏散暫停期間，所有在CSet中的分區(qū)必須被轉(zhuǎn)移疏散，Object Copy就負(fù)責(zé)將當(dāng)前分區(qū)中存活的對(duì)象拷貝到新的分區(qū)。

Termination：當(dāng)一個(gè)垃圾收集線程完成任務(wù)時(shí)，它就會(huì)進(jìn)入一個(gè)臨界區(qū)，并嘗試幫助其他垃圾線程完成任務(wù)（steal outstanding tasks），min表示該垃圾收集線程什么時(shí)候嘗試terminatie，max表示該垃圾收集回收線程什么時(shí)候真正terminated。

Termination Attempts：如果一個(gè)垃圾收集線程成功盜取了其他線程的任務(wù)，那么它會(huì)再次盜取更多的任務(wù)或再次嘗試terminate，每次重新terminate的時(shí)候，這個(gè)數(shù)值就會(huì)增加。

GC Worker Other：垃圾收集線程在完成其他任務(wù)的時(shí)間

GC Worker Total：展示每個(gè)垃圾收集線程的最小、最大、平均、差值和總共時(shí)間。

GC Worker End：min表示最早結(jié)束的垃圾收集線程結(jié)束時(shí)該JVM啟動(dòng)后的時(shí)間；max表示最晚結(jié)束的垃圾收集線程結(jié)束時(shí)該JVM啟動(dòng)后的時(shí)間。理想情況下，你希望它們快速結(jié)束，并且最好是同一時(shí)間結(jié)束。

列出了新生代GC中的一些任務(wù)：

Code Root Fixup ：釋放用于管理并行垃圾收集活動(dòng)的數(shù)據(jù)結(jié)構(gòu)，應(yīng)該接近于0，該步驟是線性執(zhí)行的；

Code Root Purge：清理更多的數(shù)據(jù)結(jié)構(gòu)，應(yīng)該很快，耗時(shí)接近于0，也是線性執(zhí)行。

Clear CT：清理card table

包含一些擴(kuò)展功能

Choose CSet：選擇要進(jìn)行回收的分區(qū)放入CSet（G1選擇的標(biāo)準(zhǔn)是垃圾最多的分區(qū)優(yōu)先，也就是存活對(duì)象率最低的分區(qū)優(yōu)先）

Ref Proc：處理Java中的各種引用——soft、weak、final、phantom、JNI等等。

Ref Enq：遍歷所有的引用，將不能回收的放入pending列表

Redirty Card：在回收過程中被修改的card將會(huì)被重置為dirty

Humongous Register：JDK8u60提供了一個(gè)特性，巨型對(duì)象可以在新生代收集的時(shí)候被回收——通過G1ReclaimDeadHumongousObjectsAtYoungGC 設(shè)置，默認(rèn)為true。

Humongous Reclaim：做下列任務(wù)的時(shí)間：確保巨型對(duì)象可以被回收、釋放該巨型對(duì)象所占的分區(qū)，重置分區(qū)類型，并將分區(qū)還到free列表，并且更新空閑空間大小。

Free CSet：將要釋放的分區(qū)還回到free列表。

展示了不同代的大小變化，以及堆大小的自適應(yīng)調(diào)整。

Eden:1097.0M(1097.0M)->0.0B(967.0M)：（1）當(dāng)前新生代收集觸發(fā)的原因是Eden空間滿了，分配了1097M，使用了1097M；（2）所有的Eden分區(qū)都被疏散處理了，在新生代結(jié)束后Eden分區(qū)的使用大小成為了0.0B；（3）Eden分區(qū)的大小縮小為967.0M

Survivors:13.0M->139.0M：由于年輕代分區(qū)的回收處理，survivor的空間從13.0M漲到139.0M；

Heap:1694.4M(2048.0M)->736.3M(2048.0M)：（1）在本次垃圾收集活動(dòng)開始的時(shí)候，堆空間整體使用量是1694.4M，堆空間的最大值是2048M；（2）在本次垃圾收集結(jié)束后，堆空間的使用量是763.4M，最大值保持不變。

第6點(diǎn)展示了本次新生代垃圾收集的時(shí)間

user=0.8：垃圾收集線程在新生代垃圾收集過程中消耗的CPU時(shí)間，這個(gè)時(shí)間跟垃圾收集線程的個(gè)數(shù)有關(guān)，可能會(huì)比real time大很多；

sys=0.0：內(nèi)核態(tài)線程消耗的CPU時(shí)間
-real=0.03：本次垃圾收集真正消耗的時(shí)間；

G1的第二種收集活動(dòng)是并發(fā)垃圾收集，并發(fā)垃圾收集的觸發(fā)條件有很多，但是做的工作都相同，它的日志如下圖所示：

標(biāo)志著并發(fā)垃圾收集階段的開始：

GC pause(G1 Evacuation Pause)(young)(initial-mark)：為了充分利用STW的機(jī)會(huì)來(lái)trace所有可達(dá)（存活）的對(duì)象，initial-mark階段是作為新生代垃圾收集中的一部分存在的（搭便車）。initial-mark設(shè)置了兩個(gè)TAMS（top-at-mark-start）變量，用來(lái)區(qū)分存活的對(duì)象和在并發(fā)標(biāo)記階段新分配的對(duì)象。在TAMS之前的所有對(duì)象，在當(dāng)前周期內(nèi)都會(huì)被視作存活的。

表示第并發(fā)標(biāo)記階段做的第一個(gè)事情：根分區(qū)掃描

GC concurrent-root-region-scan-start：根分區(qū)掃描開始，根分區(qū)掃描主要掃描的是新的survivor分區(qū)，找到這些分區(qū)內(nèi)的對(duì)象指向當(dāng)前分區(qū)的引用，如果發(fā)現(xiàn)有引用，則做個(gè)記錄；

GC concurrent-root-region-scan-end：根分區(qū)掃描結(jié)束，耗時(shí)0.0030613s

表示并發(fā)標(biāo)記階段

GC Concurrent-mark-start：并發(fā)標(biāo)記階段開始。（1）并發(fā)標(biāo)記階段的線程是跟應(yīng)用線程一起運(yùn)行的，不會(huì)STW，所以稱為并發(fā)；并發(fā)標(biāo)記階段的垃圾收集線程，默認(rèn)值是Parallel Thread個(gè)數(shù)的25%，這個(gè)值也可以用參數(shù)-XX:ConcGCThreads設(shè)置；（2）trace整個(gè)堆，并使用位圖標(biāo)記所有存活的對(duì)象，因?yàn)樵趖op TAMS之前的對(duì)象是隱式存活的，所以這里只需要標(biāo)記出那些在top TAMS之后、閾值之前的；（3）記錄在并發(fā)標(biāo)記階段的變更，G1這里使用了SATB算法，該算法要求在垃圾收集開始的時(shí)候給堆做一個(gè)快照，在垃圾收集過程中這個(gè)快照是不變的，但實(shí)際上肯定有些對(duì)象的引用會(huì)發(fā)生變化，這時(shí)候G1使用了pre-write barrier記錄這種變更，并將這個(gè)記錄存放在一個(gè)SATB緩沖區(qū)中，如果該緩沖區(qū)滿了就會(huì)將它加入到一個(gè)全局的緩沖區(qū)，同時(shí)G1有一個(gè)線程在并行得處理這個(gè)全局緩沖區(qū)；（4）在并發(fā)標(biāo)記過程中，會(huì)記錄每個(gè)分區(qū)的存活對(duì)象占整個(gè)分區(qū)的大小的比率；

GC Concurrent-mark-end：并發(fā)標(biāo)記階段結(jié)束，耗時(shí)0.3055438s

重新標(biāo)記階段，會(huì)Stop the World

Finalize Marking：Finalizer列表里的Finalizer對(duì)象處理，耗時(shí)0.0014099s；

GC ref-proc：引用（soft、weak、final、phantom、JNI等等）處理，耗時(shí)0.0000480s；

Unloading：類卸載，耗時(shí)0.0025840s；

除了前面這幾個(gè)事情，這個(gè)階段最關(guān)鍵的結(jié)果是：繪制出當(dāng)前并發(fā)周期中整個(gè)堆的最后面貌，剩余的SATB緩沖區(qū)會(huì)在這里被處理，所有存活的對(duì)象都會(huì)被標(biāo)記；

清理階段，也會(huì)Stop the World

計(jì)算出最后存活的對(duì)象：標(biāo)記出initial-mark階段后分配的對(duì)象；標(biāo)記出至少有一個(gè)存活對(duì)象的分區(qū)；

為下一個(gè)并發(fā)標(biāo)記階段做準(zhǔn)備，previous和next位圖會(huì)被清理；

沒有存活對(duì)象的老年代分區(qū)和巨型對(duì)象分區(qū)會(huì)被釋放和清理；

處理沒有任何存活對(duì)象的分區(qū)的RSet；

所有的老年代分區(qū)會(huì)按照自己的存活率（存活對(duì)象占整個(gè)分區(qū)大小的比例）進(jìn)行排序，為后面的CSet選擇過程做準(zhǔn)備；

并發(fā)清理階段

GC concurrent-cleanup-start：并發(fā)清理階段啟動(dòng)。完成第5步剩余的清理工作；將完全清理好的分區(qū)加入到二級(jí)free列表，等待最終還會(huì)到總體的free列表；

GC concurrent-cleanup-end：并發(fā)清理階段結(jié)束，耗時(shí)0.0012954s

在并發(fā)收集階段結(jié)束后，你會(huì)看到混合收集階段的日志，如下圖所示，該日志的大部分跟之前討論的新生代收集相同，只有第1部分不一樣：GC pause(G1 Evacuation Pause)(mixed),0.0129474s，這一行表示這是一個(gè)混合垃圾收集周期；在混合垃圾收集處理的CSet不僅包括新生代的分區(qū)，還包括老年代分區(qū)——也就是并發(fā)標(biāo)記階段標(biāo)記出來(lái)的那些老年代分區(qū)。

如果堆內(nèi)存空間不足以分配新的對(duì)象，或者是Metasapce空間使用率達(dá)到了設(shè)定的閾值，那么就會(huì)觸發(fā)Full GC——你在使用G1的時(shí)候應(yīng)該盡量避免這種情況發(fā)生，因?yàn)镚1的Full Gc是單線程、會(huì)Stop The World，代價(jià)非常高。Full GC的日志如下圖所示，從中你可以看出三類信息

Full GC的原因，這個(gè)圖里是Allocation Failure，還有一個(gè)常見的原因是Metadata GC Threshold；

Full GC發(fā)生的頻率，每隔幾天發(fā)生一次Full GC還可以接受，但是每隔1小時(shí)發(fā)生一次Full GC則不可接受；

Full GC的耗時(shí)，這張圖里的Full GC耗時(shí)150ms（PS：按照我的經(jīng)驗(yàn)，實(shí)際運(yùn)行中如果發(fā)生Full GC，耗時(shí)會(huì)比這個(gè)多很多）

基礎(chǔ)配置參數(shù)中，我這里還想介紹兩個(gè)：-XX:+PrintGCApplicationStoppedTime和-XX:+PrintGCApplicationConcurrentTime，這兩個(gè)參數(shù)也可以為你提供有用的信息，如下圖所示：

記錄了應(yīng)用線程在安全點(diǎn)被暫停的總時(shí)間（也就是STW的總時(shí)間）

記錄了讓所有應(yīng)用線程進(jìn)入安全點(diǎn)所花費(fèi)的總時(shí)間

記錄了在兩個(gè)安全點(diǎn)之間應(yīng)用線程運(yùn)行的時(shí)間

這篇文章只是翻譯了原文的第一部分，基礎(chǔ)參數(shù)篇，我接下來(lái)會(huì)有一篇或兩篇文章完成原文的高級(jí)參數(shù)和Debug參數(shù)兩部分。------

本號(hào)專注于后端技術(shù)、JVM問題排查和優(yōu)化、Java面試題、個(gè)人成長(zhǎng)和自我管理等主題，為讀者提供一線開發(fā)者的工作和成長(zhǎng)經(jīng)驗(yàn)，期待你能在這里有所收獲。