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

JFR と async-profiler を同じ記録で読む

🐱 この章の目次

一つのJFRファイルへ記録する

async-profilerは、プロファイルをJFR形式で出力できます。 複数のプロファイリングイベントを同時に取得する場合も、出力形式にはJFRを使います。

asprof -e cpu,alloc,lock -d 30 -f profile.jfr <pid>

このファイルはJMCで開けます。 CPUサンプル、割り当て、ロック競合を同じ時間軸へ並べると、CPUを使うコードと、そのコードが生む割り当てや競合を関連づけられます。

JDKのJFRイベントも同期して記録する

--jfrsync は、async-profilerの開始と終了に合わせてJDK側のFlight Recordingを開始します。 次の例は、async-profilerのCPUサンプルと、JDKの profile 設定によるGC、JITコンパイル、I/Oなどのイベントを一つのファイルへ保存します。

asprof -e cpu --jfrsync profile -d 60 -f combined.jfr <pid>

JMCでは、次の順で時間範囲を狭めます。

  1. CPU負荷やレイテンシが変化した区間を選ぶ。
  2. GC停止、JITコンパイル、ファイルI/O、ソケットI/Oの増減を確認する。
  3. 同じ区間のCPUサンプルで、幅の広い実行スタックを確認する。
  4. 割り当てやロックが疑わしい場合は、対象イベントを選んで再度短く記録する。

最初からすべてのイベントを高頻度で記録する必要はありません。 JFRの継続記録で異常の種類と時間を絞り、async-profilerの短い記録でスタックを詳しく取る二段階の方が、記録量と負荷を管理しやすくなります。

記録ファイルを共有する前の確認

JFRにはクラス名、メソッド名、スレッド名、ファイルパス、コマンドライン、環境に由来する文字列が含まれることがあります。 外部へ共有する前に内容と共有範囲を確認します。

JDK 21の jfr scrub は、イベント、カテゴリ、スレッドを含めるまたは除外した別ファイルを作れます。 ただし、機械的に一部を除外すれば機密情報がすべて消えるとは限りません。

jfr scrub \
  --exclude-events jdk.InitialEnvironmentVariable,jdk.SystemProperty \
  combined.jfr combined-scrubbed.jfr

除外するイベント名は、実際の記録に対して jfr metadata combined.jfrjfr summary combined.jfr で確認します。

演習

  1. JFRを default 設定で継続記録する。
  2. CPU負荷を発生させ、JFR.dump で直近の記録を保存する。
  3. 同じ負荷に対してasync-profilerのCPU記録を30秒取得する。
  4. JMCでJFRイベントとホットなスタックの時刻を比較する。
  5. 記録条件と、診断によるCPUおよびレイテンシの変化を作業記録へ残す。

参考資料