Elasticsearchのクエリが遅いのはなぜ？スローログとプロファイリングで原因を特定する方法

本記事は、2018年5月29日にObjectRocket.com/blogで公開された記事を基にしています。

Elasticsearch®に関するサポート依頼で頻繁に寄せられるのが、「レスポンスタイムが遅くて困っている」「クエリの実行に時間がかかるが、どうすればいいのか？」といったものです。本記事では、こうしたクエリの遅延問題の原因を特定し、パフォーマンスを改善するための具体的なアプローチを解説します。

2つのアプローチ

この種の質問を受けたとき、私たちはまず次の2つの観点から調査を始めます。

• 運用（オペレーション）側：現在のシステムリソースやElasticsearchのデフォルト設定を確認します。
• 開発側：クエリそのもの、その構造、そして検索対象データのマッピングを確認します。

Elasticsearch最適化シリーズの第1回となる本記事では、後者の「開発側」に焦点を当てます。スロークエリの収集方法、DSL（Domain Specific Language）クエリ言語の概要、そしてクエリ改善に役立つ各種オプションについて見ていきましょう。

あなたのクエリはどれほど遅いのか？

最初のステップは、クエリがクラスタに送信されてから完了するまでにかかる時間を把握することです。Elasticsearchの公式ドキュメントではスローログの有効化方法が必ずしも明確に説明されていないため、ここで具体例を紹介します。

まず知っておくべき点として、Elasticsearchには2種類のスローログが存在します。インデックススローログと検索スローログです。今回解決したいのはクエリが遅いという問題なので、検索スローログに注目します。もしドキュメントの登録やインデックス作成時のパフォーマンス問題であれば、インデックススローログを確認することになります。

すべてのバージョンのElasticsearchでは、スローログはデフォルトで無効になっています。したがって、クラスタ設定とインデックス設定の両方にいくつかの変更を加える必要があります。以下の例はElasticsearch 6.2を対象としていますが、過去のバージョンについても公式ドキュメントで情報を確認できます。コマンド内の$ES_versionは、実際に使用しているバージョン（例：5.5など）に置き換えてください。

• _cluster APIに対してPUTリクエストを送信し、有効化したいスローログのレベル（warn、info、debug、trace）を定義します。

  curl -XPUT https://localhost:$ES_PORT/_cluster/settings -H 'Content-Type: application/json' -d'
  {
    "transient": {
      "logger.index.search.slowlog": "DEBUG",
      "logger.index.indexing.slowlog": "DEBUG"
    }
  }'
  

• Elasticsearchはすべてのスローロギングをインデックスレベルで管理しているため、インデックスの_settings APIにリクエストを送って有効化することもできます。月次や四半期ごとにインデックスをローテーションしている場合は、インデックステンプレートにも同じ設定を追加しておきましょう。

• インデックス設定へのAPIコールを調整し、計測したいスローログの時間しきい値に合わせます。値を0に設定すると、インスタンスのプロファイリングを行い、送信されたすべてのクエリを収集できます。-1を設定するとスローログは無効になります。

• _cluster設定で使用したのと同じログレベルを使用します。この例ではDEBUGです。ES_PORTは永続的な環境変数です。

  curl -XPUT https://localhost:$ES_PORT/*/_settings?pretty -H 'Content-Type: application/json' -d '{
    "index.search.slowlog.threshold.query.debug": "-1",
    "index.search.slowlog.threshold.fetch.debug": "-1"
  }'
  

次にログを収集します。スローログはシャード単位で生成され、データノード単位で集約されます。たとえば、5つのプライマリシャード（デフォルト値）を持つデータノードが1台だけの場合、1つのクエリに対してスローログに5件のエントリが記録されます。これは、Elasticsearchでの検索が各シャード内部で実行されるためです。スローログはデータノードごとに、デフォルトでは/var/log/elasticsearch/$ClusterID_index_slowlog_queryおよび/var/log/elasticsearch/$ClusterID_index_slowlog_fetchという場所に保存されます。ご覧のとおり、検索スローログはさらに検索フェーズに応じて「fetch」と「query」の2つのログファイルに分けられています。

ログに結果が記録されたら、エントリを取り出して内容を分析してみましょう。

[2018-05-21T12:35:53,352][DEBUG][index.search.slowlog.query] [DwOfjJF] [blogpost-slowlogs][4] took[1s], took_millis[0], types[], stats[], search_type[QUERY_THEN_FETCH], total_shards[5], source[{"query":{"match":{"name":{"query":"hello world", "operator":"OR","prefix_length":0,"max_expansions":50,"fuzzy_transpositions":true, "lenient":false,"zero_terms_query":"NONE","boost":1.0}}},"sort":[{"price":{"order":"desc"}}]}]

