欢迎您访问程序员文章站本站旨在为大家提供分享程序员计算机编程知识!
您现在的位置是: 首页

复盘一个Elasticsearch排序问题的剖析

程序员文章站 2022-03-31 16:15:39
...

复盘一个Elasticsearch排序问题的剖析
            
    
    博客分类: ELK elasticsearchsort


最近线上的es查询的某个微服务接口,报了一个异常,如下:


```
nested: SearchParseException[No mapping found for [count] in order to sort on];
Caused by: SearchParseException[failed to parse search source 
```


直接从异常上看,可以得到是因为mapping里面不存在排序字段的时候,而抛出的异常,正常的情况,如果某个索引不存在并且还去查询该索引,我们可以通过对索引名字后面加*通配,来避免查询报错,如下:
```
        SearchRequestBuilder search=client.prepareSearch("log2019-07-11*");
        search.setQuery(QueryBuilders.queryStringQuery("uid:111"));
        search.addSort("count", SortOrder.DESC);
```

经询问,我们的代码里面已经加了*通配符,那么又为什么会出现这个问题呢?经过对场景的分析总结,对某个字段进行sort时,可能会报上述异常,主要在两种情况下:

(1)count字段在mapping中无定义,并没有在索引名字后缀加*通配符时,必定每次都报异常

(2)count字段在mapping中有定义,使用前面的排序方法,排序有时候报错,有时候不报

对于第一种情况,mapping里不存在定义,并且没有使用通配容错,直接使用该字段排序报错很正常。

接下来主要分析第二种情况,因为这里面有个概率事件,即大多数时候都没问题,但在少数时候会抛出异常。通过分析log发现在凌晨12点刚过的时候,会有几率出现这种问题,为了找到更多的排查线索,我让运维给出了线上当时服务端es的log文件,毕竟单纯从微服务的log里面,很难观察到这个异常前后,有没有更多的上下文log输出,想要找到这个,只能查看服务端部署es节点的log了,在拿到log之后,果然从上下文里面,发现了一些关键的信息,如下:
```
[2019-07-11 00:00:05,044][INFO ][cluster.metadata         ] [my_es] [log2019-07-11] creating index, cause [auto(index api)], templates [log], shards [3]/[2], mappings [_default_, log]
[2019-07-11 00:00:05,409][INFO ][cluster.routing.allocation] [my_es] Cluster health status changed from [RED] to [YELLOW] (reason: [shards started [[log2019-07-11][0], [log2019-07-11][2], [log2019-07-11][1]] ...]).
[2019-07-11 00:00:06,232][INFO ][cluster.routing.allocation] [my_es] Cluster health status changed from [YELLOW] to [GREEN] (reason: [shards started [[log2019-07-11][1], [log2019-07-11][1]] ...]).
[2019-07-11 00:00:06,374][INFO ][cluster.metadata         ] [my_es] [log2019-07-11] update_mapping [log]
[2019-07-11 00:00:07,153][DEBUG][action.search            ] [my_es] [log2019-07-11][0], node[QlHmfObMRg2K6FUuAaXXTw], [R], v[2], s[INITIALIZING], a[id=3aenuvbUQtGrFDBBxjJvCA], unassigned_info[[reason=INDEX_CREATED], at[2019-07-10T16:00:06.574Z]]: Failed to execute [org.elasticsearch.action.search.SearchRequest@22e9ea6f] lastShard [trueRemoteTransportException[[my_es_02][192.168.10.152:9300][indices:data/read/search[phase/query]]]; nested: SearchParseException[failed to parse search source [{"size":3,"query":{"bool":{"should":[{"term":{"uid":"44733065"}}]}},"sort":[{"count":{"order":"desc"}}]}]]; nested: SearchParseException[No mapping found for [count] in order to sort on];
Caused by: SearchParseException[failed to parse search source 

```


