これは、なにをしたくて書いたもの？
JDK Flight Recorder（JFR）とJDK Mission Control（JMC）について見てみようと思いつつ、ずっとそのままにしていたのでそろそろ
ちゃんと見ておこうかなということで。
なお、今回はざっくりコマンドの使い方の雰囲気だけを見ることにしておきます。
JEP 328：Flight Recorder（JFR）
JEP 328：Flight Recorder、JDK Flight Recorder（JFR）のページはこちら。
JFRはJavaアプリケーションとHotSpot JVMのトラブルシュートのための、オーバヘッドの少ないデータ収集フレームワークです。
要するにトラブルシューティング、モニタリング、プロファイリングを行う仕組みです。OpenJDK 11で導入されています。
OpenJDK 8にはu262でバックポートされたみたいです。
もっとも、実際に多くのディストリビューションで使えるのはu272以降のようですが。
モジュールもあり、APIを使って自分でイベントやデータの記録もできるようです。
今回は、javaコマンドやjcmdによるJFRを使ったデータの記録にフォーカスしたいと思います。
javaコマンドに-XX:StartFlightRecordingオプションを使うことで、JFRの記録を開始します。
-XX:StartFlightRecording=parameter=value
指定できるパラメーターはこちらです。オプションを複数指定する場合は、「,」区切りで指定します。
- delay … Javaアプリケーションの起動から記録を開始するまでの時間。秒（s）、分（m）、時間（h）、日（d）単位で指定可能。デフォルトは0
- disk … 記録中にディスクを書き込むかどうかをtrue／falseで指定。デフォルトはtrue
- dumponexit … Java VMが停止する時に実行中の記録をダンプするかどうかをtrue／falseで指定する。trueを指定してfilenameを入力していない場合は、レコーディングをプロセスを起動したディレクトリに保存しファイル名は自動で決定する。デフォルトはfalse
- duration … 記録の継続時間を秒（s）、分（m）、時間（h）、日（d）単位で指定する。デフォルトは0で期間は制限されない
- filename … 記録を停止する時に、結果を書き込むファイルパスを指定。
%pでJava VMのPID、%tで現在のタイムスタンプを意味する書式文字列を使用可能 - name … 記録の名前と識別子を指定
- maxage … 記録を保持するディスクデータの最大保持期間を指定する。disk=trueの場合のみ有効。秒（s）、分（m）、時間（h）、日（d）単位で指定する。デフォルトは0で最大保持期間は制限されない
- maxsize … 記録を保持するディスクデータの最大サイズ（バイト単位）を指定する。disk=trueの場合のみ有効。-XX:FlightRecorderOptionsのmaxchunksizeの指定値より小さくできない。m／MでMB単位、g／GでGB単位で指定する。デフォルトは0で最大サイズは制限されない。
- path-to-gc-roots … 記録の終了時にGCのルートへのパスを収集するかどうかをtrue／falseで指定。デフォルトはfalse
- settings … イベント設定ファイルのパスと名前を指定する。デフォルトは
${JAVA_HOME}/lib/jfr/default.jfc
また-XX:FlightRecorderOptionsでJFRの動作を制御するパラメーターを設定できます。こちらはパラメーター名のみ載せておきます。
- globalbuffersize
- maxchunksize
- memorysize
- numglobalbuffers
- old-object-queue-size
- preserve-repository
- repository
- retransform
- stackdepth
- threadbuffersize
またjcmdでもJFRの操作や設定ができます。
- JFR.start … JFRの記録の開始。
-XX:StartFlightRecordingと同等で、オプションも同じ - JFR.stop … JFRの記録の停止
- JFR.configure … JFRの設定を行う。
-XX:FlightRecorderOptionsで設定できるオプションほぼ同等 - JFR.dump … JFRの記録をダンプする
- JFR.check … 実行中のJFRの記録の情報を表示する
実際に使う時はjava-XX:StartFlightRecording〜やjcmd [PID] JFR.start、jcmd [PID] JFR.stop、jcmd [PID] JFR.dump`あたりになるでしょう。
結果を確認するプリミティブな操作としてはjfrコマンドというものも使えるようですが、実際には後述のJDK Mission Controlを使うことに
なるでしょう。
JDK Mission Control（JMC）
JDK Mission Control（JMC）は、Java VMに対してJFRによる記録を行ったり、JFRで記録したファイルを分析できたりするツールです。
JMCはOpenJDKには同梱されておらず、別途ダウンロードする必要があります。
JMCのGitHubリポジトリーに記載がありますが、以下が主要なダウンロード先ですね。
Eclipse Mission Control。
Eclipse Mission Control | Adoptium
Azul Mission Control。
Azul Mission Control - Azul | Better Java Performance, Superior Java Support
Liberica Mission Control。
JMC for Corretto（OpenJDK 8、11まで）。
GitHub - corretto/corretto-jmc: A build of JDK Mission Control (JMC) by the Corretto team.
そしてOracle、Red HatからもJMCが提供されています（有償）。
JDK Flight RecorderとJDK Mission Controlについては、このあたりも参考にするとよいかもしれません。
Zulu Flight Recorder と Mission Control を使用してデータを確認する | Microsoft Learn
Red Hat build of OpenJDK での JDK Flight Recorder の使用 | Red Hat Product Documentation
Using Java Flight Recorder - Quarkus
JDK Flight Recorder入門 - Speaker Deck
今回は簡単なアプリケーションを作成し、JFRで記録、JMC（Eclipse Mission Control）で確認してみたいと思います。
分析のテーマはヒープだったりといくつかあると思いますが、今回は処理に時間のかかるメソッドを実行してどのような結果が得られるのかを
見ていきたいと思います。
環境
今回の環境はこちら。
$ java --version openjdk 21.0.5 2024-10-15 OpenJDK Runtime Environment (build 21.0.5+11-Ubuntu-1ubuntu124.04) OpenJDK 64-Bit Server VM (build 21.0.5+11-Ubuntu-1ubuntu124.04, mixed mode, sharing) $ mvn --version Apache Maven 3.9.9 (8e8579a9e76f7d015ee5ec7bfcdc97d260186937) Maven home: $HOME/.sdkman/candidates/maven/current Java version: 21.0.5, vendor: Ubuntu, runtime: /usr/lib/jvm/java-21-openjdk-amd64 Default locale: ja_JP, platform encoding: UTF-8 OS name: "linux", version: "6.8.0-49-generic", arch: "amd64", family: "unix"
サンプルアプリケーションの作成
確認対象のアプリケーションがないと始まらないので、簡単なものを作成します。今回はJakarta RESTful Web Services（JAX-RS）の
SeBootstrapを使うことにしました。実装はRESTEasyです。
<properties> <maven.compiler.release>21</maven.compiler.release> <project.build.sourceEncoding>UTF-8</project.build.sourceEncoding> <project.reporting.outputEncoding>UTF-8</project.reporting.outputEncoding> </properties> <dependencies> <dependency> <groupId>org.jboss.resteasy</groupId> <artifactId>resteasy-core</artifactId> <version>6.2.11.Final</version> </dependency> <dependency> <groupId>org.jboss.resteasy</groupId> <artifactId>resteasy-undertow-cdi</artifactId> <version>6.2.11.Final</version> </dependency> </dependencies> <build> <plugins> <plugin> <groupId>org.apache.maven.plugins</groupId> <artifactId>maven-dependency-plugin</artifactId> <version>3.8.1</version> <executions> <execution> <id>copy-dependencies</id> <phase>prepare-package</phase> <goals> <goal>copy-dependencies</goal> </goals> <configuration> <outputDirectory>${project.build.directory}/libs</outputDirectory> </configuration> </execution> </executions> </plugin> <plugin> <groupId>org.apache.maven.plugins</groupId> <artifactId>maven-jar-plugin</artifactId> <version>3.4.2</version> <configuration> <archive> <manifest> <addClasspath>true</addClasspath> <classpathPrefix>libs/</classpathPrefix> <mainClass>org.littlewings.jfr.Server</mainClass> </manifest> </archive> </configuration> </plugin> <plugin> <groupId>org.jboss.jandex</groupId> <artifactId>jandex-maven-plugin</artifactId> <version>1.2.3</version> <executions> <execution> <id>make-index</id> <goals> <goal>jandex</goal> </goals> </execution> </executions> </plugin> </plugins> </build>
Maven Dependency PluginとMaven Jar Pluginを使って、java -jarで起動できるようにしてあります。
Jandex Maven PluginはJAX-RSのリソースクラスのスキャン用ですね。ところで、RESTEasyのSeBootstrapで使うJandexはSmallRyeの
groupIdのものではダメなようでしたね。
JAX-RSの有効化。
src/main/java/org/littlewings/jfr/RestApplication.java
package org.littlewings.jfr; import jakarta.ws.rs.ApplicationPath; import jakarta.ws.rs.core.Application; @ApplicationPath("/") public class RestApplication extends Application { }
JAX-RSリソースクラス。10秒スリープするエンドポイントと、フィボナッチ数を計算してCPUを消費するエンドポイントを作成しました。
フィボナッチ数も手元の環境ではこの数字で約10秒かかります。
src/main/java/org/littlewings/jfr/JfrTestResource.java
package org.littlewings.jfr; import java.util.concurrent.TimeUnit; import jakarta.ws.rs.GET; import jakarta.ws.rs.Path; import jakarta.ws.rs.Produces; import jakarta.ws.rs.core.MediaType; @Path("/jfr-test") public class JfrTestResource { @GET @Path("/sleep") @Produces(MediaType.TEXT_PLAIN) public String sleep() throws InterruptedException { long sleepTime = 10L; TimeUnit.SECONDS.sleep(sleepTime); return String.format("sleep[%d] sec", sleepTime); } @GET @Path("/heavy") @Produces(MediaType.TEXT_PLAIN) public String heavy() { int n = 46; long result = fib(n); return String.format("fib[%d]: %d, done", n, result); } private int fib(int n) { if (n <= 1) { return n; } return fib(n - 1) + fib(n - 2); } }
mainメソッドを持ったクラス。サーバーを起動後、Enterを打つと終了します。
src/main/java/org/littlewings/jfr/Server.java
package org.littlewings.jfr; import java.util.concurrent.ExecutionException; import jakarta.ws.rs.SeBootstrap; import org.jboss.logging.Logger; public class Server { public static void main(String... args) throws ExecutionException, InterruptedException { Logger logger = Logger.getLogger(Server.class); SeBootstrap.Configuration configuration = SeBootstrap .Configuration .builder() .host("0.0.0.0") .port(8080) .build(); SeBootstrap.Instance instance = SeBootstrap .start(new RestApplication(), configuration) .toCompletableFuture() .get(); logger.info("server startup."); System.console().readLine("> Enter stop."); instance .stop() .toCompletableFuture() .get(); } }
動作確認しましょう。パッケージングして起動。
$ mvn package $ java -jar target/jdk-flight-recorder-example-0.0.1-SNAPSHOT.jar
アクセスして確認。
$ time curl localhost:8080/jfr-test/sleep sleep[10] sec real 0m10.141s user 0m0.007s sys 0m0.005s $ time curl localhost:8080/jfr-test/heavy fib[46]: 1836311903, done real 0m9.746s user 0m0.003s sys 0m0.007s
準備ができました。
JDK Flight Recorderを使って記録を行う、JDK Mission Controlを使って結果を見る
ここから先は、JDK Flight Recorderを使って記録をしてみたり、JDK Mission Controlを使って結果を見ていきたいと思います。
JDK Mission Control（Eclipse Mission Control）をダウンロードする
今回はJDK Mission ControlとしてEclipse Mission Controlを使っていきます。
ダウンロード。
$ curl -LO https://github.com/adoptium/jmc-build/releases/download/9.0.0/org.openjdk.jmc-9.0.0-linux.gtk.x86_64.tar.gz $ tar xf org.openjdk.jmc-9.0.0-linux.gtk.x86_64.tar.gz
今回使うバージョンは9.0.0です。
Eclipse Mission Control | Adoptium
起動。
$ JDK\ Mission\ Control/jmc &
スプラッシュが表示されて
ようこそ画面へ。こちらを閉じるとJDK Mission Controlを使い始められます。
ここからいくつかの方法でJDK Flight Recorderで記録を取得し、JDK Mission Controlで確認していきたいと思います。
javaコマンド実行時に記録する
まずはjavaコマンド実行時に記録します。
dumponexit=trueをつけて、終了時にダンプするようにしてみましょう。ファイル名は自動にします。
$ java -XX:StartFlightRecording=dumponexit=true -jar target/jdk-flight-recorder-example-0.0.1-SNAPSHOT.jar
アプリケーションを起動すると、こんな表示が出ます。どうも今回の環境ではデフォルトの最大サイズは250MBになっているようですね。
[0.540s][info][jfr,startup] Started recording 1. No limit specified, using maxsize=250MB as default. [0.540s][info][jfr,startup] [0.540s][info][jfr,startup] Use jcmd 23504 JFR.dump name=1 filename=FILEPATH to copy recording data to file.
アプリケーションにアクセスします。
$ curl localhost:8080/jfr-test/sleep sleep[10] sec $ curl localhost:8080/jfr-test/heavy fib[46]: 1836311903 , done
アクセスが完了したら、アプリケーションを終了させます。
すると、アプリケーションの実行ディレクトリにこんなファイルが記録されていました。
$ ll -h hotspot-pid-23504-id-1-2024_12_15_16_00_34.jfr -rw-rw-r-- 1 xxxxx xxxxx 799K 12月 15 16:00 hotspot-pid-23504-id-1-2024_12_15_16_00_34.jfr
こちらをJDK Mission Controlで開きます。
「メソッド・プロファイリング」を開くと、すでにフィボナッチ数の計算でCPUを使っていることが指摘されています。
「Javaアプリケーション」の表示。CPU使用率の欄で、青い部分が特徴的なことがわかります。
またメソッド・プロファイリング・サンプルの数が上位のスレッドを見てみると、よりわかりやすく結果が出ています。
この部分を選択すると、スリープしていることがわかります。
またこの部分を選択すると、フィボナッチ数の計算が時間を使っていることがわかります。
スレッドで見てもイベントが見つけやすい感じがしますね。
よさそうです。
javaコマンドでオプションを指定する、他の例も載せておきましょう。
filename=start-recording.jfrでファイル名を「start-recording.jfr」に、duration=3mで記録時間を3分間にする例。
$ java -XX:StartFlightRecording=filename=start-recording.jfr,duration=3m,dumponexit=true -jar target/jdk-flight-recorder-example-0.0.1-SNAPSHOT.jar
ファイルは起動時に作成されますが、0バイトです。
今回の設定では、3分間経過するかJavaアプリケーションが終了すると記録がダンプされます。
確認結果は省略します。
jcmdでJDK Flight Recorderの操作をする
続いては、jcmdでJDK Flight Recorderの操作をしましょう。
アプリケーションは-XX:StartFlightRecordingをつけずに起動しておきます。
$ java -jar target/jdk-flight-recorder-example-0.0.1-SNAPSHOT.jar
このJavaプロセスのPIDが必要になるので、jcmd自体で確認しましょう。
$ jcmd
記録を開始します。オプションはデフォルトです。
$ jcmd [PID] JFR.start
実行すると、こんな表示が出ます。
[PID]: Started recording 1. No limit specified, using maxsize=250MB as default. Use jcmd 24986 JFR.dump name=1 filename=FILEPATH to copy recording data to file.
アプリケーションにアクセスします。
$ curl localhost:8080/jfr-test/sleep sleep[10] sec $ curl localhost:8080/jfr-test/heavy fib[46]: 1836311903 , done
記録をダンプします。
$ jcmd [PID] JFR.dump [PID]: Dumped recording, 602.2 kB written to: /path/to/hotspot-pid-24986-2024_12_15_16_23_19.jfr
ダンプすると、記録が出力されたファイルパスが表示されるようです。
※今回のPIDは24986です。
記録を停止します。
$ jcmd [PID] JFR.stop [PID]: Command executed successfully
JDK Mission Controlでの結果の確認は省略します。
なお、jcmdでJDK Flight Recorderの操作を行う場合、オプションはスペース区切りで指定するようです。
$ jcmd [PID] JFR.start filename=jmc-recording.jfr duration=1m dumponexit=true
指定可能なオプションについてはドキュメントを確認しましょう。
JDK Mission ControlからJDK Flight Recorderを操作する
最後はJDK Mission ControlからJDK Flight Recorderの操作を行ってみます。
アプリケーションは-XX:StartFlightRecordingをつけずに起動しておきます。
$ java -jar target/jdk-flight-recorder-example-0.0.1-SNAPSHOT.jar
JDK Mission ControlのJVMブラウザを見ると、ローカルで実行しているJava VMプロセスの一覧を見ることができます。
※リモートもできそうです
展開すると、「フライト・レコーダ」が現れます。もちろん記録はありません。
ここで「フライト・レコーダ」を右クリックして「フライト記録の開始」を選ぶと、記録を開始できるようになります。
ファイル名はデフォルトでは自動で決まりますが、設定することもできます。
「終了」を押すと記録が開始され、JVMブラウザでも記録が行われていることがわかります。
今回は記録時間を指定したので、終了すると自動で分析結果に移ります。
ちなみにJVMブラウザの方は「記録がありません」に戻るようです。ここに表示されるのは、記録中のものみたいですね。
今度は連続記録にしてみましょう。下に書かれていますが、連続記録の場合は明示的なダンプ操作が必要になります。
「終了」を押して記録を開始すると、記録が現れますが残り時間が無限大になっています。
この記録を右クリックしてダンプ操作を行います。記録全体をダンプしたり、範囲を絞ってダンプしたりできるようです。
記録全体をダンプすると、すぐに記録の分析結果が表示されます。
また、右クリックで「ダンプ」操作を選ぶとこんな感じで細かく聞かれますが、「記録全体をダンプします」を選ぶとそのまま分析結果を
表示してくれます。
記録を取得し終わったら、「記録」を右クリックして停止しておきましょう。
これでJDK Flight Recorderによる記録が停止します。
おわりに
JDK Flight RecorderとJDK Mission Controlを試してみました。
実はちゃんと使ってきてなかったので…これを機に使っていくようにしたいですね。
