🐱 うさねこ教室 Java・OpenAPI・OpenTelemetry の教室

async-profiler で実行スタックを測る

🐱 この章の目次

JFR と役割を分ける

async-profiler は、HotSpot JVMを対象にJava、ネイティブコード、カーネルを含むスタックを収集できるサンプリングプロファイラーです。 CPUだけでなく、wall-clock、オブジェクト割り当て、ロック競合などを別のイベントとして記録できます。

JFRはJVM内外の多数のイベントを時系列で関連づける用途に向き、async-profilerは実行スタックの分布を詳しく調べる用途に向きます。 どちらか一方で置き換えるのではなく、調べたい問いで選びます。

CPUを使っているコードを探す

既定のCPUプロファイルを30秒間取得し、対話的なフレームグラフへ保存します。

asprof -d 30 -f cpu.html <pid>

幅は、そのスタックがサンプルに現れた割合です。 実時間の長さや呼び出し回数を直接表すものではありません。 CPU使用率が低い時間帯のCPUプロファイルだけを見ても、I/O待ちやロック待ちによる遅延は分かりません。

待機、割り当て、ロックを分ける

Wall-clockプロファイルは、CPU上で実行中の時間だけでなく、スリープやI/O待ちを含む経過時間でスレッドをサンプリングします。

asprof -e wall -t -i 50ms -d 30 -f wall.html <pid>

オブジェクト割り当てとロック競合は、別のイベントとして記録します。

asprof -e alloc -d 30 -f alloc.html <pid>
asprof -e lock -d 30 -f lock.html <pid>

-t を付けるとスレッド別に表示できます。 リクエスト処理、バックグラウンド処理、GCスレッドを分けて読みたいときに使います。

割り当てプロファイルは「現在もヒープに残っているオブジェクト」ではなく、観測期間中にオブジェクトを割り当てたスタックを示します。 メモリリークの調査では、GC後も残るヒープ量、クラスヒストグラム、必要に応じてヒープダンプも組み合わせます。

本番環境では対象と時間を絞る

サンプリング方式であっても負荷がゼロになるわけではありません。 サンプリング間隔を短くすると取得回数が増え、割り当てやロックの記録量はワークロードにも左右されます。 権限やカーネル設定によっては、Linuxの perf_events や他プロセスへのアタッチが制限されます。

最初は次の条件を固定して短時間で取得します。

  • 異常が再現する時刻とエンドポイント
  • イベント種別とサンプリング間隔
  • 取得時間と対象PID
  • 取得前後のCPU、メモリ、レイテンシ

--all は複数のイベントをまとめて継続取得する便利な指定ですが、async-profilerの公式文書は本番での連続利用を推奨していません。 必要なイベントを選び、ステージング環境で負荷を確認してから適用します。

参考資料