愛(ài)鋒貝

標(biāo)題: JVM 調(diào)優(yōu)之提升 GC 吞吐量 [打印本頁(yè)]

作者: 邢義數(shù)碼君 時(shí)間: 2023-4-3 16:00
標(biāo)題: JVM 調(diào)優(yōu)之提升 GC 吞吐量
1. 背景

最近對(duì)負(fù)責(zé)的項(xiàng)目進(jìn)行了一次性能優(yōu)化，其中包括對(duì) JVM 參數(shù)的調(diào)整，算是進(jìn)行了一次簡(jiǎ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ì)信息。

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

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

看到的 gc log 形如：

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

3.1 YGC 頻繁

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

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

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

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

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

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

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

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

歡迎光臨愛(ài)鋒貝 (http://m.7gfy2te7.cn/)