有時在發起一個查詢時，他的執行過程會延遲，或者響應時間很慢。查詢緩慢可能會有多種原因范圍包括 shard 問題，或者計算查詢中的某些元素。 從 elasticsearch 2.2版本開始提供 Profile API 供用戶檢查查詢執行時間和其他詳細信息

    在官網中，profile API的首頁，有一句警告：The Profile API is a debugging tool and adds significant overhead to search execution. 意思是，查看執行計劃，會增加系統的資源開銷。大家在生產環境的時候，還是要慎用這個功能。

執行一個基礎查詢請求，只要在請求參數中加入 "profile":true，即可查看ES的執行計劃

GET /my-index-000001/_search
{
  "profile": true,
  "query" : {
    "match" : { "message" : "GET /search" }
  }
}

查看執行結果：

{
  "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": "[2aE02wS1R8q_QFnYu6vDVQ][my-index-000001][0]",
        "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": "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": "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響應的高層次元素是多個分片對象數組。每個分片對象列出其ID，該ID唯一標識該分片。ID格式為[節點ID][索引名稱][分片ID]。
整個profile可能包括一個或多個“搜索”，其中搜索是對 underlying Lucene 索引的執行查詢。大部分用戶提交的請求只會針對Lucene索引執行一次搜索。但偶爾多個搜索將執行，例如包括全球聚合(這需要執行第二個“匹配全部”查詢以獲取全球上下文)。

Query階段：

query部分包含Lucene在指定分片上執行的查詢樹詳細的時間信息。

"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 結構，我們可以發現我們的匹配查詢被 Lucene 改寫成了一個布爾值查詢(其中包含兩個子查詢：一個TermQuery)。

type字段顯示的是 Lucene 類名，通常與 Elasticsearch 中相應的名稱對齊。

description字段顯示的是查詢的解釋文本，以便于區分您的查詢部分(例如，"message:get"和"message:search"都是TermQuery，它們看起來非常相似)。
time_in_nanos 字段顯示，這個查詢整個布爾值查詢執行花費了大約 11.9 毫秒。記錄的時間包括所有子查詢。
breakdown 字段將提供有關時間如何花費的詳細信息。我們將稍后查看它。最后，children 數組列出可能存在的子查詢。由于我們搜索了兩個值(“get search”)，我們的布爾查詢包含兩個子Term queries。它們具有相同的信息(type、time、 breakdown、等等)。子查詢可以有自己的子查詢。

Collector階段：

響應的collector部分顯示高級執行詳細信息。 Lucene 的工作方式是定義一個“Collector”，負責協調匹配文檔的遍歷、評分和收集。

"collector": [
  {
    "name": "SimpleTopScoreDocCollector",
    "reason": "search_top_hits",
    "time_in_nanos": 775274
  }
]

我們看到一個名為SimpleTopScoreDocCollector的收集器被包裝為可取消的收集器。

SimpleTopScoreDocCollector是Elasticsearch默認的“得分和排序”收集器。

reason字段試圖用簡單的英語描述類名。

time_in_nanos類似于查詢樹的時間：包括所有子收集器的 wall-clock 時間。類似地，子集列表了所有子收集器。

將SimpleTopScoreDocCollector包裹在可取消的收集器中的收集器是用于檢測當前搜索是否被取消，并在發生時立即停止收集文檔的Elasticsearch工具。
需要指出的是，收集器時間與查詢時間無關。它們計算、組合并標準化獨立于查詢時間！由于Lucene的執行本質，不可能將收集器時間“合并”到查詢部分中，因此它們顯示在獨立的部分中。

rewrite階段：

Lucene中的所有查詢都經歷著一個“rewrite”過程。一個查詢(及其子查詢)可能多次被改寫，并且過程會繼續直到查詢不再發生變化。

這個過程允許Lucene進行優化，例如刪除冗余條件句，以更高效的執行路徑替換一個查詢等等。例如，Boolean → Boolean → TermQuery可以改寫為TermQuery，因為在這種情況下所有布爾查詢都是不必要的。

改寫過程非常復雜且難以顯示，因為查詢可能會發生劇烈的變化。 Rather than顯示中間結果，總改寫時間 simply 顯示為值(in nanoseconds)。這個值是累加的，它包含了所有正在改寫的查詢的總時間。