Javaの主にパフォーマンスに関連するオプションとツールの覚書。
前提
- Java 1.8
- Java HotSpot(TM) 64-Bit Server VM
コマンドラインオプション
GCアルゴリズムとヒープサイズ
シリアルGC
-XX:+UseSerialGC
単一スレッドのGCを使う。いわゆるサーバマシンでJavaEE基盤となるJVMに対して使う利点はほぼなさそうだが、ヒープサイズが100 MB程度以下で済むようなマイクロなJVMを複数起動するような場合ではアリかもしれない。
-XX:+AggressiveHeap
大きなヒープを単一のJVMに割り当てられる状況で有利に動くようにオプションが割り当てられる、なかば投げやりなオプション。
bool AggressiveHeap := true {product}
uintx BaseFootPrintEstimate := 4236855296 {product}
bool BindGCTaskThreadsToCPUs := true {product}
intx CICompilerCount := 18 {product}
uintx InitialHeapSize := 4238344192 {product}
uintx MaxHeapSize := 4238344192 {product}
uintx MaxNewSize := 4272947200 {product}
uintx MinHeapDeltaBytes := 524288 {product}
uintx NewSize := 4272947200 {product}
uintx OldPLABSize := 8192 {product}
uintx OldSize := 4260364288 {product}
bool PrintFlagsFinal := true {product}
bool PrintGCDetails := true {manageable}
bool ResizeTLAB := false {pd product}
bool ScavengeBeforeFullGC := false {product}
uintx TLABSize := 262144 {product}
uintx ThresholdTolerance := 100 {product}
bool UseLargePagesIndividualAllocation := false {pd product}
bool UseParallelGC := true {product}
uintx YoungPLABSize := 262144 {product}
パラレルGC(スループット型)
-XX:+UseParallelOldGC
Old領域のGCに複数スレッドを使う。
-XX:+UseParallelGC
Young領域(とOld領域)のGCに複数スレッドを使う(-XX:-UseParallelOldGC
と明示的にOFFにしなければ-XX:+UseParallelOldGC
も有効になる)。
コンカレントGC(CMS)
-XX:+UseConcMarkSweepGC
Old領域のGCをバックグラウンドで処理する(Young領域は複数スレッドで処理する)。
-XX:+UseParNewGC
-XX:+UseConcMarkSweepGC
するといっしょに有効になり、Young領域のGCに複数スレッドを使う。-XX:+UseConcMarkSweep -XX:-UseParNewGC
(Young領域のGCに複数スレッド使用を無効化)の組み合わせは非推奨。
-XX:CMSInitiatingOccupancyFraction=N
Old領域のスキャンを開始するタイミングを使用率で指定。Concurrent Mode Failure(ヒープのスキャンとオブジェクトの解放が追い付かずにヒープがいっぱいになってしまい、フルGCを誘発)が多発したらこの値を減らして早いうちにOld領域を処理させる。
-XX:+UseCMSInitiatingOccupancyOnly
CMSInitiatingOccupancyFractionの値を優先してスキャンのタイミングを決定する。
-XX:ConcGCThreads=N
スキャンのスレッド数を指定する。
G1GC
-XX:+UseG1GC
Young領域のGCを複数スレッドで処理し、Old領域はバックグラウンドで処理する。大きなヒープサイズ(目安として6 GB以上)のときに、CMSと比べて有利(処理の複雑さゆえに小さなヒープサイズでは逆に非効率)。
-XX:InitiatingHeapOccupancyPercent=N
コンカレントGCのCMSInitiatingOccupancyFractionと同様。
-XX:G1MixedGCCountTarget=N
Old領域リージョンの混合GC回数目標を指定する。Concurrent Mode Failureが多発したら減らし、混合GCに時間がかかりすぎている場合は増やす。
-XX:G1HeapRegionSize=N
リージョンサイズを指定する。ヒープに割り当てるオブジェクトサイズが大きい場合は、リージョンサイズも大きくすると効率的。通常はヒープサイズに応じて、リージョン数が2048個以内になるよう1~32 MBの範囲で自動調整。
巨大な(リージョンサイズの半分以上)オブジェクトは、Old扱いとなる。オブジェクトサイズがリージョンサイズの倍数より少しだけ大きいと、未使用領域によってリージョンの断片化が発生する可能性がある。このようなケースでも大きなオブジェクトが、リージョンの半分以下のサイズとなるように調整すれば、通常のオブジェクトとしてEden相当のリージョンで割当てが行われるようになる。
チューニング目標指定
-XX:MaxGCPauseMillis=N
(最大停止時間目標)
最大停止時間の目標値を指定して、ヒープサイズを動的に変更する。
-XX:GCTimeRatio=N
(スループット目標)
GCにかけてよい時間の割合を指定して、ヒープサイズを動的に変更する(スループット目標)。GC時間のアプリケーション時間に対する比率が、$\frac{1}{(1 + N)}$となるように動的に変更する。-XX:GCTimeRatio=19
ならGC時間が全体の$\frac{1}{20}$つまり5%になるようにする。
優先度は、「最大停止時間目標」 > 「スループット目標」で、これらが満たされていれば必要に応じて最小限のヒープ領域となるようサイズを縮小する。
サイズ指定
-XmsN
ヒープの初期サイズをNで指定する。
-XmxN
ヒープの最大サイズをNで指定する。
-XmnN
(-XX:NewSize=N
)
Young領域の初期サイズを指定する。G1GCでは指定しないことが推奨(最大一時停止目標時間がオーバーライドされる)。
-XX:NewRatio=N
Young領域に対するOld領域の割合(サイズ比)を指定する。
Heap
PSYoungGen total 458752K, used 23593K [0x00000000e0000000, 0x0000000100000000, 0x0000000100000000)
eden space 393216K, 6% used [0x00000000e0000000,0x00000000e170a560,0x00000000f8000000)
from space 65536K, 0% used [0x00000000fc000000,0x00000000fc000000,0x0000000100000000)
to space 65536K, 0% used [0x00000000f8000000,0x00000000f8000000,0x00000000fc000000)
ParOldGen total 524288K, used 0K [0x00000000c0000000, 0x00000000e0000000, 0x00000000e0000000)
object space 524288K, 0% used [0x00000000c0000000,0x00000000c0000000,0x00000000e0000000)
Metaspace used 2293K, capacity 4480K, committed 4480K, reserved 1056768K
class space used 254K, capacity 384K, committed 384K, reserved 1048576K
Heap
PSYoungGen total 153088K, used 7895K [0x00000000f5580000, 0x0000000100000000, 0x0000000100000000)
eden space 131584K, 6% used [0x00000000f5580000,0x00000000f5d35dc8,0x00000000fd600000)
from space 21504K, 0% used [0x00000000feb00000,0x00000000feb00000,0x0000000100000000)
to space 21504K, 0% used [0x00000000fd600000,0x00000000fd600000,0x00000000feb00000)
ParOldGen total 873984K, used 0K [0x00000000c0000000, 0x00000000f5580000, 0x00000000f5580000)
object space 873984K, 0% used [0x00000000c0000000,0x00000000c0000000,0x00000000f5580000)
Metaspace used 2293K, capacity 4480K, committed 4480K, reserved 1056768K
class space used 254K, capacity 384K, committed 384K, reserved 1048576K
-XX:MaxNewSize=N
Young領域の最大サイズを指定する。
Heap
PSYoungGen total 448000K, used 23040K [0x00000000e0c00000, 0x0000000100000000, 0x0000000100000000)
eden space 384000K, 6% used [0x00000000e0c00000,0x00000000e22801a0,0x00000000f8300000)
from space 64000K, 0% used [0x00000000fc180000,0x00000000fc180000,0x0000000100000000)
to space 64000K, 0% used [0x00000000f8300000,0x00000000f8300000,0x00000000fc180000)
ParOldGen total 536576K, used 0K [0x00000000c0000000, 0x00000000e0c00000, 0x00000000e0c00000)
object space 536576K, 0% used [0x00000000c0000000,0x00000000c0000000,0x00000000e0c00000)
Metaspace used 2293K, capacity 4480K, committed 4480K, reserved 1056768K
class space used 254K, capacity 384K, committed 384K, reserved 1048576K
-XX:MetaspaceSize=N
メタスペースの初期サイズを指定する。
-XX:MaxMetaspaceSize=N
メタスペースの最大サイズを指定する(デフォルト無制限)。
Heap
PSYoungGen total 448000K, used 23040K [0x00000000e0c00000, 0x0000000100000000, 0x0000000100000000)
eden space 384000K, 6% used [0x00000000e0c00000,0x00000000e22801a0,0x00000000f8300000)
from space 64000K, 0% used [0x00000000fc180000,0x00000000fc180000,0x0000000100000000)
to space 64000K, 0% used [0x00000000f8300000,0x00000000f8300000,0x00000000fc180000)
ParOldGen total 536576K, used 0K [0x00000000c0000000, 0x00000000e0c00000, 0x00000000e0c00000)
object space 536576K, 0% used [0x00000000c0000000,0x00000000c0000000,0x00000000e0c00000)
Metaspace used 2293K, capacity 4480K, committed 4480K, reserved 1056768K
class space used 254K, capacity 384K, committed 384K, reserved 1048576K
-XX:InitialSurvivorRatio=N
Youn領域中のSurvivor領域の初期値比率を指定する。短命オブジェクトがOldへ昇格していることがわかっており、それを抑制したい場合に大きな値を指定する。
Heap
PSYoungGen total 232960K, used 7004K [0x00000000eab00000, 0x0000000100000000, 0x0000000100000000)
eden space 116736K, 6% used [0x00000000eab00000,0x00000000eb1d7240,0x00000000f1d00000)
from space 116224K, 0% used [0x00000000f8e80000,0x00000000f8e80000,0x0000000100000000)
to space 116224K, 0% used [0x00000000f1d00000,0x00000000f1d00000,0x00000000f8e80000)
ParOldGen total 699392K, used 0K [0x00000000c0000000, 0x00000000eab00000, 0x00000000eab00000)
object space 699392K, 0% used [0x00000000c0000000,0x00000000c0000000,0x00000000eab00000)
Metaspace used 2293K, capacity 4480K, committed 4480K, reserved 1056768K
class space used 254K, capacity 384K, committed 384K, reserved 1048576K
Heap
PSYoungGen total 279552K, used 12595K [0x00000000eab00000, 0x0000000100000000, 0x0000000100000000)
eden space 209920K, 6% used [0x00000000eab00000,0x00000000eb74ce68,0x00000000f7800000)
from space 69632K, 0% used [0x00000000fbc00000,0x00000000fbc00000,0x0000000100000000)
to space 69632K, 0% used [0x00000000f7800000,0x00000000f7800000,0x00000000fbc00000)
ParOldGen total 699392K, used 0K [0x00000000c0000000, 0x00000000eab00000, 0x00000000eab00000)
object space 699392K, 0% used [0x00000000c0000000,0x00000000c0000000,0x00000000eab00000)
Metaspace used 2293K, capacity 4480K, committed 4480K, reserved 1056768K
class space used 254K, capacity 384K, committed 384K, reserved 1048576K
Heap
PSYoungGen total 314368K, used 16773K [0x00000000eab00000, 0x0000000100000000, 0x0000000100000000)
eden space 279552K, 6% used [0x00000000eab00000,0x00000000ebb61618,0x00000000fbc00000)
from space 34816K, 0% used [0x00000000fde00000,0x00000000fde00000,0x0000000100000000)
to space 34816K, 0% used [0x00000000fbc00000,0x00000000fbc00000,0x00000000fde00000)
ParOldGen total 699392K, used 0K [0x00000000c0000000, 0x00000000eab00000, 0x00000000eab00000)
object space 699392K, 0% used [0x00000000c0000000,0x00000000c0000000,0x00000000eab00000)
Metaspace used 2293K, capacity 4480K, committed 4480K, reserved 1056768K
class space used 254K, capacity 384K, committed 384K, reserved 1048576K
値を増やすと、Youngに占めるEdenの割合が増え、Survivor(FROM/TO)の割合が減る。
$Survivor領域初期サイズ = \frac{Young領域サイズ}{InitialSurvivorRatio + 2}$
デフォルトは"8"でYoung領域の10%がSurvivor領域になる。
$Survivor領域最大サイズ = \frac{Young領域最大サイズ}{MinSurvivorRatio + 2}$
デフォルトは"3"で、Survivor領域の最大は最大Youngの20%になる。
-XX:MinSurvivorRatio=N
/-XX:TargetSurvivorRatio
それぞれSurvivor領域のサイズ、空けておきたいサイズを割合指定する。
-XX:InitialTenuringThreshold=N
/-XX:MaxTenuringThreshold=N
Survivor領域に保持しておく期間(GCの回数)の初期値、最大値を指定する。言い換えるとこれを超えるGC回数よりも長命なオブジェクトはOld領域(Tenured)へ昇格する。
-XX:-UseAdaptiveSizePolicy
ヒープの各領域サイズの調整機能を無効化する。各領域サイズをカチッとキメているときに使用する。
-XX:ParallelGCTreads=N
GCのスレッド数を指定する。デフォルトでは8コアまでコア数と同じ。9コア以降で残りコア数の5/8倍スレッド追加される、というややこしい値になる。CPUコア数がN(>8)のとき、$8 + \frac{5(N - 8)}{8}$となる。
複数JVMを起動するような環境ではデフォルトは多すぎる可能性があるので、適宜減らしたりする。
効果があるのは以下の処理。
- UseParallelGCでのYoung領域(と副作用としてのUseParallelOldGCでのOld領域)
- UseParNewGCでのYoung領域
- UseParGCでのYoung領域
- CMSおよびG1でのSTWP処理
GC情報出力設定
後述する解析ツールで事後分析するのに使う。
-verbose:gc
(-XX:+PrintGC
)
GCに関する最低限の情報(ヒープ全体のGC前後におけるサイズと所要時間)を出力する。
[GC (System.gc()) 10496K->1549K(2010112K), 0.0016090 secs]
[Full GC (System.gc()) 1549K->463K(2010112K), 0.0058750 secs]
1行目は以下のように読み取る。
- マイナーGCが(
System.gc()
によって)発生 - GC前後でヒープサイズが10,496 KBから1,549 KBになった
- JVM全体のヒープ予約サイズは2,010,112 KBである
- このGCに0.0016090秒かかった
-XX:+PrintGCDetails
全てのGCで詳細情報(各GCアルゴリズムに応じた詳細内容、例えばYoung世代がどうなったとか)を出力する。
[GC (System.gc()) [PSYoungGen: 10496K->1557K(611840K)] 10496K->1565K(2010112K), 0.0017862 secs] [Times: user=0.11 sys=0.00, real=0.00 secs]
[Full GC (System.gc()) [PSYoungGen: 1557K->0K(611840K)] [ParOldGen: 8K->463K(1398272K)] 1565K->463K(2010112K), [Metaspace: 2609K->2609K(1056768K)], 0.0080374 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
1行目は以下のように読み取る。
- マイナーGCが(
System.gc()
によって)発生 - GC前後でYoung領域サイズが10,496 KBから1,557 KBになった
- Young領域の予約サイズは611,840 KBである
- GC前後でヒープ全体のサイズが10,496 KBから1,565 KBになった
- JVM全体のヒープ予約サイズは2,010,112 KBである
- このGCに0.0017862秒かかった
2行目は以下のように読み取る。
- フルGCが(
System.gc()
によって)発生 - GC前後でYoung領域サイズが1,557 KBから0 KBになった
- Young領域の予約サイズは611,840 KBである
- GC前後でOld領域サイズが8 KBから463 KBになった
- Old領域の予約サイズは1,398,272 KBである
- GC前後でヒープ全体のサイズが1,565 KBから463 KBになった
- JVM全体のヒープ予約サイズは2,010,112 KBである
- GC前後でMetaspace領域が2,609 KBから2,609 Kになった(変わっていない)
- このGCに0.0080374秒かかった
-XX:+PrintGCApplicationConcurrentTime
最後の停止からの経過時間を出力する。
Application time: 0.0069325 seconds
-XX:+PrintGCApplicationStoppedTime
停止時間を出力する。
Total time for which application threads were stopped: 0.0093222 seconds, Stopping threads took: 0.0000362 seconds
-XX:+PrintGCTimeStamps
/-XX:+PrintGCDateStamps
GC情報出力時にタイムスタンプを付与する。+PrintGCTimeStamps
はJVM起動からの経過秒、+PrintGCDateStamps
では日付と時刻にフォーマットされる(ロケール処理等もあるので他の一般的なタイムスタンプ付与処理と同様、後者のが理屈の上ではオーバーヘッドが大きい)。
0.113: [GC (System.gc()) 10496K->1501K(2010112K), 0.0013196 secs]
0.114: [Full GC (System.gc()) 1501K->463K(2010112K), 0.0068458 secs]
2019-07-25T19:23:34.716+0900: [GC (System.gc()) 10496K->1149K(2010112K), 0.0016237 secs]
2019-07-25T19:23:34.718+0900: [Full GC (System.gc()) 1149K->463K(2010112K), 0.0073745 secs]
あまり意味はないが両方出力させることもできる。
2019-07-25T19:23:34.716+0900: 0.106: [GC (System.gc()) 10496K->1149K(2010112K), 0.0016237 secs]
2019-07-25T19:23:34.718+0900: 0.108: [Full GC (System.gc()) 1149K->463K(2010112K), 0.0073745 secs]
-XX:+PrintReferenceGC
ソフト参照と弱い参照に対して処理された内容を出力する。GCへの影響度を調べたいときに使う。
[GC (System.gc()) [SoftReference, 0 refs, 0.0000099 secs][WeakReference, 11 refs, 0.0000229 secs][FinalReference, 7 refs, 0.0000123 secs][PhantomReference, 0 refs, 0 refs, 0.0000198 secs][JNI Weak Reference, 0.0000075 secs][PSYoungGen: 20992K->811K(611840K)] 20992K->819K(2010112K), 0.0018664 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
[Full GC (System.gc()) [SoftReference, 0 refs, 0.0000082 secs][WeakReference, 3 refs, 0.0000188 secs][FinalReference, 0 refs, 0.0000044 secs][PhantomReference, 0 refs, 0 refs, 0.0000068 secs][JNI Weak Reference, 0.0000236 secs][PSYoungGen: 811K->0K(611840K)] [ParOldGen: 8K->466K(1398272K)] 819K->466K(2010112K), [Metaspace: 2555K->2555K(1056768K)], 0.0056317 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
-Xloggc:/path/to/gclog
GC情報をファイル出力する(事後分析用)。
-XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=N -XX:GCLogFileSize=size
GCログのローテーション設定。
Nは保持世代数、sizeには10Mという風にサイズを指定する。
ただし、これだと起動・停止を繰返した場合に期待通りに世代管理できない。あくまでも起動中に指定サイズ×面数のファイルを作ってくれるだけ。なので-Xloggc:/path/to/gclog%t
というようにタイムスタンプをファイル名に付与して、logrotate
あたりでコントロールするほうが融通が利く(ついでに%p
でPIDを付与することもできる)。GCログが大きくなりすぎてディスクフルになるような事態を絶対に避けるということであれば、ログの内容を失うというリスクと引換に世代数とファイルサイズでコントロールすることになる。
Java HotSpot(TM) 64-Bit Server VM (25.211-b12) for linux-amd64 JRE (1.8.0_211-b12), built on Apr 1 2019 20:39:34 by "java_re" with gcc 7.3.0
Memory: 4k page, physical 7895296k(7172276k free), swap 8257532k(8257532k free)
CommandLine flags: -XX:InitialHeapSize=126324736 -XX:MaxHeapSize=2021195776 -XX:+PrintGC -XX:+PrintGCTimeStamps -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseParallelGC
0.064: [GC (System.gc()) 1249K->328K(119808K), 0.0012307 secs]
0.065: [Full GC (System.gc()) 328K->254K(119808K), 0.0034913 secs]
ログ出力中の"CommandLine flags: "行にあるように、-Xloggc
を付与すると-XX:+PrintGC -XX:+PrintGCTimStamps
で動作する。
出力ファイルは後述の解析ツールで事後分析可能。
Heap Dump出力
-XX:+HeapDumpONOutOfMemoryError
OOME時にHeap Dumpを出力する。OOMEはGCに時間がかかりすぎている場合(具体的にはGC時間98%以上、かつヒープ回収率が2%未満のとき)に起きる。-XX:-UseGCOverheadLimit
でこの動作を変更可能。
-XX:HeapDumpPath=/path/to/heapdump
Heap Dump出力先を指定する。出力ファイルは後述の解析ツールで事後分析可能。
その他メモリ関連
-XX:SoftRefLRUPolicyMSPerMB=N
ソフト参照の存続期間を指定する。より早く解放したいなら値を小さくする。
-XX:MaxDirectMemorySize=N
ネイティブバイトバッファのメモリ使用量を指定する。
-XX:+UseLargePages
OSのLarge Pageを使用してメモリを割り当てる。
-XX:+LargePageSizeInBytes=N
Large Pageのサイズを指定する(Solaris only)。
-XX:+StringTableSize=N
intern()
で格納するネイティブメモリ上のHashTableサイズを指定する。デフォルトは1009または60013。
-XX:+UseCompressedOops
オブジェクト参照に35bitのポインタを使用する。ヒープサイズが32 GB未満ではデフォルト有効。
-XX:PrintTLAB
GCログ中にTLAB(Thread Local Allocation Buffer。Edenの一部)情報を出力する。
*TLABはTranslation Lookaside Bufferではないので注意(こちらは通常TLBと略される)
TLAB: gc thread: 0x0000000061a68000 [id: 225212] desired_size: 10496KB slow allocs: 0 refill waste: 167936B alloc: 1.00000 20992KB refills: 1 waste 100.0% gc: 10747880B slow: 0B fast: 0B
TLAB: gc thread: 0x00000000029ae000 [id: 209860] desired_size: 10496KB slow allocs: 0 refill waste: 167936B alloc: 1.00000 20992KB refills: 1 waste 94.0% gc: 10104240B slow: 0B fast: 0B
TLAB totals: thrds: 2 refills: 2 max: 1 slow allocs: 0 max 0 waste: 97.0% gc: 20852120B max: 10747880B slow: 0B max: 0B fast: 0B max: 0B
-XX:TLABSize=N
TLABサイズを指定する。
-XX:-ResizeTLAB
TLABのサイズ変更を無効にする。-XX:TLABSIZE=N
指定時は常に無効。
JITコンパイラ関連
-XX:+TieredCompilation
階層的なJITコンパイルを有効化する。クライアントコンパイラとサーバコンパイラ併用モード。ネイティブメモリを余裕をもって確保できる場合に有効。
-XX:ReservedCodeCacheSize=N
N MB単位で指定。コンパイルされたコードを格納する領域の予約サイズ。64bit Java 8でのデフォルトは240MB(TierdCompilationの場合)。必要な領域サイズを見積もることは事実上不可能なので、足りなくなったら(枯渇したというメッセージを出力したら)倍々で増やしていく。
-XX:CompileThreshold=N
JITコンパイルの閾値。この値を超えて実行されたコードはコンパイルする。サーバコンパイラではデフォルト10000。この値を小さくするとJITによるコンパイルが早く始まるので、ウォームアップ時間が短く済むが、その間のCPU使用率は上がる。裏では呼出しカウンタ(メソッドをコールするたびに増加)とバックエッジカウンタ(ループから戻るたびに増加)の和で判定する。
もうちょっとでコンパイルされて効率化されるはずなのに、というコードがあるとわかっているのであれば値を小さく設定することも有効かもしれない。
-XX:+PrintCompilation
JITコンパイラのログを出力する。
84 1 3 java.lang.String::hashCode (55 bytes)
84 2 3 java.lang.String::equals (81 bytes)
85 3 3 java.lang.String::<init> (82 bytes)
85 4 3 java.util.Arrays::copyOfRange (63 bytes)
85 6 3 java.lang.Character::toLowerCase (9 bytes)
86 9 3 java.lang.CharacterDataLatin1::getProperties (11 bytes)
86 8 3 java.lang.CharacterDataLatin1::toLowerCase (39 bytes)
86 7 3 java.lang.CharacterData::of (120 bytes)
1行目は、JVM起動から84 m秒後にコンパイルID=1として、クライアントコンパイラが完全モード(3)でStringクラスのhashCodeメソッド(Javaバイトコードで55 byteのサイズ)をコンパイルした、となる。
コンパイルのモードは以下の通り。
- 0: インタプリタ実行
- 1: クライアントコンパイラがシンプルモードでコンパイル
- 2: クライアントコンパイラが制限モードでコンパイル
- 3: クライアントコンパイラが完全モードでコンパイル
- 4: サーバコンパイラがコンパイル
階層的コンパイラを有効化しておくと、下のような出力もある。
98 23 s 3 java.lang.StringBuffer::append (13 bytes)
"s"はsynchronized
メソッドであることを表す。ほかには"%"がOSR(On Stack Replacement)コンパイル(つまりループ等実行中に当該コードをコンパイルコードに入れ替える)を、"!"は例外ハンドラを含むメソッドであることを、"n"はネイティブメソッドのラッパーであることを表す。
-XX:CICompilerCount=N
JITコンパイラが使用するスレッド数を指定する。JITコンパイラがCPUを使用しすぎているとわかっているときに減らすのに使える。デフォルトではCPUコア数とコンパイラ種別(サーバ、クライアント)に応じて変わる。
JFR関連
-XX:+FlightRecorder
-XX:+UnlockCommercialFeatures
JFRを使えるようにする。
ツール
JVM情報取得
起動しているJavaプロセスの情報を取得する
jps
jcmd -l
205220 Main
205560 Jps
205220 org/netbeans/Main --branding visualvm --cachedir /path/to/cachedir
213948 sun.tools.jcmd.JCmd
jcmdの"-l"は省略可。
JVMの起動時間を取得する
jcmd $pid VM.uptime
205220:
98108.749 s
JVMのシステムプロパティを取得する
jcmd $pid VM.system_properties
205220:
#Sat Jul 27 01:01:10 GMT+09:00 2019
java.vendor=Oracle Corporation
~略~
JVMバージョンを取得する
jcmd $pid VM.version
205220:
Java HotSpot(TM) 64-Bit Server VM version 25.192-b12
JDK 8.0_192
JVMのコマンドラインを取得する
jcmd $pid VM.command_line
205220:
VM Arguments:
jvm_args: -Xms24m -Xmx256m -Dsun.jvmstat.perdata.syncWaitMs=10000 -Dsun.java2d.noddraw=true -Dsun.java2d.d3d=false -Dnetbeans.keyring.no.master=true -Dplugin.manager.install.global=false --add-exports=java.desktop/sun.awt=ALL-UNNAMED --add-exports=jdk.jvmstat/sun.jvmstat.monitor.event=ALL-UNNAMED --add-exports=jdk.jvmstat/sun.jvmstat.monitor=ALL-UNNAMED --add-exports=java.desktop/sun.swing=ALL-UNNAMED --add-exports=jdk.attach/sun.tools.attach=ALL-UNNAMED --add-modules=java.activation -XX:+HeapDumpOnOutOfMemoryError~中略~
java_command: org/netbeans/Main --branding visualvm --cachedir /path/to/cachedir
java_class_path (initial): C:\pleiades\java\8\lib\visualvm\platform\lib\boot.jar;~中略~
Launcher Type: SUN_STANDARD
コマンドフラグを取得する
jcmd $pid VM.flags -all
205220:
-XX:CICompilerCount=18 -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=~省略~
bool NeedsDeoptSuspend = false {pd product}
bool NeverActAsServerClassMachine = false {pd product}
bool NeverTenure = false {product}
uintx NewRatio = 2 {product}
uintx NewSize := 8388608 {product}
uintx NewSizeThreadIncrease = 5320 {pd product}
-all
では-XX:+PrintFlagsFinal
を指定したときと同じ出力が得られる。"="はデフォルト値を使っていて、":="はデフォルト以外の値を使っていることを表す(つまりオプション指定あり、またはエルゴノミクスによる自動調整)。"{product}"とあるのは、プラットフォーム共通の値で、"{pd product}"となっていたらプラットフォーム固有の値。"{manageable}"となっていたら実行中に変更可能であることを表す。
jinfo -flags $pid
Attaching to process ID 205220, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 25.192-b12
Non-default VM flags: -XX:CICompilerCount=18 -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=null -XX:+IgnoreUnrecognizedVMOptions -XX:InitialHeapSize=25165824 -XX:MaxHeapSize=268435456 -XX:MaxNewSize=89128960 -XX:MinHeapDeltaBytes=524288 -XX:NewSize=8388608 -XX:OldSize=16777216 -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseFastUnorderedTimeStamps -XX:-UseLargePagesIndividualAllocation -XX:+UseParallelGC
Command line: -Xms24m -Xmx256m -Dsun.jvmstat.perdata.syncWaitMs=10000 -Dsun.java2d.noddraw=true -Dsun.java2d.d3d=false -Dnetbeans.keyring.no.master=true -Dplugin.manager.install.global=false --add-exports=java.desktop/sun.awt=ALL-UNNAMED --add-exports=jdk.jvmstat/sun.jvmstat.monitor.event=ALL-UNNAMED --add-exports=jdk.jvmstat/sun.jvmstat.monitor=ALL-UNNAMED --add-exports=java.desktop/sun.swing=ALL-UNNAMED --add-exports=jdk.attach/sun.tools.attach=ALL-UNNAMED --add-modules=java.activation -XX:+IgnoreUnrecognizedVMOptions ~省略~
jinfo -flag HeapDumpOnOutOfMemoryError $pid
-XX:+HeapDumpOnOutOfMemoryError
コマンドフラグを動的に変更する
jinfo -flag +PrintGC $pid
スレッド情報(Thread Dump、javacore)
Thread Dumpを取得する
アプリケーションがスケールしないようなときに見る。これも後述する解析ツールで事後分析するのに使う。
jstack $pid
jcmd $pid Tread.print
Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.192-b12 mixed mode):
"RequestProcessor queue manager" #97 daemon prio=1 os_prio=-2 tid=0x0000000023fb0000 nid=0x356f4 in Object.wait() [0x00000000318af000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
at org.openide.util.RequestProcessor$TickTac.obtainFirst(RequestProcessor.java:2217)
- locked <0x00000000f01753c8> (a java.lang.Class for org.openide.util.RequestProcessor$TickTac)
at org.openide.util.RequestProcessor$TickTac.run(RequestProcessor.java:2193)
~中略~
"Service Thread" #24 daemon prio=9 os_prio=0 tid=0x000000001c9af800 nid=0x30d50 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
~中略~
"Finalizer" #3 daemon prio=8 os_prio=1 tid=0x000000001a72b800 nid=0x32e08 in Object.wait() [0x000000002078f000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:144)
- locked <0x00000000f03a7018> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:165)
at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:216)
~省略~
java.lang.Thread.Stateが"BLOCKED"なら、何らかの理由(例えばsynchronizedでロック待ち状態)でブロックされていることがわかる。jstack -l
でロックに関する情報を出力できる(ハングして応答しないようなら"-F"で強制出力も可)。
またはkill -3 $pid
でも出力可能。
クラス情報
クラスのロードに関する情報を取得する
jstat -class $pid
Loaded Bytes Unloaded Bytes Time
7654 16421.5 65 94.3 2.48
GC(メモリ)関連
Heap Dumpを取得して解析する
jcmd $pid GC.heap_dump /path/to/heap.hprof
jmap -dump:format=b,file=/path/to/heap.hprof $pid
jhat /path/to/heap.hprof
jhat
でWEBサーバが起動し、"http://localhost:7000" をブラウザ等で開くとこのような形で解析結果を参照可能(ポートは-port
で指定可能)。
こちらも後述する解析ツールで事後分析するのに使う。
Heapをヒストグラム表示する
jcmd $pid GC.class_histgram
jmap -histo $pid
jmap -histo:live $pid # FullGCしてから情報取得
num #instances #bytes class name
----------------------------------------------
1: 2743 3243448 [I
2: 10371 820992 [C
3: 920 633184 [D
4: 1418 512408 [B
5: 2797 319688 java.lang.Class
6: 5282 248672 [Ljava.lang.Object;
7: 10144 243456 java.lang.String
8: 5886 188352 java.util.HashMap$Node
9: 87 156848 [J
~省略~
int
の配列("[I")がヒープの3 MB程度を占めていることがわかる。Javaの内部クラスは"<"と"%gt;"で囲まれて表示される。
ランタイム分析ツール
主にJMX(Java Management eXtensions)を使用し、起動中のJVMから情報を取得するツール類。
リモートから接続を許可するには、診断対象のJVM起動時に以下のシステムプロパティを設定する。
-Dcom.sun.management.jmxremote=true
-Dcom.sun.management.jmxremote.port=$port
-Dcom.sun.management.jmxremote.authenticate=true|false
-Dcom.sun.management.jmxremote.ssl=true|false
既に起動中のJVMであれば、以下のようにして設定する。
jcmd $pid ManagementAgent.start jmxremote.port=7091 jmxremote.authenticate=false jmxremote.ssl=false
jstat
実行中のJVMの各種統計情報を取得する。vmstat
やiostat
のJava版と思えばよい。間隔と回数を指定でき、秒単位で指定する場合は"1s"のように指定する。"s"をつけないとms単位になるので注意。最初のオプションに続いて"-t"をつけるとタイムスタンプ(JVM起動からの経過秒)をつけてくれる。
jstat -options # 使用可能なオプションを表示
jstat -option [-t] $pid [Ns|N] count
メモリ・GC関連
GC情報の取得
jstat -gc $pid
S0C S1C S0U S1U EC EU OC OU MC MU CCSC CCSU YGC YGCT FGC FGCT GCT
512.0 512.0 0.0 0.0 3072.0 2801.4 8192.0 8143.8 26240.0 25255.1 3456.0 2994.5 431 0.841 227 8.809 9.650
項目 | 意味 |
---|---|
S0C | Survivor0(From/To)領域のサイズ |
S1C | Survivor1(From/To)領域のサイズ |
S0U | Survivor0(From/To)領域の使用サイズ |
S1U | Survivor1(From/To)領域の使用サイズ |
EC | Eden領域のサイズ |
EU | Eden領域の使用サイズ |
OC | Old領域のサイズ |
OU | Old領域の使用サイズ |
MC | Metaspaceのサイズ |
MU | Metaspaceの使用サイズ |
CCSC | 圧縮クラス領域のサイズ |
CCSU | 圧縮クラス領域の使用サイズ |
YGC | Young世代のGC回数 |
YGCT | Young世代のGC時間 |
FGC | フルGC回数 |
FGCT | フルGC時間 |
GCT | 総GC時間 |
サイズはKB単位でGC回数や時間は累計。
各領域の容量
jstat -gccapacity $pid
NGCMN NGCMX NGC S0C S1C EC OGCMN OGCMX OGC OC MCMN MCMX MC CCSMN CCSMX CCSC YGC FGC
4096.0 4096.0 4096.0 512.0 512.0 3072.0 8192.0 8192.0 8192.0 8192.0 0.0 1073152.0 26496.0 0.0 1048576.0 3456.0 431 19306
GCサマリと発生理由
jstat -gccause $pid
S0 S1 E O M CCS YGC YGCT FGC FGCT GCT LGCC GCC
0.00 0.00 100.00 99.95 94.91 86.17 431 0.841 25345 952.938 953.779 Allocation Failure Ergonomics
こちらは使用率(%)。LGCC(Last GC Cause)は直前のGC理由で、GCCは今まさに実行中のGC理由。"-gccause"を"-gcutil"に変えるとLGCCとGCCが表示されない。
New領域の統計
jstat -gcnew $pid
S0C S1C S0U S1U TT MTT DSS EC EU YGC YGCT
512.0 512.0 0.0 0.0 15 15 512.0 3072.0 3072.0 431 0.841
項目 | 意味 |
---|---|
TT | 殿堂入り(Old昇格)閾値(Tenuring Threshold) |
MTT | 殿堂入り(Old昇格)最大閾値(Max Tenuring Threshold) |
DSS | 適切なSurvivor領域サイズ(KB) |
"-gcnewcapacity"とするとNew領域のサイズに関する統計を取得する。
Old領域の統計
jstat -gcold $pid
MC MU CCSC CCSU OC OU YGC FGC FGCT GCT
26496.0 25148.6 3456.0 2978.0 8192.0 8191.9 431 37158 1394.167 1395.008
同様に"-gcoldcapacity"とするとOld領域のサイズに関する統計を取得する。
なお、ヒープ情報はjcmd
でも確認可能。
jcmd $pid GC.heap_info
PSYoungGen total 3584K, used 2597K [0x00000000ffc00000, 0x0000000100000000, 0x0000000100000000)
eden space 3072K, 84% used [0x00000000ffc00000,0x00000000ffe894a0,0x00000000fff00000)
from space 512K, 0% used [0x00000000fff00000,0x00000000fff00000,0x00000000fff80000)
to space 512K, 0% used [0x00000000fff80000,0x00000000fff80000,0x0000000100000000)
ParOldGen total 8192K, used 8143K [0x00000000ff400000, 0x00000000ffc00000, 0x00000000ffc00000)
object space 8192K, 99% used [0x00000000ff400000,0x00000000ffbf3f18,0x00000000ffc00000)
Metaspace used 25255K, capacity 25956K, committed 26240K, reserved 1073152K
class space used 2994K, capacity 3312K, committed 3456K, reserved 1048576K
クラスロード統計
jstat -class $pid
Loaded Bytes Unloaded Bytes Time
4622 8810.3 399 608.7 2.58
JITコンパイル統計
jstat -compile $pid
Loaded Bytes Unloaded Bytes Time
4622 8810.3 399 608.7 2.58
jstat -printcompilation $pid
Compiled Size Type Method
5485 734 1 sun/management/GcInfoCompositeData$2 run
Typeは"-XX:+PrintCompilation"で出力するコンパイルモード。
Jconsole
JVisualvm
より高機能なJMXクライアントツール。Pluginを導入することで、Jconsole自体も統合できる。
サンプリングでスレッドごとのCPU使用率を確認したり、プロファイリングでメソッドごとの呼出し回数や処理時間を確認できる。
Heap DumpやThread Dumpファイルを開くこともできる。
OSが出力したcoreファイルを開いて、Heap DumpやThread Dumpを取得することもできる。
JMC
商用本番環境でJFRを使用するには商用ライセンスが必要。それ以外でJMCを使用する分には商用ライセンス不要。
JMXクライアントツールとして以外にアラート設定により、例えばCPU使用が閾値を超えた場合やデッドロック検出時にアクションをトリガーできる。
そして何よりも、JFR(Java Flight Recorder)による低コスト(CPUオーバーヘッドは3%程度と謳われている)なアプリケーションのプロファイリングが可能。
JFRはjcmd
からも操作できる。また、JVM起動時に商用機能を有効化していない場合は、ここで有効化もできる。
jcmd $pid VM.unlock_commercial_features
jcmd $pid VM.check_commercial_features
jcmd $pid JFR.start name=hoge duration=1m filename=~/hoge.jfr
jcmd $pid JFR.check
非純正事後解析ツール
Heap Dump解析
Eclipse Memory Analyzer(MAT)が有名。パフォーマンス上よろしくないと思われる点も指摘してくれる。オブジェクトの階層等も追いかけやすい。
Thread Dump解析
samuraiやThreadLogicが有名。
samuraiはこのようにテーブル表示させると、Heap Dump取得時点のスレッド状態遷移をグラフィカルに確認できる。ブロックされていたり(赤表示)デッドロックになっていたり(赤地に骸骨マーク)するので見つけやすい。
ThreadLogicはこのようにアドバイスも表示してくれる。Oracle(Weblogic)開発者の知見が詰まっている。
GCログ解析
GCViewerが有名。Oracle HotSpotだけでなくIBM JavaやOpenJDKにも対応している。さらにはGUIで操作できるだけでなく、コマンドラインツールとしても使用可能。
このようにグラフ描画やサマリーレポートなども出力される。スループット(ここではアプリケーションの動作時間から累積停止時間を引いた割合)やヒープの健全性としてGC後にどれくらいヒープが解放されたかも見ることができる。
付録
GCチューニングの基本
ガベージ・コレクション・チューニング・ガイド 2.エルゴノミクスを参照。
- (明らかに大容量メモリが必要となるとわかっている場合を除き)最大ヒープサイズは変更せず、必要なスループット目標を設定する
- ヒープが最大まで使われてもなおスループット目標が満たされない場合は最大ヒープサイズを大きくする
- スループット目標は達成されるが、停止時間が長すぎるなら停止の目標時間を設定する。
ヒープサイズの一般的なガイドライン
ガベージ・コレクション・チューニング・ガイド 4.世代のサイズ設定を参照。
- 一時停止時間が問題になっていなければできるだけ多くのメモリをJVMに割当てる
- 適切に選択された"-Xms"と"-Xmx"を同じ値に設定することで、JVMがサイズ調整をする負荷を軽減させる
- 割当ては並列化可能なため、CPUコア数を増やすのに伴ってメモリサイズも増加させる
- まずは物理的に割当て可能な最大(スワップしない程度)のメモリをJVMが使えるようにする("-Xms"と"-Xmx")
- Young領域に適切なサイズを実測する
コレクタ選択のガイドライン
ガベージ・コレクション・チューニング・ガイド 5.使用可能なコレクタを参照。
- ヒープが100 MB程度未満、またはシングルプロセッサ環境での実行→
-XX:+UseSerialGC
- ピーク時のスループットを優先し、1秒以上の停止時間を許容できる→
-XX:+UseParallelGC
- レスポンス時間を優先し、1秒以上の停止時間を許容できない→
-XX:+UseConcMarkSweepGC
or-XX:+UseG1GC
(ヒープサイズが6 GB以上) - G1の選択基準は以下のいずれか
- ヒープの50%以上が生きている
- オブジェクトの割当て率または昇格率の変動が大きい