Docs » Database Query Performanceの監視 » シナリオ:JaxがDatabase Query Performanceを使用して遅いデータベースクエリを特定する

シナリオ:JaxがDatabase Query Performanceを使用して遅いデータベースクエリを特定する 🔗

サイト信頼性エンジニアであるJaxは、自社システムにおけるサービス遅延の問題の根本原因を特定することを担当しています。このセクションでは、Database Query Performanceを使用したワークフローに従って、システム内のサービス遅延とデータベースクエリのパフォーマンスとの関係を調べます。

異常な高レイテンシに気づく 🔗

Jaxはシステムパフォーマンスを監視しており、APMのランディングページで、order-processor サービスに1.2分という異常な高レイテンシが発生していることに気が付きました:

このスクリーンショットは、APMのランディングページの「レイテンシ別の上位サービス」セクションのクローズアップで、``order-processor`` のレイテンシが1.2分になっています。

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

このスクリーンショットは、サービスマップで見た ``order-processor`` サービスとその依存関係のクローズアップです。「依存関係」パネルでは、高レイテンシが ``mysql:mysql-prod-1`` データベースから発生していることが分かります。

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

このスクリーンショットは、Database Query Performanceのパネルを示しており、選択したデータベースで最も遅いクエリの上位5つのクエリテキストとP90レイテンシのテーブルが表示されています。

データベースのインフラストラクチャをチェックする 🔗

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

mysql-prod-1データベースのMySQLホストが「関連コンテンツ」バーに表示されます。

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

mysql-prod-1データベースのMySQLホストが「関連コンテンツ」バーに表示されます。

Database Query Performanceでクエリを分析する 🔗

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

このスクリーンショットは、Splunk APMのDatabase Query Performanceビューで、選択したデータベースのデータが表示されています。このページには、合計時間別で上位10件のクエリのテーブルが表示されており、サイドバーには選択したデータベースのリクエスト数とエラー数、レイテンシを経時的に示すグラフが表示されています。

データベースピッカーを使って利用可能なSQLデータベースから選択することもできますが、今は mysql:mysql-prod-1 に焦点を当てる必要があります。

The table under Top Queries shows a list of the top 10 queries to mysql:mysql-prod-1, sorted by default in descending order by total time. Jax can use the Sort picker to sort by P90 latency or requests per second instead. They can also use the Compare to: picker to compare the current data against a past time range. This overlays a historical line based on the selected time range on the chart in each row of the query table, enabling Jax to determine whether the problem is recent, or has been occurring over time.

サイドバーの Database Overview の下にあるチャートは、選択したデータベースのすべてのクエリのレイテンシ、リクエスト率、エラー率を要約したものであり、クエリのレイテンシの経時的な傾向を示しています。チャートはフィルターバーの現在の状態に基づいています。フィルターバーで時間範囲または環境ピッカーを変更すると、チャートに表示されるデータが変わります。

Jaxは最もレイテンシの高いクエリを選択し、詳細を表示します。Query Details パネルが開き、そのクエリの全文と、Requests & Errors および Latency のチャートが表示されます。このクエリのレイテンシが1.5分と高いことが分かります:

このスクリーンショットは、Database Query Performanceのサイドバーを示しており、上位クエリの全文と、このクエリ固有のレイテンシおよびリクエスト数とエラー数のチャートが表示されています。

この証拠に基づいて、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%が「データベース」カテゴリーで占められていることも示しています:

このスクリーンショットは、データベースのレイテンシ問題に関連する特定のトレースの「トレースビュー」を示しています。トレース内の特定のスパンが展開され、``db.statement`` のスパンタグが強調表示されており、このスパンがDatabase Query PerformanceビューでJaxが特定したのと同じデータベースクエリを含んでいることが分かります。「パフォーマンスサマリー」とこのデータベースの名前も強調表示されています。

Tip

データベースクエリが長く、スパン内で切り捨てられている場合は、ページ下部の 関連コンテンツ タイルを選択すると、Log Observerにピボットし、クエリ全体をログで表示することができます。

Jaxはこの情報を得て、当該のデータベースをサポートするDBAに連絡し、問題を引き起こしているクエリの正確なテキストを提供します。そして、この遅延の原因を調査し、サービスレイテンシのさらなる問題を防ぐためにデータベースコールを最適化するよう依頼します。

このレイテンシの問題が持つ広範囲の影響を引き続き調査するには、Tag Spotlightを使用して、どのデータベーススパンタグおよび値が最も高いレイテンシに関連しているかを特定し、どのビジネスワークフローがこの問題の影響を受けているかを確認することができます。Tag Spotlightを使用したトラブルシューティングのシナリオ例については、シナリオ:DeepuがTag Spotlightを使用してエラーの根本原因を見つける を参照してください。

さらに詳しく 🔗

Database Query Performanceの詳細については、以下のリンクを参照してください:

このページは 2023年06月08日 に最終更新されました。