JVM 調(diào)優(yōu)之提升 GC 吞吐量

邢義數(shù)碼君

1. 背景

最近對負(fù)責(zé)的項(xiàng)目進(jìn)行了一次性能優(yōu)化，其中包括對 JVM 參數(shù)的調(diào)整，算是進(jìn)行了一次簡單的 JVM 調(diào)優(yōu)，JVM參數(shù)調(diào)整之后，服務(wù)的整體性能有 5% 左右的提升，還算不錯(cuò)。
先介紹一下項(xiàng)目的基本情況：
項(xiàng)目是一個(gè)高 QPS 壓力的 web 服務(wù)，單機(jī) QPS 一直維持在 1.5K 以上，由于舊機(jī)器的拖累，配置的堆大小是 8G，其中 young 區(qū)是 4G，垃圾回收器用的是 parNew + CMS。
2. 舊狀

首先是查看當(dāng)前 GC 的情況，主要是使用 jstat 查看 GC 的概況，再查看 gc log，分析單次 gc 的詳細(xì)狀況。使用 jstat -gcutil pid 1000 每隔一秒打印一次 gc 統(tǒng)計(jì)信息。

登錄/注冊后可看大圖

可以看到，單次 gc平均耗時(shí)是 60ms 左右，還算可以接受，但 YGC 非常頻繁，基本上每秒一次，有的時(shí)候還會(huì)一秒兩次，在一秒兩次的時(shí)候，服務(wù)對業(yè)務(wù)響應(yīng)時(shí)長的壓力就會(huì)變得很大。
接著查看 gc log，打印 gc log 需要在 JVM 啟動(dòng)參數(shù)里添加以下參數(shù)：

• -XX:+PrintGCDateStamps：打印 gc 發(fā)生的時(shí)間戳。
  
• -XX:+PrintTenuringDistribution：打印 gc 發(fā)生時(shí)的分代信息。
  
• -XX:+PrintGCApplicationStoppedTime：打印 gc 停頓時(shí)長
  
• -XX:+PrintGCApplicationConcurrentTime：打印 gc 間隔的服務(wù)運(yùn)行時(shí)長
  
• -XX:+PrintGCDetails：打印 gc 詳情，包括 gc 前/內(nèi)存等。
  
• -Xloggc:../gclogs/gc.log.date：指定 gc log 的路徑
  

看到的 gc log 形如：

登錄/注冊后可看大圖

單次 GC 方面并不能直接看出問題，但可以看到 gc 前有很多次 18ms 左右的停頓。
3. 分析和調(diào)整

3.1 YGC 頻繁

