Profile API
编辑Profile API
编辑Profile API 是一种调试工具,会对搜索执行增加显著的开销。
提供有关搜索请求中各个组件执行的详细计时信息。
描述
编辑Profile API 让用户深入了解搜索请求如何在底层执行,以便用户了解某些请求为何缓慢,并采取措施加以改进。请注意,Profile API,除此之外,不会测量网络延迟、请求在队列中花费的时间或在协调节点上合并分片响应所花费的时间。
Profile API 的输出 非常 冗长,特别是对于跨多个分片执行的复杂请求。建议对响应进行美化打印,以帮助理解输出。
示例
编辑任何 _search
请求都可以通过添加顶层 profile
参数来分析
resp = client.search( index="my-index-000001", profile=True, query={ "match": { "message": "GET /search" } }, ) print(resp)
response = client.search( index: 'my-index-000001', body: { profile: true, query: { match: { message: 'GET /search' } } } ) puts response
const response = await client.search({ index: "my-index-000001", profile: true, query: { match: { message: "GET /search", }, }, }); console.log(response);
GET /my-index-000001/_search { "profile": true, "query" : { "match" : { "message" : "GET /search" } } }
API 返回以下结果
{ "took": 25, "timed_out": false, "_shards": { "total": 1, "successful": 1, "skipped": 0, "failed": 0 }, "hits": { "total": { "value": 5, "relation": "eq" }, "max_score": 0.17402273, "hits": [...] }, "profile": { "shards": [ { "id": "[q2aE02wS1R8qQFnYu6vDVQ][my-index-000001][0]", "node_id": "q2aE02wS1R8qQFnYu6vDVQ", "shard_id": 0, "index": "my-index-000001", "cluster": "(local)", "searches": [ { "query": [ { "type": "BooleanQuery", "description": "message:get message:search", "time_in_nanos" : 11972972, "breakdown" : { "set_min_competitive_score_count": 0, "match_count": 5, "shallow_advance_count": 0, "set_min_competitive_score": 0, "next_doc": 39022, "match": 4456, "next_doc_count": 5, "score_count": 5, "compute_max_score_count": 0, "compute_max_score": 0, "advance": 84525, "advance_count": 1, "score": 37779, "build_scorer_count": 2, "create_weight": 4694895, "shallow_advance": 0, "create_weight_count": 1, "build_scorer": 7112295, "count_weight": 0, "count_weight_count": 0 }, "children": [ { "type": "TermQuery", "description": "message:get", "time_in_nanos": 3801935, "breakdown": { "set_min_competitive_score_count": 0, "match_count": 0, "shallow_advance_count": 3, "set_min_competitive_score": 0, "next_doc": 0, "match": 0, "next_doc_count": 0, "score_count": 5, "compute_max_score_count": 3, "compute_max_score": 32487, "advance": 5749, "advance_count": 6, "score": 16219, "build_scorer_count": 3, "create_weight": 2382719, "shallow_advance": 9754, "create_weight_count": 1, "build_scorer": 1355007, "count_weight": 0, "count_weight_count": 0 } }, { "type": "TermQuery", "description": "message:search", "time_in_nanos": 205654, "breakdown": { "set_min_competitive_score_count": 0, "match_count": 0, "shallow_advance_count": 3, "set_min_competitive_score": 0, "next_doc": 0, "match": 0, "next_doc_count": 0, "score_count": 5, "compute_max_score_count": 3, "compute_max_score": 6678, "advance": 12733, "advance_count": 6, "score": 6627, "build_scorer_count": 3, "create_weight": 130951, "shallow_advance": 2512, "create_weight_count": 1, "build_scorer": 46153, "count_weight": 0, "count_weight_count": 0 } } ] } ], "rewrite_time": 451233, "collector": [ { "name": "QueryPhaseCollector", "reason": "search_query_phase", "time_in_nanos": 775274, "children" : [ { "name": "SimpleTopScoreDocCollector", "reason": "search_top_hits", "time_in_nanos": 775274 } ] } ] } ], "aggregations": [], "fetch": { "type": "fetch", "description": "", "time_in_nanos": 660555, "breakdown": { "next_reader": 7292, "next_reader_count": 1, "load_stored_fields": 299325, "load_stored_fields_count": 5, "load_source": 3863, "load_source_count": 5 }, "debug": { "stored_fields": ["_id", "_routing", "_source"] }, "children": [ { "type" : "FetchFieldsPhase", "description" : "", "time_in_nanos" : 238762, "breakdown" : { "process_count" : 5, "process" : 227914, "next_reader" : 10848, "next_reader_count" : 1 } }, { "type": "FetchSourcePhase", "description": "", "time_in_nanos": 20443, "breakdown": { "next_reader": 745, "next_reader_count": 1, "process": 19698, "process_count": 5 }, "debug": { "fast_path": 5 } }, { "type": "StoredFieldsPhase", "description": "", "time_in_nanos": 5310, "breakdown": { "next_reader": 745, "next_reader_count": 1, "process": 4445, "process_count": 5 } } ] } } ] } }
即使是简单的查询,响应也相对复杂。让我们在继续更复杂的示例之前,逐个分解它。
profile 响应的整体结构如下
{ "profile": { "shards": [ { "id": "[q2aE02wS1R8qQFnYu6vDVQ][my-index-000001][0]", "node_id": "q2aE02wS1R8qQFnYu6vDVQ", "shard_id": 0, "index": "my-index-000001", "cluster": "(local)", "searches": [ { "query": [...], "rewrite_time": 51443, "collector": [...] } ], "aggregations": [...], "fetch": {...} } ] } }
为参与响应的每个分片返回一个 profile,并通过唯一 ID 标识。 |
|
如果查询是在本地集群上运行的,则集群名称将从复合 ID 中删除,并在此处标记为“(local)”。对于使用跨集群搜索在 remote_cluster 上运行的 profile,“id”值将类似于 |
|
查询计时和其他调试信息。 |
|
累积的重写时间。 |
|
每个收集器的名称和调用计时。 |
|
聚合计时、调用计数和调试信息。 |
|
获取计时和调试信息。 |
由于搜索请求可能会针对索引中的一个或多个分片执行,并且一个搜索可能覆盖一个或多个索引,因此 profile 响应中的顶级元素是一个 shard
对象数组。每个分片对象列出其 id
,该 ID 唯一标识分片。ID 的格式为 [nodeID][clusterName:indexName][shardID]
。如果搜索是针对本地集群运行的,则不添加 clusterName,格式为 [nodeID][indexName][shardID]
。
profile 本身可能包含一个或多个“搜索”,其中搜索是针对底层 Lucene 索引执行的查询。用户提交的大多数搜索请求将仅针对 Lucene 索引执行单个 search
。但有时会执行多个搜索,例如包括全局聚合(需要为全局上下文执行辅助“match_all”查询)。
在每个 search
对象中,将有两个已分析信息的数组:query
数组和 collector
数组。与 search
对象一起,还有一个 aggregations
对象,其中包含聚合的性能分析信息。将来可能会添加更多部分,例如 suggest
、highlight
等。
还会有一个 rewrite
指标,显示重写查询所花费的总时间(以纳秒为单位)。
与其他统计信息 API 一样,Profile API 支持人类可读的输出。可以通过将 ?human=true
添加到查询字符串来启用此功能。在这种情况下,输出包含额外的 time
字段,其中包含四舍五入的、人类可读的计时信息(例如 "time": "391,9ms"
,"time": "123.3micros"
)。
分析查询
编辑Profile API 提供的详细信息直接公开了 Lucene 类名称和概念,这意味着对结果的完整解释需要相当高级的 Lucene 知识。此页面试图简要介绍 Lucene 如何执行查询,以便你可以使用 Profile API 成功诊断和调试查询,但这只是一个概述。为了完全理解,请参阅 Lucene 的文档,在某些情况下,请参阅代码。
话虽如此,通常不需要完全理解即可修复缓慢的查询。通常,只需看到查询的特定组件速度较慢,而不必理解为什么例如该查询的 advance
阶段是原因,这就足够了。
query
部分
编辑query
部分包含有关 Lucene 在特定分片上执行的查询树的详细计时。此查询树的整体结构将与你原始的 Elasticsearch 查询类似,但可能略有不同(有时差异很大)。它还将使用类似但不总是相同的命名。使用我们之前的 match
查询示例,让我们分析 query
部分
"query": [ { "type": "BooleanQuery", "description": "message:get message:search", "time_in_nanos": "11972972", "breakdown": {...}, "children": [ { "type": "TermQuery", "description": "message:get", "time_in_nanos": "3801935", "breakdown": {...} }, { "type": "TermQuery", "description": "message:search", "time_in_nanos": "205654", "breakdown": {...} } ] } ]
基于 profile 结构,我们可以看到我们的 match
查询被 Lucene 重写为一个包含两个子句 (都包含 TermQuery) 的 BooleanQuery。type
字段显示 Lucene 类名称,并且通常与 Elasticsearch 中的等效名称对齐。description
字段显示查询的 Lucene 说明文本,并且可以用来帮助区分查询的各个部分(例如,message:get
和 message:search
都是 TermQuery,否则它们看起来会相同)。
time_in_nanos
字段显示整个 BooleanQuery 的执行时间约为 11.9 毫秒。记录的时间包括所有子项。
breakdown
字段将提供有关时间如何花费的详细统计信息,我们稍后将对此进行研究。最后,children
数组列出可能存在的任何子查询。因为我们搜索了两个值 (“get search”),所以我们的 BooleanQuery 包含两个子 TermQuery。它们具有相同的信息(类型、时间、分解等)。允许子项拥有自己的子项。
计时分解
编辑breakdown
组件列出有关底层 Lucene 执行的详细计时统计信息
"breakdown": { "set_min_competitive_score_count": 0, "match_count": 5, "shallow_advance_count": 0, "set_min_competitive_score": 0, "next_doc": 39022, "match": 4456, "next_doc_count": 5, "score_count": 5, "compute_max_score_count": 0, "compute_max_score": 0, "advance": 84525, "advance_count": 1, "score": 37779, "build_scorer_count": 2, "create_weight": 4694895, "shallow_advance": 0, "create_weight_count": 1, "build_scorer": 7112295, "count_weight": 0, "count_weight_count": 0 }
计时以挂钟纳秒为单位列出,并且根本没有标准化。关于整体 time_in_nanos
的所有注意事项都适用于此处。分解的目的是让你了解 A) Lucene 中哪些机制实际上占用了时间,以及 B) 各个组件之间的时间差异的大小。与整体时间一样,分解包括所有子项的时间。
统计信息的含义如下
所有参数
编辑
|
Lucene 中的查询必须能够在多个 IndexSearcher 中重复使用(可以将其视为针对特定 Lucene 索引执行搜索的引擎)。这使 Lucene 处于棘手的位置,因为许多查询需要累积与它所使用的索引关联的临时状态/统计信息,但 Query 合约规定它必须是不可变的。 |
|
此参数显示为查询构建 Scorer 所花费的时间。Scorer 是一种迭代匹配文档并生成每个文档得分的机制(例如,“foo”与文档的匹配程度如何?)。请注意,这会记录生成 Scorer 对象所需的时间,而不是实际为文档评分的时间。某些查询的 Scorer 初始化速度较快或较慢,具体取决于优化、复杂性等。 |
|
Lucene 方法 |
|
|
|
某些查询(例如短语查询)使用“两阶段”过程来匹配文档。首先,文档被“近似”匹配,如果它近似匹配,则使用更严格(且成本更高)的过程再次检查它。第二阶段验证是 |
|
这会记录通过 Scorer 为特定文档评分所花费的时间 |
|
记录特定方法的调用次数。例如, |
collectors
部分
编辑响应的收集器部分显示高级执行详细信息。Lucene 通过定义“收集器”来工作,该收集器负责协调匹配文档的遍历、评分和收集。收集器还是单个查询如何记录聚合结果、执行无范围的“全局”查询、执行查询后过滤器等的方式。
看一下之前的示例
"collector": [ { "name": "QueryPhaseCollector", "reason": "search_query_phase", "time_in_nanos": 775274, "children" : [ { "name": "SimpleTopScoreDocCollector", "reason": "search_top_hits", "time_in_nanos": 775274 } ] } ]
我们看到一个名为 QueryPhaseCollector
的顶层收集器,它包含一个子收集器 SimpleTopScoreDocCollector
。SimpleTopScoreDocCollector
是 Elasticsearch 使用的默认“评分和排序”收集器
。reason
字段尝试提供类名称的纯英文描述。time_in_nanos
与 Query 树中的时间类似:包括所有子项的挂钟时间。同样,children
列出所有子收集器。当请求聚合时,QueryPhaseCollector
将包含一个额外的子收集器,其原因 aggregation
是执行聚合的收集器。
需要注意的是,收集器时间与查询时间相互独立。它们是独立计算、组合和标准化的!由于 Lucene 执行的特性,无法将收集器的时间“合并”到查询部分,因此它们会分开显示。
作为参考,各种收集器的原因如下:
|
一个对文档进行评分和排序的收集器。这是最常见的收集器,会在大多数简单搜索中看到。 |
|
一个仅计算与查询匹配的文档数量但不获取源的收集器。当指定 |
|
一个将收集热门结果以及聚合作为查询阶段一部分的收集器。它支持在找到 |
|
一个在指定时间段后停止执行的收集器。当指定了顶层参数 |
|
Elasticsearch 使用的一个收集器,用于对查询范围执行聚合。单个 |
|
一个对全局查询范围(而不是指定的查询)执行聚合的收集器。由于全局范围与执行的查询必然不同,它必须执行自己的 match_all 查询(您将在查询部分看到添加的此查询)来收集您的整个数据集。 |
rewrite
部分
编辑Lucene 中的所有查询都会经历一个“重写”过程。一个查询(及其子查询)可能会被重写一次或多次,并且该过程会一直持续到查询停止更改为止。此过程允许 Lucene 执行优化,例如删除冗余子句、用更高效的执行路径替换一个查询等。例如,Boolean → Boolean → TermQuery 可以重写为 TermQuery,因为在这种情况下所有 Boolean 都是不必要的。
重写过程是复杂且难以显示的,因为查询可能会发生巨大变化。与其显示中间结果,不如简单地将总重写时间显示为一个值(以纳秒为单位)。此值为累积值,包含所有正在重写的查询的总时间。
一个更复杂的示例
编辑为了演示稍微复杂一些的查询和关联的结果,我们可以分析以下查询
resp = client.search( index="my-index-000001", profile=True, query={ "term": { "user.id": { "value": "elkbee" } } }, aggs={ "my_scoped_agg": { "terms": { "field": "http.response.status_code" } }, "my_global_agg": { "global": {}, "aggs": { "my_level_agg": { "terms": { "field": "http.response.status_code" } } } } }, post_filter={ "match": { "message": "search" } }, ) print(resp)
response = client.search( index: 'my-index-000001', body: { profile: true, query: { term: { 'user.id' => { value: 'elkbee' } } }, aggregations: { my_scoped_agg: { terms: { field: 'http.response.status_code' } }, my_global_agg: { global: {}, aggregations: { my_level_agg: { terms: { field: 'http.response.status_code' } } } } }, post_filter: { match: { message: 'search' } } } ) puts response
const response = await client.search({ index: "my-index-000001", profile: true, query: { term: { "user.id": { value: "elkbee", }, }, }, aggs: { my_scoped_agg: { terms: { field: "http.response.status_code", }, }, my_global_agg: { global: {}, aggs: { my_level_agg: { terms: { field: "http.response.status_code", }, }, }, }, }, post_filter: { match: { message: "search", }, }, }); console.log(response);
GET /my-index-000001/_search { "profile": true, "query": { "term": { "user.id": { "value": "elkbee" } } }, "aggs": { "my_scoped_agg": { "terms": { "field": "http.response.status_code" } }, "my_global_agg": { "global": {}, "aggs": { "my_level_agg": { "terms": { "field": "http.response.status_code" } } } } }, "post_filter": { "match": { "message": "search" } } }
此示例具有
- 一个查询
- 一个范围聚合
- 一个全局聚合
- 一个 post_filter
API 返回以下结果
{ ... "profile": { "shards": [ { "id": "[P6xvulHtQRWuD4YnubWb7A][my-index-000001][0]", "node_id": "P6xvulHtQRWuD4YnubWb7A", "shard_id": 0, "index": "my-index-000001", "cluster": "(local)", "searches": [ { "query": [ { "type": "TermQuery", "description": "message:search", "time_in_nanos": 141618, "breakdown": { "set_min_competitive_score_count": 0, "match_count": 0, "shallow_advance_count": 0, "set_min_competitive_score": 0, "next_doc": 0, "match": 0, "next_doc_count": 0, "score_count": 0, "compute_max_score_count": 0, "compute_max_score": 0, "advance": 3942, "advance_count": 4, "count_weight_count": 0, "score": 0, "build_scorer_count": 2, "create_weight": 38380, "shallow_advance": 0, "count_weight": 0, "create_weight_count": 1, "build_scorer": 99296 } }, { "type": "TermQuery", "description": "user.id:elkbee", "time_in_nanos": 163081, "breakdown": { "set_min_competitive_score_count": 0, "match_count": 0, "shallow_advance_count": 0, "set_min_competitive_score": 0, "next_doc": 2447, "match": 0, "next_doc_count": 4, "score_count": 4, "compute_max_score_count": 0, "compute_max_score": 0, "advance": 3552, "advance_count": 1, "score": 5027, "count_weight_count": 0, "build_scorer_count": 2, "create_weight": 107840, "shallow_advance": 0, "count_weight": 0, "create_weight_count": 1, "build_scorer": 44215 } } ], "rewrite_time": 4769, "collector": [ { "name": "QueryPhaseCollector", "reason": "search_query_phase", "time_in_nanos": 1945072, "children": [ { "name": "SimpleTopScoreDocCollector", "reason": "search_top_hits", "time_in_nanos": 22577 }, { "name": "AggregatorCollector: [my_scoped_agg, my_global_agg]", "reason": "aggregation", "time_in_nanos": 867617 } ] } ] } ], "aggregations": [...], "fetch": {...} } ] } }
如您所见,输出比以前详细得多。查询的所有主要部分都已表示出来
- 第一个
TermQuery
(user.id:elkbee) 表示主要的term
查询。 - 第二个
TermQuery
(message:search) 表示post_filter
查询。
收集器树非常简单,显示了单个 QueryPhaseCollector 如何保存用于收集热门结果的普通评分 SimpleTopScoreDocCollector,以及用于运行所有范围聚合的 BucketCollectorWrapper。
了解 MultiTermQuery 输出
编辑需要特别注意 MultiTermQuery
查询类。这包括通配符、正则表达式和模糊查询。这些查询会发出非常详细的响应,并且结构不够清晰。
本质上,这些查询会根据每个段重写自身。如果您想象通配符查询 b*
,它在技术上可以匹配任何以字母“b”开头的标记。枚举所有可能的组合是不可能的,因此 Lucene 会在被评估的段的上下文中重写查询,例如,一个段可能包含标记 [bar, baz]
,因此查询会重写为“bar”和“baz”的 BooleanQuery 组合。另一个段可能只有标记 [bakery]
,因此查询会重写为“bakery”的单个 TermQuery。
由于这种动态的、基于每个段的重写,干净的树结构会失真,不再遵循清晰的“血统”来显示一个查询如何重写为下一个查询。目前,我们只能抱歉,并建议您如果觉得该查询的子项太令人困惑,请折叠该查询的详细信息。幸运的是,所有计时统计数据都是正确的,只是响应中的物理布局不正确,因此只需分析顶级的 MultiTermQuery,如果您发现详细信息太难理解,则忽略其子项就足够了。
希望这在未来的迭代中得到修复,但这仍然是一个棘手的问题,仍在进行中。:)
分析聚合
编辑aggregations
部分
编辑aggregations
部分包含特定分片执行的聚合树的详细计时。此聚合树的整体结构将类似于您原始的 Elasticsearch 请求。让我们再次执行之前的查询,这次看看聚合分析
resp = client.search( index="my-index-000001", profile=True, query={ "term": { "user.id": { "value": "elkbee" } } }, aggs={ "my_scoped_agg": { "terms": { "field": "http.response.status_code" } }, "my_global_agg": { "global": {}, "aggs": { "my_level_agg": { "terms": { "field": "http.response.status_code" } } } } }, post_filter={ "match": { "message": "search" } }, ) print(resp)
response = client.search( index: 'my-index-000001', body: { profile: true, query: { term: { 'user.id' => { value: 'elkbee' } } }, aggregations: { my_scoped_agg: { terms: { field: 'http.response.status_code' } }, my_global_agg: { global: {}, aggregations: { my_level_agg: { terms: { field: 'http.response.status_code' } } } } }, post_filter: { match: { message: 'search' } } } ) puts response
const response = await client.search({ index: "my-index-000001", profile: true, query: { term: { "user.id": { value: "elkbee", }, }, }, aggs: { my_scoped_agg: { terms: { field: "http.response.status_code", }, }, my_global_agg: { global: {}, aggs: { my_level_agg: { terms: { field: "http.response.status_code", }, }, }, }, }, post_filter: { match: { message: "search", }, }, }); console.log(response);
GET /my-index-000001/_search { "profile": true, "query": { "term": { "user.id": { "value": "elkbee" } } }, "aggs": { "my_scoped_agg": { "terms": { "field": "http.response.status_code" } }, "my_global_agg": { "global": {}, "aggs": { "my_level_agg": { "terms": { "field": "http.response.status_code" } } } } }, "post_filter": { "match": { "message": "search" } } }
这将产生以下聚合分析输出
{ "profile": { "shards": [ { "aggregations": [ { "type": "NumericTermsAggregator", "description": "my_scoped_agg", "time_in_nanos": 79294, "breakdown": { "reduce": 0, "build_aggregation": 30885, "build_aggregation_count": 1, "initialize": 2623, "initialize_count": 1, "reduce_count": 0, "collect": 45786, "collect_count": 4, "build_leaf_collector": 18211, "build_leaf_collector_count": 1, "post_collection": 929, "post_collection_count": 1 }, "debug": { "total_buckets": 1, "result_strategy": "long_terms", "built_buckets": 1 } }, { "type": "GlobalAggregator", "description": "my_global_agg", "time_in_nanos": 104325, "breakdown": { "reduce": 0, "build_aggregation": 22470, "build_aggregation_count": 1, "initialize": 12454, "initialize_count": 1, "reduce_count": 0, "collect": 69401, "collect_count": 4, "build_leaf_collector": 8150, "build_leaf_collector_count": 1, "post_collection": 1584, "post_collection_count": 1 }, "debug": { "built_buckets": 1 }, "children": [ { "type": "NumericTermsAggregator", "description": "my_level_agg", "time_in_nanos": 76876, "breakdown": { "reduce": 0, "build_aggregation": 13824, "build_aggregation_count": 1, "initialize": 1441, "initialize_count": 1, "reduce_count": 0, "collect": 61611, "collect_count": 4, "build_leaf_collector": 5564, "build_leaf_collector_count": 1, "post_collection": 471, "post_collection_count": 1 }, "debug": { "total_buckets": 1, "result_strategy": "long_terms", "built_buckets": 1 } } ] } ] } ] } }
从分析结构中我们可以看到,my_scoped_agg
在内部作为 NumericTermsAggregator
运行(因为它正在聚合的字段 http.response.status_code
是一个数字字段)。在同一级别,我们看到一个来自 my_global_agg
的 GlobalAggregator
。该聚合然后有一个子项 NumericTermsAggregator
,它来自 http.response.status_code
的第二个词项的聚合。
time_in_nanos
字段显示每个聚合执行的时间,并且包括所有子项。虽然总时间很有用,但 breakdown
字段将提供有关时间如何花费的详细统计信息。
一些聚合可能会返回专家 debug
信息,这些信息描述了聚合底层执行的特性,“对于那些处理聚合的人员很有用,但我们不希望对其他人有用。它们在版本、聚合和聚合执行策略之间可能会有很大差异。
计时细分
编辑breakdown
组件列出了有关底层执行的详细统计信息
"breakdown": { "reduce": 0, "build_aggregation": 30885, "build_aggregation_count": 1, "initialize": 2623, "initialize_count": 1, "reduce_count": 0, "collect": 45786, "collect_count": 4, "build_leaf_collector": 18211, "build_leaf_collector_count": 1 }
breakdown
组件中的每个属性都对应于聚合的内部方法。例如,build_leaf_collector
属性测量运行聚合的 getLeafCollector()
方法所花费的纳秒数。以 _count
结尾的属性记录特定方法的调用次数。例如,"collect_count": 2
表示聚合在两个不同的文档上调用了 collect()
。reduce
属性保留供将来使用,并且始终返回 0
。
计时以挂钟纳秒为单位列出,并且根本没有标准化。有关总体 time
的所有警告都适用于此处。细分的目的是让您了解 A) Elasticsearch 中哪些机制实际上占用了时间,以及 B) 各个组件之间的时间差异幅度。与总时间一样,细分包括所有子项的时间。
分析获取
编辑所有获取文档的分片都将在分析中有一个 fetch
部分。让我们执行一个小搜索并查看获取分析
resp = client.search( index="my-index-000001", filter_path="profile.shards.fetch", profile=True, query={ "term": { "user.id": { "value": "elkbee" } } }, ) print(resp)
response = client.search( index: 'my-index-000001', filter_path: 'profile.shards.fetch', body: { profile: true, query: { term: { 'user.id' => { value: 'elkbee' } } } } ) puts response
const response = await client.search({ index: "my-index-000001", filter_path: "profile.shards.fetch", profile: true, query: { term: { "user.id": { value: "elkbee", }, }, }, }); console.log(response);
GET /my-index-000001/_search?filter_path=profile.shards.fetch { "profile": true, "query": { "term": { "user.id": { "value": "elkbee" } } } }
这是获取分析
{ "profile": { "shards": [ { "fetch": { "type": "fetch", "description": "", "time_in_nanos": 660555, "breakdown": { "next_reader": 7292, "next_reader_count": 1, "load_stored_fields": 299325, "load_stored_fields_count": 5, "load_source": 3863, "load_source_count": 5 }, "debug": { "stored_fields": ["_id", "_routing", "_source"] }, "children": [ { "type" : "FetchFieldsPhase", "description" : "", "time_in_nanos" : 238762, "breakdown" : { "process_count" : 5, "process" : 227914, "next_reader" : 10848, "next_reader_count" : 1 } }, { "type": "FetchSourcePhase", "description": "", "time_in_nanos": 20443, "breakdown": { "next_reader": 745, "next_reader_count": 1, "process": 19698, "process_count": 5 }, "debug": { "fast_path": 4 } }, { "type": "StoredFieldsPhase", "description": "", "time_in_nanos": 5310, "breakdown": { "next_reader": 745, "next_reader_count": 1, "process": 4445, "process_count": 5 } } ] } } ] } }
由于这是有关 Elasticsearch 执行获取方式的调试信息,因此它可能会根据请求和版本的不同而更改。即使是补丁版本也可能会更改此处的输出。这种缺乏一致性使其对于调试很有用。
无论如何!time_in_nanos
测量获取阶段的总时间。breakdown
计算并计时我们在 next_reader
中的每个段准备,以及在 load_stored_fields
中加载存储字段所花费的时间。Debug 包含各种非计时信息,特别是 stored_fields
列出了获取必须加载的存储字段。如果它是一个空列表,则获取将完全跳过加载存储字段。
children
部分列出了执行实际获取工作的子阶段,并且 breakdown
具有 next_reader
中每个段准备以及 process
中每个文档获取的计数和计时。
我们努力提前加载获取所需的所有存储字段。这往往会使 _source
阶段每次命中花费几微秒。在这种情况下,_source
阶段的真正成本隐藏在细分的 load_stored_fields
组件中。可以通过设置 "_source": false, "stored_fields": ["_none_"]
来完全跳过加载存储字段。
分析 DFS
编辑DFS 阶段在查询阶段之前运行,以收集与查询相关的全局信息。它目前用于两种情况
- 当
search_type
设置为dfs_query_then_fetch
并且索引具有多个分片时。 - 当搜索请求包含 knn 部分时。
可以通过将 profile
设置为搜索请求的一部分的 true
来分析这两种情况。
分析 DFS 统计信息
编辑当 search_type
设置为 dfs_query_then_fetch
并且索引具有多个分片时,dfs 阶段会收集词项统计信息以提高搜索结果的相关性。
以下是在使用 dfs_query_then_fetch
的搜索中将 profile
设置为 true
的示例
让我们首先设置一个具有多个分片的索引,并在 keyword
字段上索引一对具有不同值的文档。
resp = client.indices.create( index="my-dfs-index", settings={ "number_of_shards": 2, "number_of_replicas": 1 }, mappings={ "properties": { "my-keyword": { "type": "keyword" } } }, ) print(resp) resp1 = client.bulk( index="my-dfs-index", refresh=True, operations=[ { "index": { "_id": "1" } }, { "my-keyword": "a" }, { "index": { "_id": "2" } }, { "my-keyword": "b" } ], ) print(resp1)
response = client.indices.create( index: 'my-dfs-index', body: { settings: { number_of_shards: 2, number_of_replicas: 1 }, mappings: { properties: { "my-keyword": { type: 'keyword' } } } } ) puts response response = client.bulk( index: 'my-dfs-index', refresh: true, body: [ { index: { _id: '1' } }, { "my-keyword": 'a' }, { index: { _id: '2' } }, { "my-keyword": 'b' } ] ) puts response
const response = await client.indices.create({ index: "my-dfs-index", settings: { number_of_shards: 2, number_of_replicas: 1, }, mappings: { properties: { "my-keyword": { type: "keyword", }, }, }, }); console.log(response); const response1 = await client.bulk({ index: "my-dfs-index", refresh: "true", operations: [ { index: { _id: "1", }, }, { "my-keyword": "a", }, { index: { _id: "2", }, }, { "my-keyword": "b", }, ], }); console.log(response1);
PUT my-dfs-index { "settings": { "number_of_shards": 2, "number_of_replicas": 1 }, "mappings": { "properties": { "my-keyword": { "type": "keyword" } } } } POST my-dfs-index/_bulk?refresh=true { "index" : { "_id" : "1" } } { "my-keyword" : "a" } { "index" : { "_id" : "2" } } { "my-keyword" : "b" }
设置索引后,我们现在可以分析搜索查询的 dfs 阶段。对于此示例,我们使用词项查询。
resp = client.search( index="my-dfs-index", search_type="dfs_query_then_fetch", pretty=True, size="0", profile=True, query={ "term": { "my-keyword": { "value": "a" } } }, ) print(resp)
response = client.search( index: 'my-dfs-index', search_type: 'dfs_query_then_fetch', pretty: true, size: 0, body: { profile: true, query: { term: { "my-keyword": { value: 'a' } } } } ) puts response
const response = await client.search({ index: "my-dfs-index", search_type: "dfs_query_then_fetch", pretty: "true", size: 0, profile: true, query: { term: { "my-keyword": { value: "a", }, }, }, }); console.log(response);
GET /my-dfs-index/_search?search_type=dfs_query_then_fetch&pretty&size=0 { "profile": true, "query": { "term": { "my-keyword": { "value": "a" } } } }
在响应中,我们看到一个分析,其中包含每个分片的 dfs
部分以及搜索阶段其余部分的分析输出。一个分片的 dfs
部分如下所示
"dfs" : { "statistics" : { "type" : "statistics", "description" : "collect term statistics", "time_in_nanos" : 236955, "breakdown" : { "term_statistics" : 4815, "collection_statistics" : 27081, "collection_statistics_count" : 1, "create_weight" : 153278, "term_statistics_count" : 1, "rewrite_count" : 0, "create_weight_count" : 1, "rewrite" : 0 } } }
在此响应的 dfs.statistics
部分,我们可以看到 time_in_nanos
,它是收集此分片术语统计信息的总耗时,以及各个部分的进一步细分。
分析 kNN 搜索
编辑k 最近邻 (kNN) 搜索在 dfs 阶段运行。
以下是在具有 knn
部分的搜索中将 profile
设置为 true
的示例
首先,让我们设置一个包含多个密集向量的索引。
resp = client.indices.create( index="my-knn-index", mappings={ "properties": { "my-vector": { "type": "dense_vector", "dims": 3, "index": True, "similarity": "l2_norm" } } }, ) print(resp) resp1 = client.bulk( index="my-knn-index", refresh=True, operations=[ { "index": { "_id": "1" } }, { "my-vector": [ 1, 5, -20 ] }, { "index": { "_id": "2" } }, { "my-vector": [ 42, 8, -15 ] }, { "index": { "_id": "3" } }, { "my-vector": [ 15, 11, 23 ] } ], ) print(resp1)
response = client.indices.create( index: 'my-knn-index', body: { mappings: { properties: { "my-vector": { type: 'dense_vector', dims: 3, index: true, similarity: 'l2_norm' } } } } ) puts response response = client.bulk( index: 'my-knn-index', refresh: true, body: [ { index: { _id: '1' } }, { "my-vector": [ 1, 5, -20 ] }, { index: { _id: '2' } }, { "my-vector": [ 42, 8, -15 ] }, { index: { _id: '3' } }, { "my-vector": [ 15, 11, 23 ] } ] ) puts response
const response = await client.indices.create({ index: "my-knn-index", mappings: { properties: { "my-vector": { type: "dense_vector", dims: 3, index: true, similarity: "l2_norm", }, }, }, }); console.log(response); const response1 = await client.bulk({ index: "my-knn-index", refresh: "true", operations: [ { index: { _id: "1", }, }, { "my-vector": [1, 5, -20], }, { index: { _id: "2", }, }, { "my-vector": [42, 8, -15], }, { index: { _id: "3", }, }, { "my-vector": [15, 11, 23], }, ], }); console.log(response1);
PUT my-knn-index { "mappings": { "properties": { "my-vector": { "type": "dense_vector", "dims": 3, "index": true, "similarity": "l2_norm" } } } } POST my-knn-index/_bulk?refresh=true { "index": { "_id": "1" } } { "my-vector": [1, 5, -20] } { "index": { "_id": "2" } } { "my-vector": [42, 8, -15] } { "index": { "_id": "3" } } { "my-vector": [15, 11, 23] }
完成索引设置后,我们现在可以分析 kNN 搜索查询。
resp = client.search( index="my-knn-index", profile=True, knn={ "field": "my-vector", "query_vector": [ -5, 9, -12 ], "k": 3, "num_candidates": 100 }, ) print(resp)
response = client.search( index: 'my-knn-index', body: { profile: true, knn: { field: 'my-vector', query_vector: [ -5, 9, -12 ], k: 3, num_candidates: 100 } } ) puts response
const response = await client.search({ index: "my-knn-index", profile: true, knn: { field: "my-vector", query_vector: [-5, 9, -12], k: 3, num_candidates: 100, }, }); console.log(response);
POST my-knn-index/_search { "profile": true, "knn": { "field": "my-vector", "query_vector": [-5, 9, -12], "k": 3, "num_candidates": 100 } }
在响应中,我们看到一个配置文件,其中包括每个分片的 dfs
部分中的 knn
部分,以及其余搜索阶段的配置文件输出。
分片的其中一个 dfs.knn
部分如下所示
"dfs" : { "knn" : [ { "vector_operations_count" : 4, "query" : [ { "type" : "DocAndScoreQuery", "description" : "DocAndScore[100]", "time_in_nanos" : 444414, "breakdown" : { "set_min_competitive_score_count" : 0, "match_count" : 0, "shallow_advance_count" : 0, "set_min_competitive_score" : 0, "next_doc" : 1688, "match" : 0, "next_doc_count" : 3, "score_count" : 3, "compute_max_score_count" : 0, "compute_max_score" : 0, "advance" : 4153, "advance_count" : 1, "score" : 2099, "build_scorer_count" : 2, "create_weight" : 128879, "shallow_advance" : 0, "create_weight_count" : 1, "build_scorer" : 307595, "count_weight": 0, "count_weight_count": 0 } } ], "rewrite_time" : 1275732, "collector" : [ { "name" : "SimpleTopScoreDocCollector", "reason" : "search_top_hits", "time_in_nanos" : 17163 } ] } ] }
在响应的 dfs.knn
部分,我们可以看到 query、rewrite 和 collector 的计时输出。与许多其他查询不同,kNN 搜索在查询重写期间完成大部分工作。这意味着 rewrite_time
表示在 kNN 搜索上花费的时间。属性 vector_operations_count
表示 kNN 搜索期间执行的向量操作的总计数。
分析注意事项
编辑与任何分析器一样,Profile API 会给搜索执行引入不可忽略的开销。对诸如 collect
、advance
和 next_doc
之类的低级方法调用进行检测可能相当昂贵,因为这些方法是在紧密循环中调用的。因此,默认情况下不应在生产环境中启用分析,并且不应与未分析的查询时间进行比较。分析只是一种诊断工具。
在某些情况下,特殊的 Lucene 优化会被禁用,因为它们不适合进行分析。这可能会导致某些查询报告的相对时间比未分析的查询时间长,但通常与分析查询中的其他组件相比,不应产生剧烈的影响。
局限性
编辑- 分析当前不测量网络开销。
- 分析也不考虑在队列中花费的时间、在协调节点上合并分片响应,或者诸如构建全局序号(用于加速搜索的内部数据结构)之类的其他工作。
- 建议当前不提供分析统计信息。
- 当前不提供聚合的 reduce 阶段的分析。
- 分析器正在检测内部结构,这些内部结构可能会因版本而异。生成的 json 应被视为大部分不稳定,特别是
debug
部分中的内容。