背景
线上的Elasticsearch集群在某一天早上开始写入吞吐下降,环比下降了30%,但是业务的数据量环比没有下降,从而导致数据积压在Kafka中无法消费。
写入吞吐下降后,通过查看监控,发现cpu使用率和load也下降,并没有明显的异常能够表明是Elasticsearch集群出了问题,问题变得棘手起来了。
问题定位
通过查看jstack,可以看到有热点线程,大量线程栈顶为java时间解析类,并且主要有两种时间解析类栈顶:
结合上述时间解析类的堆栈,查看elasticsearch源码,发现在北京时间9月29日 08:00刚好是一个特殊的时间点,0时区的9月29日00:00, 会触发时间解析类的日期检查函数,判断29号是否一个合法的日期:
而这个代码里的if条件,实际上是会进行编译优化,通过抓取进程的火焰图,可以验证性能下降实际上与编译优化的Deoptimization有关,Deoptimization正常情况下占用cpu一般在0.1%,而下图中实际占用了19.92%,这就意味着出现编译退化导致解释执行,而Java的解释执行相比编译优化执行速度慢了两个数量级。
编译退化,实际上是触发了JDK的一个bug(https://bugs.openjdk.java.net/browse/JDK-8227523),在29日这个临界时间点附近,可能触发LocatDate::create()在带有和不带有日期检查(switch分支)的编译优化代码之间反复切换,当切换超过400次之后,就会触发编译退化到解释执行。Presto也有遇到过类似的问题:http://armsword.com/2019/09/18/solve-presto-system-load-too-high/。
此外,从写入的数据字段来看,每条数据会包含4个时间字段,会进一步加大进入到LocateDate::create()的概率,从而拉低写入性能。
解决方案
- 临时的解决方案:快速重启集群可以使得JIT编译优化进行到正确的优化分支,避免反复编译优化,触发JDK 的bug。
- 长期方案: 通过调整JVM参数,规避进入到编译退化分支的可能性:
-XX:PerMethodRecompilationCutoff=10000
-XX:PerBytecodeRecompilationCutoff=10000
-XX:ReservedCodeCacheSize=512M