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

創(chuàng)新互聯(lián)建站成立與2013年，是專業(yè)互聯(lián)網(wǎng)技術(shù)服務(wù)公司，擁有項目網(wǎng)站設(shè)計制作、成都網(wǎng)站制作網(wǎng)站策劃，項目實施與項目整合能力。我們以讓每一個夢想脫穎而出為使命，1280元定結(jié)做網(wǎng)站,已為上家服務(wù),為定結(jié)各地企業(yè)和個人服務(wù),聯(lián)系電話:18980820575

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

1. 基礎(chǔ)參數(shù)- 在生產(chǎn)中使用G1收集器，必須使用這些參數(shù)
2. 高級參數(shù)- 隨著應(yīng)用的成熟或業(yè)務(wù)負載的增加，需要使用這些參數(shù)針對某些問題進行調(diào)優(yōu)。
3. Debug參數(shù)- 這些參數(shù)是用來解決特定的性能問題，如果某個問題在非生產(chǎn)環(huán)境中無法復現(xiàn)，才會在生產(chǎn)環(huán)境中使用這些參數(shù)排查問題。

基礎(chǔ)參數(shù)

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

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

新生代收集

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

1. 四個關(guān)鍵信息
   • 新生代垃圾收集發(fā)生的時間——2016-12-12T10:40:18.811-0500，通過設(shè)置-XX:+PrintGCDateStamps參數(shù)可以打印出這個時間；
   • JVM啟動后的相對時間——25.959
   • 這次收集的類型——新生代收集，只回收Eden分區(qū)
   • 這次收集花費的時間——0.0305171s，即30ms
2. 列出了新生代收集中并行收集的詳細過程
   • Parallel Time：并行收集任務(wù)在運行過程中引發(fā)的STW（Stop The World）時間，從新生代垃圾收集開始到最后一個任務(wù)結(jié)束，共花費26.6ms
   • GC Workers：有4個線程負責垃圾收集，通過參數(shù)-XX:ParallelGCThreads設(shè)置，這個參數(shù)的值的設(shè)置，跟CPU有關(guān)，如果物理CPU支持的線程個數(shù)小于8，則最多設(shè)置為8；如果物理CPU支持的線程個數(shù)大于8，則默認值為number * 5/8
   • GC Worker Start：第一個垃圾收集線程開始工作時JVM啟動后經(jīng)過的時間（min）；最后一個垃圾收集線程開始工作時JVM啟動后經(jīng)過的時間（max）；diff表示min和max之間的差值。理想情況下，你希望他們幾乎是同時開始，即diff趨近于0。
   • Ext Root Scanning：掃描root集合（線程棧、JNI、全局變量、系統(tǒng)表等等）花費的時間，掃描root集合是垃圾收集的起點，嘗試找到是否有root集合中的節(jié)點指向當前的收集集合（CSet）
   • Update RS(Remembered Set or RSet)：每個分區(qū)都有自己的RSet，用來記錄其他分區(qū)指向當前分區(qū)的指針，如果RSet有更新，G1中會有一個post-write barrier管理跨分區(qū)的引用——新的被引用的card會被標記為dirty，并放入一個日志緩沖區(qū)，如果這個日志緩沖區(qū)滿了會被加入到一個全局的緩沖區(qū)，在JVM運行的過程中還有線程在并發(fā)處理這個全局日志緩沖區(qū)的dirty card。Update RS表示允許垃圾收集線程處理本次垃圾收集開始前沒有處理好的日志緩沖區(qū)，這可以確保當前分區(qū)的RSet是最新的。
     • Processed Buffers，這表示在Update RS這個過程中處理多少個日志緩沖區(qū)。
   • Scan RS：掃描每個新生代分區(qū)的RSet，找出有多少指向當前分區(qū)的引用來自CSet。
   • Code Root Scanning：掃描代碼中的root節(jié)點（局部變量）花費的時間
   • Object Copy：在疏散暫停期間，所有在CSet中的分區(qū)必須被轉(zhuǎn)移疏散，Object Copy就負責將當前分區(qū)中存活的對象拷貝到新的分區(qū)。
   • Termination：當一個垃圾收集線程完成任務(wù)時，它就會進入一個臨界區(qū)，并嘗試幫助其他垃圾線程完成任務(wù)（steal outstanding tasks），min表示該垃圾收集線程什么時候嘗試terminatie，max表示該垃圾收集回收線程什么時候真正terminated。
     • Termination Attempts：如果一個垃圾收集線程成功盜取了其他線程的任務(wù)，那么它會再次盜取更多的任務(wù)或再次嘗試terminate，每次重新terminate的時候，這個數(shù)值就會增加。
   • GC Worker Other：垃圾收集線程在完成其他任務(wù)的時間
   • GC Worker Total：展示每個垃圾收集線程的最小、最大、平均、差值和總共時間。
   • GC Worker End：min表示最早結(jié)束的垃圾收集線程結(jié)束時該JVM啟動后的時間；max表示最晚結(jié)束的垃圾收集線程結(jié)束時該JVM啟動后的時間。理想情況下，你希望它們快速結(jié)束，并且最好是同一時間結(jié)束。
