求你了晤碘,GC 日志打印別再瞎配置了

先點(diǎn)贊再看皆辽,養(yǎng)成好習(xí)慣

生產(chǎn)環(huán)境上信夫,或者其他要測(cè)試 GC 問題的環(huán)境上蹦哼,一定會(huì)配置上打印GC日志的參數(shù)王悍,便于分析 GC 相關(guān)的問題岛心。

但是可能很多人配置的都不夠“完美”沦零,要么是打印的內(nèi)容過少祭隔,要么是輸出到控制臺(tái),要么是一個(gè)大文件被覆蓋路操,要么是……

本文帶你一步一步疾渴,配置一個(gè)完美的 GC 日志打印策略

打印內(nèi)容

為了保留足夠多的“現(xiàn)場(chǎng)證據(jù)”千贯,最好是把 GC 相關(guān)的信息打印的足夠完整而且你的程序真的不差你GC時(shí)打印日志I/O消耗的那點(diǎn)性能

打印基本 GC 信息

打印 GC 日志的第一步搞坝,就是開啟 GC 打印的參數(shù)了搔谴,也是最基本的參數(shù)。

-XX:+PrintGCDetails -XX:+PrintGCDateStamps

打印對(duì)象分布

為了分析 GC 時(shí)的晉升情況和晉升導(dǎo)致的高暫停桩撮,不看對(duì)象年齡分布日志怎么行

-XX:+PrintTenuringDistribution

輸出內(nèi)容示例:

Desired survivor size 59244544 bytes, new threshold 15 (max 15)
- age   1:     963176 bytes,     963176 total
- age   2:     791264 bytes,    1754440 total
- age   3:     210960 bytes,    1965400 total
- age   4:     167672 bytes,    2133072 total
- age   5:     172496 bytes,    2305568 total
- age   6:     107960 bytes,    2413528 total
- age   7:     205440 bytes,    2618968 total
- age   8:     185144 bytes,    2804112 total
- age   9:     195240 bytes,    2999352 total
- age  10:     169080 bytes,    3168432 total
- age  11:     114664 bytes,    3283096 total
- age  12:     168880 bytes,    3451976 total
- age  13:     167272 bytes,    3619248 total
- age  14:     387808 bytes,    4007056 total
- age  15:     168992 bytes,    4176048 total

GC 后打印堆數(shù)據(jù)

每次發(fā)生 GC 時(shí)敦第,對(duì)比一下 GC 前后的堆內(nèi)存情況,更直觀

-XX:+PrintHeapAtGC

輸出內(nèi)容示例:

{Heap before GC invocations=0 (full 0):
 garbage-first heap   total 1024000K, used 324609K [0x0000000781800000, 0x0000000781901f40, 0x00000007c0000000)
  region size 1024K, 6 young (6144K), 0 survivors (0K)
 Metaspace       used 3420K, capacity 4500K, committed 4864K, reserved 1056768K
  class space    used 371K, capacity 388K, committed 512K, reserved 1048576K
Heap after GC invocations=1 (full 1):
 garbage-first heap   total 1024000K, used 21755K [0x0000000781800000, 0x0000000781901f40, 0x00000007c0000000)
  region size 1024K, 0 young (0K), 0 survivors (0K)
 Metaspace       used 3420K, capacity 4500K, committed 4864K, reserved 1056768K
  class space    used 371K, capacity 388K, committed 512K, reserved 1048576K
}

打印 STW 時(shí)間

暫停時(shí)間是 GC 最重要的指標(biāo)店量,肯定不能少

-XX:+PrintGCApplicationStoppedTime

輸出內(nèi)容示例:

Total time for which application threads were stopped: 0.0254260 seconds, Stopping threads took: 0.0000218 seconds

打印 safepoint 信息

進(jìn)入STW階段之前芜果,需要要找到一個(gè)合適的 safepoint ,這個(gè)指標(biāo)一樣很重要(非必選融师,出現(xiàn) GC 問題時(shí)最好加上此參數(shù)調(diào)試)

-XX:+PrintSafepointStatistics -XX:PrintSafepointStatisticsCount=1

輸出內(nèi)容示例:

         vmop                    [threads: total initially_running wait_to_block]    [time: spin block sync cleanup vmop] page_trap_count
