ユーザーエクスペリエンス向上のためのElasticsearchスロークエリのトラブルシューティング

Elastic Cloud(Elasticsearch Service/ESS)ユーザーへの重要な注記:現在、この記事で言及されているコンテンツはElastic Cloudでは利用できません。しかし、私たちは貴重なユーザーの皆様の声を集めたいと考えています。この特徴の利用に関心がある場合は、Elastic Supportまでご連絡ください。

Elasticsearch®をご利用のすべての方にとって、検索エンジンとしてクエリを特定し、トラブルシューティングを行うことは習得すべき重要なスキルです。Eコマース、オブザーバビリティ、ワークプレイス向けの検索ソリューションのいずれであっても、Elasticsearchの動作が遅いと、ユーザーエクスペリエンスに悪影響を及ぼします。

Elasticsearchの低速なクエリを特定するには、スローログを使用できます。これは、特定のしきい値で実行されたクエリをキャプチャするものです。スローログのしきい値を正しく設定すること自体が課題となります。たとえば、高負荷時に500ミリ秒かかるクエリは許容範囲かもしれませんが、低負荷時に同じクエリを実行すると許容できない場合があります。スローログはこれらを区別せず、500ミリ秒を超えるすべてのクエリをログに記録します。スローログは非常に優れた機能であり、しきい値に応じてさまざまな粒度でキャプチャできます。一方、トレーシングではすべてのクエリを確認し、しきい値内に収まっているクエリがいくつあるかを特定できます。

アプリケーションパフォーマンス監視(APM)は、もはやアプリケーション単体に限定されるものではありません。Elasticsearchのインストルメンテーションを使用することで、Elasticsearchをアプリケーションスタックへの依存関係としてではなく、本格的なサービスとして追加できるようになりました。これにより、スローログで得られる情報よりも詳細なパフォーマンスの状況を把握できます。

以下の例では、データコーパスとしてOpenWebTextを使用します。これには約40GBの純粋なテキストと約800万件の個別ドキュメントが含まれており、32GB RAMを搭載したM1 Max Macbook上でローカルに実行されます。

開始する

Elasticsearchでのトレーシングの有効化は、静的設定(elasticsearch.ymlで構成)と、実行時にPUT _cluster/settingsコマンドを使用して切り替え可能な動的設定によって行われます。この動的設定の1つがサンプリングレートです。サンプリングレートなどの一部の設定は、実行時に切り替えることができます。elasticsearch.ymlでは、以下を設定します。

バージョン 9.x で有効

telemetry.agent.enabled: true
telemetry.agent.server_url: "url of the APM server"

バージョン7.xおよび8.xで有効

tracing.apm.enabled: true
tracing.apm.agent.server_url: "url of the APM server"

シークレットトークン(またはAPIキー)は、Elasticsearchキーストア内に存在する必要があります。キーストアツールは、<your elasticsearch install directory>/bin/elasticsearch-keystoreにあります。バージョン7.xおよび8.xでは、次のコマンドを使用してください。elasticsearch-keystore add tracing.apm.secret_tokenまたはtracing.apm.api_keyバージョン9.xでは、代わりにtelemetry.secret_tokenまたはtelemetry.api_keyを使用してください。その後、Elasticsearchを再起動する必要があります。トレーシングの詳細については、トレーシングドキュメントをご覧ください。

APMが有効になると、KibanaのAPMビューでElasticsearchがさまざまなREST APIエンドポイントを自動的にキャプチャしていることを確認できます。ここでは主にPOST /{index}/_検索するの呼び出しに焦点を当て、そこから何が得られるかを見ていきます。

Elasticsearchのスクリーンショット

クエリをGET /{index}/_searchボックスで直接調べることで、以下のウォーターフォール内訳を確認できます。これには、Elasticsearchが内部で何を行っているかについてのより深い洞察を提供する内部スパンが含まれています。また、この検索の全体的な所要時間(86ミリ秒)も確認できます。

トレースのサンプル

クエリに付随するメタデータには、HTTPヘッダー、ユーザーエージェント、Elasticsearch Nodeの場所(クラウドプロバイダーのメタデータ、ホスト名、コンテナ情報)、一部のシステム情報、URLの詳細に関する広範な情報が含まれています。基本的なトランザクション情報を使用して、平均トランザクション時間をプロットするLensチャートを作成し、上昇傾向か下降傾向かを確認できます。

当社の検索するアプリケーション

もうスローログを使用する必要がないのは素晴らしいことです!トランザクションの所要時間を判断し、任意のしきい値以下で回答された検索する回数を確認できます。しかし、1つ欠点があります。Elasticsearchは送信されたクエリをキャプチャしないため、クエリに時間がかかったことはわかっても、そのクエリが何であったのかはわかりません。