3. 列出了新生代GC中的一些任務(wù)：
   • Code Root Fixup：釋放用于管理并行垃圾收集活動的數(shù)據(jù)結(jié)構(gòu)，應(yīng)該接近于0，該步驟是線性執(zhí)行的；
   • Code Root Purge：清理更多的數(shù)據(jù)結(jié)構(gòu)，應(yīng)該很快，耗時接近于0，也是線性執(zhí)行。
   • Clear CT：清理card table
4. 包含一些擴展功能
   • Choose CSet：選擇要進行回收的分區(qū)放入CSet（G1選擇的標準是垃圾最多的分區(qū)優(yōu)先，也就是存活對象率最低的分區(qū)優(yōu)先）
   • Ref Proc：處理Java中的各種引用——soft、weak、final、phantom、JNI等等。
   • Ref Enq：遍歷所有的引用，將不能回收的放入pending列表
   • Redirty Card：在回收過程中被修改的card將會被重置為dirty
   • Humongous Register：JDK8u60提供了一個特性，巨型對象可以在新生代收集的時候被回收——通過G1ReclaimDeadHumongousObjectsAtYoungGC設(shè)置，默認為true。
   • Humongous Reclaim：做下列任務(wù)的時間：確保巨型對象可以被回收、釋放該巨型對象所占的分區(qū)，重置分區(qū)類型，并將分區(qū)還到free列表，并且更新空閑空間大小。
   • Free CSet：將要釋放的分區(qū)還回到free列表。
