一次JVM GC长暂停的排查过程

作者: 美团Java | 来源:发表于2018-07-14 15:19 被阅读373次

    现象

    通过CAT埋点,发现在35~36分钟时候,出现JVM的GC耗时异常

    通过跳板机登录机器,找到GC日志进行查看,如下图

    在显示的最后一行中,我们看到其中user=0,sys=0,real=4.31s,表示JVM经历了长达4s多的STW,也即在这段时间内,该机器是无法对外提供服务的,请求到达该机器,最终只能超时返回。

    排查

    根据经验,这种 real > user + sys 的情况,大概率是内存的swap和密集型的IO造成的,可以顺着这个思路进行排查,这时候就突显了系统监控的重要性了,通过查看IO监控

    我们可以发现,在对应的时间上确实存在大量的IO操作。

    为什么频繁IO会引起长时间GC

    在发生GC时,需要把相关数据写入GC日志,在写入期间,因为write()系统调用导致了暂停。这种日志的写操作,即使在异步、缓存IO或非阻塞IO模式下,还是有可能因为系统机制(比如页面缓存的回写),导致长时间的阻塞。

    如何减轻因为IO造成的影响?

    可以将Java日志文件移动到一个单独的或高性能的磁盘驱动器(例如SSD, tmpfs)

    相关文章

      网友评论

      • 风007claudio:你好大神 多谢你的分享! 这个gcverbose log是生产环境的么?我发现打了很多low level的gc log 有多大的overhead么?disk方面的overhead可以写到其他的磁盘解决 个人觉得cpu方面的可能是最大的overhead
      • wangzaixiang:原因还需要继续排查,write系统调用一般是非阻塞的,尤其是写日志这么小的操作
        风007claudio:@wangzaixiang 是不是gc log writer是受害者?

      本文标题:一次JVM GC长暂停的排查过程

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