Elasticsearch GC优化实践

近期业务查询线上ES集群出现频繁超时告警，尤其是早晨某个时间点固定的报一波超时，从调用链监控上很难看出是什么业务行为导致的。

初步猜测

查看Grafana上Elasticsaerch的基础监控，发现业务告警与ES的Old GC（老年代GC）卡顿时间基本吻合：

 

同时注意到，Old区的内存持续增长，不到1小时就会将Old区填满，经过Old GC几乎全部可以回收掉：

猜测：

• 是什么导致Old区快速增长？可能是内存分配速率过高导致过早晋升？可能是分配很大的对象？
• 为什么Old GC这么慢？ES卡顿大概率与它有关，早晨时间固定发生可能与业务某种行为有关。

查看GC配置

所以先用JVM工具从外围查看一下GC配置与大概情况。

jmap查看ES堆情况：

• MaxHeapSize：整个堆31GB。
• MaxNewSize：Young区只有1GB。
• OldSize：Old区有30GB。
• NewRatio：取值2表示Young区应该占整个堆的1/3，应该是10GB才对，而实际才1GB，这非常奇怪。

我们期望的默认行为是Young=10GB，Old=20GB才对，为什么变成了1GB和30GB这样？

查看了一下JVM最终的启动参数，竟然真的自行推断Young区只占1GB空间，难道是JVM的BUG？

把剩余的GC参数谷歌了一下，果然发现有人测试过JDK8的-XX:+UseConcMarkSweepGC会导致NewRatio参数失效，原因不明！

这么小的Young区肯定会导致频繁Young GC （通过jstat -gc观察YGC每秒1~2次） ，对ES性能肯定没有好处， 虽然和Old GC慢没啥直接关系 ，但也必须先修复一下再说了，通过-Xmn直接指定Young区10GB即可：

重启ES观察到Young区大小正确，观察jstat -gc发现Young GC频率显著下降了6倍。

再次观察grafana，发现YGC频率的确下降（YGC之间有间隔了）：

Old区仍旧保持高增速：

但是因为Young区从1GB调到10GB了，所以每次YGC对JVM heap的收缩振幅会更明显，图形上出现明显的起落，但整个JVM heap持续走高的势头没有改变，因为对象仍旧在快速晋升到Old区，直到Old区填满后一次Old GC再大幅回落。

开启GC日志

接下来要分析Old区快速增长的原因，另外要看一下为什么Old GC会卡顿1秒，能否优化？

配置开启GC日志，重启ES：

为了判断是不是存在很多”中生命期”的对象存在而导致频繁晋升到Old区，所以需要打开-XX:MaxTenuringThreshold=15参数，令Young区晋升条件提高为15代YGC，以便观察Young区的对象年龄分布。

一开始我采用默认参数是6代晋升，这是当时的截图：

图中观察到1~6岁的对象都有，每一代就几十MB的空间占用，我们知道YGC后6岁的就会进入Old区，1~5岁的就会都涨1岁，所以我怀疑就是每次YGC会导致第6代几十MB的”中生命期”对象晋升到Old区，大概算了一下这个速度的确和Old GC的周期接近，看样大概率是这个原因导致Old区增长的。

如果我调高晋升年龄到15代，有可能活到10岁的”中生命期”对象就会最终在YGC被回收掉，可能会减缓Old区的增长速度，抱着这个想法我才将XX:MaxTenuringThreshold调到了15，想给”中生命期”对象多一些机会被YGC回收掉。

但实际情况是15代都均匀的分布着对象，可见”中生命期”的对象活的比想象的要久，能熬过15代YGC还不释放，既然现实情况就是有很多”中生命期”对象存在，那减缓Old区增长的想法是比较难实现了， 索性继续研究一下为什么Old GC那么卡的问题吧 。

优化Old GC速度

根据打印到磁盘上gc日志，可以深入分析一下CMS Old GC的流程耗时在哪里，我们应该重点关注会导致STW（stop the world）的阶段耗时。

CMS垃圾回收算法是Old区的GC算法，它的开始以这样的日志标识：

2022-03-12T13:19:54.273+0800: 96253.129: [GC (CMS Initial Mark) [1 CMS-initial-mark: 23554181K(31398336K)] 23611096K(32395136K), 0.0063801 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]

初始化标记阶段，只会STW一丢丢的时间，基本可以忽略。

整个CMS的经历如下阶段：

在Remark阶段会有明显的STW，知乎上是这样描述的：

因为Old GC全流程比较漫长，期间Young区会快速填充，等到Remark阶段要扫全堆的时候Young区也填满了很多对象，此时强制配置一波YGC（本身又很快），应该可以减少Remark的STW耗时。

目前观察到Remark阶段耗时：

STW长达0.8秒，的确很惨，我们加上这个选项：

-XX:+CMSScavengeBeforeRemark

添加上述配置后，可以看到Remark阶段时间STW耗时缩短了7倍左右：

优化效果

红色为原线上配置的对照实例，其他机器均已生效新配置：

可见，GC频率与耗时均明显下降，新的Old GC耗时已经降低到原先的Young GC耗时的水平，早晨超时报警的情况也消失了。