
统计结果显示:
- 正常每分钟都有5秒左右的中断 。
- 在11:29~11:30之间,中断频次陡增,这恰恰是问题现象开始出现的时间段 。每分钟的中断总时间甚至高达20~30秒 。
04 关于Safepoint的调查
Safepoint有多种类型,为了确认Safepoint的具体类型,继续让现场同学协助,在jvm.options中添加如下参数,打开JVM日志:
-XX:+PrintSafepointStatistics
-XX:PrintSafepointStatisticsCount=10
-XX:+UnlockDiagnosticVMOptions
-XX:-DisplayVMOutput
-XX:+LogVMOutput
-XX:LogFile=<vm_log_path>等待问题再次复现的过程中,我基于ES运行日志中统计了每一分钟的读写请求频次:
读写请求次数是相对平稳的,这排除了用户请求陡增方面的原因 。
拿到JVM日志时,看到大量的Safepoint类型为ForceSafepoint:

而偏向锁回收相关的Safepoint却应该是长这样的:

这让我疑惑了 。开始在网上搜索ForceSafepoint的触发原因,结果,一无所获 。
查看hotspot的源码,发现至少有5种相关场景:

可见,ForceSafepoint是一个“杂烩”,就像统计图中的“Others”一项 。从这里开始,我将JDK加入到了“重点嫌疑人”清单中 。
继续分析JVM日志 。在每一条Safepoint日志中,同时记录了当时的线程总数(threads: total一列):

回顾一下,出现问题时,三个节点的线程总数有明显出入,问题发生后,线程总数是增多的,尤其是Lucene Merge Threads 。
“多个Lucene Merge任务”与“陡增的ForceSafepoint/STW中断”,哪个是“因”哪个是“果”?
依据JVM日志中统计了每一分钟的ForceSafepoint次数,以及线程总数的变化 。将两条曲线叠加在一起,得到下图:

从图中来看,似乎是ForceSafepoint逐步增多在先,后面的线程才逐步增多 。也就是说,STW中断变多在先,然后多个Merge任务线程才开始逐步积累,就好比,一条目录上突然增设了多个红绿灯,然后这条目录逐步变得拥堵 。
此时,开始请教Kona JDK团队的同学,我把GC日志以及thread dump日志分享给了他,并把我目前为止的发现都告诉了他,最大的怀疑点就是这些不正常的ForceSafepoints,我需要了解ForceSafepoints的原因 。
过了一段时间后,他回复我:这个是arm版本的jdk 。因缺乏arm编译机应急柜,暂时没法给我提供一个debug版本的arm jdk 。
突然明白,我犯了”先入为主”的错误,尽管一开始就意识到需要对环境进行调查 。
难怪在本地X86环境中始终无法复现 。难怪网上搜索ForceSafepoint时一无所获 。
接下来和客户电话会议沟通时,获知:
- 类似的业务,在另外一套X86环境中,没有发现此类问题 。
- 在这套arm环境中,还有另外一个Elasticsearch集群,请求量更低,但没有发现此类问题 。
推荐阅读
- 红米6aroot教程 红米一键root工具下载
- 艾兰岛下载 艾兰岛怎么下载
- 迅雷下载怎么加速 迅雷下载加速教程
- 电影下载软件哪个好用 电影最全的软件推荐
- 声音驱动下载安装 免费声卡驱动安装下载
- ie修复工具修复浏览器 ie修复工具推荐下载
- mp3音乐免费下载软件推荐 好用的mp3音乐免费下载软件
- 字体管家app下载 字体管家安装教程
- 格莉斯的旅程在哪里下载 Gris下载地址分享
- 木马专杀工具哪个好 专杀木马病毒软件下载
