先点赞再看，养成好习惯

生产环境上，或者其余要测试 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 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 最重要的指标，必定不能少

-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_count0.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_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 办法万一有问题，不得打印进去看看？

-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, .....

看似很美妙，几行配置就搞定了输入文件的问题。然而这种形式有一些问题：

  1. -Xloggc 形式指定的日志文件，是笼罩写的形式，每次启动都会笼罩，历史日志会失落
  2. 当超过最大宰割数后，会从第0个文件开始从新写入，而且是笼罩
  3. -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 文件的大小不会过大，完满！

最终失去的日志文件名会像这个样子：

  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. ....

最佳实际 - 残缺参数

# 必备-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
原创不易，禁止未受权的转载。如果我的文章对您有帮忙，就请点赞/珍藏/关注激励反对一下吧❤❤❤❤❤❤