配置文件 API
编辑配置文件 API编辑
配置文件 API 是一种调试工具，会增加搜索执行的显著开销。
提供有关搜索请求中各个组件执行的详细计时信息。
描述编辑
配置文件 API 让用户能够深入了解搜索请求在底层的执行方式，以便用户能够理解为什么某些请求速度较慢，并采取措施改进它们。请注意，配置文件 API 除其他事项外，不测量网络延迟、请求在队列中花费的时间或在协调节点上合并分片响应所花费的时间。
配置文件 API 的输出非常冗长，特别是对于跨多个分片执行的复杂请求。建议对响应进行格式化输出，以帮助理解输出。
示例编辑
可以通过添加顶级 profile 参数来分析任何 _search 请求
response = client.search(
index: 'my-index-000001',
body: {
profile: true,
query: {
match: {
message: 'GET /search'
}
}
}
)
puts 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", "_ignored", "_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": {
"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": {...}
}
]
}
}
|
为参与响应的每个分片返回一个配置文件，并由唯一 ID 标识。 |
|
|
如果查询在本地集群上运行，则集群名称将从组合 ID 中省略，并在此处标记为“（本地）”。对于使用跨集群搜索在 remote_cluster 上运行的配置文件，“id”值将类似于 |
|
|
查询计时和其他调试信息。 |
|
|
累积重写时间。 |
|
|
每个收集器的名称和调用计时。 |
|
|
聚合计时、调用计数和调试信息。 |
|
|
获取计时和调试信息。 |
因为搜索请求可能会针对索引中的一个或多个分片执行，并且搜索可能涵盖一个或多个索引，所以配置文件响应中的顶级元素是 shard 对象数组。每个分片对象都列出其 id，该 ID 唯一标识该分片。ID 的格式为 [nodeID][clusterName:indexName][shardID]。如果针对本地集群运行搜索，则不会添加 clusterName，格式为 [nodeID][indexName][shardID]。
配置文件本身可能包含一个或多个“搜索”，其中搜索是对底层 Lucene 索引执行的查询。用户提交的大多数搜索请求只会针对 Lucene 索引执行一次 search。但有时会执行多次搜索，例如包含全局聚合（需要为全局上下文执行辅助“match_all”查询）。
在每个 search 对象内部，将有两个分析信息数组：query 数组和 collector 数组。与 search 对象一起的是一个 aggregations 对象，其中包含聚合的配置文件信息。将来可能会添加更多部分，例如 suggest、highlight 等。
还将有一个 rewrite 指标，显示重写查询所花费的总时间（以纳秒为单位）。
与其他统计 API 一样，配置文件 API 支持人类可读的输出。可以通过在查询字符串中添加 ?human=true 来启用此功能。在这种情况下，输出包含额外的 time 字段，其中包含四舍五入的、人类可读的计时信息（例如 "time": "391,9ms"、"time": "123.3micros"）。
分析查询编辑
配置文件 API 提供的详细信息直接公开了 Lucene 类名和概念，这意味着要完全解释结果，需要对 Lucene 有相当深入的了解。本页尝试对 Lucene 如何执行查询进行速成课程，以便您可以使用配置文件 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": {...}
}
]
}
]
根据配置文件结构，我们可以看到我们的 match 查询被 Lucene 重写为具有两个子句（都包含 TermQuery）的 BooleanQuery。type 字段显示 Lucene 类名，并且通常与 Elasticsearch 中的等效名称一致。description 字段显示查询的 Lucene 解释文本，并用于帮助区分查询的不同部分（例如，message:get 和 message:search 都是 TermQuery，否则看起来相同）。
time_in_nanos 字段显示此查询花费了大约 11.9 毫秒来执行整个 BooleanQuery。记录的时间包括所有子级。
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 部分编辑
响应的 Collectors 部分显示了高级执行细节。Lucene 通过定义一个“Collector”来工作，它负责协调匹配文档的遍历、评分和收集。Collectors 也是单个查询如何记录聚合结果、执行无范围的“全局”查询、执行查询后过滤器等的。
看看前面的例子
"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 使用的默认“评分和排序”Collector。reason 字段尝试给出类名的简单英文描述。time_in_nanos 类似于查询树中的时间：包含所有子级的挂钟时间。类似地，children 列出了所有子收集器。当请求聚合时，QueryPhaseCollector 将持有一个额外的子收集器，其原因是 aggregation，它是执行聚合的那个。
应该注意的是，Collector 时间独立于查询时间。它们是独立计算、组合和标准化的！由于 Lucene 执行的性质，不可能将 Collectors 中的时间“合并”到查询部分，因此它们显示在不同的部分。
作为参考，各种收集器的原因是
|
|
对文档进行评分和排序的收集器。这是最常见的收集器，在大多数简单搜索中都会看到 |
|
|
仅计算与查询匹配的文档数量但不获取源的收集器。当指定了 |
|
|
一个收集器，它结合了收集热门点击和聚合作为查询阶段的一部分。它支持在找到 |
|
|
在指定时间段后停止执行的收集器。当指定了顶级参数 |
|
|
Elasticsearch 用于针对查询范围运行聚合的收集器。单个 |
|
|
针对全局查询范围而不是指定查询执行聚合的收集器。因为全局范围必然不同于执行的查询，所以它必须执行自己的 match_all 查询（您将在查询部分看到添加的）来收集您的整个数据集 |
rewrite 部分编辑
Lucene 中的所有查询都经过“重写”过程。一个查询（及其子查询）可能会被重写一次或多次，并且该过程会一直持续到查询停止更改为止。此过程允许 Lucene 执行优化，例如删除冗余子句、将一个查询替换为更有效的执行路径等。例如，Boolean → Boolean → TermQuery 可以重写为 TermQuery，因为在这种情况下所有布尔值都是不必要的。
重写过程很复杂，难以显示，因为查询可能会发生巨大变化。没有显示中间结果，而是简单地将总重写时间显示为一个值（以纳秒为单位）。此值是累积的，包含所有被重写查询的总时间。
一个更复杂的例子编辑
为了演示稍微复杂的查询和相关结果，我们可以分析以下查询
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
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查询。
Collector 树相当简单，显示了单个 QueryPhaseCollector 如何保存用于收集热门点击的普通评分 SimpleTopScoreDocCollector，以及用于运行所有范围聚合的 BucketCollectorWrapper。
了解 MultiTermQuery 输出编辑
需要特别说明的是 MultiTermQuery 类查询。这包括通配符、正则表达式和模糊查询。这些查询会发出非常详细的响应，并且结构不是 overly 结构化的。
本质上，这些查询会在每个段的基础上重写自身。如果您想象一下通配符查询 b*，它在技术上可以匹配任何以字母“b”开头的标记。枚举所有可能的组合是不可能的，因此 Lucene 在评估的段的上下文中重写查询，例如，一个段可能包含标记 [bar, baz]，因此查询重写为“bar”和“baz”的 BooleanQuery 组合。另一个段可能只有标记 [bakery]，因此查询重写为“bakery”的单个 TermQuery。
由于这种动态的、每个段的重写，干净的树结构变得扭曲，不再遵循显示一个查询如何重写为下一个查询的干净“谱系”。目前，我们所能做的就是道歉，并建议您折叠该查询的子级的详细信息（如果它太混乱）。幸运的是，所有计时统计数据都是正确的，只是响应中的物理布局不正确，因此如果您发现细节太难解释，则只需分析顶级 MultiTermQuery 并忽略其子级就足够了。
希望这会在未来的迭代中得到修复，但这是一个棘手的问题，仍在进行中。:)
分析聚合编辑
aggregations 部分编辑
aggregations 部分包含由特定分片执行的聚合树的详细计时。此聚合树的整体结构将类似于您最初的 Elasticsearch 请求。让我们再次执行之前的查询，这次查看聚合配置文件
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
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 部分。让我们执行一个小搜索，看看提取配置文件
response = client.search(
index: 'my-index-000001',
filter_path: 'profile.shards.fetch',
body: {
profile: true,
query: {
term: {
'user.id' => {
value: 'elkbee'
}
}
}
}
)
puts 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", "_ignored", "_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 字段上索引一对具有不同值的文档。
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
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 阶段。在本例中，我们使用词项查询。
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
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 的示例
让我们首先设置一个包含多个密集向量的索引。
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
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 搜索查询。
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
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 部分中，我们可以看到 查询、重写 和 收集器 的计时输出。与许多其他查询不同，kNN 搜索在查询重写期间完成了大部分工作。这意味着 rewrite_time 表示在 kNN 搜索上花费的时间。属性 vector_operations_count 表示在 kNN 搜索期间执行的向量运算总数。
分析注意事项编辑
与任何分析器一样，Profile API 会给搜索执行带来不可忽略的开销。检测 collect、advance 和 next_doc 等低级方法调用的行为可能相当昂贵，因为这些方法是在紧密循环中调用的。因此，默认情况下不应在生产设置中启用分析，并且不应将其与未分析的查询时间进行比较。分析只是一种诊断工具。
在某些情况下，特殊的 Lucene 优化会被禁用，因为它们不适合分析。这可能会导致某些查询报告的相对时间比未分析的查询更长，但与分析查询中的其他组件相比，通常不会产生显著影响。
限制编辑
- 分析目前不测量网络开销。
- 分析也不考虑在队列中花费的时间、在协调节点上合并分片响应或构建全局序号（用于加速搜索的内部数据结构）等额外工作。
- 分析统计信息当前不适用于建议。
- 聚合的 reduce 阶段的分析当前不可用。
- Profiler 正在检测可能因版本而异的内部结构。生成的 json 应该被认为大部分是不稳定的，尤其是在
debug部分中的内容。