Elasticsearch检索性能分析：Profile API

说明：本文在ES 5.4.0版本上验证。

Elasticsearch从2.2版本开始提供 Profile API 供用户检查检索、聚合、过滤执行时间和其他细节信息，帮助用户分析每次检索各个环节所用的时间。

官方文档: Profiling Queries https://www.elastic.co/guide/en/elasticsearch/reference/5.4/_profiling_queries.html

使用方法

要使用Profile API，需要在查询中加上"profile": true，具体示例如下：

GET/POST /test/_search { "profile": true, "query": { "term": { "message": { "value": "search" } } }, "aggs": { "non_global_term": { "terms": { "field": "agg" }, "aggs": { "second_term": { "terms": { "field": "sub_agg" } } } }, "another_agg": { "cardinality": { "field": "aggB" } }, "global_agg": { "global": {}, "aggs": { "my_agg2": { "terms": { "field": "globalAgg" } } } } }, "post_filter": { "term": { "my_field": "foo" } } }

注：以上检索包括term检索、聚合、子聚合和过滤器，原文提交方法为GET，但一般带请求体的HTTP请求都使用POST方式。

以上请求的响应如下：

{ "profile": { "shards": [ { "id": "[P6-vulHtQRWuD4YnubWb7A][test][0]", "searches": [ { "query": [ { "type": "TermQuery", "description": "my_field:foo", "time": "0.4094560000ms", "time_in_nanos": "409456", "breakdown": { "score": 0, "score_count": 1, "next_doc": 0, "next_doc_count": 2, "match": 0, "match_count": 0, "create_weight": 31584, "create_weight_count": 1, "build_scorer": 377872, "build_scorer_count": 1, "advance": 0, "advance_count": 0 } }, { "type": "TermQuery", "description": "message:search", "time": "0.3037020000ms", "time_in_nanos": "303702", "breakdown": { "score": 0, "score_count": 1, "next_doc": 5936, "next_doc_count": 2, "match": 0, "match_count": 0, "create_weight": 185215, "create_weight_count": 1, "build_scorer": 112551, "build_scorer_count": 1, "advance": 0, "advance_count": 0 } } ], "rewrite_time": 7208, "collector": [ { "name": "MultiCollector", "reason": "search_multi", "time": "1.378943000ms", "time_in_nanos": "1378943", "children": [ { "name": "FilteredCollector", "reason": "search_post_filter", "time": "0.4036590000ms", "time_in_nanos": "403659", "children": [ { "name": "SimpleTopScoreDocCollector", "reason": "search_top_hits", "time": "0.006391000000ms", "time_in_nanos": "6391" } ] }, { "name": "BucketCollector: [[non_global_term, another_agg]]", "reason": "aggregation", "time": "0.9546020000ms", "time_in_nanos": "954602" } ] } ] }, { "query": [ { "type": "MatchAllDocsQuery", "description": "*:*", "time": "0.04829300000ms", "time_in_nanos": "48293", "breakdown": { "score": 0, "score_count": 1, "next_doc": 3672, "next_doc_count": 2, "match": 0, "match_count": 0, "create_weight": 6311, "create_weight_count": 1, "build_scorer": 38310, "build_scorer_count": 1, "advance": 0, "advance_count": 0 } } ], "rewrite_time": 1067, "collector": [ { "name": "GlobalAggregator: [global_agg]", "reason": "aggregation_global", "time": "0.1226310000ms", "time_in_nanos": "122631" } ] } ] } ] } }

Profile API响应说明

Query Query 段由构成Query的元素以及它们的时间信息组成。Profile API结果中Query 部分的基本组成是： query type ：显示哪种类型的查询被触发。 time: lucene执行此查询所用的时间。单位是毫秒。 time_in_nanos – 执行此查询所用的时间。单位是纳秒。 breakdown – 有关查询的更详细的细节，主要与lucene参数有关。 children – 具有多个关键字的查询被拆分成相应术语的布尔查询，每个查询都作为单独的查询来执行。每个子查询的详细信息将填充到Profile API输出的子段中。

Rewrite Time 由于多个关键字会分解以创建个别查询，所以在这个过程中肯定会花费一些时间。将查询重写一个或多个组合查询的时间被称为“重写时间”。(以纳秒为单位)。

Collectors 在Lucene中，收集器是负责收集原始结果，收集和组合结果，执行结果排序等的过程。