0.371: ParallelGCFailedAllocation       [      10          0              0    ]      [     0     0     0     0     7    ]  0   
Execute full gc...dataList has been promoted to cms old space
         vmop                    [threads: total initially_running wait_to_block]    [time: spin block sync cleanup vmop] page_trap_count
0.379: ParallelGCSystemGC               [      10          0              0    ]      [     0     0     0     0    16    ]  0   
         vmop                    [threads: total initially_running wait_to_block]    [time: spin block sync cleanup vmop] page_trap_count
0.396: no vm operation                  [       9          1              1    ]      [     0     0     0     0   341    ]  0   

打印 Reference 處理信息

強(qiáng)引用/弱引用/軟引用/虛引用/finalize 方法萬一有問題师幕,不得打印出來看看?

-XX:+PrintReferenceGC

輸出內(nèi)容示例:

2021-02-19T12:41:30.462+0800: 5072726.605: [SoftReference, 0 refs, 0.0000521 secs]
2021-02-19T12:41:30.462+0800: 5072726.605: [WeakReference, 0 refs, 0.0000069 secs]
2021-02-19T12:41:30.462+0800: 5072726.605: [FinalReference, 0 refs, 0.0000056 secs]
2021-02-19T12:41:30.462+0800: 5072726.605: [PhantomReference, 0 refs, 0 refs, 0.0000059 secs]
2021-02-19T12:41:30.462+0800: 5072726.605: [JNI Weak Reference, 0.0000131 secs], 0.4635293 secs]

完整參數(shù)

# requireds
-XX:+PrintGCDetails 
-XX:+PrintGCDateStamps 
-XX:+PrintTenuringDistribution 
-XX:+PrintHeapAtGC 
-XX:+PrintReferenceGC 
-XX:+PrintGCApplicationStoppedTime

# optional
-XX:+PrintSafepointStatistics 
-XX:PrintSafepointStatisticsCount=1

輸出方式

上面只是定義了打印的內(nèi)容诬滩,默認(rèn)情況下霹粥,這些日志會(huì)輸出到控制臺(tái)(標(biāo)準(zhǔn)輸出)。那如果你的程序日志也輸出到控制臺(tái)呢疼鸟,這個(gè)日志內(nèi)容就會(huì)很亂后控,分析起來很麻煩。如果你是追加的方式(比如 tomcat 的 catalina.out 就是追加)空镜,這個(gè)文件會(huì)越來越大浩淘,分析起來就要命了。

所以需要一種分割日志的機(jī)制吴攒,這個(gè)機(jī)制嘛……JVM自然是提供的张抄。

JVM 的日志分割

JVM提供了幾個(gè)用于分割 GC 日志的參數(shù):

# GC日志輸出的文件路徑
-Xloggc:/path/to/gc.log
# 開啟日志文件分割
-XX:+UseGCLogFileRotation 
# 最多分割幾個(gè)文件,超過之后從頭開始寫
-XX:NumberOfGCLogFiles=14
# 每個(gè)文件上限大小洼怔,超過就觸發(fā)分割
-XX:GCLogFileSize=100M

按照這個(gè)參數(shù)署惯,每個(gè)GC日志只要超過20M就會(huì)進(jìn)行分割,最多分割5個(gè)文件镣隶,文件名依次是gc.log.0,gc.log.1,gc.log.2,gc.log.3,gc.log.4, .....

看似很美好极谊,幾行配置就搞定了輸出文件的問題。但是這種方式有一些問題:

  1. -Xloggc 方式指定的日志文件安岂,是覆蓋寫的方式轻猖,每次啟動(dòng)都會(huì)覆蓋,歷史日志會(huì)丟失
  2. 當(dāng)超過最大分割數(shù)后域那,會(huì)從第0個(gè)文件開始重新寫入咙边,而且是覆蓋
  3. -XX:NumberOfGCLogFiles 并不能設(shè)置為無限

這個(gè)覆蓋的問題就有點(diǎn)惡心了,每次啟動(dòng)覆蓋之前的歷史日志……這誰能忍?

使用時(shí)間戳命名文件

于是有另一種解決方案败许。不使用 JVM 提供的日志分割功能友瘤,而是每次啟動(dòng)用時(shí)間戳命名日志文件,這樣可以每次啟動(dòng)都使用不同的文件檐束,就不會(huì)出現(xiàn)覆蓋的問題了辫秧。

