Elasticsearch慢查询中took_millis大于timeout设置的原因及排查方法

问题1：为何took_millis远大于设置的500ms超时？ #

• 首先纠正认知偏差：ES的timeout参数不是强制中断型超时，属于协作型超时，分片执行查询时仅会在固定检查点（比如完成一段倒排索引遍历、收集完一批匹配文档）才会判断是否超时，不会在执行计算逻辑的中途强行终止任务。如果遇到大结果集排序、模糊查询全量扫描、高基数聚合这类长周期无检查点的操作，就会等到当前计算逻辑跑完才会触发超时返回，自然会超出设置的阈值。
• timeout参数默认仅限制分片查询（query）阶段的耗时，took_millis统计的是ES内部全链路耗时，包含query阶段、fetch拉取文档阶段、协调节点结果聚合、节点间内部通信的全部耗时，fetch阶段的开销不会被timeout限制，额外产生的耗时会直接计入总耗时。
• 分片所在节点的资源挤压也会导致超时失效：如果当时节点CPU被其他任务占满、磁盘IO达到瓶颈、查询线程池队列已满，请求会排队等待执行，排队时间也会被计入took_millis，且排队阶段不会触发超时检查。

问题2：如何统计超时设置与took_millis之间的耗时分布？ #

• 开启查询Profile诊断：在你的查询请求参数中加上"profile": true，返回结果会详细拆解每个分片的query阶段每个查询子句的耗时、fetch阶段拉取文档、构建返回结果的耗时，可直接定位到超时额外开销的产生环节。
• 完善慢日志配置：除了已开启的查询慢日志，还要开启fetch阶段慢日志、协调节点慢日志，对比同一条请求在协调节点、数据分片节点的日志时间戳，可计算出节点间传输、协调节点结果聚合的耗时占比。
• 调用节点统计接口：执行GET _nodes/stats/indices/search接口，可获取所有节点的查询队列等待时长、query阶段总耗时、fetch阶段总耗时的聚合统计，可批量排查集群层面的耗时分布规律。
• 配合监控看板统计：如果使用了ES自带监控或第三方APM工具，可直接查看搜索请求全链路耗时分布的统计面板，重点关注队列等待时间、query耗时、fetch耗时三类核心指标的占比。

内容的提问来源于stack exchange，提问作者freeBirdzz