注意,在报这个异常之前,有两行关键的log:
```
[2019-07-11 00:00:05,409][INFO ][cluster.routing.allocation] [my_es] Cluster health status changed from [RED] to [YELLOW] (reason: [shards started [[log2019-07-11][0], [log2019-07-11][2], [log2019-07-11][1]] ...]).
[2019-07-11 00:00:06,232][INFO ][cluster.routing.allocation] [my_es] Cluster health status changed from [YELLOW] to [GREEN] (reason: [shards started [[log2019-07-11][1], [log2019-07-11][1]] ...]).

```

期间报异常的前2秒,es集群状态经历了从red到yellow再到green,虽然只有短暂的1秒,但却是排查问题非常关键的信息,我们知道出现这种信息的时候,代表的是es的主分片和副本分片正在做初始化或者出现了异常等待恢复,由此可以推论出这样一个场景,当凌晨12点刚过的第5秒,有写入该索引的es数据,触发了es动态索引的创建,由于这个索引有3个shard,每个shard分别有2个副本shard,也就是说共有6个shard需要初始化,假设初始化需要的时间为2秒,那么,恰巧在第6秒的时候,有个查询带排序的请求过来了,这个时候由于索引初始化并没有完成,所以在当天部分shard的mapping里面并没有查到该字段的信息,故产生了异常,之后当这个索引创建完成之后,再次收到的新查询请求是没有问题的。为了验证我们这个猜想,我们需要一段程序来做测试:

设计的复现场景有如下两步:

(1)A线程模拟查询请求,一直都在查询某一天的索引数据,起初这个索引并不存在,因为不存在所以查询使用通配符的方法,即使有排序字段,也并不会报错。
A线程的查询代码如下:
```
        SearchRequestBuilder search=client.prepareSearch("log2019-07-11*");
        search.setQuery(QueryBuilders.queryStringQuery("uid:111"));
        search.addSort("count", SortOrder.DESC);
        SearchResponse sr=search.get();
        for ( SearchHit hit: sr.getHits()){
            System.out.println(hit.getSource().toString());
        }
        System.out.println(Thread.currentThread().getName()+"=>query"+"   hit="+sr.getHits().getTotalHits());
```


(2)B线程在A线程启动3秒后执行,然后向这个不存在的索引插入一条数据,由于第一次插入数据,这天的索引会被自动创建,里面就会涉及shard的初始化过程,这个时候同时A线程在查询就会复现出问题:
```
[No mapping found for [count] in order to sort on]
```


B线程的写入代码如下:
```
        IndexRequestBuilder builder = client.prepareIndex("log2019-07-11", "log").setId("111");
        builder.setCreate(true);
        java.util.Map<String , Object> map=new HashMap<>();
        map.put("uid","111");
        map.put("count","3");
        builder.setSource(map);
        builder.execute().actionGet();
        System.out.println(Thread.currentThread().getName()+" => " + "create index finished. " );
```


知道问题后,那么如何解决这个问题呢?其实非常简单,我们只需要对于排序不存在的字段,作一下缺失容错即可,如下:
```
search.addSort("count", SortOrder.DESC);
```

改为
```
search.addSort(SortBuilders.fieldSort("count").unmappedType("integer").order(SortOrder.DESC));
```

上面的代码,告诉es如果在排序时,遇到一个不存在的字段,我们只需要给其设置正确的排序类型即可,这样就能避免前面提到的2个导致排序失败的原因:

(1)count排序字段在mapping中无定义,并没有在索引名字后缀加*通配符时,必定每次都报异常(查询一个不存在字段,是不会报异常的,不管索引名有无后缀通配符)

(2)count排序字段在mapping中有定义,使用前面的排序方法,排序有时候报错,有时候不报(真正原因是当时shard正在做初始化导致的)



es索引本身是shemeless的结构,对于正常查询一个不存在的字段,是不会报错的,但是对于排序的字段,则有可能出现异常,所以我们在写相关的代码时,可以对排序字段加个容错处理,以提高我们程序的健壮性。






















  • 复盘一个Elasticsearch排序问题的剖析
            
    
    博客分类: ELK elasticsearchsort
  • 大小: 29.7 KB
相关标签: elasticsearch sort