# 使用-%t作為日志文件名
-XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:/path/to/gc-%t.log

# 生成的文件名是這種:gc-2021-03-29_20-41-47.log

可是這樣就完美嗎?

雖然沒有覆蓋的問題被丧,但由于沒有日志分割的功能盟戏,每次啟動(dòng)后只有一個(gè)GC日志文件,單個(gè)日志文件可能會(huì)非常巨大甥桂。過大的日志文件分析起來是很麻煩的柿究,必須得分割。

二者結(jié)合

這里只需要稍微調(diào)整一下策略黄选,將 JVM 分割和時(shí)間戳命名兩種方案結(jié)合蝇摸,就可以得到最優(yōu)的方式了。

# GC日志輸出的文件路徑
-Xloggc:/path/to/gc-%t.log
# 開啟日志文件分割
-XX:+UseGCLogFileRotation 
# 最多分割幾個(gè)文件办陷,超過之后從頭開始寫
-XX:NumberOfGCLogFiles=14
# 每個(gè)文件上限大小貌夕,超過就觸發(fā)分割
-XX:GCLogFileSize=100M

配置時(shí)間戳作文 GC 日志文件名的同時(shí),也配置JVM的GC日志分割策略民镜。這樣一來啡专,既保證了 GC 文件不會(huì)被覆蓋,又保證了單個(gè) GC 文件的大小不會(huì)過大制圈,完美们童!

最終得到的日志文件名會(huì)像這個(gè)樣子:

  1. gc-2021-03-29_20-41-47.log.0
  2. gc-2021-03-29_20-41-47.log.1
  3. gc-2021-03-29_20-41-47.log.2
  4. gc-2021-03-29_20-41-47.log.3
  5. ....

最佳實(shí)踐 - 完整參數(shù)

# 必備
-XX:+PrintGCDetails 
-XX:+PrintGCDateStamps 
-XX:+PrintTenuringDistribution 
-XX:+PrintHeapAtGC 
-XX:+PrintReferenceGC 
-XX:+PrintGCApplicationStoppedTime

# 可選
-XX:+PrintSafepointStatistics 
-XX:PrintSafepointStatisticsCount=1

# GC日志輸出的文件路徑
-Xloggc:/path/to/gc-%t.log
# 開啟日志文件分割
-XX:+UseGCLogFileRotation 
# 最多分割幾個(gè)文件,超過之后從頭文件開始寫
-XX:NumberOfGCLogFiles=14
# 每個(gè)文件上限大小鲸鹦,超過就觸發(fā)分割
-XX:GCLogFileSize=100M

原創(chuàng)不易慧库,禁止未授權(quán)的轉(zhuǎn)載。如果我的文章對(duì)您有幫助馋嗜,就請(qǐng)點(diǎn)贊/收藏/關(guān)注鼓勵(lì)支持一下吧??????

