遅いトレースやエンドポイントを調査する

本番環境においてアプリケーションのパフォーマンスに問題がある場合、分散型トレーシングとプロファイリングによるコードスタックトレースのベンチマークを統合することで、パフォーマンスのボトルネックを特定する強力な方法となります。APM 分散型トレーシングと Continuous Profiler の両方が有効になっているアプリケーションプロセスは、自動的にリンクされます。

Code Hotspots タブでスパン情報からプロファイリングデータに直接移動し、パフォーマンス問題に関連する特定のコード行を見つけることができます。同様に、低速でリソースを消費するエンドポイントも、プロファイリング UI で直接デバッグできます。

遅いトレースのコードのホットスポットを特定する

前提条件

Java サービスのプロファイリングを有効にすると、Code Hotspots の識別がデフォルトで有効化されます。手動でインスツルメントされたコードの場合、Continuous Profiler はスパンのスコープをアクティブにする必要があります。

final Span span = tracer.buildSpan("ServicehandlerSpan").start();
try (final Scope scope = tracer.activateSpan(span)) { // mandatory for Datadog continuous profiler to link with span
    // worker thread impl
  } finally {
    // Step 3: Finish Span when work is complete
    span.finish();
  }
Java Flight Recorder (JFR) の代わりに Datadog プロファイラーを使用することを強くお勧めします。

Python サービスのプロファイリングを起動すると、コードのホットスポット識別がデフォルトで有効化されます。

dd-trace-py バージョン 0.44.0+ が必要です。

Ruby サービスのプロファイリングを起動すると、コードのホットスポット識別がデフォルトで有効化されます。

新しいタイムライン機能 (ベータ版) を有効にするには

  • dd-trace-rb 1.15 以上にアップグレードする
  • DD_PROFILING_EXPERIMENTAL_TIMELINE_ENABLED=true に設定する

Linux と macOS で Node.js サービスのプロファイリングを有効にすると、Code Hotspots の識別がデフォルトで有効になります。Windows ではこの機能は利用できません。

dd-trace-js のバージョン 5.0.0 以降、4.24.0 以降または 3.45.0 以降が必要です。

タイムライン機能 (ベータ版) を有効にするには

  • dd-trace-js 5.1.0 以降、4.25.0 以降または 3.46.0 以降にアップグレードします
  • DD_PROFILING_TIMELINE_ENABLED=1 を設定します

Go サービスのプロファイリングを起動すると、コードのホットスポット識別がデフォルトで有効化されます。

新しいタイムライン機能 (ベータ版) を有効にするには、以下の環境変数を設定してください。

os.Setenv("DD_PROFILING_EXECUTION_TRACE_ENABLED", "true")
os.Setenv("DD_PROFILING_EXECUTION_TRACE_PERIOD", "15m")

これらの変数を設定すると、実行トレースデータが 15 分ごとに最大 1 分間 (または 5 MiB) 記録されます。

このデータは、

  • 検索クエリに go_execution_traced:yes を追加して Profile List で表示できます。プロファイルをクリックすると Profile Timeline が表示されます。さらに深く見るには、プロファイルをダウンロードし、go tool trace または gotraceui を使用して、含まれている go.trace ファイルを表示します。
  • 検索クエリに @go_execution_traced:yes (@ に注意) を追加してトレースエクスプローラーで表示できます。スパンをクリックし、Code Hotspots タブを選択してスパンタイムラインを表示します。

実行トレースを記録している間、アプリケーションがガベージコレクションのように CPU 使用率の増加を観測する可能性があります。ほとんどのアプリケーションでは大きな影響はないはずですが、Go 1.21 にはこのオーバーヘッドをなくすためのパッチが含まれています。

この機能を利用するには、dd-trace-go のバージョン 1.37.0 以上 (タイムラインベータの場合は 1.52.0 以上) が必要で、Go のバージョン 1.18 以上 (タイムラインベータの場合は 1.21 以上) で最適に動作します。

.NET サービスのプロファイリングを起動すると、コードのホットスポット識別がデフォルトで有効化されます。

この機能を使用するには dd-trace-dotnet のバージョン 2.30.0 以上が必要です。

PHP サービスのプロファイリングを起動すると、コードのホットスポット識別がデフォルトで有効化されます。

dd-trace-php のバージョン 0.71 以上が必要です。

タイムライン機能 (ベータ版) を有効にするには

  • dd-trace-php をバージョン 0.89 以上にアップグレードしてください。
  • 環境変数 DD_PROFILING_EXPERIMENTAL_TIMELINE_ENABLED=1 または INI 設定 datadog.profiling.experimental_timeline_enabled=1 を設定します

スパン実行の内訳

