JVM之GC日志续

作者: java搬砖从来不加班 | 来源:发表于2021-08-17 21:15 被阅读0次
    需求三天改,加班一月长,
    家人不相见,怒刷进度墙。 
    奋斗需牢记,调薪语不详,
    此中辛酸泪,误识谭浩强。
    

    本文大概阐述和GC日志相关的jvm启动参数的一些内容。

    GC日志相关基本参数

    -XX:+PrintGCDetails
      输出GC的详细日志
    -XX:+PrintGCTimeStamps
      输出GC的时间戳(以基准时间的形式)
    -XX:+PrintGCDateStamps
      输出GC的时间戳(以日期的形式,如 2013-05-04T21:53:59.234+0800)
    -XX:+PrintHeapAtGC
      在进行GC的前后打印出堆的信息
    -XX:+PrintGCApplicationStoppedTime
      输出GC造成应用暂停的时间
    -XX:+PrintReferenceGC
      引用相关信息,虚、弱、强引用的个数和耗时
    -Xloggc:../logs/gc.log
      日志文件的输出路径
    

    特殊说明:生产环境gc日志要遵循够用就好的原则,因为gc日志的时间也是会算在stw时间里的,如果gc日志的输出是同步刷盘模式,有可能会因为系统其他IO异常造成gc停顿时间的异常(由于gc打印造成的异常我们下一篇再详细介绍下)

    GC日志相关特殊参数

    1. GC日志滚动

    -XX:+UseGCLogFileRotation
    

    GC日志的输出会发生文件IO,有时候也会造成不必要的停顿,可以将GC日志输出到tmpfs(内存文件系统)中,但tmpfs会消耗内存,为了避免内存被浪费可以使用-XX:+UseGCLogFileRotation滚动GC日志。

    2. 禁写Statistics数据

    -XX:+PerfDisableSharedMem
    

    gstst会默默的在/tmp/hperf 目录写上一点statistics数据。
    如果gc时,刚好遇到PageCache刷盘,把文件阻塞了,就不能结束这个Stop the World的安全点了。用上述参数禁用jstat,用jmx来代替即可。参见:jvm-mmap-pause

    3. 安全点相关参数

    -XX:+PrintSafepointStatistics
    -XX:PrintSafepointStatisticsCount = 1
    

    安全点相关日志输出如下:

    vmop[threads: total initially_running wait_to_block][time: spin block sync cleanup vmop]page_trap_count
    0.257: ParallelGCFailedAllocation[       9          0              0    ][     0     0     0     0     2    ]  0
    0.261: novmoperation[       7          0              1    ][     0     0     0     0     0    ]  0
    
    • vmop
    • 表示 引发STW的原因
    • [thread]
    • total:安全点里的总线程数
    • initially_running:安全点时开始时正在运行状态的线程数
    • wait_to_block:在VM Operation开始前需要等待其暂停的线程数
    • [time]
    • spin:等待线程响应safepoint号召的时间
    • block:暂停所有线程所用的时间
    • sync:(spin + block),==从开始到进入安全点所耗的时间,可用于判断进入安全点耗时
    • cleanup:清理所需时间
    • vmop:真正执行VM Operation的时间

    no vm operation 说明这里没有vm相关操作发生,因此表示是一个安全点
    安全点对系统的健康监控是非常重要的。会使用到安全点的场景有GC、偏向锁撤销等,总之是提供一个对象状态不变的状态点,去让系统进行一系列的后续操作。
    这里要顺便提一下另一个和安全点相关的jvm参数:-XX:-UseBiasedLocking
    禁用偏向锁的设置参数,在有的情况下比较有效,如果并发竞争变大,会导致偏向锁撤销频繁,这个时候我们可能会看到安全点的耗时增加,进而导致了gc时间和系统响应时间增大,关于安全点和偏向锁的异常案例,我们也放在下一篇一并列举

    补:性能和调优相关特殊参数

    1. dump相关参数

    这个应该不属于gc日志相关参数,但是都在jvm启动参数里,就顺便提下

    • 1.heap dump
    -XX:+HeapDumpOnOutOfMemoryError
    

    这个参数,主要作用是,在系统发生oom异常时,自动进行heap dump操作,有些大佬说在容器环境混部情况下,在普通硬盘上会造成20秒以上的硬盘IO跑满,对其他宿主程序是很不友好的,但是按生产环境的实际运营情况看,这个参数还是非常有用的,在系统发生oom异常需要尽快重启恢复的时候,dump下来的现场文件对异常的排查是非常有帮助的。

    • 2.core dump
    ulimit -c unlimited
    

    从CoreDump能够转出Heap Dump 和 Thread Dump 还有crash的地方,非常实用

    2. Integer Cache

    -XX:AutoBoxCacheMax=20000
    

    对于Integer和 Long,JDK默认只缓存 -128 ~ +127,超出范围的数字就要实时构建新的Integer对象。对于性能要求很高的系统场景,可以设置此参数,据有关测算,QPS影响达4%左右。

    3. 启动时预访问

    -XX:+AlwaysPreTouch
    

    ElasticSearch和Cassandra都设置了此参数。作用是内存页预访问,可能启动时慢上一点,但访问时会更快速些,比如新生代晋升到老生代时不会临时访问页面使得GC停顿时间加长。

    4. 即时编译

    -XX:-UseCounterDecay
    -XX:-TieredCompilation
    

    gc默认进行技术器衰减操作,可能会导致某些临界访问量的方法,一直无法转成热点代码,所以可以使用UseCounterDecay参数来禁用计数器衰减操作。TieredCompilation是1.8默认开启的多层编译。但是业界大佬在实测时发现启动初期可能有性能减弱,有需要可以将其禁用。

    总结

    本篇主要概述了gc日志所涉及到的一些可能需要关注的参数设置,其中提及的一些实际案例,我们后续文章补充;也顺便列举了一些和性能相关的jvm启动参数,在大家平时有遇到类似问题可以当做个参考。
    当然,和gc相关的jvm启动参数是非常多的,gc策略、并发收集线程数、eden和s区的比例、对象年代、cms的碎片压缩、G1的停顿时间等等,每一个都可以结合实际需求单独一篇来展开阐述。后续有机会再逐一补充吧

    相关文章

      网友评论

        本文标题:JVM之GC日志续

        本文链接:https://www.haomeiwen.com/subject/vyqibltx.html