一次簡單的G1gc參數調優
本文轉載自微信公眾號「再見伐木機」，作者再見伐木機。轉載本文請聯系再見伐木機公眾號。
緣起
交易的查詢服務調用組件的ES進行查詢，ES服務會間歇性的3-4天抖動一次(發生mixedGC)，每次mixedgc耗時都在700ms+，而正常的dubbo超時設置在1s左右，所以當發生GC的時候會引起短時集中式的查詢超時，引起大量報警，而在之前的處理手段都是手動在凌晨四點觸發GC，防止白天對業務應用產生抖動。
插曲
這里要糾正一個很多人的誤解，為什么G1老年代的收集叫做mixedGC?
首先G1的進行老年代垃圾回收的時候不一定是全部的老年代，一般是部分的old region，然后因為老年的收集是可以和young gc同時進行的，所以叫mixedgc。
大部分我遇見以及協助排查的GC案例中幾乎最終都是代碼的問題，比較令人的滿意的一個系統運行的場景其實是每次Ygc都能很好的消化掉垃圾對象，畢竟G1垃圾收集器的默認參數又少、又不錯。
開始
(如上圖)我們從一個正常來說服務調用的鏈路說起：
從鏈路追蹤來看，上游應用發送請求的時間和下游開始處理請求的時間應該相差無幾。但是，一個rpc過程拋開業務邏輯中間需要哪些過程呢?
(此圖從網上copy，如有抄襲嫌疑，請聯系我刪除圖片狗頭保命)
可以看到，有序列化，網絡傳輸等等。那一般接口超時會有哪些因素引起呢?
窮舉法：網絡問題、服務硬件問題、GC問題等
歷史重現
X月XX日，線上查詢服務又一次發生了抖動，于是公司內某張姓大佬過來問我,對話如下：
張大佬：雞哥，請教個問題
雞哥：你說說看，我應該不會(圖片)
張大佬：G1中加了-XX:+ParallelRefProcEnabled參數之后，GC耗時還是會很長，導致一波超時，你知道什么情況么?
雞哥：你確定么?
我們來分析下這個參數，按道理來說這個參數(-XX:+ParallelRefProcEnabled)的含義是：盡可能啟用并行引用處理
那好，
我們探索下他為什么要加這個參數?是出現了什么現象讓他要加這個參數?
原來是張姓大佬通過gclog發現每次GC的【ref proc】階段耗時比較長，于是他從網上搜索到了這個參數之后就加上試了一下
現象
如上圖我們可以發現在gc過程中 ref-proc(mixedgc)階段發生了700ms+的暫停
那
【ref proc】階段到底是干什么的?
其實是對各種軟弱虛引用等的處理
圖中ref-proc 0.7034259 secs 就是處理 soft、weak、phantom、final、JNI 等等引用的時間
Oracle官方文檔如下描述：
其實是在G1的remark階段，對上述的引用根據其特定類型更新所指對象
額外分析
這又得從G1的Ygc說起，我們都知道，Ygc就是對象填滿Eden區然后觸發Ygc，而正常來說G1中有設置
- -XX:MaxGCPauseMillis GC 最大停頓時間，默認 200ms 這個參數會影響到Ygc的STW時間，為什么呢?我們思考一下， MaxGCPauseMillis 時間越小，給STW時間也就越小，年輕代大概率就越小;反之 MaxGCPauseMillis 時間越大，給STW時間也就越大，年輕代大概率就會越大。此時是不是有人會有疑問?那我為了減少STW的時間，我就去降低MaxGCPauseMillis
此言差矣!!!!
MaxGCPauseMillis 越小，年輕代也越小，從而導致有很多短生命周期的對象被過早晉升到老年代。而老年代你們都懂的，標記清理過程比年輕代要復雜的多，整體效率也低，就導致雖然GC停滯時間下降了，但GC次數可能增多，整體吞吐量下降的情況。并且GC次數增多也會導致對CPU資源的占用增加，跟業務線程一起爭搶CPU
第一次處理
然后當天晚點時間，我被拉進一個三人組成的GC問題處理群
實驗了
三組對比參數
未調試:沒有加ParallelRefProcEnabled，年輕代自動分配了17g，Ygc(40ms)，mixedgc (500ms)
調試1:-XX:+ParallelRefProcEnabled，年輕代自動分配了2g，Ygc(50ms)，Ygc次數增加，mixedgc(200ms)
調試2:-XX:+ParallelRefProcEnabled和-XX:ParallelgCThreads=8，年輕代17g，Ygc(40ms)，Ygc次數與未調試的情況差不多，mixedgc還沒有觸發，所以耗時未知
我們可以基本上看到很明顯的問題就是通過加入(-XX:+ParallelRefProcEnabled)
現象：
總結一
其實我們發現官網推薦的指導手段，讓gc時間從700ms+下降到300ms左右，但是對于業務側還是會引起一波超時抖動
第二次處理
當然300ms完全沒辦法支撐，還是會帶來大量抖動，但是現有的gclog不夠觀察到本質，于是我推薦了如下參數，觀測更具體的信息
-XX:+PrintReferenceGC
第二次現象
終于在X月X號，終于觸發了一次Mixedgc，日志也出來了(如下)
第二次處理
我們可以看到Softreference和FinalReference 占了兩個大頭，一個是132ms，一個255ms
其實問題幾乎就已經快壓縮到最后了，此時可以看到Application stop 621ms
第三次現象
于是，問題定位到了就可以著手去解決了!
因為軟引用大家都知道，內存不足的時候才會去收集，所以項目中生成的軟引用對象太多的話，會在gc過程中產生較大的處理壓力
我們這次加上了 -XX:SoftRefLRUPolicyMSPerMB=0
官方解釋：Soft reference在虛擬機中比在客戶集中存活的更長一些。其清除頻率可以用命令行參數 -XX:SoftRefLRUPolicyMSPerMB=
第三次結果
結果是什么?
我們可以看到的現象是 soft引用和final引用在每次Ygc過程中都被收集掉一部分，且數量比之前大一倍
而finalReference的疑問是什么呢?
因為在java8的SocketServiceImpl里實現了Object的finalize方法，為了防止socket鏈接忘了釋放資源，而進行幫助釋放
當有大量短鏈接未來得及釋放，會導致Finalizer對象過多，引起一開始我們看到的現象，所以猜測ES使用的OKHTTP的調用方式，但是無法dump，所以無從考證
但因為已經在每次Ygc中進行收集了，其實也算是達到預期，但是不是很完美。
當然好像JDK9中的AbstractPlainSocketImpl已經不再復寫finalize方法了，因為finallize() 方法是Object類的方法, 用于在類被GC回收時 做一些處理操作, 但是JVM并不能保證finalize() 方法一定被執行,由finalize()方法的調用時機具有不確定性，從一個對象變得不可到達開始，到finalize()方法被執行，所花費的時間這段時間是任意長的。我們并不能依賴finalize()方法能及時的回收占用的資源，可能出現的情況是在我們耗盡資源之前，gc卻仍未觸發，因而通常的做法是提供顯示的close()方法供客戶端手動調用
小插曲
不少人的認知是soft引用會在內存不足時候回收?其實不一定，軟引用的回收是需要一定條件的我們看官方文檔怎么說
clock - timestamp <= freespace * SoftRefLRUPolicyMSPerMB
clock：上次GC的時間戳
timestamp：表示最近一次讀取軟引用對象的時間戳
這兩者的差值表示該軟引用對象多久沒被使用了，差值越大，軟引用對象價值越低，負數則表示軟引用對象剛剛被使用
freespace是空閑空間大小，SoftRefLRUPolicyMSPerMB表示每一MB的空閑內存空間可以允許軟引用對象存活多久，這也就間接的解釋了，為什么空間不夠用，空閑空間越小，軟應用對象就會被回收，因為它的存活時間會隨著空閑空間的減小而遞減。可以把 【freespace * SoftRefLRUPolicyMSPerMB】理解為忍耐度，對軟應用對象的忍耐程度。
等待
其實從gclog和現象之中大概已經猜測到基本上已經算是成功了，但是呢，加上這個參數【SoftRefLRUPolicyMSPerMB】也是有風險的，如下我說的
例子：假設程序中有很多反射創建類的操作，因為反射創建的類本身的Class對象都是被SoftReference軟引用的，加上了如上的參數，軟引用就會被盡快的釋放掉，所以就會產生，反射創建大量類->剛創建完GC回收掉很多->反射執行繼續創建大量類，最終導致Metaspace區域被打滿->導致FullGC
結果
等待了4天之后，聽著張姓大佬一陣激動的叫喊
發現mixedgc已經穩定到85ms左右
小插曲
1.為什么軟引用收集參數【SoftRefLRUPolicyMSPerMB】沒有在jvm中默認打開?
答：因為軟引用的特性特別適合做Cache，設計者目的就是想讓cache常駐內存，所以要到內存不夠的時候才去觸發收集
2.是否要引用ZGC?
中間有人給張姓大佬推薦了ZGC,于是我掏出了這種圖，JDK11開始有的，也是2018年9月左右發布，
第一，可以嘗試，但是這算是屏蔽了問題，而走捷徑;
第二，沒有人完全能hold住，出了問題誰來負責和修復?
GC調優的幾個核心要素
一.要有信心
二.不斷壓縮問題到死角
三.多組參數實驗對比
畢竟沒有兼容所有場景的參數，只有符合自己業務場景的參數調優
附件(給大家參考借鑒，gclog中每個步驟在干什么)：
[GC pause (G1 Evacuation Pause) (young), 0.0022483 secs]
young -> 年輕代 Evacuation-> 復制存活對象
[Parallel Time: 1.0 ms, GC Workers: 10] # 并發執行的GC線程數，以下階段是并發執行的
[GC Worker Start (ms): Min: 109.0, Avg: 109.1, Max: 109.1, Diff: 0.2]
[Ext Root Scanning (ms): Min: 0.1, Avg: 0.2, Max: 0.3, Diff: 0.2, Sum: 2.3] # 外部根分區掃描
[Update RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0] # 更新已記憶集合 Update RSet，檢測從年輕代指向老年代的對象
[Processed Buffers: Min: 0, Avg: 0.0, Max: 0, Diff: 0, Sum: 0]
[Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]# RSet掃描
[Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1] # 代碼根掃描
[Object Copy (ms): Min: 0.3, Avg: 0.3, Max: 0.4, Diff: 0.1, Sum: 3.5] # 轉移和回收，拷貝存活的對象到survivor/old區域
[Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0] # 完成上述任務后，如果任務隊列已空，則工作線程會發起終止要求。
[Termination Attempts: Min: 1, Avg: 5.8, Max: 9, Diff: 8, Sum: 58]
[GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1] # GC外部的并行活動，該部分并非GC的活動，而是JVM的活動導致占用了GC暫停時間(例如JNI編譯)。
[GC Worker Total (ms): Min: 0.5, Avg: 0.6, Max: 0.7, Diff: 0.2, Sum: 5.9]
[GC Worker End (ms): Min: 109.7, Avg: 109.7, Max: 109.7, Diff: 0.0]
[Code Root Fixup: 0.0 ms] # 串行任務，根據轉移對象更新代碼根
[Code Root Purge: 0.0 ms] #串行任務， 代碼根清理
[Clear CT: 0.5 ms] #串行任務，清除全局卡片 Card Table 標記
[Other: 0.8 ms]
[Choose CSet: 0.0 ms] # 選擇下次收集集合 CSet
[Ref Proc: 0.4 ms] # 引用處理 Ref Proc，處理軟引用、弱引用、虛引用、final引用、JNI引用
[Ref Enq: 0.0 ms] # 引用排隊 Ref Enq
[Redirty Cards: 0.3 ms] # 卡片重新臟化 Redirty Cards：重新臟化卡片
[Humongous Register: 0.0 ms]
[Humongous Reclaim: 0.0 ms] # 回收空閑巨型分區 Humongous Reclaim，通過查看所有根對象以及年輕代分區的RSet，如果確定RSet中巨型對象沒有任何引用，該對象分區會被回收。
[Free CSet: 0.0 ms] # 釋放分區 Free CSet
[Eden: 12288.0K(12288.0K)->0.0B(11264.0K) Survivors: 0.0B->1024.0K Heap: 12288.0K(20480.0K)->832.0K(20480.0K)]
[Times: user=0.01 sys=0.00, real=0.00 secs]
從年輕代分區拷貝存活對象時，無法找到可用的空閑分區
從老年代分區轉移存活對象時，無法找到可用的空閑分區 這兩種情況之一導致的 YGC
[GC pause (G1 Evacuation Pause) (young) (to-space exhausted), 0.0916534 secs]
并發標記周期 Concurrent Marking Cycle 中的 根分區掃描階段，被 YGC中斷
[GC pause (G1 Evacuation Pause) (young)[GC concurrent-root-region-scan-end, 0.0007157 secs]
