Java Flight Recorder (JFR) のはじめかた


JFR とは

Java Flight Recorder（JFR）とは、実行中のJavaアプリケーションに関する診断情報やプロファイリングデータを収集するための、JVM に組み込まれたイベント記録ツールです。

その名前の通り、航空機に搭載されている「フライトデータレコーダー（ブラックボックス）」に似た役割を果たします。 つまり、システムの正常な動作時から問題発生時まで、常にJVMやアプリケーションの内部で何が起こっているかを詳細に記録し続け、障害発生時の原因究明やパフォーマンスのボトルネック特定に効果を発揮します。

以前は商用機能でしたが、OpenJDK 11以降でオープンソース化されました。

JFR はデフォルト設定でパフォーマンスへの影響は1%未満と言われており、問題発生時に備えて有効化しておくことが推奨されます。


JFR と JMC(JDK Mission Control）

JFR は収集されたデータを .jfr というバイナリファイルに出力します。

この .jfr ファイルを人間が分かりやすい形で可視化し、分析するためのツールが JDK Mission Control(JMC) です。

JFR と JMC はセットで利用するのが一般的で、JMC を使うことで、収集された膨大なデータをグラフや表で直感的に分析し、問題の根本原因を効率的に突き止めることができます。

JMC のリポジトリは https://github.com/openjdk/jmc で、実行ファイルは Eclipse Mission Control などからダウンロードできます。

Brew の場合は以下でインストールすることもできます。

brew install --cask jdk-mission-control


JFR の有効化

JFR を有効化するには、JVM の起動オプションで -XX:StartFlightRecording を指定します。-XX:FlightRecorderOptions にてJFRフレームワークのオプション指定をすることができます。

JVM の起動オプションで指定する他、jcmd から JFR.start とすることで有効化することもできますし、JMC から操作することもできます。

-XX:StartFlightRecording は JVM 起動オプションとして以下のように指定します。

java -XX:StartFlightRecording=name=myApp,maxsize=500M <myApp>

これにより JFR によるイベントの記録が開始されます。

イベントの記録は、JVM 内のバッファメモリに蓄積され(スレッドローカルバッファ→グローバルバッファ)、溢れたものがディスクに吐き出されます。 この吐き出し先のディスク領域が「リポジトリ」と呼ばれ、デフォルトではシステムの一時ディレクトリが利用されます。

リポジトリには、-XX:FlightRecorderOptions の maxchunksize=size で指定したサイズ(デフォルト12M)で分割された .jfr ファイルが溜まっていきます(maxsize を超える場合は古いものが消えていく)。 このファイルを JMC で見ることもできますが、JFR 的にはあくまでも一時ファイルの扱いなので、java を終了したタイミングで消えてしまいます(後述の preserve-repository 設定で残すこともできます)。

ですので、以下のコマンドで .jfr ファイルのダンプを取得する必要があります。

jcmd <pid> JFR.dump filename=myrecording.jfr

または、-XX:StartFlightRecording で dumponexit=true としておくと、java 終了時にダンプファイルを自動で生成するようにすることもできます。ただし、プロセスを強制終了した場合はダンプファイルの生成は行われません(Ctrl+Cなどで終了した場合はダンプファイルが生成されます)。終了時のダンプファイルが生成されなかった場合は、リポジトリにチャンクファイルが残るので、こちらのファイルを解析することになります。

ファイル名の指定も合わせると、以下のような起動オプションにすることができます。

java -XX:StartFlightRecording=name=myApp,maxsize=500M,dumponexit=true,filename=logs/myrecording_%p_%t.jfr <myApp>

ファイル名の %p はプロセスID、%t は現在日時に展開されます。

maxsize は filename で指定したダンプファイルのサイズではなく、「リポジトリ」に作成されたチャンクファイルの合計サイズを制限する点に注意してください。「リポジトリ」の制限は、maxage で保持時間として指定することもできます。両方を指定した場合は、制限に早く達した方が適用されます。 デフォルトの取得情報の場合、環境にもよると思いますが、目安として1時間で15M、1日で360M程度のファイルが生成されます。


取得した .jfr ファイルは JMC で「ファイルを開く...」より読み込むことで解析を行うことができます。

スポットでプロファイルを得たいだけの場合は、JMC から「ファイル」「接続...」で接続して収集、またはJVMブラウザから接続先を選択してフライト記録の開始などの操作でプロファイリングデータを得ることも可能です。


JFR のオプション指定

StartFlightRecording オプション設定一覧

このオプションは、Javaアプリケーションの起動と同時に JFR(Java Flight Recorder) による記録を開始するために使用します。 設定は key=value の形式で、カンマ区切りで複数指定できます。

設定項目 説明 デフォルト値
name レコーディングセッションを識別するための名前 (なし)
disk データをディスク上の一時リポジトリに書き出すかどうか(falseの場合データはメモリ上の循環バッファにのみ保持される) true
dumponexit JVMが正常にシャットダウンする際に、記録データをファイルにダンプするかどうか false
filename dumponexit=true の場合に記録データを書き出すファイルパス (なし)
maxsize リポジトリに保存する記録データの最大合計サイズ(このサイズを超えると古いデータから削除される)(256m, 1g) 0 (無制限)
maxage リポジトリに保持する記録データの最長期間(この期間を過ぎたデータは削除される)(30m, 6h, 1d) 0 (無制限)
delay Javaプロセス起動後、JFRの記録を開始するまでの待機時間(20s, 5m) 0 (無制限)
duration JFRの記録を実行する期間(期間終了時にファイルに書き出される)(10m, 1h) 0 (無制限)
path-to-gc-roots OldObjectSampleイベント発生時にオブジェクトがGCされずに残っている理由(GCルートへの参照パス)を収集するかどうか(パフォーマンスへの影響が大) false
settings 使用するイベント設定テンプレートを指定(default, profile, /path/to/my-settings.jfc) default

起動後30秒待ってから10分間、詳細なプロファイリング(profile.jfc)を取得する例は以下のようになります。

java -XX:StartFlightRecording=delay=30s,duration=10m,settings=profile,filename=performance-snapshot.jfr -jar my-application.jar

FlightRecorderOptions オプション設定一覧

このオプションは、JFRフレームワーク自体の基本的な動作(エンジン設定)やリソース(メモリバッファ、ディスクリポジトリなど)を設定するために使用します。

設定項目 (key) 説明 デフォルト値 (JDK 17時点)
repository 一時ディスクストレージのリポジトリ システムの一時ディレクトリ
preserve-repository JVM終了後もリポジトリに保存されたファイルを保持するかどうか false
globalbuffersize 全スレッドで共有されるイベントデータを保持するための合計メモリバッファサイズ(溢れたものはディスクに書き出される) (JVMが動的に計算)
numglobalbuffers 使用するグローバル・バッファの数 (JVMが動的に計算)
maxchunksize ディスクリポジトリに書き込まれる個々のデータチャンクファイルの最大サイズ 12M
memorysize 使用するバッファ・メモリーサイズ 10M
retransform JVMTI を使用してイベントクラスを再変換するかどうかを指定 true
threadbuffersize スレッドのローカルバッファーサイズ 8k
stackdepth スタックトレースのスタック深度 64
old-object-queue-size 追跡する古いオブジェクトの最大数 256


jcmd からの操作

jcmd で実行中のJavaプロセスに対して、JFRの記録を開始、停止、ダンプを指示できます。

jcmd <pid> <コマンド> [オプション]
  • <pid>: 対象となるJavaプロセスのプロセスID
  • <コマンド>: JFR.start, JFR.stop など
  • [オプション]: コマンドに渡すパラメータ
コマンド 説明
JFR.start 新しいJFRレコーディングをバックグラウンドで開始
JFR.dump 特定のID番号の記録によってその時点までに収集されたデータをダンプ(デフォルトでは記録1のデータがダンプされる)(レコーディングは継続)
JFR.stop 特定のID番号の記録を停止します(デフォルトでは記録1が停止される)(停止時にファイルへ書き出すことも可能)
JFR.check 指定されたプロセスで実行されているすべての記録のステータス(記録ID番号、ファイル名、期間など)をチェック

プロセスID は、jcmd を引数なしで実行することで一覧されます。

プロセスID 123 で、"WebAppProfile" という名前のレコーディングを10分間行う例

jcmd 123 JFR.start name=WebAppProfile duration=10m filename=profile-dump.jfr settings=profile

プロセスID 123 のレコーディング "WebAppProfile" の現在の内容を /tmp/dump.jfr に書き出す例

jcmd 123 JFR.dump name=WebAppProfile filename=/tmp/dump.jfr

プロセスID 123 のレコーディング "WebAppProfile" を停止し、最後に final-dump.jfr に内容を保存する例

jcmd 12345 JFR.stop name=WebAppProfile filename=final-dump.jfr

プロセスID 123 の詳細情報を表示する例

jcmd 12345 JFR.check verbose=true