用PROFILE API 定位 ES 慢查詢
轉載處：https://www.easyice.cn/archives/267
有時在發起一個查詢時，他會被延遲，或者響應時間很慢，查詢緩慢可能會有多種原因；範圍包括 shard 問題，或者計算查詢中的某些元素。 從 elasticsearch 2.2版本開始提供 Profile API 供使用者檢查查詢執行時間和其他詳細資訊。在這篇部落格中，我們將探討如何使用profile API檢視查詢計時。
Profile API
Profile API 是Elasticsearch 2.2版本的一個實驗性特性， Profile API 返回所有分片的詳細資訊。為了簡單起見，我們建立一個只有1個分片的索引。
Index creation:
| 1 2 3 4 5 6 7 8 |
curl -XPUT http:localhost:9200/myindex -d '{ "settings":{ "number_of_replicas": 0, "number_of_shards": 1 } }'
|
在上面建立的索引中，我們為演示基本的搜尋寫入若干文件，然後從結果中解釋 profile API。讓我們索引三個doc:
| 1 2 3 4 5 6 7 8 9 10 11 |
curl -XPOST http://localhost:9200/myindex/mytype/1 -d '{ "brand" : "Cotton Plus" }' curl -XPOST http://localhost:9200/myindex/mytype/2 -d '{ "brand" : "Van Huesen" }' curl -XPOST http://localhost:9200/myindex/mytype/3 -d '{ "brand" : "Arrow" }'
|
可以通過在 query 部分上方提供 “profile: true” 來啟用Profile API。讓我們來看看帶profile引數的 query 在單個查詢中長什麼樣子：
| 1 2 3 4 5 6 7 8 9 10 |
curl XPOST http://localhost:9200/myindex/mytype/_search -d '{ "profile": true, "query": { "match": { "brand": "Cotton Plus" } } }'
|
Profile API的結果是基於每個分片計算的。由於在我們的例子中只有一個分片，我們在profile API響應的分片陣列中只有一個數組元素，如下所示：
| 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 |
{ "shards": [ { "id": "[egPYczsCRTqaeJ8jKhFjtw][myindex][0]", "searches": [ { "query": [ { "query_type": "BooleanQuery", "lucene": "brand:levi brand:goals", "time": "1.293761000ms", "breakdown": { "score": 0, "create_weight": 136078, "next_doc": 0, "match": 0, "build_scorer": 1082113, "advance": 0 }, "children": [ { "query_type": "TermQuery", "lucene": "brand:levi", "time": "0.04626300000ms", "breakdown": { "score": 0, "create_weight": 30190, "next_doc": 0, "match": 0, "build_scorer": 16073, "advance": 0 } }, { "query_type": "TermQuery", "lucene": "brand:goals", "time": "0.02930700000ms", "breakdown": { "score": 0, "create_weight": 16600, "next_doc": 0, "match": 0, "build_scorer": 12707, "advance": 0 } } ] } ], "rewrite_time": 64032, "collector": [ { "name": "TotalHitCountCollector", "reason": "search_count", "time": "0.002931000000ms" } ] } ] } }
|
Profile API響應說明
上面的響應顯示的是單個分片。每個分片都被分配一個唯一的ID，ID的格式是[nodeID][indexName][shardID]。現在在"shards"數組裡還有另外三個元素，它們是：
- query
- rewrrite_time
- collector
Query
Query 段由構成Query的元素以及它們的時間資訊組成。Profile API結果中Query 部分的基本組成是：
- query type – 它向我們顯示了哪種型別的查詢被觸發。此處是布林值。因為多個關鍵字匹配查詢被分成兩個布林查詢。
-
lucene – 該欄位顯示啟動查詢的lucene方法。這裡是
"brand:levi brand:goals" -
time – lucene 執行此查詢所用的時間。單位是毫秒。
- breakdown – 有關查詢的更詳細的細節，主要與lucene引數有關。
- children – 具有多個關鍵字的查詢被拆分成相應術語的布林查詢，每個查詢都作為單獨的查詢來執行。每個子查詢的詳細資訊將填充到Profile API輸出的子段中。在上面的章節中，可以看到第一個子元素查詢是
"levi"，下面給出查詢時間和其他breakdown引數等詳細資訊。同樣，對於第二個關鍵字，有一個名為"goals"的子元素具有與其兄弟相同的資訊。從查詢中的子段中，我們可以得到關於哪個搜尋項在總體搜尋中造成最大延遲的資訊。
Rewrite Time
由於多個關鍵字會分解以建立個別查詢，所以在這個過程中肯定會花費一些時間。將查詢重寫一個或多個組合查詢的時間被稱為“重寫時間”。(以納秒為單位)。
Collectors
在Lucene中，收集器是負責收集原始結果，收集和組合結果，執行結果排序等的過程。例如，在上面的執行的查詢中，當查詢語句中給出size:0時，使用的收集器是"totalHitCountCollector"。這隻返回搜尋結果的數量（search_count），不返回文件。此外，收集者所用的時間也一起給出了。
總結
在這篇部落格中，我們看到Profile API非常有用，它讓我們清楚地看到查詢時間。通過向我們提供有關子查詢的詳細資訊，清楚地知道在那個環節查詢慢，這是非常有用的。另外，API返回結果中，關於Lucene的詳細資訊也讓我們深入瞭解到 elasticsearch 是如何執行查詢的。
參考：
http://cwiki.apachecn.org/display/Elasticsearch/Profile+API