?著作權(quán)歸作者所有,轉(zhuǎn)載或內(nèi)容合作請(qǐng)聯(lián)系作者
  • 序言:七十年代末齐板,一起剝皮案震驚了整個(gè)濱河市,隨后出現(xiàn)的幾起案子嵌戈,更是在濱河造成了極大的恐慌覆积,老刑警劉巖听皿,帶你破解...
    沈念sama閱讀 217,542評(píng)論 6 504
  • 序言:濱河連續(xù)發(fā)生了三起死亡事件熟呛,死亡現(xiàn)場(chǎng)離奇詭異,居然都是意外死亡尉姨,警方通過查閱死者的電腦和手機(jī)庵朝,發(fā)現(xiàn)死者居然都...
    沈念sama閱讀 92,822評(píng)論 3 394
  • 文/潘曉璐 我一進(jìn)店門,熙熙樓的掌柜王于貴愁眉苦臉地迎上來,“玉大人九府,你說我怎么就攤上這事椎瘟。” “怎么了侄旬?”我有些...
    開封第一講書人閱讀 163,912評(píng)論 0 354
  • 文/不壞的土叔 我叫張陵肺蔚,是天一觀的道長(zhǎng)。 經(jīng)常有香客問我儡羔,道長(zhǎng)宣羊,這世上最難降的妖魔是什么? 我笑而不...
    開封第一講書人閱讀 58,449評(píng)論 1 293
  • 正文 為了忘掉前任汰蜘,我火速辦了婚禮仇冯,結(jié)果婚禮上,老公的妹妹穿的比我還像新娘族操。我一直安慰自己苛坚,他們只是感情好,可當(dāng)我...
    茶點(diǎn)故事閱讀 67,500評(píng)論 6 392
  • 文/花漫 我一把揭開白布色难。 她就那樣靜靜地躺著泼舱,像睡著了一般。 火紅的嫁衣襯著肌膚如雪枷莉。 梳的紋絲不亂的頭發(fā)上柠掂,一...
    開封第一講書人閱讀 51,370評(píng)論 1 302
  • 那天,我揣著相機(jī)與錄音依沮,去河邊找鬼涯贞。 笑死,一個(gè)胖子當(dāng)著我的面吹牛危喉,可吹牛的內(nèi)容都是我干的宋渔。 我是一名探鬼主播,決...
    沈念sama閱讀 40,193評(píng)論 3 418
  • 文/蒼蘭香墨 我猛地睜開眼辜限,長(zhǎng)吁一口氣:“原來是場(chǎng)噩夢(mèng)啊……” “哼皇拣!你這毒婦竟也來了?” 一聲冷哼從身側(cè)響起薄嫡,我...
    開封第一講書人閱讀 39,074評(píng)論 0 276
  • 序言:老撾萬榮一對(duì)情侶失蹤氧急,失蹤者是張志新(化名)和其女友劉穎,沒想到半個(gè)月后毫深,有當(dāng)?shù)厝嗽跇淞掷锇l(fā)現(xiàn)了一具尸體吩坝,經(jīng)...
    沈念sama閱讀 45,505評(píng)論 1 314
  • 正文 獨(dú)居荒郊野嶺守林人離奇死亡,尸身上長(zhǎng)有42處帶血的膿包…… 初始之章·張勛 以下內(nèi)容為張勛視角 年9月15日...
    茶點(diǎn)故事閱讀 37,722評(píng)論 3 335
  • 正文 我和宋清朗相戀三年哑蔫,在試婚紗的時(shí)候發(fā)現(xiàn)自己被綠了钉寝。 大學(xué)時(shí)的朋友給我發(fā)了我未婚夫和他白月光在一起吃飯的照片弧呐。...
    茶點(diǎn)故事閱讀 39,841評(píng)論 1 348
  • 序言:一個(gè)原本活蹦亂跳的男人離奇死亡,死狀恐怖嵌纲,靈堂內(nèi)的尸體忽然破棺而出俘枫,到底是詐尸還是另有隱情,我是刑警寧澤逮走,帶...
    沈念sama閱讀 35,569評(píng)論 5 345
  • 正文 年R本政府宣布鸠蚪,位于F島的核電站,受9級(jí)特大地震影響师溅,放射性物質(zhì)發(fā)生泄漏邓嘹。R本人自食惡果不足惜,卻給世界環(huán)境...
    茶點(diǎn)故事閱讀 41,168評(píng)論 3 328
  • 文/蒙蒙 一险胰、第九天 我趴在偏房一處隱蔽的房頂上張望汹押。 院中可真熱鬧,春花似錦起便、人聲如沸棚贾。這莊子的主人今日做“春日...
    開封第一講書人閱讀 31,783評(píng)論 0 22
  • 文/蒼蘭香墨 我抬頭看了看天上的太陽妙痹。三九已至,卻和暖如春鼻疮,著一層夾襖步出監(jiān)牢的瞬間怯伊,已是汗流浹背。 一陣腳步聲響...
    開封第一講書人閱讀 32,918評(píng)論 1 269
  • 我被黑心中介騙來泰國打工判沟, 沒想到剛下飛機(jī)就差點(diǎn)兒被人妖公主榨干…… 1. 我叫王不留耿芹,地道東北人。 一個(gè)月前我還...
    沈念sama閱讀 47,962評(píng)論 2 370
  • 正文 我出身青樓挪哄,卻偏偏與公主長(zhǎng)得像吧秕,于是被迫代替她去往敵國和親。 傳聞我的和親對(duì)象是個(gè)殘疾皇子迹炼,可洞房花燭夜當(dāng)晚...
    茶點(diǎn)故事閱讀 44,781評(píng)論 2 354

推薦閱讀更多精彩內(nèi)容