各トレースのビューから、選択したスパンの範囲内のプロファイリングデータが Code Hotspots タブに表示されます。

左側の値は、選択されたスパンの間にそのメソッド呼び出しに費やされた時間を表します。ランタイムと言語によって、カテゴリーは異なります。

  • CPU は、CPU タスクを実行するのに費やした時間を示します。
  • Synchronization は、モニター待ちの時間、スレッドがスリープしている時間、パークしている時間などを表示します。
  • VM operations は、VM オペレーション (例えば、ガベージコレクション、コンパイル、セーフポイント、ヒープダンプ) の待ち時間を示します。
  • ファイル I/O は、ディスクの読み取り/書き込み動作の実行待ちに費やした時間を示します。
  • ソケット I/O は、ネットワークの読み取り/書き込み動作の実行待ちに費やした時間を示します。
  • Monitor enter は、スレッドがロックでブロックされている時間を表示します。
  • Uncategorized は、前述のカテゴリーに分類できないスパンの実行に要した時間を表示します。
  • CPU は、CPU タスクを実行するのに費やした時間を示します。
  • Lock Wait は、スレッドがロックでブロックされている時間を表示します。
  • Uncategorized は、前述のカテゴリーに分類できないスパンの実行に要した時間を表示します。
  • CPU は、CPU タスクを実行するのに費やした時間を示します。
  • Uncategorized は、CPU 実行以外のスパン実行に要した時間を表示します。
  • CPU は、CPU タスクの実行にかかった時間を示します。Node.js experimental CPU プロファイラーで収集されたプロファイルにのみ表示されます。
  • Uncategorized は、CPU 実行以外のスパン実行に要した時間を表示します。
  • CPU は、CPU タスクを実行するのに費やした時間を示します。
  • Off-CPU は、CPU 実行以外のスパン実行に要した時間を表示します。
  • CPU は、CPU タスクを実行するのに費やした時間を示します。
  • Lock Wait は、スレッドがロックでブロックされている時間を表示します。
  • Uncategorized は、前述のカテゴリーに分類できないスパンの実行に要した時間を表示します。
  • CPU は、CPU タスクを実行するのに費やした時間を示します。
  • Uncategorized は、CPU 実行以外のスパン実行に要した時間を表示します。

プラスアイコン + をクリックすると、そのメソッドのスタックトレースが逆順に展開されます。値の上にカーソルを置くと、カテゴリー別に説明される時間の割合が表示されます。

スパン実行のタイムラインビュー

Timeline ビューは、スパンの期間における時間ベースのパターンと作業分布を表示します。

スパンの Timeline ビューでは、次のことが可能です。

  • 時間のかかるメソッドを分離する。
  • スレッド間の複雑な相互作用を整理する。
  • リクエストに影響を与えたランタイムアクティビティを明らかにする。

ランタイムや言語によって、レーンは異なります。

各レーンはスレッドを表しています。共通のプールからのスレッドはまとめてグループ化されています。プールを展開することで、各スレッドの詳細を確認できます。

上のレーンは、余分なレイテンシーを追加するかもしれないランタイムアクティビティです。これらはリクエスト自体に関係ないこともあります。

タイムラインを使って p95 リクエストの遅延やタイムアウトをデバッグする方法については、ブログ記事 プロファイリングでリクエストの遅延を理解するを参照してください。

各レーンは goroutine を表します。これには、選択されたスパンを開始した goroutine と、その goroutine が作成した goroutine とその子孫が含まれます。同じ go ステートメントで作成された goroutine はグループ化されます。グループを展開して各 goroutine の詳細を見ることができます。

上のレーンは、余分なレイテンシーを追加するかもしれないランタイムアクティビティです。これらはリクエスト自体に関係ないこともあります。

タイムラインを使って p95 リクエストの遅延やタイムアウトをデバッグする方法については、ブログ記事 Datadog のプロファイリングタイムラインによる Go リクエストレイテンシーのデバッグを参照してください。

Ruby でこの機能を有効にする方法については、前提条件を参照してください。

各レーンはスレッドを表します。共通のプールからのスレッドは一緒にグループ化されます。プールを展開すると、各スレッドの詳細を表示できます。

各レーンはスレッドを表します。共通のプールからのスレッドは一緒にグループ化されます。プールを展開すると、各スレッドの詳細を表示できます。

上部のレーンは、余分なレイテンシーを追加する可能性のあるランタイムアクティビティを表しています。これらはリクエスト自体に関係ないこともあります。

Node.js でこの機能を有効にする方法については、前提条件を参照してください。

JavaScript のスレッドには 1 つのレーンがあります。

上のレーンはガベージコレクターのランタイムアクティビティで、リクエストに余分なレイテンシーを追加する可能性があります。

