【elasticsearch】Profile APIでクエリ解析
Profile API
elasticsearch2.2が先月リリースされ(リリースノート)Profile APIという機能が追加されました。
この機能はRDBMSの実行計画のようにクエリ実行の流れがわかる情報をAPIで提供してくれます。
スローなクエリの解析に効果がありそうだと個人的にも期待している機能です。
どうやって使う?
Profile APIの使い方はすごく簡単で、クエリ実行時にprofileをtrueにセットしてあげると
{ "profile": true, "query": { "match": { "pref": "茨城" } } }
こちらのようにクエリの実行情報を実行結果とともに返してくれます。
{ "id": "[GjqU-RMDQbiR3zU58ITvgA][population][2]", "searches": [ { "query": [ { "query_type": "BooleanQuery", "lucene": "pref:茨 pref:城", "time": "0.5796450000ms", "breakdown": { "score": 6486, "create_weight": 155444, "next_doc": 7623, "match": 0, "build_scorer": 143408, "advance": 0 }, "children": [ { "query_type": "TermQuery", "lucene": "pref:茨", "time": "0.2137220000ms", "breakdown": { "score": 3054, "create_weight": 92406, "next_doc": 2069, "match": 0, "build_scorer": 116193, "advance": 0 } }, { "query_type": "TermQuery", "lucene": "pref:城", "time": "0.05296200000ms", "breakdown": { "score": 621, "create_weight": 39380, "next_doc": 798, "match": 0, "build_scorer": 12163, "advance": 0 } } ] } ], "rewrite_time": 6780, "collector": [ { "name": "SimpleTopScoreDocCollector", "reason": "search_top_hits", "time": "0.01149200000ms" } ] } }
どんな情報が取れる?
Profile APIで取得できる情報の種類はこちらです
query | Lucene内でどのようにクエリが実行されているか |
collector | LuceneのCollector(検索結果の収集やスコアリング、ソートなどを行うクラス)がどのように実行されているか |
rewrite | Luceneによって実行クエリがどのようにリライトされたか |
そして提供される情報はどんどん増えていく予定です(suggestやhighlightなど)
出力される情報はLucene内での出来事についてなので、Luceneについて詳しくないと
細かいところまで理解することは難しそうです(自分も苦戦しています)
ただ、たとえLuceneがわからなくてもクエリのどこが遅くなってる原因なのか何となく分かる情報になっています。たとえばqueryセクションをみてますと
"query": [ { "query_type": "BooleanQuery", "lucene": "pref:茨 pref:城", "time": "0.5796450000ms", "breakdown": { "score": 6486, "create_weight": 155444, "next_doc": 7623, "match": 0, "build_scorer": 143408, "advance": 0 }, "children": [ { "query_type": "TermQuery", "lucene": "pref:茨", "time": "0.2137220000ms", "breakdown": { "score": 3054, "create_weight": 92406, "next_doc": 2069, "match": 0, "build_scorer": 116193, "advance": 0 } }, { "query_type": "TermQuery", "lucene": "pref:城", "time": "0.05296200000ms", "breakdown": { "score": 621, "create_weight": 39380, "next_doc": 798, "match": 0, "build_scorer": 12163, "advance": 0 } } ] } ]
こちらはアナライズされている県名のフィールドに「茨城」で検索した場合のProfileですが
LuceneのBooleanQuery全体で0.579ms、その子どもとなるTermQueryでそれぞれ0.213ms、
0.052msかかっていることがわかります。
ちなみに各項目は
query_type | Lucene内で実行されるクラス名 |
lucene | Luceneクエリ |
time | 実行時間(ms) |
breakdown | 時間がどのように使われたかの詳細 |
とのことです。
おわりに
スローなクエリにはProfile API!とだけ覚えて帰っていただければと思います。