为啥在elasticsearch慢查询中take_millis和超时之间有很多时间成本

Posted 2023-03-22

【中文标题】为啥在elasticsearch慢查询中take_millis和超时之间有很多时间成本

【英文标题】：Why there is much time cost between took_millis and timeout in elasticsearch slow query为什么在elasticsearch慢查询中take_millis和超时之间有很多时间成本

【发布时间】：2021-12-06 00:09:38

【问题描述】：

我在生产环境中遇到了一些慢查询，我配置了慢日志来查找一些像这样的慢查询信息（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 这样的一些外部阶段。我有两个问题：

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

非常感谢！

【问题讨论】：

你的索引有多少个主分片？

【参考方案1】：

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

"默认情况下，正在运行的搜索只检查它是否被取消 段边界，因此取消可以延迟很大 段。”

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

检查问题3627、4586 和2929

这可以解释 timeout 和 take_millis 之间的 504ms，你的查询只需要那么长的时间，并且没有及时取消。

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

【讨论】：

另外值得一提的是，指定的超时时间是per shard，所以如果您的索引有多个分片，超时会根据分片大小很快加起来。