- JAVA
JFR(Java Flight Recorder)入門|記録とjfrコマンド分析
JFR(JDK Flight Recorder)は、JVM に組み込まれた「記録装置」です。 CPU を使っているメソッド・GC・ロック待ち・ファイルやソケットの I/O・例外などを、低い負荷でイベントとして記録し、.jfr ファイルに残します。起動時なら -XX:StartFlightRecording、動いているプロセスなら jcmd <PID> JFR.start で記録を始め、JDK 付属の jfr コマンド(JDK 21 以降は jfr view)で、GUI なしに分析できます。
# 起動時に60秒記録する
java -XX:StartFlightRecording:duration=60s,filename=rec.jfr -jar app.jar
# 動いているプロセスで記録する
jcmd 12345 JFR.start name=diag settings=profile
jcmd 12345 JFR.dump name=diag filename=/var/tmp/diag.jfr
jcmd 12345 JFR.stop name=diag
# 分析する(JDK 21 以降)
jfr view hot-methods rec.jfr # CPU を使っているメソッド
jfr view gc-pauses rec.jfr # GC の停止時間
jfr view contention-by-site rec.jfr # ロック待ちの場所
jfr view latencies-by-type rec.jfr # 待ち時間の種類ごとの合計
確認環境:OpenJDK 1.8.0_504・17.0.20.1・21.0.10・25.0.4.1(Ubuntu 24.04)。CPU・メモリ確保・ロック競合・ソケット I/O・ファイル I/O の負荷を同時にかけるプログラムを JDK 21 で動かし、-XX:StartFlightRecording と jcmd JFR.* で記録して jfr summary・print・view の出力を載せています。JDK 25 の CPU 時間サンプリングとメソッド計測、JDK 8 での記録も動かしました。オプションと既定値は各 JDK の jcmd help JFR.start・jfr help・付属の .jfc ファイルで、JDK Mission Control は Oracle の製品ページで確かめています(確認日 2026年10月13日)。
本記事の内容は、ご自由にお使いください。
ご利用の際は、出典として本ページへのリンクを記載いただけますようお願いします。
(記載例)出典:株式会社RJC「JFR(Java Flight Recorder)入門|記録とjfrコマンド分析」
JFR でわかること
| 調べたいこと | 記録されるイベントの例 | 見るコマンド(JDK 21 以降) |
|---|---|---|
| CPU を使っているメソッド | jdk.ExecutionSample |
jfr view hot-methods |
| GC の回数・停止時間 | jdk.GarbageCollection・jdk.GCPhasePause |
jfr view gc・gc-pauses |
| メモリを多く確保している場所 | jdk.ObjectAllocationSample |
jfr view allocation-by-site |
| ロック待ち | jdk.JavaMonitorEnter |
jfr view contention-by-site |
| ソケット・ファイルの遅い I/O | jdk.SocketRead・jdk.FileWrite |
jfr view socket-reads-by-host・file-writes-by-path |
| スレッドごとの CPU | jdk.ThreadCPULoad |
jfr view thread-cpu-load |
| メモリリークの候補 | jdk.OldObjectSample |
jfr view memory-leaks-by-site |
| 待ち時間の全体像 | 上の各イベントの duration |
jfr view latencies-by-type |
スレッドダンプやヒープダンプが「その瞬間の写真」なのに対し、JFR は「一定時間の録画」です。たまに遅くなる・徐々に重くなる、といった時間で変わる問題に向いています。
版ごとの違い
| JDK | 記録 | jfr コマンド |
jfr view・jcmd JFR.view |
|---|---|---|---|
| 8(今回の 1.8.0_504) | ○(-XX:StartFlightRecording=...) |
○(print・summary・metadata など) | × |
| 17 | ○ | ○(configure が増える) | × |
| 21 | ○ | ○(view・scrub が増える) | ○ |
| 25 | ○ | ○ | ○(CPU 時間サンプリングなどの view が増える) |
今回の OpenJDK 1.8.0_504 では、-XX:+UnlockCommercialFeatures なしで記録でき、jfr コマンドも付いていました。JDK 7〜8 の時代の Oracle JDK では商用機能のフラグが必要でしたが、OpenJDK の JDK 11 以降では不要です(JEP 328)。
記録の取り方1:起動時に -XX:StartFlightRecording
java -XX:StartFlightRecording:duration=20s,filename=rec.jfr,settings=profile -jar app.jar
[0.801s][info][jfr,startup] Started recording 1. The result will be written to:
[0.801s][info][jfr,startup]
[0.801s][info][jfr,startup] rec.jfr
= でも : でもつなげられます(-XX:StartFlightRecording=duration=... も同じ)。よく使うパラメーターです(JDK 21 の jcmd help JFR.start より)。
| パラメーター | 既定値 | 意味 |
|---|---|---|
duration |
0s(止めるまで) | 記録する時間 |
filename |
なし | 書き出すファイル。ディレクトリも指定でき、%p(PID)・%t(日時)が使える |
settings |
default.jfc |
どのイベントをどの間隔で取るか。default か profile |
maxage |
0s(無制限) | ディスクに残す期間 |
maxsize |
0(無制限) | ディスクに残す量。何も指定しないと 250MB が使われた(下のログ) |
dumponexit |
false | JVM 終了時に書き出す |
name |
自動 | 記録の名前(jcmd で指定するときに使う) |
path-to-gc-roots |
false | 記録の終わりに、リーク候補の GC ルートまでの経路を集める(時間がかかる) |
duration も filename も付けずに起動すると、次のログが出ました。無期限で記録し続け、最大 250MB を保つ動きです。
[0.923s][info][jfr,startup] Started recording 1. No limit specified, using maxsize=250MB as default.
[0.923s][info][jfr,startup]
[0.923s][info][jfr,startup] Use jcmd 17520 JFR.dump name=1 to copy recording data to file.
本番で常に記録しておき、何か起きたら JFR.dump で直前の分を取り出す、という使い方ができます。期間で区切るなら maxage=1h のように指定します。
記録の取り方2:動いているプロセスに jcmd
jcmd 16604 JFR.start name=diag settings=profile maxage=10m maxsize=200m
16604:
Started recording 1.
Use jcmd 16604 JFR.dump name=diag filename=FILEPATH to copy recording data to file.
| コマンド | 役割 | 実行結果(JDK 21) |
|---|---|---|
JFR.start |
記録を始める | Started recording 1. |
JFR.check |
記録中の一覧 | Recording 1: name=diag maxsize=200.0MB maxage=10m (running) |
JFR.view <view> |
記録中のデータをその場で表示(JDK 21 以降) | 下に出力 |
JFR.dump |
今までの分をファイルに書く(記録は続く) | Dumped recording "diag", 2.1 MB written to: |
JFR.stop |
記録を止める | Stopped recording "diag". |
JFR.configure |
リポジトリの場所などを設定 | ― |
jcmd JFR.view を使うと、ファイルに書き出さずにその場で集計が見られます。 10秒記録したところで実行した結果です。
jcmd 16604 JFR.view hot-methods
Java Methods that Executes the Most
Method Samples Percent
----------------------------------------------------------------------------- ------- -------
java.lang.Integer.formatUnsignedInt(int, int, byte[], int) 298 30.56%
Workload.checksum(int) 235 24.10%
java.lang.Integer.getChars(int, int, byte[]) 205 21.03%
Workload.lambda$main$1() 204 20.92%
java.util.ArrayList.grow(int) 17 1.74%
jcmd は、対象プロセスと同じユーザーで実行します。コンテナでは、そのコンテナの中で実行します。
settings の早見表(default と profile)
JDK には default.jfc と profile.jfc の2つの設定が付いています。それぞれのファイルの説明文は次のとおりです。
| 設定 | ファイルの説明(原文) | 向いている使い方 |
|---|---|---|
default |
Low overhead configuration safe for continuous use in production environments, typically less than 1 % overhead. | 本番で常に記録する |
profile |
Low overhead configuration for profiling, typically around 2 % overhead. | 問題を調べる短い時間だけ |
2つの違いは、jcmd help JFR.start に出る「オプション」でまとめて確かめられます(JDK 21)。
| オプション | default | profile | 意味 |
|---|---|---|---|
method-profiling |
normal | high | CPU サンプリングの細かさ |
allocation-profiling |
low | medium | メモリ確保のサンプリング |
gc |
normal | detailed | GC イベントの細かさ |
locking-threshold |
20ms | 10ms | これより長いロック待ちを記録 |
file-threshold |
20ms | 10ms | これより長いファイル I/O を記録 |
socket-threshold |
20ms | 10ms | これより長いソケット I/O を記録 |
memory-leaks |
types | stack-traces | OldObjectSample に作成時のスタックを付けるか |
exceptions |
errors | errors | all で全例外を記録(多いと重い) |
オプションやイベントの設定は、起動時にもその場で上書きできます。
# ロック待ちを 1ms から記録する
jcmd 12345 JFR.start jdk.JavaMonitorEnter#threshold=1ms
# GC を細かく、メソッドのサンプリングを高く
java -XX:StartFlightRecording:gc=detailed,method-profiling=high -jar app.jar
jcmd help JFR.start の末尾には「Note, if the default event settings are modified, overhead may exceed 1%.」とあり、設定を細かくするほど負荷は上がります。 自分用の設定ファイルは jfr configure で作れます(JDK 17 以降)。
負荷をかけたプログラム
分析の題材として、5種類の負荷を同時にかけるプログラムを用意しました。
import java.io.*;
import java.net.*;
import java.nio.file.*;
import java.util.*;
public class Workload {
static final Object LOCK = new Object();
static volatile long sink;
public static void main(String[] args) throws Exception {
int seconds = args.length > 0 ? Integer.parseInt(args[0]) : 20;
// 1. CPU:重い計算
start("cpu-worker", () -> { while (true) sink += checksum(200_000); });
// 2. GC:短命オブジェクトを大量に作る
start("alloc-worker", () -> { while (true) { List<String> l = new ArrayList<>(); for (int i = 0; i < 10_000; i++) l.add("item-" + i); sink += l.size(); } });
// 3. ロック競合:ロックの中で 30ms 待つ
for (int t = 0; t < 4; t++) start("lock-worker-" + t, () -> { while (true) { synchronized (LOCK) { pause(30); } } });
// 4. ソケット I/O:応答に 50ms かかるサーバー
ServerSocket server = new ServerSocket(0);
start("slow-server", () -> { while (true) { try (Socket s = server.accept()) { pause(50); s.getOutputStream().write(new byte[1024]); } catch (IOException e) { } } });
start("socket-client", () -> { while (true) { try (Socket s = new Socket("127.0.0.1", server.getLocalPort())) { s.getInputStream().readNBytes(1024); } catch (IOException e) { } } });
// 5. ファイル I/O:大きめの書き込みと fsync
Path file = Files.createTempFile("jfr-demo", ".dat");
start("file-writer", () -> { byte[] buf = new byte[8 * 1024 * 1024]; while (true) { try (FileOutputStream out = new FileOutputStream(file.toFile())) { out.write(buf); out.getFD().sync(); } catch (IOException e) { } } });
Thread.sleep(seconds * 1000L);
System.exit(0);
}
static long checksum(int n) {
long h = 0;
for (int i = 0; i < n; i++) h = h * 31 + Integer.toHexString(i).hashCode();
return h;
}
static void pause(long ms) { try { Thread.sleep(ms); } catch (InterruptedException e) { Thread.currentThread().interrupt(); } }
static void start(String name, Runnable r) { Thread t = new Thread(r, name); t.setDaemon(true); t.start(); }
}
java -Xmx256m -XX:StartFlightRecording:duration=20s,filename=rec.jfr,settings=profile Workload 25
20秒の記録で、ファイルは 4,565,099 バイトでした。
分析1:jfr summary で全体を見る
jfr summary rec.jfr
Version: 2.1
Chunks: 1
Start: 2026-10-13 05:54:15 (UTC)
Duration: 20 s
Event Type Count Size (bytes)
=============================================================
jdk.GCPhaseParallel 118578 3292783
jdk.TenuringDistribution 11235 126308
...
まず、調べたいイベントが記録されているかを数で確かめます。今回の記録から抜き出しました。
| イベント | 件数 | 読み方 |
|---|---|---|
jdk.ExecutionSample |
2,577 | CPU サンプリング。数が少なすぎると傾向が読めない |
jdk.GarbageCollection |
749 | 20秒で749回の GC |
jdk.SocketRead |
381 | しきい値(profile は 10ms)を超えたソケット読み込み |
jdk.JavaMonitorEnter |
161 | しきい値を超えた synchronized の待ち |
jdk.FileWrite |
28 | しきい値を超えたファイル書き込み |
分析2:jfr view で4つのホットスポットを探す(JDK 21 以降)
jfr view は、よく使う集計を表にして出すコマンドです。JDK 21 の jfr help view には、JVM・環境・アプリの3つに分けて約70の view が並んでいました。--width で表の幅を変えられます。
CPU:hot-methods と thread-cpu-load
jfr view --width 140 hot-methods rec.jfr
Java Methods that Executes the Most
Method Samples Percent
--------------------------------------------------------------------------------------------------------------------------- ------- -------
java.lang.Integer.formatUnsignedInt(int, int, byte[], int) 823 31.94%
java.lang.Integer.getChars(int, int, byte[]) 610 23.67%
Workload.lambda$main$1() 542 21.03%
java.lang.StringLatin1.hashCode(byte[]) 432 16.76%
java.lang.String.hashCode() 104 4.04%
java.util.ArrayList.grow(int) 54 2.10%
hot-methods は、スタックの一番上(今まさに動いているメソッド)で数えます。 そのため JDK の内部メソッドが上位に来やすく、「自分のコードのどこから呼ばれたか」は見えにくくなります。そこで、スタックの中で最初に出てくる自分のクラスの行を数える短いスクリプトを用意しました。
import json, sys, collections
# 使い方: jfr print --json --events ExecutionSample rec.jfr > es.json
# python3 top_frames.py es.json Workload.
data = json.load(open(sys.argv[1]))
prefix = sys.argv[2]
count = collections.Counter()
events = data["recording"]["events"]
for e in events:
for f in e["values"]["stackTrace"]["frames"]:
m = f["method"]
name = m["type"]["name"] + "." + m["name"]
if name.startswith(prefix):
count[f'{name}:{f["lineNumber"]}'] += 1
break
total = len(events)
for k, n in count.most_common(5):
print(f"{n:6d} {n * 100 / total:6.2f}% {k}")
1361 52.81% Workload.checksum:31
597 23.17% Workload.lambda$main$1:15
1 0.04% Workload.lambda$main$5:24
サンプルの約53%が checksum の31行目(Integer.toHexString(i).hashCode() の行)から来ていました。 上の formatUnsignedInt や getChars は、この行から呼ばれた先です。15行目は alloc-worker の文字列連結の行です。
スレッドごとの CPU は thread-cpu-load で見ます。
Thread System User
------------------------------------------------------------------------------------------------------------------- ------ ------
cpu-worker 0.71% 34.60%
alloc-worker 0.67% 33.90%
file-writer 5.82% 3.24%
main 0.19% 2.29%
file-writer は System(OS の中)の割合が高く、ファイルの書き込みと fsync に時間を使っていると読めます。
GC:gc-pauses と gc
jfr view gc-pauses rec.jfr
GC Pauses
---------
Total Pause Time: 1.05 s
Number of Pauses: 749
Minimum Pause Time: 0.584 ms
Median Pause Time: 1.21 ms
Average Pause Time: 1.41 ms
P90 Pause Time: 2.13 ms
P95 Pause Time: 2.76 ms
P99 Pause Time: 4.85 ms
P99.9% Pause Time: 7.60 ms
20秒のうち合計 1.05 秒、GC で止まっていました。 1回ごとの停止は短い(中央値 1.21 ms)ものの、回数が多い形です。jfr view gc で1回ずつ見ると、Young GC のたびにヒープが 60〜110MB から 13MB 前後まで下がっていました。GC 後の値が下がっているので、リークではなく「短命オブジェクトを作りすぎ」と読めます。作っている場所は allocation-by-site で見ます。
Method Allocation Pressure
------------------------------------------------------------------------------------------------------------- -------------------
jdk.internal.misc.Unsafe.allocateUninitializedArray(Class, int) 31.07%
java.lang.Integer.toUnsignedString0(int, int) 29.34%
java.lang.StringConcatHelper.newString(byte[], long) 23.66%
java.util.Arrays.copyOf(Object[], int) 15.90%
GC ログの読み方と GC の種類は、関連記事「Java ガベージコレクションの仕組みとGC種類比較|ログの読み方まで」で扱っています。
ロック:contention-by-site
jfr view contention-by-site rec.jfr
StackTrace Count Avg. Max.
--------------------------------------------------------------------------------------------------------------------- ----- ------- -------
Workload.lambda$main$2() 160 368 ms 966 ms
jdk.jfr.internal.PlatformRecorder.periodicTask() 1 16.5 ms 16.5 ms
lock-worker のロックで、1回あたり平均 368 ms、最長 966 ms 待っていました。 ロックの中で 30 ms 待つ処理を4本のスレッドが取り合っているためです。1件ずつの中身は jfr print で見られ、直前にロックを持っていたスレッド(previousOwner)もわかります。
jfr print --events JavaMonitorEnter --stack-depth 3 rec.jfr
jdk.JavaMonitorEnter {
startTime = 14:54:15.099 (2026-10-13)
duration = 288 ms
monitorClass = java.lang.Object (classLoader = bootstrap)
previousOwner = "lock-worker-1" (javaThreadId = 28)
address = 0x7F424C0034C0
eventThread = "lock-worker-0" (javaThreadId = 27)
stackTrace = [
...
synchronized の待ちは JavaMonitorEnter、ReentrantLock などの待ちは jdk.ThreadPark に記録されます。synchronized の基本は関連記事「Java synchronizedで排他制御|スレッドセーフを実行結果で検証」で扱っています。
I/O:latencies-by-type・socket-reads-by-host・file-writes-by-path
「何を待って時間を使っているか」の全体は latencies-by-type が便利です。
Event Type Count Average P 99 Longest Total
------------------------------------------------------------------------------------------- ----- ------- ------- ------- -------
Java Monitor Blocked 161 366 ms 977 ms 966 ms 58.9 s
Java Thread Sleep 1,031 37.9 ms 54.1 ms 57.9 ms 39.0 s
Java Monitor Wait 1 20.0 s 20.0 s 20.0 s 20.0 s
Socket Read 381 51.4 ms 59.2 ms 66.6 ms 19.6 s
File Write 28 15.6 ms 45.4 ms 45.4 ms 437 ms
Socket Write 1 13.0 ms 13.0 ms 13.0 ms 13.0 ms
Socket Read は平均 51.4 ms で、サーバー側の 50 ms の遅れがそのまま出ています。相手ごと・ファイルごとの内訳は次の view で見ます。
Host Reads Total Read
---------------------------------------------------------------------------------------------------------------- ----- ----------
localhost 381 381.0 kB
Path Writes Total Written
------------------------------------------------------------------------------------------------------------ ------ -------------
/tmp/jfr-demo12864795327763818015.dat 28 224.0 MB
I/O のイベントはしきい値(default は 20 ms、profile は 10 ms)より短いものは記録されません。 短い I/O が大量にある場合は、しきい値を下げて記録します。
よく使う view の一覧
| 目的 | view |
|---|---|
| CPU | hot-methods・thread-cpu-load・cpu-load |
| GC | gc・gc-pauses・gc-configuration・heap-configuration |
| メモリ確保 | allocation-by-site・allocation-by-class・allocation-by-thread |
| ロック | contention-by-site・contention-by-class・contention-by-thread |
| I/O | latencies-by-type・socket-reads-by-host・file-writes-by-path・file-reads-by-path |
| 例外 | exception-count・exception-by-site・exception-by-message |
| リーク | memory-leaks-by-class・memory-leaks-by-site |
| 仮想スレッド | pinned-threads |
| 環境 | jvm-flags・system-properties・container-configuration |
jfr view --verbose <view> rec.jfr で、その view の元になる問い合わせ(クエリ)も表示されます。view の名前のかわりにイベント名(jdk.GarbageCollection など)を渡すと、そのイベントが表で出ます。
分析3:jfr print で1件ずつ見る(JDK 11〜17 でも使える)
jfr view が無い JDK 11〜17 では、jfr print で絞り込んで読みます。
jfr print --events ExecutionSample rec.jfr | head
jfr print --events 'jdk.SocketRead,jdk.FileWrite' rec.jfr
jfr print --categories GC rec.jfr
jfr print --json --events ExecutionSample rec.jfr > es.json # スクリプトで集計する
jfr metadata rec.jfr # イベントの項目一覧
--stack-depth でスタックの深さを変えられます。JSON で書き出せば、上の top_frames.py のように自由に集計できます。JDK 8 の jfr print でも同じ形で出ました。
jdk.ExecutionSample {
startTime = 14:56:20.900
sampledThread = "main" (javaThreadId = 1)
state = "STATE_RUNNABLE"
stackTrace = [
java.lang.Integer.formatUnsignedInt(int, int, char[], int, int) line: 337
java.lang.Integer.toUnsignedString0(int, int) line: 315
java.lang.Integer.toHexString(int) line: 233
Hello8.main(String[]) line: 1
]
}
JDK 25 で増えた分析:CPU 時間サンプリングとメソッド計測
JDK 25 には、実際の CPU 時間でサンプリングする jdk.CPUTimeSample(Linux のみ・実験的)と、指定したメソッドの呼び出し回数と時間を測る jdk.MethodTiming が入りました。同じプログラムで試しました。
java -XX:StartFlightRecording:jdk.CPUTimeSample#enabled=true,jdk.MethodTiming#enabled=true,jdk.MethodTiming#filter=Workload::checksum,filename=j25.jfr Workload 10
jfr view cpu-time-hot-methods j25.jfr
jfr view method-timing j25.jfr
Java Methods that Execute the Most from CPU Time Sampler (Experimental)
Method Samples Percent
------------------------------------------------------------------------------------------------------- ------- -------
java.lang.Integer.formatUnsignedInt(int, int, byte[], int) 337 22.97%
Workload.lambda$main$1() 309 21.06%
jdk.internal.util.DecimalDigits.uncheckedGetCharsLatin1(int, int, byte[]) 291 19.84%
jdk.internal.util.ArraysSupport.hashCodeOfUnsigned(byte[], int, int, int) 200 13.63%
java.io.FileOutputStream.writeBytes(byte[], int, int, boolean) 108 7.36%
Timed Method Invocations Minimum Time Average Time Maximum Time
------------------------------------------------------------------- ----------- ------------ ------------ -------------
Workload.checksum(int) 1,185 2.090000 ms 8.560000 ms 145.000000 ms
JDK 21 の hot-methods には出なかった FileOutputStream.writeBytes(ネイティブの書き込み)が CPU 時間の 7.36% として出ています。 従来のサンプリングは Java のコードを動かしているスレッドだけを数えるのに対し、CPU 時間サンプリングは OS から見た CPU 時間で数えるためです。method-timing は、コードを変えずに特定のメソッドの回数と時間を測れます。
オーバーヘッドの目安
| 情報源 | 書かれている目安 |
|---|---|
default.jfc の説明 |
typically less than 1 % overhead(本番で常時記録しても安全な設定) |
profile.jfc の説明 |
typically around 2 % overhead |
jcmd help JFR.start |
既定のイベント設定を変えると 1% を超えることがある |
path-to-gc-roots の説明 |
経路の収集は時間がかかる。リークが疑われるときだけ使う |
負荷を上げやすいのは、しきい値を 0 にした I/O・ロックのイベント、exceptions=all、allocation-profiling=maximum など、件数が多くなる設定です。jfr summary でイベントの件数を見て、件数の多いイベントを確かめます。
記録ファイルの扱い(環境変数も入る)
今回の記録には、jdk.InitialEnvironmentVariable が197件、jdk.InitialSystemProperty が15件入っていました。jfr view environment-variables で、起動時の環境変数がそのまま読めます。 環境変数に API キーやパスワードを入れている場合、記録ファイルにも入ります。
JDK 21 の jfr には scrub があり(JDK 17 の jfr には無い)、イベントを取り除いたコピーを作れます。
jfr scrub --exclude-events InitialEnvironmentVariable,InitialSystemProperty rec.jfr rec-scrubbed.jfr
Scrubbed recording file written to:
rec-scrubbed.jfr
取り除いたあとの jfr summary では、2つのイベントが0件になりました。社外に渡す・チケットに添付するときは、先に scrub すると安心です。
JDK Mission Control(JMC)で見る
JDK Mission Control(JMC)は、JFR の記録を GUI で分析するツールです。Oracle の製品ページでは JMC 9 が案内されています。.jfr ファイルを開くと、記録の自動分析の結果や、メソッド・GC・ロック・I/O などの情報を画面で見られます。
| 方法 | 向いている場面 |
|---|---|
jfr view・jcmd JFR.view |
サーバー上ですぐ見る。結果をテキストで共有する |
jfr print --json + スクリプト |
自分の観点で集計する。複数の記録を比べる |
| JMC | グラフで全体を眺める。スレッドの時系列やフレームグラフを見る |
JMC は JDK とは別に配布されています。記録を取る環境(サーバー)に JMC を入れる必要はなく、ファイルを手元に持ってきて開けます。
よくある質問
Q. 本番で常に JFR を有効にしてもよいですか。
A. default.jfc は、ファイルの説明で「本番で常時使っても安全な、通常 1% 未満の負荷の設定」とされています。maxage や maxsize で残す量を決めておき、何か起きたときに JFR.dump で取り出す使い方ができます。負荷は設定とアプリによって変わるので、自分のアプリで計測して決めます。
Q. コンテナの中のアプリで記録したいです。
A. -XX:StartFlightRecording を起動オプション(JAVA_TOOL_OPTIONS など)に入れるか、コンテナの中で jcmd を実行します。書き出し先はコンテナが消えても残るボリュームにします。JVM オプション全体は関連記事「JVMオプション一覧|Xmx・Xms・GCログ設定をJava 21対応で」で扱っています。
Q. スレッドダンプやヒープダンプとはどう使い分けますか。 A. 今まさに止まっている原因を見るならスレッドダンプ、メモリの中身を見るならヒープダンプ、時間を通して何に時間を使ったかを見るなら JFR です。それぞれ関連記事「スレッドダンプの取り方と読み方|jstack・jcmdとデッドロック」と関連記事「ヒープダンプの取り方と解析|OutOfMemoryErrorの原因を探す」で扱っています。メモリ不足のメッセージごとの原因は関連記事「Java OutOfMemoryErrorの原因と対処|メッセージ別に解説」で扱っています。
Q. jfr view が使えません。
A. jfr view は JDK 21 で入ったコマンドです。JDK 17 以前では jfr print・jfr summary を使うか、記録ファイルを JDK 21 以降の jfr で開きます。JDK 17 で取った記録を JDK 21 の jfr view hot-methods で読めることも確かめました(記録ファイルの形式は JDK 17・21 で 2.1、JDK 8 で 2.0 でした)。
まとめ
- 起動時は
-XX:StartFlightRecording:duration=...,filename=...、動いているプロセスはjcmd JFR.start→JFR.dump→JFR.stop - 何も指定しないと無期限・最大 250MBで記録し続ける。本番での常時記録には
default、調査にはprofile - JDK 21 以降は
jfr viewで CPU(hot-methods)・GC(gc-pauses)・ロック(contention-by-site)・I/O(latencies-by-type)がすぐ見られる。jcmd JFR.viewなら書き出しも要らない hot-methodsはスタックの一番上で数える。自分のコードの行を知るにはjfr print --jsonで集計する- I/O・ロックのイベントはしきい値より短いものは記録されない
- 記録には環境変数も入る。渡す前に
jfr scrub - JDK 25 では CPU 時間サンプリング(実験的)とメソッド計測が加わった
参考・出典
確認日はいずれも 2026年10月13日です。
- JDK 21 Tool Specifications「jfr」:https://docs.oracle.com/en/java/javase/21/docs/specs/man/jfr.html
- JDK 21 Tool Specifications「jcmd」:https://docs.oracle.com/en/java/javase/21/docs/specs/man/jcmd.html
- JDK 21 Tool Specifications「java」(-XX:StartFlightRecording):https://docs.oracle.com/en/java/javase/21/docs/specs/man/java.html
- Java SE 21 API「jdk.jfr」:https://docs.oracle.com/en/java/javase/21/docs/api/jdk.jfr/jdk/jfr/package-summary.html
- OpenJDK「JEP 328: Flight Recorder」:https://openjdk.org/jeps/328
- OpenJDK「JEP 509: JFR CPU-Time Profiling (Experimental)」:https://openjdk.org/jeps/509
- OpenJDK「JEP 520: JFR Method Timing & Tracing」:https://openjdk.org/jeps/520
- Oracle「JDK Mission Control」:https://www.oracle.com/java/technologies/jdk-mission-control.html
本記事の内容は、ご自由にお使いください。
ご利用の際は、出典として本ページへのリンクを記載いただけますようお願いします。
(記載例)出典:株式会社RJC「JFR(Java Flight Recorder)入門|記録とjfrコマンド分析」
株式会社RJC ― SI事業・SES事業・AI駆動開発。RJCは一緒に成長を楽しめる会社です。
WE ARE HIRING
RJCで一緒に開発しながら、
成長を楽しみませんか?
RJCは、Web・モバイル・AIを活用した開発プロジェクトで、テックリードやPM・PMOも活躍するシステム開発会社です。会社を知る、待遇を確かめる、話を聞いてみる。気になるところ見てみてください!
- 127日年間休日
- 12時間平均残業時間
- 毎日ガチャ遊びココロも大切にする福利厚生。アマギフなどの賞品ラインナップ!
ほかにも、チケットレストラン、書籍読み放題、2年ごとの慰労報奨(休暇 or 金一封)、11期連続の黒字決算。