记一次Elasticsearch GeoIpDownloader的启动异常排查过程

Posted 2023-02-27 MCNU云原生

最近碰到了Elasticsearch GeoIpDownloader相关的一个异常，花费了不少精力排查，故此记录一下，希望碰到同样问题的童鞋们少走弯路。

这个异常是在Elasticsearch启动的过程中报的error，如下所示，从提示信息来看是因为GeoIpDownloader更新数据库失败导致。

[2023-02-01T15:34:09,249][ERROR][o.e.i.g.GeoIpDownloader  ] [node1] exception during geoip databases updateorg.elasticsearch.ElasticsearchException: not all primary shards of [.geoip_databases] index are active at org.elasticsearch.ingest.geoip@8.4.3/org.elasticsearch.ingest.geoip.GeoIpDownloader.updateDatabases(GeoIpDownloader.java:134)
...
[2023-02-01T15:34:10,144][WARN ][o.e.i.g.GeoIpDownloader  ] [node1] could not delete old chunks for geoip database [GeoLite2-ASN.mmdb]org.elasticsearch.action.search.SearchPhaseExecutionException: all shards failed at org.elasticsearch.server@8.4.3/org.elasticsearch.action.search.AbstractSearchAsyncAction.onPhaseFailure(AbstractSearchAsyncAction.java:728)

GeoIpDownloader是用于下载地图数据库的，在更新的过程中会判断是否所有的分片都是active状态，如果不是的话会抛出这个错误。

        var geoipIndex = clusterState.getMetadata().getIndicesLookup().get(GeoIpDownloader.DATABASES_INDEX);
        if (geoipIndex != null) 
            if (clusterState.getRoutingTable().index(geoipIndex.getWriteIndex()).allPrimaryShardsActive() == false) 
                throw new RuntimeException("not all primary shards of [" + DATABASES_INDEX + "] index are active");

实际上在第一次启动Elasticsearch的时候运行是正常的，并没有出现这个错误，从日志来看，确实Elasticsearch自动创建了一个名为.geoip_databases的索引，并且自动下载了geoip数据库，名为GeoLite2-ASN.mmdb，当重新启动以后程序会自动去更新这个数据库。

[2022-12-14T14:30:42,065][INFO ][o.e.c.m.MetadataCreateIndexService] [node1] [.geoip_databases] creating index, cause [auto(bulk api)], templates [], shards [1]/[0]
[2022-12-14T14:30:42,463][INFO ][o.e.c.r.a.AllocationService] [node1] current.health="GREEN" message="Cluster health status changed from [YELLOW] to [GREEN] (reason: [shards started [[.geoip_databases][0]]])." previous.health="YELLOW" reason="shards started [[.geoip_databases][0]]"
[2022-12-14T14:30:43,929][INFO ][o.e.i.g.GeoIpDownloader  ] [node1] successfully downloaded geoip database [GeoLite2-ASN.mmdb]
[2022-12-14T14:30:44,355][INFO ][o.e.i.g.DatabaseNodeService] [node1] successfully loaded geoip database file [GeoLite2-ASN.mmdb]

既然提示说存在分片的状态是非active的，那么就使用_cat API查询一下.geoip_databases索引的分片情况。

https://192.168.56.11:9200/_cat/shards/.geoip_databases?v
index            shard prirep state   docs  store ip            node
.geoip_databases 0     p      STARTED   37 35.6mb 192.168.56.11 node1

可以看到是有一个编号是0的分片，是一个主分片，状态是STARTED，再通过索引级别的cat API看看结果，通过以下结果可以看到这个索引有1个主分片，0个副本分片，整体状态是green的。

https://192.168.56.11:9200/_cat/indices/.geoip_databases?v
health status index            uuid                   pri rep docs.count docs.deleted store.size pri.store.size
green  open   .geoip_databases CFuIkBC2QFSKf4a8aiKmcA   1   0         37            0     35.6mb         35.6mb

这基本可以判定.geoip_databases并没有存在非active状态的分片。这里似乎存在一个状态判断异常的问题。

我在社区留言，官方团队回复：

一、排查是否可能是因为资源不足，例如存储不足；

二、在GeoIpDownloader中有几个已知的竞争条件，在启动/停止的时候可能触发一些意向不想的问题，这些问题目前对集群的运行没有影响，只是在启动的时候短暂出现。github上有issue专门在讨论这个问题：https://github.com/elastic/elasticsearch/issues/92888。

初步判断在GeoIpDownloader下载更新的环节存在bug，可能导致索引分片状态判断不准确，从而抛出以上错误。

解决方案：

可以在未使用到此功能的时候选择先关闭geoip库的更新，在elasticsearch.yml中添加如下配置：

ingest.geoip.downloader.enabled: false

关闭geoip数据库的更新，重新启动后会自动删除.geoip_databases索引。