一次JVM GC长暂停的排查过程
2018-07-14 本文已影响373人
美团Java
现象
通过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)
