共计 4748 个字符,预计需要花费 12 分钟才能阅读完成。
先点赞再看,养成好习惯
生产环境上,或者其余要测试 GC 问题的环境上,肯定会配置上打印 GC 日志的参数,便于剖析 GC 相干的问题。
然而可能很多人配置的都不够“完满”,要么是打印的内容过少,要么是输入到控制台,要么是一个大文件被笼罩,要么是……
本文带你一步一步,配置一个完满的 GC 日志打印策略
打印内容
为了保留足够多的“现场证据”,最好是 GC 相干的信息打印残缺。而且你的程序真的不差你 GC 时打印日志 I / O 耗费的那点性能
打印根本 GC 信息
打印 GC 日志的第一步,就是开启 GC 打印的参数了,也是最根本的参数。
-XX:+PrintGCDetails -XX:+PrintGCDateStamps
打印对象散布
为了剖析 GC 时的 降职状况和降职导致的高暂停,不看对象年龄散布日志怎么行
-XX:+PrintTenuringDistribution
输入内容示例:
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 后打印堆数据
每次产生 GC 时,比照一下 GC 前后的堆内存状况,更直观
-XX:+PrintHeapAtGC
输入内容示例:
{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 工夫
暂停工夫是 GC 最重要的指标,必定不能少
-XX:+PrintGCApplicationStoppedTime
输入内容示例:
Total time for which application threads were stopped: 0.0254260 seconds, Stopping threads took: 0.0000218 seconds
打印 safepoint 信息
进入 STW 阶段之前,须要要找到一个适合的 safepoint,这个指标一样很重要(非必选,呈现 GC 问题时最好加上此参数调试)
-XX:+PrintSafepointStatistics -XX:PrintSafepointStatisticsCount=1
输入内容示例:
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 解决信息
强援用 / 弱援用 / 软援用 / 虚援用 /finalize 办法万一有问题,不得打印进去看看?
-XX:+PrintReferenceGC
输入内容示例:
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]
残缺参数
# requireds
-XX:+PrintGCDetails
-XX:+PrintGCDateStamps
-XX:+PrintTenuringDistribution
-XX:+PrintHeapAtGC
-XX:+PrintReferenceGC
-XX:+PrintGCApplicationStoppedTime
# optional
-XX:+PrintSafepointStatistics
-XX:PrintSafepointStatisticsCount=1
输入形式
下面只是定义了打印的内容,默认状况下,这些日志会输入到控制台(规范输入)。那如果你的程序日志也输入到控制台呢,这个日志内容就会很乱,剖析起来很麻烦。如果你是追加的形式(比方 tomcat 的 catalina.out 就是追加),这个文件会越来越大,剖析起来就要命了。
所以须要一种宰割日志的机制,这个机制嘛……JVM 天然是提供的。
JVM 的日志宰割
JVM 提供了几个用于宰割 GC 日志的参数:
# GC 日志输入的文件门路
-Xloggc:/path/to/gc.log
# 开启日志文件宰割
-XX:+UseGCLogFileRotation
# 最多宰割几个文件,超过之后从头开始写
-XX:NumberOfGCLogFiles=14
# 每个文件下限大小,超过就触发宰割
-XX:GCLogFileSize=100M
依照这个参数,每个 GC 日志只有超过 20M 就会进行宰割,最多宰割 5 个文件,文件名顺次是gc.log.0,gc.log.1,gc.log.2,gc.log.3,gc.log.4, .....
看似很美妙,几行配置就搞定了输入文件的问题。然而这种形式有一些问题:
- -Xloggc 形式指定的日志文件,是笼罩写的形式,每次启动都会笼罩,历史日志会失落
- 当超过最大宰割数后,会从第 0 个文件开始从新写入,而且是笼罩
- -XX:NumberOfGCLogFiles 并不能设置为有限
这个笼罩的问题就有点恶心了,每次启动笼罩之前的历史日志……这谁能忍?
应用工夫戳命名文件
于是有另一种解决方案。不应用 JVM 提供的日志宰割性能,而是每次启动用工夫戳命名日志文件,这样能够每次启动都应用不同的文件,就不会呈现笼罩的问题了。
# 应用 -%t 作为日志文件名
-XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:/path/to/gc-%t.log
# 生成的文件名是这种:gc-2021-03-29_20-41-47.log
可是这样就完满吗?
尽管没有笼罩的问题,但因为没有日志宰割的性能,每次启动后只有一个 GC 日志文件,单个日志文件可能会十分微小。过大的日志文件剖析起来是很麻烦的,必须得宰割。
二者联合
这里只须要略微调整一下策略,将 JVM 宰割和工夫戳命名两种计划联合,就能够失去 最优的形式 了。
# GC 日志输入的文件门路
-Xloggc:/path/to/gc-%t.log
# 开启日志文件宰割
-XX:+UseGCLogFileRotation
# 最多宰割几个文件,超过之后从头开始写
-XX:NumberOfGCLogFiles=14
# 每个文件下限大小,超过就触发宰割
-XX:GCLogFileSize=100M
配置工夫戳作文 GC 日志文件名的同时,也配置 JVM 的 GC 日志宰割策略。这样一来,既保证了 GC 文件不会被笼罩,又保障了单个 GC 文件的大小不会过大,完满!
最终失去的日志文件名会像这个样子:
- gc-2021-03-29_20-41-47.log.0
- gc-2021-03-29_20-41-47.log.1
- gc-2021-03-29_20-41-47.log.2
- gc-2021-03-29_20-41-47.log.3
- ….
最佳实际 – 残缺参数
# 必备
-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
# 最多宰割几个文件,超过之后从头文件开始写
-XX:NumberOfGCLogFiles=14
# 每个文件下限大小,超过就触发宰割
-XX:GCLogFileSize=100M
原创不易,禁止未受权的转载。如果我的文章对您有帮忙,就请点赞 / 珍藏 / 关注激励反对一下吧❤❤❤❤❤❤