サンプル検索アプリをインストルメント化してみましょう。ここでは、2つのルートを持つシンプルなFlaskアプリを使用します。search_singlesearch_phraseは、Elasticsearchにおけるmatchクエリとmatch_phraseクエリをそれぞれ表します。例えば、次のようなクエリを使用できます。

{
  "query": {
    "match": {
      "content": "support"
    }
  }
}
And
{
  "query": {
    "match_phrase": {
      "content": "support protest"
    }
  }
}

以下のFlaskコードは search_single ルートを実装しています。 search_phrase も非常によく似ていますが、 match の代わりに match_phrase を使用する点が異なります。

@app.route("/search_single", methods=["GET"])
def search_single():
    query = request.args.get("q", "")
    if not query.strip():
        return jsonify({"error": "No search query provided"}), 400
    try:
        result = es.search(
            index=ES_INDEX, query={"match": {"content": query}}
        )

        hits = result["hits"]["hits"]
        response = []
        for hit in hits:
            response.append(
                {
                    "score": hit["_score"],
                    "content": hit["_source"]["content"],
                }
            )
        
        return jsonify(response)

準備が整いましたので、curl -XGET "http://localhost:5000/search_single?q='microphone'" を呼び出して microphone という用語を検索します。

私たちは主にObserveするために検索アプリケーションにAPMを追加していますが、APMエージェントは送信リクエストをキャプチャし、メタデータ情報で強化します。今回のケースでは、span.db.statementにElasticsearchクエリが含まれています。そして以下のケースでは、誰かがwindowを検索しました。

スパン詳細

すべてを組み合わせる

Flaskサービスでクエリサイズを5,000に設定しました。つまり、Elasticsearchは1回のJSON対応で最大5,000件の一致ドキュメントを返します。これは大きな数値であり、その大半の時間はディスクからのドキュメント取得に費やされます。上位100件のドキュメントに変更した後、比較を行うことでダッシュボードで何が起きたかを迅速に特定できます。

APMビューでトランザクションを確認し、クリティカルパスに対してlabs機能を有効にするとオーバーレイが作成され、アプリケーションの処理時間がどこで費やされているかが表示されます。

APM タイムラインビュー

その後、以下のフィールドを使用してダッシュボードを作成しました:transaction.duration.uses_query_tooktransaction.name。一般的なKQLフィルターには、service.nameprocessor.event: transactiontransaction.name: POST /{index}/_検索するが含まれます。

ヒント: [Data view] 管理に移動し、APMデータストリームを含むData viewを選択して、 transaction.duration.us フィールドを選択し、フォーマットを duration に変更します。これにより、マイクロ秒単位ではなく、人間が読み取れる形式で自動的に表示されるようになります。

Lensのアノテーション特徴を活用することで、中央のLensから、ドキュメント数を100に変更したことで平均検索するトランザクションが大幅に減少したことがわかります。それだけでなく、右上のレコード総数にも注目してください。検索する速度が速くなったため、スループットも向上しました!私はヒストグラムがとても気に入っているので、上段の中央に作成しました。X軸にトランザクション期間、Y軸にレコード数を設定しています。さらにAPMはメトリックを提供するため、CPU使用率(%)をいつでも特定できるほか、JVMヒープ、非ヒープ使用量、スレッドカウントなどの有用な情報も確認できます。

グラフとチャート

まとめ

このブログ記事では、Elasticsearchをインストルメンテーションされたアプリケーションとして活用することの重要性と、ボトルネックをより簡単に特定する方法について説明しました。また、トランザクション時間を異常検知のメトリックとして使用したり、アプリケーションのA/Bテストを行ったりすることも可能です。Elasticsearchが高速化しているかどうかを疑問に思う必要はもうありません。その問いに答えるためのデータが手元にあるからです。さらに、ユーザーエージェントからクエリに至るまで収集されたすべてのメタデータが、トラブルシューティングに役立ちます。

ダッシュボードとData viewはこちらからインポートできます。

警告

Elasticsearch内のトランザクションの期間に問題があります。これは修正され、次回の8.9.1リリースで提供される予定です。それまでの間、トランザクションは誤ったクロックを使用するため、全体の期間に影響が生じます。

本記事に記述されているあらゆる機能ないし性能のリリースおよびタイミングは、Elasticの単独裁量に委ねられます。現時点で提供されていないあらゆる機能ないし性能は、すみやかに提供されない可能性、または一切の提供が行われない可能性があります。