java - 为什么elasticsearch慢查询中take_millis和timeout之间有很多时间开销

Question

我在生产环境中遇到了一些慢查询，我配置了慢日志来查找一些慢查询信息，比如这样(query_string with 500ms timeout):

[2021-06-21T10:43:33,930][DEBUG][index.search.slowlog.query.xxxx] [xxx][g][2] took[1s], took_millis[1043], total_hits[424690], types[top], stats[], search_typ      e[QUERY_THEN_FETCH], total_shards[6], source[{query_string}]

本例中，查询超时为500ms，响应中的take_millis为1043ms。据我所知，超时仅对查询解析有用，取值表示 es 中的执行时间，没有一些外部阶段，如 Query timing: ‘took’ value and what I’m measuring .我有两个问题:

• 首先，为什么超时和take_millis之间有504ms(1043 - 500 = 504)？
• 其次，我如何知道超时和 take_millis 时间之间的详细时间成本？

非常感谢!

Answer 1

为查询设置超时并不能确保查询在其执行时间超过该超时时实际上被取消。 Elasticsearch 文档指出:

"By default, a running search only checks if it is cancelled or not onsegment boundaries, therefore the cancellation can be delayed by largesegments."

https://www.elastic.co/guide/en/elasticsearch/reference/6.8/search.html#global-search-timeout

检查问题 3627 , 4586和 2929

这可以解释timeout和take_millis之间的504ms，你的query就用了这么久，并没有及时取消。

要分析查询执行并查看可能导致这些长时间延迟的原因，您可以使用 profile API 重新运行查询.请注意，如果您的查询执行缓慢无法重现，这将无法帮助您解决问题。如果您的查询大部分时间都运行良好，请尝试将这些运行缓慢的查询与服务器负载等外部因素相关联。