JVM长时间stop the world问题分析

最新推荐文章于 2022-08-18 17:42:23 发布

springzzj

最新推荐文章于 2022-08-18 17:42:23 发布

阅读量810

点赞数

本文链接：https://blog.csdn.net/weixin_42566547/article/details/103671955

版权

线上Java服务出现超时问题，分析发现与stop the world现象相关。通过日志、GC参数、Safepoint监控、IO统计等手段定位问题，最终确定为磁盘高IO及坏道导致。调整GC日志位置、减少日志输出、检查磁盘状态后，问题得到解决。

摘要由CSDN通过智能技术生成

近期，线上服务偶尔会出现超时情况。说一下背景，我们的开发语言是java，在单台物理机上部署了3个java模块，他们之间互相调用。服务p999耗时有时候会超过10s，按道理我们的业务不会停滞这么长时间，并且在长时间内只有一台机器多次出现了这个问题。下面是我们的分析流程：

1. 登录机器查看WARN报警日志，事故发生时刻打印了大批WARN日志。进一步发现，在大批打印日志之前，有很长时间没有打印任何日志。怀疑可能是java模块GC导致的stop the world。

2. JVM中增加了-XX:+PrintGC参数，会将gc日志输出到指定文件。查看gc日志，发现确实有长时间stop the world的情况，并和问题发生时间吻合。但是有时候出现在minor gc中，有时候出现在普通的safepoint安全点位置。说明并不单纯是gc导致的，但是问题发生原因肯定和stop theworld有关。

3. 为了知道到底是什么原因导致的stop the world，我们在线下给JVM增加Safepoint相关的参数-XX:+PrintSafepointStatistics -XX:PrintSafepointStatisticsCount=1。jvm需要进入安全点的事情有：gc、代码优化、加载类、取消偏向锁等。但是不幸的是，线下在压力很大的时候也没法复现问题。这样只能在线上打开Safepoint日志等待问题出现，但是我们担心这样会影响jvm性能，暂时这条路先缓一缓。

4. 我们有了新的发现，问题发生时刻机器IO都比较高（sar -dp可以看到历史IO情况，默认情况下是10分钟记录一次，可以改成1分钟一次），并且有时候会两个模块同时出现问题并同时恢复。这样，我们猜测可能是机器本身的问题导致该台机器上所有模块都出现stop