5. 展示了不同代的大小變化，以及堆大小的自適應(yīng)調(diào)整。
   • Eden:1097.0M(1097.0M)->0.0B(967.0M)：（1）當前新生代收集觸發(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）在本次垃圾收集活動開始的時候，堆空間整體使用量是1694.4M，堆空間的最大值是2048M；（2）在本次垃圾收集結(jié)束后，堆空間的使用量是763.4M，最大值保持不變。
6. 第6點展示了本次新生代垃圾收集的時間
   • user=0.8：垃圾收集線程在新生代垃圾收集過程中消耗的CPU時間，這個時間跟垃圾收集線程的個數(shù)有關(guān)，可能會比real time大很多；
   • sys=0.0：內(nèi)核態(tài)線程消耗的CPU時間
     -real=0.03：本次垃圾收集真正消耗的時間；

并發(fā)垃圾收集

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

1. 標志著并發(fā)垃圾收集階段的開始：
   • GC pause(G1 Evacuation Pause)(young)(initial-mark)：為了充分利用STW的機會來trace所有可達（存活）的對象，initial-mark階段是作為新生代垃圾收集中的一部分存在的（搭便車）。initial-mark設(shè)置了兩個TAMS（top-at-mark-start）變量，用來區(qū)分存活的對象和在并發(fā)標記階段新分配的對象。在TAMS之前的所有對象，在當前周期內(nèi)都會被視作存活的。
2. 表示第并發(fā)標記階段做的第一個事情：根分區(qū)掃描
   • GC concurrent-root-region-scan-start：根分區(qū)掃描開始，根分區(qū)掃描主要掃描的是新的survivor分區(qū)，找到這些分區(qū)內(nèi)的對象指向當前分區(qū)的引用，如果發(fā)現(xiàn)有引用，則做個記錄；
   • GC concurrent-root-region-scan-end：根分區(qū)掃描結(jié)束，耗時0.0030613s
3. 表示并發(fā)標記階段
   • GC Concurrent-mark-start：并發(fā)標記階段開始。（1）并發(fā)標記階段的線程是跟應(yīng)用線程一起運行的，不會STW，所以稱為并發(fā)；并發(fā)標記階段的垃圾收集線程，默認值是Parallel Thread個數(shù)的25%，這個值也可以用參數(shù)-XX:ConcGCThreads設(shè)置；（2）trace整個堆，并使用位圖標記所有存活的對象，因為在top TAMS之前的對象是隱式存活的，所以這里只需要標記出那些在top TAMS之后、閾值之前的；（3）記錄在并發(fā)標記階段的變更，G1這里使用了SATB算法，該算法要求在垃圾收集開始的時候給堆做一個快照，在垃圾收集過程中這個快照是不變的，但實際上肯定有些對象的引用會發(fā)生變化，這時候G1使用了pre-write barrier記錄這種變更，并將這個記錄存放在一個SATB緩沖區(qū)中，如果該緩沖區(qū)滿了就會將它加入到一個全局的緩沖區(qū)，同時G1有一個線程在并行得處理這個全局緩沖區(qū)；（4）在并發(fā)標記過程中，會記錄每個分區(qū)的存活對象占整個分區(qū)的大小的比率；
   • GC Concurrent-mark-end：并發(fā)標記階段結(jié)束，耗時0.3055438s
4. 重新標記階段，會Stop the World
   • Finalize Marking：Finalizer列表里的Finalizer對象處理，耗時0.0014099s；
   • GC ref-proc：引用（soft、weak、final、phantom、JNI等等）處理，耗時0.0000480s；
   • Unloading：類卸載，耗時0.0025840s；
   • 除了前面這幾個事情，這個階段最關(guān)鍵的結(jié)果是：繪制出當前并發(fā)周期中整個堆的最后面貌，剩余的SATB緩沖區(qū)會在這里被處理，所有存活的對象都會被標記；

5. 清理階段，也會Stop the World

   • 計算出最后存活的對象：標記出initial-mark階段后分配的對象；標記出至少有一個存活對象的分區(qū)；
   • 為下一個并發(fā)標記階段做準備，previous和next位圖會被清理；
   • 沒有存活對象的老年代分區(qū)和巨型對象分區(qū)會被釋放和清理；
   • 處理沒有任何存活對象的分區(qū)的RSet；
   • 所有的老年代分區(qū)會按照自己的存活率（存活對象占整個分區(qū)大小的比例）進行排序，為后面的CSet選擇過程做準備；
6. 并發(fā)清理階段
   • GC concurrent-cleanup-start：并發(fā)清理階段啟動。完成第5步剩余的清理工作；將完全清理好的分區(qū)加入到二級free列表，等待最終還會到總體的free列表；
   • GC concurrent-cleanup-end：并發(fā)清理階段結(jié)束，耗時0.0012954s

混合收集

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

Full GC

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

1. Full GC的原因，這個圖里是Allocation Failure，還有一個常見的原因是Metadata GC Threshold；
2. Full GC發(fā)生的頻率，每隔幾天發(fā)生一次Full GC還可以接受，但是每隔1小時發(fā)生一次Full GC則不可接受；
3. Full GC的耗時，這張圖里的Full GC耗時150ms（PS：按照我的經(jīng)驗，實際運行中如果發(fā)生Full GC，耗時會比這個多很多）

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

1. 記錄了應(yīng)用線程在安全點被暫停的總時間（也就是STW的總時間）
2. 記錄了讓所有應(yīng)用線程進入安全點所花費的總時間
3. 記錄了在兩個安全點之間應(yīng)用線程運行的時間

總結(jié)

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

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

網(wǎng)站名稱：【譯】深入理解G1的GC日志（一）
標題鏈接：http://m.newbst.com/article16/jdgpgg.html

成都網(wǎng)站建設(shè)公司_創(chuàng)新互聯(lián)，為您提供品牌網(wǎng)站制作、響應(yīng)式網(wǎng)站、軟件開發(fā)、網(wǎng)站導航、做網(wǎng)站、定制網(wǎng)站

廣告

聲明：本網(wǎng)站發(fā)布的內(nèi)容（圖片、視頻和文字）以用戶投稿、用戶轉(zhuǎn)載內(nèi)容為主，如果涉及侵權(quán)請盡快告知，我們將會在第一時間刪除。文章觀點不代表本網(wǎng)站立場，如需處理請聯(lián)系客服。電話：028-86922220；郵箱：631063699@qq.com。內(nèi)容未經(jīng)允許不得轉(zhuǎn)載，或轉(zhuǎn)載時需注明來源： 創(chuàng)新互聯(lián)