原文はこちら。
The original article was written by Erik Gahlin (Consulting Member of Technical Staff, Java Platform Group, Oracle).
https://egahlin.github.io/2023/05/30/views.html
JDK 21で、JFRに新たにviewコマンドが追加されます。これは集約されたイベントデータをシェルで表示するものです。このコマンドを使って、アプリケーションに関する情報を表示できます。このとき記録ファイルをダンプしたり、JDK Mission Controlを開いたりする必要はありません。
JDK Mission Control (JMC)
https://jdk.java.net/jmc/
$ jcmd 1739 JFR.view hot-methods
Java methods that execute the most
Method Samples Percent
------------------------------------------------------------- ------- -------
sun.java2d.marlin.Renderer._endRendering(...) 1659 42.99%
sun.java2d.marlin.MarlinTileGenerator.getAlphaRLE(...) 592 15.34%
sun.java2d.marlin.MarlinCache.copyAARowRLE_WithBlockFlags(...) 447 11.58%
sun.java2d.marlin.MarlinCache.copyAARowNoRLE(...) 246 6.37%
sun.java2d.marlin.Renderer.addLine(...) 89 2.31%
sun.java2d.marlin.Renderer.copyAARow(...) 86 2.23%
sun.java2d.marlin.ArrayCacheInt.fill(...) 73 1.89%
...
このコマンドを利用するには、まず記録を開始します。
$ java -XX:StartFlightRecording -jar my.jar
アプリケーション実行中に、jcmdツールを使って実行中の全てのJavaプロセスをリスト表示できます。
The jcmd Command
https://docs.oracle.com/en/java/javase/20/docs/specs/man/jcmd.html
$ jcmd
37417 my.jar
37418 jdk.jcmd/sun.tools.jcmd.JCmd
PIDやjar/classファイル名をJFR.viewと表示すべきビュー名を共に利用して情報を表示します。以下はその例です。
$ jcmd 37417 JFR.view allocation-by-site
Allocation by Site
Method Allocation Pressure
------------------------------------------------------- -------------------
java.lang.StringUTF16.compress(char[], int, int) 37.50%
java.lang.Integer.valueOf(int) 13.75%
spec.jbb.infra.Util.TransactionLogBuffer.getLine(...) 9.22%
java.math.BigDecimal.valueOf(long, int) 8.92%
spec.jbb.CustomerReportTransaction.process(...) 7.55%
java.math.BigDecimal.layoutChars(boolean) 5.71%
...
allocation-by-siteビューは、JDK 16で追加されたjdk.ObjectAllocationSampleイベントを基に生成されるものです。ビュー名を指定しなければ、利用可能な全てのニューを確認できます。JDK 21では70個の事前定義済みのビューが付属しており、将来のリリースではさらに追加される予定です。これらのビューはJava virtual machine、Environment、そしてApplicationの3カテゴリに分類されています。
$ jcmd 37417 JFR.view
...
Java virtual machine views:
class-modifications gc-concurrent-phases longest-compilations
compiler-configuration gc-configuration native-memory-committed
compiler-phases gc-cpu-time native-memory-reserved
compiler-statistics gc-pause-phases safepoints
deoptimizations-by-reason gc-pauses tlabs
deoptimizations-by-site gc-references vm-operations
gc heap-configuration
Environment views:
active-recordings cpu-information jvm-flags
active-settings cpu-load native-libraries
container-configuration cpu-load-samples network-utilization
container-cpu-throttling cpu-tsc recording
container-cpu-usage environment-variables system-information
container-io-usage events-by-count system-processes
container-memory-usage events-by-name system-properties
Application views:
allocation-by-class exception-count native-methods
allocation-by-site file-reads-by-path object-statistics
allocation-by-thread file-writes-by-path pinned-threads
class-loaders finalizers socket-reads-by-host
contention-by-address hot-methods socket-writes-by-host
contention-by-class latencies-by-type thread-allocation
longest-class-loading thread-count
contention-by-thread memory-leaks-by-class thread-cpu-load
exception-by-message memory-leaks-by-site thread-start
exception-by-site modules
デフォルトでは、ビューは直近10分以内のデータ32MBを範囲としますが、カスタムの時間範囲を設定することもできます。設定には、maxageとmaxsizeというパラメータを使用します。これらは、JFR.dumpコマンドのmaxageやmaxsizeパラメータと同様の働きをします。
$ jcmd my.jar JFR.view maxage=1h maxsize=2000MB gc-pauses
GC Pauses
---------
Total Pause Time: 2,93 s
Number of Pauses: 272
Minimum Pause Time: 0,471 ms
Median Pause Time: 7,82 ms
Average Pause Time: 10,8 ms
P90 Pause Time: 10,2 ms
P95 Pause Time: 20,9 ms
P99 Pause Time: 256 ms
P99.9% Pause Time: 256 ms
Maximum Pause Time: 256 ms
出力フォーマットはwidth、cell-height、truncateというパラメータで制御できます。widthパラメータは利用する最大文字数（例えば120）を設定します。設定しない場合は、テーブルの大きさは自動的に調整されます。
cell-heightパラメータは表のセル内で使用する行数を指定します。大抵のビューの場合、デフォルトは1ですが、文字が収まらない場合には1より大きな値を設定することもできます。このオプションは複数行のスタックトレースを表示する際に特に有用です。
最後に、truncateパラメータをbeginまたはendに設定すると、文字あふれ時に最初もしくは最後の文字を省略するかどうかを決定できます。デフォルトでは、末尾で文字を切り捨てます。
$ jcmd my.jar JFR.view cell-height=3 truncate=beginning width=80 system-processes
System Processes
First Observed Last Observed PID Command Line
-------------- ------------- ----- --------------------------------------------
13:22:57 13:24:29 13028 C:\Program Files (x86)\Intel\Intel(R) Rapid
Storage Technology enterprise\IAStorIcon.exe
13:22:57 13:24:29 16200 C:\Program Files\Git\git-bash.exe
13:22:57 13:24:29 7232 C:\Program Files\Microsoft Visual Studio\202
2\Enterprise\Common7\IDE\PerfWatson2.exe
13:22:57 13:24:29 18216 C:\Program Files\Microsoft Visual Studio\202
2\Enterprise\Common7\IDE\VC\vcpackages\x86\V
CPkgSrv.exe
13:22:57 13:24:29 8536 C:\Program Files\Microsoft Visual Studio\202
2\Enterprise\Common7\IDE\devenv.exe
13:22:57 13:24:29 15228 C:\Program Files\Microsoft Visual Studio\202
2\Enterprise\Common7\ServiceHub\Hosts\Servic
eHub.Host.CLR.AnyCPU\ServiceHub.Host.CLR.exe
13:22:57 13:24:29 14128 ...es\Microsoft Visual Studio\2022\Enterpris
e\Common7\ServiceHub\Hosts\ServiceHub.Host.C
LR.AnyCPU\ServiceHub.TestWindowStoreHost.exe
bin/jfrツールを使えば、viewコマンドは記録ファイルに対しても利用できます。
The jfr Command
https://docs.oracle.com/en/java/javase/20/docs/specs/man/jfr.html
ファイル名を-XX:StartFlightRecordingオプションで設定すればファイルが作成されます。JVMが終了すると、記録コンテンツをファイルに書き出します。
viewではなく、JFRイベント名を指定できます。以下の例は、カスタムイベントをjdk.jfrイベントAPIを使って作成しています。
Event (Java SE 20 & JDK 20)
https://docs.oracle.com/en/java/javase/20/docs/api/jdk.jfr/jdk/jfr/Event.html
レンダリング出力における列ヘッダーはLabelアノテーションから、バイト・フォーマットはDataAmountアノテーションから取得します。
Label (Java SE 20 & JDK 20)
https://docs.oracle.com/en/java/javase/20/docs/api/jdk.jfr/jdk/jfr/Label.html
DataAmount (Java SE 20 & JDK 20)
https://docs.oracle.com/en/java/javase/20/docs/api/jdk.jfr/jdk/jfr/DataAmount.html
import jdk.jfr.*;
public class Example {
@Name("example.FreeMemory")
@Label("Free Memory")
static class FreeMemoryEvent extends Event {
@Description("An approximation of the amount of memory available for allocation")
@Label("Free Memory")
@DataAmount(DataAmount.BYTES)
long free;
}
public static void main(String... args) throws Exception {
for(int i = 0; i < 3; i++) {
checkFreeMemory();
Thread.sleep(1000);
}
}
public static void checkFreeMemory() {
FreeMemoryEvent event = new FreeMemoryEvent();
event.begin();
event.free = Runtime.getRuntime().freeMemory();
event.commit();
}
}
プログラムを実行し、イベントを表示します。
$ java -XX:StartFlightRecording:filename=recording.jfr Example.java
$ jfr view --cell-height 2 FreeMemory recording.jfr
Free Memory
Start Time Duration Event Thread Stack Trace Free Memory
---------- --------- ---------------- ----------------------------- -----------
12:25:29 0,0213 ms main Example.checkFreeMemory() 240,7 MB
Example.main(String[])
12:25:30 0,0114 ms main Example.checkFreeMemory() 238,0 MB
Example.main(String[])
12:25:31 0,0218 ms main Example.checkFreeMemory() 237,7 MB
Example.main(String[])
どのイベントが記録に保持されているかを確認するには、summaryコマンドを使います。
$ jfr summary recording.jfr
ファイルを読むパーサーはビューを構成するイベントのみをパースするため、ほとんどの場合で処理時間が短くて済みます。内部的には、ビューはクエリ言語でできています。ビューを構成するクエリを見るには、--verboseパラメータを指定します。
$ jfr view --verbose gc recording.jfr
Garbage Collections
Start GC ID Type Heap Before GC Heap After GC Longest Pause
(startTime) (gcId) (eventType.label) (heapUsed) (heapUsed) (longestPause)
----------- ------ ------------------------ -------------- ------------- --------------
13:16:44 0 Young Garbage Collection 409,7 MB 3,1 MB 10,0 ms
13:16:44 1 Old Garbage Collection 3,1 MB 2,6 MB 21,8 ms
13:16:45 2 Young Garbage Collection 330,4 MB 3,9 MB 1,40 ms
13:16:45 3 Old Garbage Collection 3,9 MB 3,5 MB 32,1 ms
13:16:45 4 Young Garbage Collection 3,5 MB 3,5 MB 0,471 ms
13:16:45 5 Old Garbage Collection 3,5 MB 3,5 MB 20,0 ms
13:16:58 6 Young Garbage Collection 2,0 GB 33,0 MB 29,4 ms
...
COLUMN 'Start', 'GC ID', 'Type', 'Heap Before GC', 'Heap After GC', 'Longest Pause'
FORMAT none, none, missing:Unknown, none, none, none SELECT G.startTime, gcId,
[Y|O].eventType.label, B.heapUsed, A.heapUsed, longestPause FROM GarbageCollection AS G,
GCHeapSummary AS B, GCHeapSummary AS A, OldGarbageCollection AS O,
YoungGarbageCollection AS Y WHERE B.when = 'Before GC' AND A.when = 'After GC' GROUP BY
gcId ORDER BY G.startTime
上記の例では、以下の4種類のイベント
jdk.GarbageCollectionjdk.GCHeapSummaryjdk.YoungGarbageCollectionjdk.OldGarbageCollection
でビューが構成されていて、これらのイベントをGROUP BY句内でgcIdを使用して結合しています。クエリ言語はOpenJDKのエンジニアがビューを定義するのを簡素化するためのものです。現在は実験的なものですが、将来的には、エンドユーザーにも公開されるかもしれません。
新しいviewコマンドを試すには、JDK 21のアーリーアクセスビルドをダウンロードしてください。
OpenJDK JDK 21 Early-Access Builds
https://jdk.java.net/21/
Command-Line Reference
jfr view [--verbose]
[--width <integer>]
[--truncate <mode>]
[--cell-height <integer>]
<view>
<file>
--verbose Displays the query that makes up the view
--width <integer> The width of the view in characters. Default value depends on the view
--truncate <mode> How to truncate content that exceeds space in a table cell.
Mode can be 'beginning' or 'end'. Default value is 'end'
--cell-height <integer> Maximum number of rows in a table cell. Default value depends on the view
<view> Name of the view or event type to display. See list below for
available views
<file> Location of the recording file (.jfr)
jcmd <pid> JFR.view [options]
Options:
cell-height (Optional) Maximum number of rows in a table cell. (INTEGER, no default value)
maxage (Optional) Length of time for the view to span. (INTEGER followed by
's' for seconds 'm' for minutes or 'h' for hours, default value is 10m)
maxsize (Optional) Maximum size for the view to span in bytes if one of
the following suffixes is not used: 'm' or 'M' for megabytes OR
'g' or 'G' for gigabytes. (STRING, default value is 32MB)
truncate (Optional) How to truncate content that exceeds space in a table cell.
Mode can be 'beginning' or 'end'. (STRING, default value 'end')
verbose (Optional) Displays the query that makes up the view.
(BOOLEAN, default value false)
<view> (Mandatory) Name of the view or event type to display.
See list below for available views. (STRING, no default value)
width (Optional) The width of the view in characters
(INTEGER, no default value)
Logico Inside 