直接查看 gc log并不直觀，我們可以借用一些可視化工具來幫助我們分析， [gceasy](https://gceasy.io/) 是個(gè)挺不錯(cuò)的網(wǎng)站，我們把 gc log 上傳上去后， gceasy 可以幫助我們生成各個(gè)維度的圖表幫助分析。
查看 gceasy 生成的報(bào)告，發(fā)現(xiàn)我們服務(wù)的 gc 吞吐量是 95%，它指的是 JVM 運(yùn)行業(yè)務(wù)代碼的時(shí)長占 JVM 總運(yùn)行時(shí)長的比例，這個(gè)比例確實(shí)有些低了，運(yùn)行 100 分鐘就有 5 分鐘在執(zhí)行 gc。幸好這些 GC 中絕大多數(shù)都是 YGC，單次時(shí)長可控且分布平均，這使得我們服務(wù)還能平穩(wěn)運(yùn)行。
解決這個(gè)問題要么是減少對象的創(chuàng)建，要么就增大 young 區(qū)。前者不是一時(shí)半會(huì)兒都解決的，需要查找代碼里可能有問題的點(diǎn)，分步優(yōu)化。
而后者雖然改一下配置就行，但以我們對 GC 最直觀的印象來說，增大 young 區(qū)，YGC 的時(shí)長也會(huì)迅速增大。
其實(shí)這點(diǎn)不必太過擔(dān)心，我們知道 YGC 的耗時(shí)是由 GC 標(biāo)記 + GC 復(fù)制 組成的，相對于 GC 復(fù)制，GC 標(biāo)記是非?？斓摹６?young 區(qū)內(nèi)大多數(shù)對象的生命周期都非常短，如果將 young 區(qū)增大一倍，GC 標(biāo)記的時(shí)長會(huì)提升一倍，但到 GC 發(fā)生時(shí)被標(biāo)記的對象大部分已經(jīng)死亡， GC 復(fù)制的時(shí)長肯定不會(huì)提升一倍，所以我們可以放心增大 young 區(qū)大小。
由于低內(nèi)存舊機(jī)器都被換掉了，我把堆大小調(diào)整到了 12G，young 區(qū)保留為 8G。
3.2 分代調(diào)整

除了 GC 太頻繁之外，GC 后各分代的平均大小也需要調(diào)整。

登錄/注冊后可看大圖

我們知道 GC 的提升機(jī)制，每次 GC 后，JVM 存活代數(shù)大于 MaxTenuringThreshold 的對象提升到老年代。當(dāng)然，JVM 還有動(dòng)態(tài)年齡計(jì)算的規(guī)則：按照年齡從小到大對其所占用的大小進(jìn)行累積，當(dāng)累積的某個(gè)年齡大小超過了 survivor 區(qū)的一半時(shí)，取這個(gè)年齡和 MaxTenuringThreshold 中更小的一個(gè)值，作為新的晉升年齡閾值，但看各代總的內(nèi)存大小，是達(dá)不到 survivor 區(qū)的一半的。

登錄/注冊后可看大圖

所以這十五個(gè)分代內(nèi)的對象會(huì)一直在兩個(gè) survivor 區(qū)之間來回復(fù)制，再觀察各分代的平均大小，可以看到，四代以上的對象已經(jīng)有一半都會(huì)保留到老年區(qū)了，所以可以將這些對象直接提升到老年代，以減少對象在兩個(gè) survivor 區(qū)之間復(fù)制的性能開銷。
所以我把 MaxTenuringThreshold 的值調(diào)整為 4，將存活超過四代的對象直接提升到老年代。
3.3 偏向鎖停頓

還有一個(gè)問題是 gc log 里有很多 18ms 左右的停頓，有時(shí)候連續(xù)有十多條，雖然每次停頓時(shí)長不長，但連續(xù)多次累積的時(shí)間也非常可觀。這是因?yàn)?.8 之后 JVM 對鎖進(jìn)行了優(yōu)化，添加了偏向鎖的概念，避免了很多不必要的加鎖操作，但偏向鎖一旦遇到鎖競爭，取消鎖需要進(jìn)入 safe point，導(dǎo)致 STW。
解決方式很簡單，JVM 啟動(dòng)參數(shù)里添加 -XX:-UseBiasedLocking 即可。
4. 結(jié)果

調(diào)整完 JVM 參數(shù)后先是對服務(wù)進(jìn)行壓測，發(fā)現(xiàn)性能確實(shí)有提升，也沒有發(fā)生嚴(yán)重的 GC 問題，之后再把調(diào)整好的配置放到線上機(jī)器進(jìn)行灰度，同時(shí)收集 gc log，再次進(jìn)行分析。
由于 young 區(qū)大小翻倍了，所以 YGC 的頻率減半了，GC 的吞量提升到了 97.75%。 平均 GC 時(shí)長略有上升，從 60ms 左右提升到了 66ms，還是挺符合預(yù)期的。
由于 CMS 在進(jìn)行 GC 時(shí)也會(huì)清理 young 區(qū)，CMS 的時(shí)長也受到了影響，CMS 的最終標(biāo)記和并發(fā)清理階段耗時(shí)增加了，也比較正常。
另外我還統(tǒng)計(jì)了對業(yè)務(wù)的影響，之前因?yàn)?GC 導(dǎo)致超時(shí)的請求大大減少了。
小結(jié)

總之，這是一次挺成功的 GC 調(diào)整，讓我對 GC 有了更深的理解，但由于沒有深入到 old 區(qū)，之前學(xué)習(xí)到的 CMS 相關(guān)的知識還沒有復(fù)習(xí)到。不過性能優(yōu)化并不是一朝一夕的事，需要時(shí)刻關(guān)注問題，及時(shí)做出調(diào)整。
參考：記一次簡單的 JVM 調(diào)優(yōu)

-----------------------------