FlinkFlink jvm参数配置GC日志

Posted 九师兄

tags:

篇首语:本文由小常识网(cha138.com)小编为大家整理,主要介绍了FlinkFlink jvm参数配置GC日志相关的知识,希望对你有一定的参考价值。

1.概述

转载:Flink jvm参数配置GC日志

生产环境上,或者其他要测试 GC 问题的环境上,一定会配置上打印GC日志的参数,便于分析 GC 相关的问题。

但是可能很多人配置的都不够“完美”,要么是打印的内容过少,要么是输出到控制台,要么是一个大文件被覆盖,要么是……

本文带你一步一步,配置一个完美的 GC 日志打印策略

打印内容

为了保留足够多的“现场证据”,最好是把 GC 相关的信息打印的足够完整。而且你的程序真的不差你GC时打印日志I/O消耗的那点性能

打印基本 GC 信息

打印 GC 日志的第一步,就是开启 GC 打印的参数了,也是最基本的参数。

-XX:+PrintGCDetails -XX:+PrintGCDateStamps

   

打印对象分布

为了分析 GC 时的晋升情况和晋升导致的高暂停,不看对象年龄分布日志怎么行

-XX:+PrintTenuringDistribution

   

输出内容示例:


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

GC 后打印堆数据

每次发生 GC 时,对比一下 GC 前后的堆内存情况,更直观

-XX:+PrintHeapAtGC

   

输出内容示例:


   
  1. Heap before GC invocations= 0 (full  0):
  2.  garbage-first heap   total 1024000K, used 324609K [ 0x00000007818000000x0000000781901f400x00000007c0000000)
  3.   region size 1024K,  6 young (6144K),  0 survivors (0K)
  4.  Metaspace       used 3420K, capacity 4500K, committed 4864K, reserved 1056768K
  5.    class space    used 371Kcapacity 388Kcommitted 512Kreserved 1048576K
  6. Heap after GC invocations= 1 (full  1):
  7.  garbage-first heap   total 1024000K, used 21755K [ 0x00000007818000000x0000000781901f400x00000007c0000000)
  8.   region size 1024K,  0 young (0K),  0 survivors (0K)
  9.  Metaspace       used 3420K, capacity 4500K, committed 4864K, reserved 1056768K
  10.    class space    used 371Kcapacity 388Kcommitted 512Kreserved 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

   

输出内容示例:


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

打印 Reference 处理信息

强引用/弱引用/软引用/虚引用/finalize 方法万一有问题,不得打印出来看看?

-XX:+PrintReferenceGC

   

输出内容示例:


   
  1. 2021- 02- 19T12: 41: 30.462+ 08005072726.605: [SoftReference,  0 refs,  0.0000521 secs]
  2. 2021- 02- 19T12: 41: 30.462+ 08005072726.605: [ WeakReference0 refs,  0.0000069 secs]
  3. 2021- 02- 19T12: 41: 30.462+ 08005072726.605: [FinalReference,  0 refs,  0.0000056 secs]
  4. 2021- 02- 19T12: 41: 30.462+ 08005072726.605: [PhantomReference,  0 refs,  0 refs,  0.0000059 secs]
  5. 2021- 02- 19T12: 41: 30.462+ 08005072726.605: [JNI Weak Reference,  0.0000131 secs],  0.4635293 secs]

完整参数


   
  1. # requireds
  2. -XX:+PrintGCDetails 
  3. -XX:+PrintGCDateStamps 
  4. -XX:+PrintTenuringDistribution 
  5. -XX:+PrintHeapAtGC 
  6. -XX:+PrintReferenceGC 
  7. -XX:+PrintGCApplicationStoppedTime
  8. # optional
  9. -XX:+PrintSafepointStatistics 
  10. -XX:PrintSafepointStatisticsCount=1

输出方式

上面只是定义了打印的内容,默认情况下,这些日志会输出到控制台(标准输出)。那如果你的程序日志也输出到控制台呢,这个日志内容就会很乱,分析起来很麻烦。如果你是追加的方式(比如 tomcat 的 catalina.out 就是追加),这个文件会越来越大,分析起来就要命了。

所以需要一种分割日志的机制,这个机制嘛……JVM自然是提供的。

JVM 的日志分割

JVM提供了几个用于分割 GC 日志的参数:


   
  1. # GC日志输出的文件路径
  2. -Xloggc: /path/to/gc.log
  3. # 开启日志文件分割
  4. -XX:+UseGCLogFileRotation 
  5. # 最多分割几个文件,超过之后从头开始写
  6. -XX:NumberOfGCLogFiles= 14
  7. # 每个文件上限大小,超过就触发分割
  8. -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 提供的日志分割功能,而是每次启动用时间戳命名日志文件,这样可以每次启动都使用不同的文件,就不会出现覆盖的问题了。


   
  1. # 使用-%t作为日志文件名
  2. -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc: /path/to/gc-%t.log
  3. # 生成的文件名是这种:gc-2021-03-29_20-41-47.log

可是这样就完美吗?

虽然没有覆盖的问题,但由于没有日志分割的功能,每次启动后只有一个GC日志文件,单个日志文件可能会非常巨大。过大的日志文件分析起来是很麻烦的,必须得分割。

二者结合

这里只需要稍微调整一下策略,将 JVM 分割和时间戳命名两种方案结合,就可以得到最优的方式了。


   
  1. # GC日志输出的文件路径
  2. -Xloggc: /path/to/gc-%t.log
  3. # 开启日志文件分割
  4. -XX:+UseGCLogFileRotation 
  5. # 最多分割几个文件,超过之后从头开始写
  6. -XX:NumberOfGCLogFiles= 14
  7. # 每个文件上限大小,超过就触发分割
  8. -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

  • ....

最佳实践 - 完整参数


   
  1. # 必备
  2. -XX:+PrintGCDetails 
  3. -XX:+PrintGCDateStamps 
  4. -XX:+PrintTenuringDistribution 
  5. -XX:+PrintHeapAtGC 
  6. -XX:+PrintReferenceGC 
  7. -XX:+PrintGCApplicationStoppedTime
  8. # 可选
  9. -XX:+PrintSafepointStatistics 
  10. -XX:PrintSafepointStatisticsCount=1
  11. # GC日志输出的文件路径
  12. -Xloggc:/path/to/gc-%t.log
  13. # 开启日志文件分割
  14. -XX:+UseGCLogFileRotation 
  15. # 最多分割几个文件,超过之后从头文件开始写
  16. -XX:NumberOfGCLogFiles=14
  17. # 每个文件上限大小,超过就触发分割
  18. -XX:GCLogFileSize=100M

以上是关于FlinkFlink jvm参数配置GC日志的主要内容,如果未能解决你的问题,请参考以下文章

jvm GC日志 相关参数

Java虚拟机详解----常用JVM配置参数

JVM常用GC日志打印参数

java虚拟机常用的jvm配置参数

jvm GC参数调优

JVM·参数配置