高度な調整：Elasticsearchでのスロークエリの発見と修正

By
Louis Ong

Elasticsearchは非常に柔軟で機能が豊富なアプリケーションであり、多数のさまざまな方法でデータをクエリできます。しかし、期待しているよりも実行速度の遅いクエリを経験したことはありませんか？Elasticsearchのような分散システムでは、ロードバランサーの設定、ネットワークレイテンシ（帯域幅、NICカード/ドライバー）など、さまざまな要素がクエリのパフォーマンスに影響を与える可能性があります。

このブログでは、クエリの実行速度の低下を引き起こす原因と、それらをElasticsearchのコンテキスト内で特定する方法を説明します。この記事では、Elasticsearchの一般的なトラブルシューティング方法を使用するため、ある程度Elasticsearchの仕組みに精通していることが必要になる場合があります。

Elasticsearchでのスロークエリの一般的な原因

扱いが難しいケースを見る前に、まずはスロークエリの一般的な原因とその解決方法を見ていきます。

症状：非アクティブ時にリソース使用率が高い

どのシャードもリソース（CPU/メモリー）を消費します。インデックス/検索リクエストがゼロの場合でも、シャードが存在していることでクラスターのオーバーヘッドが消費されます。

問題

クラスターのシャードが多すぎるため、どのクエリも実行速度が遅くなっていると感じる場合があります。経験則では、ノードごとの非フローズンのシャード数は、構成したヒープのGBあたり20未満に維持することが良いと言えます。

解決策

シャード数とフローズン状態のインデックス数を減らし、および/または負荷に対処できるようにノードを増やします。Hot-Warmアーキテクチャー（時間ベースのインデックスに効果的）とElasticsearchの ロールオーバー/縮小機能を使用して、シャード数を効率的に管理することを検討しましょう。最初に重要なのは、どのデプロイメントでも適切なキャパシティープランニングを実行して、各検索ユースケースに最適なシャード数を決定することです。

症状：スレッドプールの拒否数が多い

検索スレッドプールで「拒否」数が継続的に上昇しており、クラスターの前回の再起動から累積しています。 

GET /_cat/thread_pool/search?v&h=node_name,name,active,rejected,completed

応答は下記のようになります。 

node_name             name   active rejected completed
instance-0000000001   search      0       10         0
instance-0000000002   search      0       20         0
instance-0000000003   search      0       30         0

問題

クエリの対象となるシャードが多すぎて、クラスター内のコア数を超過しています。これにより、検索スレッドプール内でタスクがキューに入れられ、検索の拒否が発生します。別の一般的な原因として考えられるのは、ディスクI/Oが遅い場合です。これによって検索がキューに入れられたり、またはCPUが完全に飽和したりします。 

解決策

インデックス作成時に、1プライマリー：1レプリカモデルを採用します。この設定をインデックス時にロールアウトするのに有効な方法は、インデックステンプレートを使用することです。（1P：1RはElasticsearch 7.0以降でデフォルトとなります）。Elasticsearch 5.1以降では、検索タスクのキャンセルをサポートしています。これは、タスク管理APIでスロークエリが発生した場合に効果的です。ディスクI/Oを改善するためには、Elasticのストレージ推奨事項を確認して、推奨されるハードウェアを使用してパフォーマンスを最大化するようにしてください。

症状：CPU使用率およびインデックスレイテンシが高い

クラスターの飽和時にメトリックの相関付けが、高いCPU使用率とインデックスレイテンシを示しています。

問題

クラスターにインデックス作業の高い負荷がかかっており、検索パフォーマンスに影響しています。

解決策

index.refresh_ interval（ドキュメントがインデックスされたときから表示できるようになるまでの時間）を増やす（たとえば30秒）ことで、通常はインデックスパフォーマンスが改善されます。実際の状況は異なる場合があるため、テストすることが重要です。これにより、1秒ごと（デフォルト）に新しいセグメントを作成するというシャードの作業負荷が軽減されます。

インデックスの作業負荷が高いユースケースについては、Elasticのインデックスの調整に関する推奨事項を確認し、インデックスと検索の両方のパフォーマンスを最適化してください。

症状：レプリカシャードが多いことによってレイテンシが増加している

クエリのレイテンシは、レプリカ―シャード数を増加（たとえば1から2に増加）した後に見られることがあります。より多くのデータが存在する場合は、キャッシュされたデータがすぐに削除され、オペレーティングシステムのページフォールトが増加します。

問題

インデックスの頻繁にクエリされる部分をキャッシュに保持するのに十分なメモリーが、ファイルシステムキャッシュにありません。Elasticsearchのクエリキャッシュには、LRU削除ポリシーが実装されています。つまり、キャッシュがいっぱいになると、新しいデータ用の領域を作るために、最近もっとも使われていないデータが削除されます。

