シナリオ:JaxがDatabase Query Performanceを使用して遅いデータベースクエリを特定する 🔗
サイト信頼性エンジニアであるJaxは、自社システムにおけるサービス遅延の問題の根本原因を特定することを担当しています。このセクションでは、Database Query Performanceを使用したワークフローに従って、システム内のサービス遅延とデータベースクエリのパフォーマンスとの関係を調べます。
異常な高レイテンシに気づく 🔗
Jaxはシステムパフォーマンスを監視しており、APMのランディングページで、order-processor
サービスに1.2分という異常な高レイテンシが発生していることに気が付きました:

Jaxは、レイテンシの値を選択して、このサービスとその依存関係のサービスマップビューに移動します。このパネルには、そのサービスの依存関係と比較したサービスの経時的なレイテンシのグラフが表示されます。Dependencies を選択すると、「依存関係」パネルが開き、order-processor
の依存サービスを詳しく見ることができます。「アウトバウンドの依存関係」までスクロールダウンして、mysql:mysql-prod-1
データベースのP90レイテンシも非常に高いことに気が付きます:

サービスマップで mysql:mysql-prod-1
データベースを選択すると、サイドバーにリクエスト数とレイテンシのサマリーチャートが表示されます。サイドバーの Database Query Performance パネルには、現在の時間範囲内で最も遅いSQLクエリのP90レイテンシが表示されます。最上位のクエリのP90レイテンシも1.4分であることに気が付きます:

データベースのインフラストラクチャをチェックする 🔗
Database Query Performanceを掘り下げる前に、Jaxは mysql:mysql-prod-1
データベースのインフラストラクチャに問題がないことを確認したいと考えます。「関連コンテンツ」機能を使用すると、MySQLホストをすぐに特定することができます。MySQLホストは、推定データベースをクリックすると「関連コンテンツバー」に表示されます。

ホストを選択すると、インフラストラクチャのメトリクスの表示が正常であるため、インフラストラクチャがレイテンシの原因ではないことが分かります。ホストの「関連コンテンツ」バーには、Database Query Performance、APM、Log Observerにリンクした各タイルがあります。

Database Query Performanceでクエリを分析する 🔗
Jaxはこのパネルを選択してDatabase Query Performanceを開きます。Database Query Performanceで表示されるデータには、フィルターバーで選択した mysql:mysql-prod-1
データベースが適用されます:

データベースピッカーを使って利用可能なSQLデータベースから選択することもできますが、今は mysql:mysql-prod-1
に焦点を当てる必要があります。
Top Queries の下にあるテーブルは、mysql:mysql-prod-1
に対する上位10個のクエリのリストを示しており、デフォルトでは合計時間の降順でソートされています。Jaxは、Sort ピッカーを使用して、P90レイテンシまたはリクエスト数/秒でソートすることができます。また、Compare to: ピッカーを使って、現在のデータを過去の時間範囲と比較することもできます。これにより、クエリテーブルの各行のチャートに、選択した時間範囲に基づく履歴線が重なり、問題が最近発生したものなのか、それとも長期にわたって発生しているものなのかを判断することができます。
サイドバーの Database Overview の下にあるチャートは、選択したデータベースのすべてのクエリのレイテンシ、リクエスト率、エラー率を要約したものであり、クエリのレイテンシの経時的な傾向を示しています。チャートはフィルターバーの現在の状態に基づいています。フィルターバーで時間範囲または環境ピッカーを変更すると、チャートに表示されるデータが変わります。
Jaxは最もレイテンシの高いクエリを選択し、詳細を表示します。Query Details パネルが開き、そのクエリの全文と、Requests & Errors および Latency のチャートが表示されます。このクエリのレイテンシが1.5分と高いことが分かります:

この証拠に基づいて、Jaxはこのクエリが高サービスレイテンシの原因である可能性があることを特定します。Jaxはコピーボタンを選択してステートメントのテキストをコピーし、チームのデータベース管理者に渡します。
トレース例の検索 🔗
高レイテンシが特定のクエリの多くの実行を伴う複数のスパンによるものか、遅いクエリの1回の実行を伴う単一の長いスパンによるものかを判断するために、Jaxはこの問題のあるクエリを含むトレースの例を探すことにしました。
Jaxはレイテンシチャート内をクリックし、X軸上のある時間を分離し、その時間からのトレース例のテーブルを読み込みます。読み込まれた各トレースに、スパンタグとして mysql:mysql-prod-1
が含まれていることを確認しました 。また、これらのトレースはすべて異常に長い時間がかかっています。おそらく、特定した遅いデータベースクエリが原因です。

トレースのテーブルから、Jaxは、テーブル内のトレースのうち、最も時間の長いトレースを選択し、[トレースビュー]ページとウォーターフォールチャートを開きます。また、データベース名を含むスパンタグを選択すると、問題のあるクエリを含むスパンを開いて、クエリをコンテキストで正確に確認することができます。
「トレースビュー」で、Jaxはスクロールして mysql:mysql-prod-1
データベースを参照するスパンを見つけます。このスパンは「トレースウォーターフォール」で推定サービスとして識別されています。このスパンを選択して開き、db.statement
スパンタグの下にあるクエリを表示して、Database Query Performanceビューで疑念を抱いたのと同じSQLステートメントであることを確認します。
Jaxは、当該のデータベースコールを含むスパンがトレース内の他のスパンよりも非常に長いことに気が付きます。これは、調査中の高レイテンシが1つの長いスパンに関連していることを示すものです。右サイドバーの「パフォーマンスサマリー」は、トレースの作業負荷の99.8%が「データベース」カテゴリーで占められていることも示しています:

Tip
データベースクエリが長く、スパン内で切り捨てられている場合は、ページ下部の 関連コンテンツ タイルを選択すると、Log Observerにピボットし、クエリ全体をログで表示することができます。
Jaxはこの情報を得て、当該のデータベースをサポートするDBAに連絡し、問題を引き起こしているクエリの正確なテキストを提供します。そして、この遅延の原因を調査し、サービスレイテンシのさらなる問題を防ぐためにデータベースコールを最適化するよう依頼します。
このレイテンシの問題が持つ広範囲の影響を引き続き調査するには、Tag Spotlightを使用して、どのデータベーススパンタグおよび値が最も高いレイテンシに関連しているかを特定し、どのビジネスワークフローがこの問題の影響を受けているかを確認することができます。Tag Spotlightを使用したトラブルシューティングのシナリオ例については、シナリオ:DeepuがTag Spotlightを使用してエラーの根本原因を見つける を参照してください。
さらに詳しく 🔗
Database Query Performanceの詳細については、以下のリンクを参照してください:
Database Query Performanceの概要については、Database Query Performanceの監視 を参照してください。
Database Query Performanceを有効化する方法は、Database Query Performanceを有効にする を参照してください。
「関連コンテンツ」の詳細は、Splunk Observability Cloudの関連コンテンツ を参照してください。
Database Query Performanceに関する問題のトラブルシューティングについては、Database Query Performanceのトラブルシューティング を参照してください。
Database Query Performanceに関する参考資料は、Database Query Performanceの参考情報 を参照してください。