求求你了,配个GC日志呗,不然咋分析故障原因
点击关注 ? 芋道源码 文章源自JAVA秀-https://www.javaxiu.com/31362.html
收录于话题文章源自JAVA秀-https://www.javaxiu.com/31362.html
#芋道源码文章源自JAVA秀-https://www.javaxiu.com/31362.html
120个文章源自JAVA秀-https://www.javaxiu.com/31362.html
点击上方“芋道源码”,选择“设为星标”文章源自JAVA秀-https://www.javaxiu.com/31362.html
管她前浪,还是后浪?文章源自JAVA秀-https://www.javaxiu.com/31362.html
能浪的浪,才是好浪!文章源自JAVA秀-https://www.javaxiu.com/31362.html
每天 8:55 更新文章,每天掉亿点点头发...文章源自JAVA秀-https://www.javaxiu.com/31362.html
文章源自JAVA秀-https://www.javaxiu.com/31362.html 源码精品专栏文章源自JAVA秀-https://www.javaxiu.com/31362.html
原创 | Java 2020 超神之路,很肝~文章源自JAVA秀-https://www.javaxiu.com/31362.html
中文详细注释的开源项目文章源自JAVA秀-https://www.javaxiu.com/31362.html
RPC 框架 Dubbo 源码解析文章源自JAVA秀-https://www.javaxiu.com/31362.html
网络应用框架 Netty 源码解析文章源自JAVA秀-https://www.javaxiu.com/31362.html
消息中间件 RocketMQ 源码解析文章源自JAVA秀-https://www.javaxiu.com/31362.html
数据库中间件 Sharding-JDBC 和 MyCAT 源码解析文章源自JAVA秀-https://www.javaxiu.com/31362.html
作业调度中间件 Elastic-Job 源码解析文章源自JAVA秀-https://www.javaxiu.com/31362.html
分布式事务中间件 TCC-Transaction 源码解析文章源自JAVA秀-https://www.javaxiu.com/31362.html
Eureka 和 Hystrix 源码解析文章源自JAVA秀-https://www.javaxiu.com/31362.html
Java 并发源码文章源自JAVA秀-https://www.javaxiu.com/31362.html
来源:juejin.cn/post/6949885566536138783文章源自JAVA秀-https://www.javaxiu.com/31362.html
打印内容文章源自JAVA秀-https://www.javaxiu.com/31362.html
打印基本 GC 信息文章源自JAVA秀-https://www.javaxiu.com/31362.html
打印对象分布文章源自JAVA秀-https://www.javaxiu.com/31362.html
GC 后打印堆数据文章源自JAVA秀-https://www.javaxiu.com/31362.html
打印 STW 时间文章源自JAVA秀-https://www.javaxiu.com/31362.html
打印 safepoint 信息文章源自JAVA秀-https://www.javaxiu.com/31362.html
打印 Reference 处理信息文章源自JAVA秀-https://www.javaxiu.com/31362.html
完整参数文章源自JAVA秀-https://www.javaxiu.com/31362.html
输出方式文章源自JAVA秀-https://www.javaxiu.com/31362.html
JVM 的日志分割文章源自JAVA秀-https://www.javaxiu.com/31362.html
使用时间戳命名文件文章源自JAVA秀-https://www.javaxiu.com/31362.html
二者结合文章源自JAVA秀-https://www.javaxiu.com/31362.html
最佳实践 - 完整参数
文章源自JAVA秀-https://www.javaxiu.com/31362.html
先点赞再看,养成好习惯文章源自JAVA秀-https://www.javaxiu.com/31362.html
生产环境上,或者其他要测试 GC 问题的环境上,一定会配置上打印GC日志的参数,便于分析 GC 相关的问题。文章源自JAVA秀-https://www.javaxiu.com/31362.html
但是可能很多人配置的都不够“完美”,要么是打印的内容过少,要么是输出到控制台,要么是一个大文件被覆盖,要么是……文章源自JAVA秀-https://www.javaxiu.com/31362.html
本文带你一步一步,配置一个完美的 GC 日志打印策略文章源自JAVA秀-https://www.javaxiu.com/31362.html
打印内容
为了保留足够多的“现场证据”,最好是把 GC 相关的信息打印的足够完整 。而且你的程序真的不差你GC时打印日志I/O消耗的那点性能文章源自JAVA秀-https://www.javaxiu.com/31362.html
打印基本 GC 信息
打印 GC 日志的第一步,就是开启 GC 打印的参数了,也是最基本的参数。文章源自JAVA秀-https://www.javaxiu.com/31362.html
-XX:+PrintGCDetails -XX:+PrintGCDateStamps
打印对象分布
为了分析 GC 时的晋升情况和晋升导致的高暂停 ,不看对象年龄分布日志怎么行文章源自JAVA秀-https://www.javaxiu.com/31362.html
-XX:+PrintTenuringDistribution
输出内容示例:文章源自JAVA秀-https://www.javaxiu.com/31362.html
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 前后的堆内存情况,更直观文章源自JAVA秀-https://www.javaxiu.com/31362.html
-XX:+PrintHeapAtGC
输出内容示例:文章源自JAVA秀-https://www.javaxiu.com/31362.html
{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 1048576KHeap 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 最重要的指标,肯定不能少文章源自JAVA秀-https://www.javaxiu.com/31362.html
-XX:+PrintGCApplicationStoppedTime
输出内容示例:文章源自JAVA秀-https://www.javaxiu.com/31362.html
Total time for which application threads were stopped: 0.0254260 seconds, Stopping threads took: 0.0000218 seconds
打印 safepoint 信息
进入STW阶段之前,需要要找到一个合适的 safepoint ,这个指标一样很重要(非必选,出现 GC 问题时最好加上此参数调试)文章源自JAVA秀-https://www.javaxiu.com/31362.html
-XX:+PrintSafepointStatistics -XX:PrintSafepointStatisticsCount=1
输出内容示例:文章源自JAVA秀-https://www.javaxiu.com/31362.html
vmop [threads: total initially_running wait_to_block] [time: spin block sync cleanup vmop] page_trap_count0.371: ParallelGCFailedAllocation [ 10 0 0 ] [ 0 0 0 0 7 ] 0Execute 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_count0.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_count0.396: no vm operation [ 9 1 1 ] [ 0 0 0 0 341 ] 0
打印 Reference 处理信息
强引用/弱引用/软引用/虚引用/finalize 方法万一有问题,不得打印出来看看?文章源自JAVA秀-https://www.javaxiu.com/31362.html
-XX:+PrintReferenceGC
输出内容示例:文章源自JAVA秀-https://www.javaxiu.com/31362.html
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 就是追加),这个文件会越来越大,分析起来就要命了。文章源自JAVA秀-https://www.javaxiu.com/31362.html
所以需要一种分割日志的机制,这个机制嘛……JVM自然是提供的。文章源自JAVA秀-https://www.javaxiu.com/31362.html
JVM 的日志分割
JVM提供了几个用于分割 GC 日志的参数:文章源自JAVA秀-https://www.javaxiu.com/31362.html
## 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, .....
文章源自JAVA秀-https://www.javaxiu.com/31362.html
看似很美好,几行配置就搞定了输出文件的问题。但是这种方式有一些问题:文章源自JAVA秀-https://www.javaxiu.com/31362.html
-Xloggc 方式指定的日志文件,是覆盖写的方式,每次启动都会覆盖,历史日志会丢失文章源自JAVA秀-https://www.javaxiu.com/31362.html
当超过最大分割数后,会从第0个文件开始重新写入,而且是覆盖文章源自JAVA秀-https://www.javaxiu.com/31362.html
-XX:NumberOfGCLogFiles 并不能设置为无限文章源自JAVA秀-https://www.javaxiu.com/31362.html
这个覆盖的问题就有点恶心了,每次启动覆盖之前的历史日志……这谁能忍?文章源自JAVA秀-https://www.javaxiu.com/31362.html
使用时间戳命名文件
于是有另一种解决方案。不使用 JVM 提供的日志分割功能,而是每次启动用时间戳命名日志文件,这样可以每次启动都使用不同的文件,就不会出现覆盖的问题了。文章源自JAVA秀-https://www.javaxiu.com/31362.html
## 使用-%t作为日志文件名-XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:/path/to/gc-%t.log## 生成的文件名是这种:gc-2021-03-29_20-41-47.log
可是这样就完美吗?文章源自JAVA秀-https://www.javaxiu.com/31362.html
虽然没有覆盖的问题,但由于没有日志分割的功能,每次启动后只有一个GC日志文件,单个日志文件可能会非常巨大。过大的日志文件分析起来是很麻烦的,必须得分割。文章源自JAVA秀-https://www.javaxiu.com/31362.html
二者结合
这里只需要稍微调整一下策略,将 JVM 分割和时间戳命名两种方案结合,就可以得到最优的方式 了。文章源自JAVA秀-https://www.javaxiu.com/31362.html
## GC日志输出的文件路径-Xloggc:/path/to/gc-%t.log## 开启日志文件分割-XX:+UseGCLogFileRotation## 最多分割几个文件,超过之后从头开始写-XX:NumberOfGCLogFiles=14## 每个文件上限大小,超过就触发分割-XX:GCLogFileSize=100M
配置时间戳作文 GC 日志文件名的同时,也配置JVM的GC日志分割策略。这样一来,既保证了 GC 文件不会被覆盖,又保证了单个 GC 文件的大小不会过大,完美!文章源自JAVA秀-https://www.javaxiu.com/31362.html
最终得到的日志文件名会像这个样子:文章源自JAVA秀-https://www.javaxiu.com/31362.html
gc-2021-03-29_20-41-47.log.0文章源自JAVA秀-https://www.javaxiu.com/31362.html
gc-2021-03-29_20-41-47.log.1文章源自JAVA秀-https://www.javaxiu.com/31362.html
gc-2021-03-29_20-41-47.log.2文章源自JAVA秀-https://www.javaxiu.com/31362.html
gc-2021-03-29_20-41-47.log.3文章源自JAVA秀-https://www.javaxiu.com/31362.html
....文章源自JAVA秀-https://www.javaxiu.com/31362.html
最佳实践 - 完整参数
## 必备-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
- END -文章源自JAVA秀-https://www.javaxiu.com/31362.html
欢迎加入我的知识星球,一起探讨架构,交流源码。加入方式,长按下方二维码噢:文章源自JAVA秀-https://www.javaxiu.com/31362.html
文章源自JAVA秀-https://www.javaxiu.com/31362.html
已在知识星球更新源码解析如下:文章源自JAVA秀-https://www.javaxiu.com/31362.html
文章源自JAVA秀-https://www.javaxiu.com/31362.html
文章源自JAVA秀-https://www.javaxiu.com/31362.html
文章源自JAVA秀-https://www.javaxiu.com/31362.html
文章源自JAVA秀-https://www.javaxiu.com/31362.html
最近更新《芋道 SpringBoot 2.X 入门》系列,已经 20 余篇,覆盖了 MyBatis、Redis、MongoDB、ES、分库分表、读写分离、SpringMVC、Webflux、权限、WebSocket、Dubbo、RabbitMQ、RocketMQ、Kafka、性能测试等等内容。文章源自JAVA秀-https://www.javaxiu.com/31362.html
提供近 3W 行代码的 SpringBoot 示例,以及超 4W 行代码的电商微服务项目。文章源自JAVA秀-https://www.javaxiu.com/31362.html
获取方式:点“在看”,关注公众号并回复 666 领取,更多内容陆续奉上。文章源自JAVA秀-https://www.javaxiu.com/31362.html
文章源自JAVA秀-https://www.javaxiu.com/31362.html
文章有帮助的话,在看,转发吧。谢谢支持哟 (*^__^*)文章源自JAVA秀-https://www.javaxiu.com/31362.html
阅读原文文章源自JAVA秀-https://www.javaxiu.com/31362.html

评论