對一次 GC日誌的分析

会飞的猪發表於2020-07-21

在一次壓測時,發現應用做了大量的 YongGc。
透過日誌可以看到觸發 YongGc 的有兩種途徑:
Allocation Failure
GCLocker Initiated GC

日誌詳情:

2020-05-20T19:54:57.647+0800: 351449.612: [GC (Allocation Failure) 2020-05-20T19:54:57.647+0800: 351449.612: [ParNew
Desired survivor size 8716288 bytes, new threshold 15 (max 15)
- age   1:     118080 bytes,     118080 total
- age   2:      83272 bytes,     201352 total
- age   3:      23904 bytes,     225256 total
- age   4:      29168 bytes,     254424 total
- age   5:      86944 bytes,     341368 total
- age   6:      89744 bytes,     431112 total
- age   7:     114144 bytes,     545256 total
- age   8:      11400 bytes,     556656 total
- age   9:      26056 bytes,     582712 total
- age  10:     162856 bytes,     745568 total
- age  11:      30648 bytes,     776216 total
- age  12:      25960 bytes,     802176 total
- age  13:      15552 bytes,     817728 total
- age  14:      82336 bytes,     900064 total
- age  15:     175536 bytes,    1075600 total
: 138365K->1989K(153344K), 0.0170535 secs] 1094019K->957739K(2080128K), 0.0172034 secs] [Times: user=0.03 sys=0.00, real=0.01 secs] 

透過閱讀日誌可以得到的資訊為:
1)Allocation Failure:年輕代中沒有足夠的空間能夠儲存新的資料了。
2)年輕使用的是 ParNew 垃圾收集器。ParNew 是一個 Serial 收集器的多執行緒版本,會使用多個 CPU 和執行緒完成垃圾收集工作(預設使用的執行緒數和 CPU 數相同,可以使用-XX:ParallelGCThreads 引數限制)。該收集器採用複製演算法回收記憶體,期間會停止其他工作執行緒,即 Stop The World。
3)Desired survivor size 8716288 bytes, new threshold 15 (max 15) 期望存活 8M 的記憶體,JVM 內部計算出的晉升閾值最大值為 15。同時可以看到不同晉升閾值的記憶體大小。
4)138365K->1989K(153344K) 138365 千位元組=135.12 兆位元組 133.18 兆
當前的年輕代佔用的大小為 135M YongGc 後記憶體大小為 1989 千位元組=1.94 兆位元組 實際年輕代的總儲存為 153344 千位元組=149.75 兆位元組 YongGc 耗時 17ms
5) 1094019K->957739K(2080128K), 0.0172034 secs 三個引數分別為:堆區垃圾回收前的大小 (1094019 千位元組=1068.37 兆),堆區垃圾回收後的大小 (957739 千位元組=935.29 兆),堆區總大小 (2080128 千位元組=2031.375 兆位元組)。減少 133.08 兆。 說明有 0.1 兆晉升到了老年代。

對 GC 日誌進行的資料統計。

來看一下引數配置:

-XX:MaxDirectMemorySize=1G
-XmX2G
-XmS2G

# CMS GC config
-XX:+UseConcMarkSweepGC
-XX:CMSInitiatingOccupancyFraction=70
-XX:+UseCMSInitiatingOccupancyOnly
-XX:+PrintTenuringDistribution
-XX:MaxTenuringThreshold=15

# GC log
-XX:+PrintGC
-XX:+PrintGCDetails
-XX:+PrintGCDateStamps
-XX:+PrintGCTimeStamps
-XX:+UseGCLogFileRotation
-XX:NumberOfGCLogFiles=2
-XX:GCLogFileSize=128M
-Xloggc:/var/lib/jetty/logs/gc.log

# other config
-XX:+PrintCommandLineFlags
-XX:-OmitStackTraceInFastThrow
-XX:+HeapDumpOnOutOfMemoryError
# -XX:+HeapDumpBeforeFullGC
# -XX:+HeapDumpAfterFullGC
-XX:HeapDumpPath=/var/lib/jetty/logs/dump.hprof
-Dfile.encoding=UTF-8

那麼既然推斷年輕代的大小過小。目前透過配置的引數沒有設定年輕代,那麼目前年輕代的大小為多大呢,且設定多少合適呢。
透過目前的日誌可以看到年輕代的大小為 135M 左右。

那麼這個值是怎麼算出來的呢?

Sun 官方建議年輕代的大小為整個堆的 3/8 左右, 所以按照上述設定的方式,可以設定為 768M。

可以透過設定年輕代大小後,再次觀察 yonggc 的次數和 yonggc 平均耗時、總耗時來決定這個引數是否可行。

JVM 引數最佳化的目的就是降低 gc 頻率、GC 平均耗時和總耗時。從而達到降低程式停頓的時長。

同時可以看下透過調整引數後。gc 吞吐率是否上升了。如果上升了也從側面反映 gc 的頻率和耗時降低了。

以上觀點純屬個人認識,如有問題歡迎留言討論。

相關文章