このログエントリから読み取れる主な情報は以下のとおりです。

• 日付・タイムスタンプ
• ログレベル
• スローログの種類
• ノード名
• インデックス名
• シャード番号
• 処理時間
• クエリ本体（_source）

時間がかかりすぎていると特定できたクエリが得られたら、次のツールを使って詳細に分解できます。

_profile API

_profile APIは、検索に関する膨大な情報を提供し、各シャード内で何が起こったのかを、個々の検索コンポーネントの実行時間レベルまで分解して表示します。検索が複雑になるほど、_profileの出力も詳細になります。

Kibanaのプロファイリングツール

Kibana®のプロファイリングツールは、_profile APIと連携して動作します。個々の検索コンポーネントとその所要時間を見やすいウォーターフォール形式で可視化してくれるため、クエリのどの部分がボトルネックになっているのかを直感的に把握できます。

Elasticsearch検索の2つのフェーズ：「Query then Fetch」

ここまでで、遅いクエリを特定し、プロファイラで実行時間を分析しました。しかし、コンポーネントごとの時間結果を見ただけでは、検索は速くなりません。では、次に何をすべきでしょうか？　クエリの仕組みを理解することが重要です。以下の2つのフェーズを理解することで、速度と関連性の両面でElasticsearchから最高の結果を引き出すようにクエリを再設計できるようになります。

クエリフェーズ（Query Phase）

• コーディネータノードがクエリを受け付けます。
• コーディネータが検索対象のインデックス（または複数のインデックス）を特定します。
• コーディネータが、対象インデックスのシャードを持つノードのリストを作成します（プライマリとレプリカが混在します）。
• コーディネータがクエリを各ノードに転送します。
• 各ノード上のシャードがクエリを処理します。
• クエリは（デフォルトで）上位10ドキュメントに対してスコアリングされます。
• 結果リストがコーディネータノードに返されます。

フェッチフェーズ（Fetch Phase）

• フェッチフェーズはコーディネータノードから始まります。コーディネータは、各シャードから送られてきた50件（5シャード×10件）の結果の中から、上位10ドキュメントを決定します。
• コーディネータが、上位10ドキュメントの取得要求をシャードに送信します。（最もスコアの高いドキュメントが1つのシャードに集中している場合もあれば、複数のシャードに分散している場合もあります。）

リストが返却されると、マスタがドキュメントをクエリレスポンスの_hitsセクションに表示します。

結果スコアの重要性

結果スコアはElasticsearchにおいて非常に重要です。通常、検索エンジンを使うときは、最も正確な結果を求めます。たとえば、果物のキウイを検索しているのに、結果に靴磨きの「Kiwi」が含まれていたら困りますよね。Elasticsearchは、指定されたパラメータに基づいてクエリ結果をスコアリングします。クエリの関連性については別のブログ記事で詳しく取り上げますが、ここでも触れておくべき重要なポイントがあります。検索が速くても、求めている結果が得られなければ、その検索は時間の無駄になってしまうということです。では、どうすれば検索を高速化できるのでしょうか？

フィルタの活用

検索パフォーマンスを向上させる方法のひとつがフィルタです。フィルタ付きクエリはあなたの強力な味方になるでしょう。まずフィルタを適用することが重要です。検索におけるフィルタはドキュメントのスコアに影響しないため、少ないリソースで検索対象範囲を絞り込むことができます。

フィルタ付きクエリでは、ブール条件との組み合わせにより、「Yを含むかどうか」でスコアリングする前に、「Xを含むすべてのドキュメント」を先に絞り込むことができます。さらに、フィルタはキャッシュ可能であるという利点もあります。

フィルタはElasticsearchクエリを高速化する唯一の手段ではありません。クエリパフォーマンスを改善するその他の手法については、今後のブログで詳しく紹介する予定です。

まとめ

クエリの最適化は、次のシンプルなステップで実行できます。

• スローロギングを有効にして、実行に時間がかかっているクエリを特定する
• 特定した検索を_profile APIで実行し、個々のコンポーネントのタイミングを確認する
• フィルタ、フィルタ、とにかくフィルタを活用する

Elasticsearchの管理についてご質問がある方は、ぜひお気軽にお問い合わせください。無料トライアルを含むすべてのインスタンスで、Elasticsearchに精通したデータベース管理者によるサポートをご利用いただけます。開発に集中したい方は、Elasticsearchの運用管理をお任せください。

Kibana付きのElasticsearch 6の無料トライアルを試してみたい方は、今すぐ始めてみましょう。ご不明な点があればお気軽にご相談ください。

フィードバックタブからコメントやご質問をお送りいただくこともできます。また、Sales Chatをクリックして、今すぐチャットで会話を始めることも可能です。