解決策

ファイルシステムキャッシュのために50%以上の物理的RAMを残しておきます。特にクラスターにI/Oの問題が影響している場合は、メモリーが多ければ多いほど、キャッシュできる量も増えます。 ヒープサイズが適切に構成されている場合、ファイルシステムキャッシュに利用できる物理的RAMのスペースが残っていれば、検索パフォーマンスの高速化に大いに役立ちます。

たとえば、128 GBのRAMサーバーの30 GBをヒープ用、残りのメモリーをファイルシステムキャッシュ（OSキャッシュと呼ばれることもある）用に確保します。そして、最近アクセスされたデータの4 KBブロックをオペレーティングシステムがキャッシュすることで、同じファイルを何度も読み込む場合はディスクにアクセスすることがほとんどなくなり、その読み込みリクエストはメモリーから直接対応されるようになります。

Elasticsearchでは、ファイルシステムキャッシュだけでなく、クエリキャッシュとリクエストキャッシュも使用して検索を高速化します。 これらすべてのキャッシュは、利用できるさまざまなシャードコピーをその都度切り替えるのではなく、search-request-preference（検索-リクエスト-優先設定）を使用して、特定の検索リクエストが毎回同じシャードセットにルーティングされるように最適化できます。このようにすることで、リクエストキャッシュ、ノードクエリキャッシュ、およびファイルシステムキャッシュをより活用できるようになります。

症状：リソースの共有時に使用率が高い

オペレーティングシステムのCPU/ディスクI/Oの使用率が一貫して高くなっています。サードパーティーのアプリケーションを停止すると、パフォーマンスゲインが見られます。

問題

リソース（CPUおよび/またはディスクI/O）がその他のプロセス（Logstashなど）およびElasticsearch自体と競合しています。

解決策

共有ハードウェア上で、他のリソース負荷の高いアプリケーションとともにElasticsearchを実行しないようにします。

症状：一意性が高いフィールドの集計が原因でヒープ使用率が高い

一意性が高い値（ID、ユーザー名、メールアドレスなど）を含んでいるフィールドの集計に対してクエリを実行すると、パフォーマンスが低下します。ヒープダンプ分析時に、「search」、「buckets」、「aggregation」などの用語があるJavaオブジェクトが見られるはずです。これらはヒープの多くを消費します。

問題

カージナリティが高いフィールドの集計には、多くのバケットを取得するために多大なリソースが必要になります。 ネストされたフィールドや結合されたフィールドには、ネストされた集計が存在している場合もあります。

解決策

カージナリティが高い用語の集計のパフォーマンスを改善するには、コンサルティングチームに所属している私の同僚が書いたこちらのブログをお読みください：https://www.elastic.co/jp/blog/improving-the-performance-of-high-cardinality-terms-aggregations-in-elasticsearch。

さらに調整するためには、ネストされたフィールドおよび結合されたフィールドに関する推奨事項を確認し、集計のパフォーマンスを改善してください。

スロークエリが時々発生する場合

一般的に、時々または断続的にスロークエリが発生する場合は、インデックス向けの調整/検索向けの調整に関する推奨事項が役に立つ可能性があります。時々発生するスロークエリは、以下の監視メトリックの1つまたは複数に密接に関係しています。

Elasticsearchには、adaptive replica selection（ARS）（適応型レプリカ選択）と呼ばれる便利な機能があります。これによって調整ノードは、データノードの負荷を認識でき、検索の実行に最適なシャードコピーを選択できるようになり、検索スループットとレイテンシの両方を改善することが可能になります。ARSは、クエリ時間の間の負荷を均等に分散させることで、時々発生するスロークエリに大いに役立ちます。Elasticsearch 7.0以降では、ARSはデフォルトで有効化されます。

スロークエリが継続的に発生する場合

スロークエリが継続的に発生する場合は、クエリから1つ1つ機能を削除していき、それでもクエリが遅いかどうかをチェックすることが可能です。パフォーマンスの問題を再現する最もシンプルなクエリを見つけることが、問題の切り分けと特定に役立ちます。

  • ハイライト表示をしなくても遅いですか？
  • 集計をしなくても遅いですか？
  • sizeをゼロに設定しても遅いですか？（ sizeをゼロに設定すると、Elasticsearchは検索リクエストの結果をキャッシュして検索を高速化します）

「検索用の調整」に関する推奨事項のいずれかが役に立ちますか？

トラブルシューティング時には、しばしば次のことが役に立ちます。

クエリがKibanaビジュアライゼーションからの場合は、visualization spy panel（ビジュアライゼーションスパイパネル）（Kibanaバージョン6.3以前）またはdashboard inspect panel（ダッシュボード検査パネル）（Kibanaバージョン6.4以降）を使用して、実際のクエリリクエストを表示およびエクスポートし、プロファイルAPIにインポートしてさらに分析します。

