记一次Elasticsearch问题排查

AIoT团队在搜索平台上维护了一个较大的索引，其写入平均有2k到3k的tps，查询也有数百QPS。由于该索引较重要且占用资源较多，因此使用Elasticsearch的template功能将之单独部署在专用的机器上。

从5月底开始，写入此索引的flink实时任务就会偶现失败重启的情况，经排查，发现是写入Elasticsearch的请求超时导致的，结合当时机器的cpu占用等指标判定是写入tps过高导致Elasticsearch无法承受，因此，将该索引所占的机器从2台升级到3台，并使用业务数据进行了一轮写入压测，发现能支撑业务方的写入速率，扩完后较长一段时间内，该索引也一直没有出现问题，因此认为问题已经被解决了。

然而，在6月22日凌晨，上述问题再次出现，通过查看指标，发现当时的写入速率并无显著提升。

1. 索引写入速率

既然不是由写入速率提升造成的，那就接着排查其他可能占用CPU资源的行为。

2. 索引查询速率

3. jvm gc次数

4. 节点merge速率

5. 节点写入队列长度

由上述指标可以看出，写入耗时过久是因为索引的其中一个节点写入队列过长，无法及时处理写入导致的。然而在写入队列变长的过程中，节点的gc，merge等操作并无明显变化，索引的查询速率也没有明显提升，因此猜测是某些具有特殊特征的文档导致es写入过慢导致的。

在上述猜测下，我们的思路就变成了找出导致索引过慢的罪魁祸首文档。因此就从埋点数据中收集了很多慢索引文档，尝试手动索引，但均能很快索引完成。

但是线上问题依旧存在，为了使业务不出问题，我们从以下手段尝试修复线上问题：

• 加速Elasticsearch的索引效率

1. 调大索引的refresh_interval参数

2. 修改index.translog.durability为async等

3. 关闭部分字段的索引配置

• 降低flink任务的写数据频率

但是每次尝试均以失败而告终，每次都是实时任务启动不久，写入就超时了。但是在不断排查问题过程中，发现了此问题的以下特征：

• 批量任务与实时任务的写数据TPS差不多，然而批量任务就不会有问题

• 每次出问题的机器都不是同一台

因此，不是机器的问题，应该也不是某些文档的问题（因为后续重建索引时会把之前实时任务同步的文档移到批量任务阶段同步）。因此，为了搞清楚Elasticsearch在这个阶段究竟在做什么导致无法写入数据，我们选取了一个写入队列很长的节点，执行了数次jstack指令，获取Elasticsearch进程的执行堆栈后，发现其中的8个write线程很长时间都处于WAITING状态，其调用堆栈如下：

最后通过查看对应版本的Elasticsearch源代码，发现Elasticsearch的write线程在执行文档的索引操作时需要获取文档主键对应的锁，以防止不同线程同时修改同一篇文档，而出问题时，write线程大部分时间都是在等待这个锁，那就说明很可能是因为实时任务往Elasticsearch批量写入的文档里很多都是同一个主键的，导致write线程的锁争用情况非常严重，后来通过分析数据binlog验证了这个猜想。同时也可以解释上述两个问题：

• 因为批量任务是从数据库中获取数据，对同一个id的多次修改并不会保存历史记录，只会存储当前快照，而实时任务的数据源来自数据库的binlog，其中保存了数据表的所有改动，对同一个id多次修改都会重复同步至Elasticsearch

• 由于每次大量修改的数据id不同，因此路由到的节点也不同，导致每次都会在不同节点上出问题。

在确定问题的具体原因之后，我们修改了同步实时数据的flink任务，使用滚动窗口聚合一段时间内的binlog，将之去重，在窗口结束时再把数据写往Elasticsearch。通过这种方式，降低了重复id出现的频率，但是会导致数据同步的时效性延长一个窗口的时间。与业务方协商后，将窗口定位5s，并不会对业务造成影响，上线后终于解决了这个问题。

The End