PHP でこの機能を有効にする方法については、前提条件を参照してください。

PHPのスレッドには 1 つのレーンがあります。このスレッドで実行されるファイバーは、グループ化された別々のレーンで表されます。

上部のレーンは、ファイルのコンパイルやガベージコレクションによりリクエストのレイテンシーが増加する可能性のあるランタイムアクティビティを表しています。

プロファイルをトレースから閲覧する

内訳のデータタイプごとに、View In Full Page をクリックすると、同じデータが新しいページで表示されます。そこから、フレームグラフに視覚化を変更することができます。 Focus On セレクタをクリックすると、データの範囲を定義することができます。

  • Span & Children は、選択したスパンと同じサービス内のすべての子孫スパンにプロファイリングデータをスコープします。
  • Span only は、プロファイリングデータをあらかじめ選択されたスパンにのみスコープします。
  • Span time period は、スパンがアクティブだった期間中のすべてのスレッドにプロファイリングデータをスコープします。
  • Full profile は、データのスコープを以前に選択されたスパンを実行したサービスプロセス全体の 60 秒に設定します。

コードのパフォーマンスを API エンドポイントごとに分解する

前提条件

Java サービスのプロファイリングを起動すると、エンドポイントプロファイリングがデフォルトで有効化されます。

Datadog プロファイラーの使用が必要です。JFR はサポートされていません。

Python サービスのプロファイリングを起動すると、エンドポイントプロファイリングがデフォルトで有効化されます。

dd-trace-py のバージョン 0.54.0 以上が必要です。

Go サービスのプロファイリングを起動すると、エンドポイントプロファイリングがデフォルトで有効化されます。

dd-trace-go バージョン 1.37.0 以上が必要で、Go バージョン 1.18 以降で最適に動作します。

Ruby サービスのプロファイリングを起動すると、エンドポイントプロファイリングがデフォルトで有効化されます。

dd-trace-rb のバージョン 0.54.0 以上が必要です。

Linux と macOS で Node.js サービスのプロファイリングを有効にすると、エンドポイントプロファイリングがデフォルトで有効になります。Windows ではこの機能は利用できません。

dd-trace-js のバージョン 5.0.0 以降、4.24.0 以降または 3.45.0 以降が必要です。

.NET サービスのプロファイリングを起動すると、エンドポイントプロファイリングがデフォルトで有効化されます。

dd-trace-dotnet のバージョン 2.15.0 以上が必要です。

PHP サービスのプロファイリングを起動すると、エンドポイントプロファイリングがデフォルトで有効化されます。

dd-trace-php のバージョン 0.79.0 以上が必要です。

エンドポイントプロファイリング

エンドポイントプロファイリングは、Web サービスの任意のエンドポイントでフレームグラフをスコープし、遅いエンドポイント、レイテンシーが多いエンドポイント、エンドユーザーエクスペリエンスが悪い原因となっているエンドポイントを見つけることができます。これらのエンドポイントは、デバッグが難しく、なぜ遅いのかを理解するのが困難な場合があります。遅い原因は、エンドポイントが多くの CPU サイクルを消費するなど、意図しない大量のリソースを消費している可能性があります。

エンドポイントプロファイリングを利用すると、以下のことが可能になります。

  • エンドポイント全体のレスポンスタイムを遅くしているボトルネックとなるメソッドを特定する。
  • CPU、メモリ、例外などの貴重なリソースを消費する上位のエンドポイントを切り分ける。これは、一般的にパフォーマンスを向上させるためにサービスを最適化しようとしている場合に特に役立ちます。
  • サードパーティのコードやランタイムライブラリが、エンドポイントの速度低下やリソース消費の重さの原因になっているかどうかを把握する。

最もリソースを消費しているエンドポイントを追跡する

CPU やウォールタイムなどの貴重なリソースを消費している上位のエンドポイントを追跡することは価値があります。このリストは、エンドポイントが回帰していないか、あるいは新たに導入したエンドポイントが大幅にリソースを消費してサービス全体の速度を低下させていないかどうかを確認するのに役立ちます。

次のイメージは、GET /store_history がこのサービスの CPU の 20% を消費して定期的に影響を与えていることを示しています。

上位のエンドポイントの消費リソースのグラフ化

リクエストごとの平均リソース消費量の追跡

Per endpoint call を選択すると、トラフィックが時間の経過とともに変化しても、動作の変化を確認できます。これは、プログレッシブロールアウトのサニティチェックや日々のトラフィックパターンの分析に役立ちます。

次のビデオは、/GET train のリクエストあたりの CPU が 2 倍になったことを示しています。

その他の参考資料