遅いまたは負荷の高いクエリをキャッシュする

Elasticsearchのような分散アプリケーション内で、異なる複数のリクエスト/スレッドを同時に処理していると、遅いまたは負荷の高いクエリを特定することは難しい場合があります。これは、クラスターのパフォーマンスを低下させる高負荷のクエリ（長期間のガーベージコレクション（GC）サイクルなど）を実行しているユーザーを制御できない場合にはさらに複雑になり、最悪の場合はメモリー不足（OOM）の状況に陥ってしまいます。

Elasticsearchバージョン7.0では、メモリーが予約されているときの実際のヒープ領域使用率を計測する新しい回路遮断戦略を採用しています。この新しい戦略により、クラスターの過負荷を引き起こす高負荷のクエリに対するノードの回復性が改善されます。これはデフォルトで有効化されており、新しいクラスター設定indices.breaker.total.use_real_memoryで制御できます。

ただし、これらはベストエフォート型であることに注意が必要です。これらの対象にならない状況では、OOMによるクラッシュ後にヒープダンプを収集、または稼働中のJVMからヒープダンプを収集することで、根本原因の把握に役立つ場合があります。

Elasticsearchには他にも、OOMからクラスターを防御する保護設定（最大バケットソフト制限）があります。この最大バケット集計設定により、バケット数が超過（バージョン7.0のデフォルトでは1万）した場合（複数の集計レイヤを実行するなど）、実行が停止され、検索リクエストは失敗となります。

さらに、高負荷となる可能性のあるクエリを特定するために回路遮断設定（indices.breaker.request.limit）を使用することができます。この設定では、まずは低いしきい値から開始してクエリを切り分け、徐々にしきい値を上げて特定のクエリに絞り込んでいくようにします。

スローログ

実行速度の遅いクエリは、Elasticsearchでスローログをオンにすることで特定することも可能です。スローログは具体的にシャードレベルで機能します。つまり、データノードのみが該当します。調整のみ/クライアントノードは、データ（インデックス/シャード）を保持していないため該当しません。

スローログは以下のような質問への回答に役立ちます。

  • クエリにはどれくらいの時間がかかりましたか？
  • クエリリクエストの本文の内容は何でしたか？

スローログ出力の例： 

[2019-02-11T16:47:39,882][TRACE][index.search.slowlog.query] [2g1yKIZ] [logstash-20190211][4] took[10.4s], took_millis[10459], total_hits[16160], types[], stats[],
search_type[QUERY_THEN_FETCH], total_shards[10], source[{"size":0,"query":{"bool":{"must":[{"range":{"timestamp":{"from":1549266459837,"to":1549871259837,"include_lower":true,
"include_upper":true,"format":"epoch_millis","boost":1.0}}}],"adjust_pure_negative":true,"boost":1.0}},"_source":{"includes":[],"excludes":[]},"stored_fields":"*","docvalue_fields":
[{"field":"timestamp","format":"date_time"},{"field":"utc_time","format":"date_time"}],"script_fields":{"hour_of_day":{"script":{"source":"doc['timestamp'].value.getHourOfDay()",
"lang":"painless"},"ignore_failure":false}},"aggregations":{"maxAgg":{"max":{"field":"bytes"}},"minAgg":{"min":{"field":"bytes"}}}}], id[]],

スローログのメッセージの詳細：

項目説明
[2019-02-11T16:47:39,882]クエリ日
[TRACE]ログレベル
[index.search.slowlog.query]検索スローログのクエリフェーズ
[2g1yKIZ]ノード名
[logstash-20190211]インデックス名
[4]実行されたクエリのシャード番号
took[10.4s]シャード[4]で実行された処理時間。注：スローログを確認するときには、異なるシャードの時間をすべて加算することはしないようにします。各シャードは並行して実行されている可能性があるためです。
took_millis[10459]実行時間（ミリ秒）
total_hits[16160]総ヒット数
search_type[QUERY_THEN_FETCH]検索タイプ
total_shards[10]インデックスの総シャード数
source[]実行されたクエリの本文

監査ログ

ゴールドまたはプラチナのサブスクリプションをご利用のお客様は、Elasticセキュリティ機能を利用することができるため、監査ログをオンにしてクエリのさらなる詳細を取得できます。（30日間のトライアルでElasticのセキュリティ機能のテストを開始できます）。 監査ログは以下のような質問への回答に役立ちます。

  • クエリはいつ発生しましたか？
  • 誰がクエリを実行しましたか？
  • クエリの内容は何ですか？

