33
30

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?

More than 5 years have passed since last update.

Javaパフォーマンス関連覚書

Last updated at Posted at 2019-07-28

Javaの主にパフォーマンスに関連するオプションとツールの覚書。

前提

  • Java 1.8
  • Java HotSpot(TM) 64-Bit Server VM

コマンドラインオプション

GCアルゴリズムとヒープサイズ

シリアルGC

-XX:+UseSerialGC

単一スレッドのGCを使う。いわゆるサーバマシンでJavaEE基盤となるJVMに対して使う利点はほぼなさそうだが、ヒープサイズが100 MB程度以下で済むようなマイクロなJVMを複数起動するような場合ではアリかもしれない。

-XX:+AggressiveHeap

大きなヒープを単一のJVMに割り当てられる状況で有利に動くようにオプションが割り当てられる、なかば投げやりなオプション。

AggressiveHeap,PringFlagsFinal
     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領域の割合(サイズ比)を指定する。

NewRatio=1
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
NewRatio=5
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領域の最大サイズを指定する。

NewSize=500M,MaxNewSize=500M
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

メタスペースの最大サイズを指定する(デフォルト無制限)。

MetaspaceSize=100M,MaxMetaspaceSize=100M
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へ昇格していることがわかっており、それを抑制したい場合に大きな値を指定する。

InitialSurvivorRatio=1
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
InitialSurvivorRatio=5
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
InitialSurvivorRatio=10
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では日付と時刻にフォーマットされる(ロケール処理等もあるので他の一般的なタイムスタンプ付与処理と同様、後者のが理屈の上ではオーバーヘッドが大きい)。

PrintGCTimeStamps+PrintGC
0.113: [GC (System.gc())  10496K->1501K(2010112K), 0.0013196 secs]
0.114: [Full GC (System.gc())  1501K->463K(2010112K), 0.0068458 secs]
PrintGCDateStamps+PrintGC
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]

あまり意味はないが両方出力させることもできる。

PrintGCDateStamps+PintGCTimeStamps+PrintGC
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への影響度を調べたいときに使う。

+PrintGCDetails,+PrintReferenceGC
[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ログが大きくなりすぎてディスクフルになるような事態を絶対に避けるということであれば、ログの内容を失うというリスクと引換に世代数とファイルサイズでコントロールすることになる。

/path/to/gclogYYYY-mm-dd_HH-MM-SS
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
jps
205220 Main
205560 Jps
jcmd
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
-allなし
205220:
-XX:CICompilerCount=18 -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=~省略~
-all指定(抜粋)
     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
jstack/jcmd
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で指定可能)。

image.png

こちらも後述する解析ツールで事後分析するのに使う。

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の各種統計情報を取得する。vmstatiostatの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

基本的な機能を持ったJMXクライアントツール。
image.png

JVisualvm

より高機能なJMXクライアントツール。Pluginを導入することで、Jconsole自体も統合できる。
サンプリングでスレッドごとのCPU使用率を確認したり、プロファイリングでメソッドごとの呼出し回数や処理時間を確認できる。
image.png
image.png

Heap DumpやThread Dumpファイルを開くこともできる。
image.png

OSが出力したcoreファイルを開いて、Heap DumpやThread Dumpを取得することもできる。
image.png

JMC

商用本番環境でJFRを使用するには商用ライセンスが必要。それ以外でJMCを使用する分には商用ライセンス不要。
JMXクライアントツールとして以外にアラート設定により、例えばCPU使用が閾値を超えた場合やデッドロック検出時にアクションをトリガーできる。
image.png

そして何よりも、JFR(Java Flight Recorder)による低コスト(CPUオーバーヘッドは3%程度と謳われている)なアプリケーションのプロファイリングが可能。
image.png

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)が有名。パフォーマンス上よろしくないと思われる点も指摘してくれる。オブジェクトの階層等も追いかけやすい。

image.png

image.png

Thread Dump解析

samuraiThreadLogicが有名。

image.png

samuraiはこのようにテーブル表示させると、Heap Dump取得時点のスレッド状態遷移をグラフィカルに確認できる。ブロックされていたり(赤表示)デッドロックになっていたり(赤地に骸骨マーク)するので見つけやすい。

image.png
ThreadLogicはこのようにアドバイスも表示してくれる。Oracle(Weblogic)開発者の知見が詰まっている。

GCログ解析

GCViewerが有名。Oracle HotSpotだけでなくIBM JavaやOpenJDKにも対応している。さらにはGUIで操作できるだけでなく、コマンドラインツールとしても使用可能。

image.png
このようにグラフ描画やサマリーレポートなども出力される。スループット(ここではアプリケーションの動作時間から累積停止時間を引いた割合)やヒープの健全性として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%以上が生きている
    • オブジェクトの割当て率または昇格率の変動が大きい

参考情報

33
30
0

Register as a new user and use Qiita more conveniently

  1. You get articles that match your needs
  2. You can efficiently read back useful information
  3. You can use dark theme
What you can do with signing up
33
30

Delete article

Deleted articles cannot be recovered.

Draft of this article would be also deleted.

Are you sure you want to delete this article?