監査設定は、デフォルトでは項目数が多いため、調整する必要があります。

  1. セキュリティ監査ログを有効化： elasticsearch.ymlにxpack.security.audit.enabled: trueを設定します。
  2. セキュリティ監査出力でログまたはインデックスを有効化： elasticsearch.ymlにxpack.security.audit.outputs:[logfile, index]を設定します。

    注：
    • xpack.security.audit.outputs設定は、バージョン6.0～6.2および5.xのみが該当します。バージョン7.0ではこの設定は認識されません。xpack.security.audit.enabledがtrueに設定されていると、json出力がデフォルト（<clustername>_audit.json）となります。
    • トラブルシューティングを目的とした場合、インデックスではなくログファイルを選択することを推奨します。多項目の監査ログではクラスターパフォーマンスに不要な負荷がかかる可能性があり、意図していたサイズよりもセキュリティインデックスが大きくなる場合があります。
    • 監査モードは負荷が高くなるため、トラブルシューティングが終了した場合はオフにすることを検討してください。
  3. authentication_successとなったアクセスをイベントリストに含める： elasticsearch.ymlにxpack.security.audit.logfile.events.include: authentication_success を設定します。

    注：
    • この設定はデフォルトのイベントには含まれていません。これを設定することでデフォルト設定が上書きされます。
    • イベントをもう1つ追加する必要があります（置き換えるのではなく）。まず既存のデフォルトのイベントリストを記載し、そして、その最後のエントリーの後に上記の設定を追加してください。
    • 監査イベントのリクエスト本文を出力する： elasticsearch.ymlにxpack.security.audit.logfile.events.emit_request_body: true を設定します。

これらの設定により、ユーザーのクエリを以下のように監視できます。

  • ユーザー：louisong
  • クエリ時刻： 2019-05-01T19:26:53,554 (UTC)
  • クエリエンドポイント： _msearch（通常、Kibanaビジュアライゼーション/ダッシュボードからのクエリを意味します）
  • クエリ本文：下記ログの"request.body":から始まります。

    {"@timestamp":"2019-05-01T19:26:53,554", "node.id":"Z1z_64sIRcy4dW2eqyqzMw", "event.type":"rest", "event.action":"authentication_success", "user.name":"louisong", "origin.type":"rest", "origin.address":"127.0.0.1:51426", "realm":"default_native", "url.path":"/_msearch", "url.query":"rest_total_hits_as_int=true&ignore_throttled=true", "request.method":"POST", "request.body":"{\"index\":\"*\",\"ignore_unavailable\":true,\"preference\":1556709820160}\n{\"aggs\":{\"2\":{\"terms\":{\"field\":\"actions\",\"size\":5,\"order\":{\"_count\":\"desc\"},\"missing\":\"__missing__\"}}},\"size\":0,\"_source\":{\"excludes\":[]},\"stored_fields\":[\"*\"],\"script_fields\":{},\"docvalue_fields\":[{\"field\":\"access_token.user_token.expiration_time\",\"format\":\"date_time\"},{\"field\":\"canvas-workpad.@created\",\"format\":\"date_time\"},{\"field\":\"canvas-workpad.@timestamp\",\"format\":\"date_time\"},{\"field\":\"creation_time\",\"format\":\"date_time\"},{\"field\":\"expiration_time\",\"format\":\"date_time\"},{\"field\":\"maps-telemetry.timeCaptured\",\"format\":\"date_time\"},{\"field\":\"task.runAt\",\"format\":\"date_time\"},{\"field\":\"task.scheduledAt\",\"format\":\"date_time\"},{\"field\":\"updated_at\",\"format\":\"date_time\"},{\"field\":\"url.accessDate\",\"format\":\"date_time\"},{\"field\":\"url.createDate\",\"format\":\"date_time\"}],\"query\":{\"bool\":{\"must\":[{\"range\":{\"canvas-workpad.@timestamp\":{\"format\":\"strict_date_optional_time\",\"gte\":\"2019-05-01T11:11:53.498Z\",\"lte\":\"2019-05-01T11:26:53.498Z\"}}}],\"filter\":[{\"match_all\":{}},{\"match_all\":{}}],\"should\":[],\"must_not\":[]}},\"timeout\":\"30000ms\"}\n", "request.id":"qrktsPxyST2nVh29GG7tog"}

    まとめ

    このブログでは、スロークエリの一般的な原因と、それらに対処するための解決策について説明しました。また、継続的におよび時々発生するスロークエリを特定するさまざまな方法についても説明しました。一般的にスロークエリは、対処が必要なクラスターパフォーマンスの問題を示す兆候として捉えられています。

    Elasticsearchは、クエリ時間を改善できるように、また今後リリースするバージョンでさらに高速なクエリパフォーマンスを実現できるように、継続的に取り組んでいます。このブログがスロークエリへの対処に役立つことを願っています。ご質問がある場合は遠慮なく、Elasticsearchのディスカッションフォーラムに投稿してください。さらにディスカッションを展開できます。快適な検索エクスペリエンスをお楽しみください。