JVM パフォーマンス チューニングおよび監視ツールの使用に関する詳細な説明

[[280944]]

実際のエンタープライズ レベルの Java アプリケーションの開発と保守では、次のような問題に遭遇することがあります。

• OutOfMemoryError、メモリ不足
• メモリリーク
• スレッドデッドロック
• ロック競合
• JavaプロセスがCPUを大量に消費する
• ......

これらの問題は、日常の開発や保守において多くの人が無視するかもしれません (たとえば、上記の問題に遭遇したときに、問題の根本原因を掘り下げずに、単にサーバーを再起動したり、メモリを増やしたりする人もいます)。しかし、これらの問題を理解して解決できることは、Java プログラマーが進歩するために必要な要件です。この記事では、議論の出発点となることを目指して、一般的に使用されている JVM パフォーマンス チューニングおよび監視ツールをいくつか紹介します。

さらに、運用・保守、開発、テストのいずれの場合でも、これらの監視およびチューニング ツールの使用方法を習得する必要があります。

A. jps (Java 仮想マシン プロセス ステータス ツール)

jps は主に、JVM で実行されているプロセスのステータス情報を出力するために使用されます。構文の形式は次のとおりです。

 jps [オプション] [ホストID]

hostid が指定されていない場合は、現在のホストまたはサーバーがデフォルトになります。

コマンドラインパラメータオプションは次のように記述されます。

 -q はクラス名、Jar 名、およびメインメソッドに渡されるパラメータを出力しません。
 -mはメインメソッドに渡されたパラメータを出力します
-l メインクラスまたはJarの完全修飾名を出力します
-vはJVMに渡されたパラメータを出力します

例えば：

ルート@ubuntu:/# jps -m -l
 2458 org.artifactory.standalone.main.Main /usr/ローカル/artifactory-2.2.5/etc/jetty.xml
 29920 com.sun.tools.hat.Main -port 9998 /tmp/dump.dat
 3149 org.apache.catalina.startup.Bootstrap の開始
30972 sun.tools.jps.Jps -m -l
 8247 org.apache.catalina.startup.Bootstrap の開始
25687 com.sun.tools.hat.Main -port 9999 dump.dat
 21711 mrf-center.jar

B. スタック

jstack は主に、Java プロセス内のスレッド スタック情報を表示するために使用されます。構文の形式は次のとおりです。

 jstack [オプション] pid
 jstack [オプション] 実行可能コア
jstack [オプション] [server-id@]remote-hostname-または-ip

コマンドラインパラメータオプションは次のように記述されます。

 -l 長いリストでは、追加のロック情報が出力されます。デッドロックが発生した場合、jstack -l pid を使用してロックの保持状態を観察できます。 -m 混合モードでは、Java スタック情報だけでなく、C/C++ スタック情報 (ネイティブ メソッドなど) も出力されます。

jstack はスレッド スタックを見つけることができます。スタック情報に基づいて特定のコードを見つけることができるため、JVM パフォーマンス チューニングで広く使用されています。 Java プロセスで最も CPU を消費する Java スレッドを見つけて、スタック情報を探す例を見てみましょう。使用されるコマンドは、ps、top、printf、jstack、grep です。

最初のステップは、Java プロセス ID を見つけることです。サーバーにデプロイした Java アプリケーションの名前は mrf-center です。

 root@ubuntu:/# ps -ef | grep mrf-center | grep -v grep
ルート 21711 1 1 14:47 pts/3 00:02:10 java -jar mrf-center.jar

プロセス ID は 21711 です。2 番目のステップは、プロセス内で CPU を最も消費するスレッドを見つけることです。 ps -Lfp pid または ps -mp pid -o THREAD, tid, time または top -Hp pid を使用できます。ここでは3番目を使います。出力は次のようになります。

TIME 列は、各 Java スレッドによって消費された CPU 時間です。 CPU 時間が最も長いスレッドはスレッド ID 21742 です。

 printf "%x\n" 21742

21742 の 16 進数値は 54ee であり、以下で使用されます。

さて、次のステップでは、ついに jstack の出番です。jstack は、プロセス 21711 のスタック情報を出力するために使用され、次のようにスレッド ID の 16 進値に従って grep されます。

ルート@ubuntu:/# jstack 21711 | grep 54ee
 "PollIntervalRetrySchedulerThread" prio=10 tid=0x00007f950043e000 nid=0x54ee in Object.wait [0x00007f94c6eda000]

PollIntervalRetrySchedulerThread クラスの Object.wait によって CPU が消費されていることがわかります。自分のコードを探したところ、次のコードを見つけました。

 // アイドル待機
getLog.info( "スレッド[" + getName() + "]はアイドル状態で待機しています..." );
スケジューラスレッド状態 = PollTask​​SchedulerThreadState.IdleWaiting;
 long now = System.currentTimeMillis;
長い待機時間 = 現在 + getIdleWaitTime;
 long timeUntilContinue = waitTime - 現在;
 synchronized(sigLock) {try {
 if(!停止.get) {
 sigLock.wait(継続するまで待機)。
 }
 } キャッチ (InterruptedException を無視) {
 }
 }

ポーリングタスクのアイドル待機コードです。上記の sigLock.wait(timeUntilContinue) は、前の Object.wait に対応します。

C. jmap (メモリマップ) と jhat (Java ヒープ分析ツール)

jmap はヒープメモリの使用量を表示するために使用され、通常は jhat と組み合わせて使用​​されます。

jmap の構文形式は次のとおりです。

 jmap [オプション] pid
 jmap [オプション] 実行可能コア
jmap [オプション] [server-id@]remote-hostname-または-ip

64 ビット JVM 上で実行している場合は、-J-d64 コマンド オプション パラメータを指定する必要がある場合があります。

 jmap -permstat pid

プロセスのクラス ローダーと、クラス ローダーによってロードされた永続生成オブジェクトの情報を印刷し、次の図に示すように、クラス ローダー名、オブジェクトが生きているかどうか (信頼できない)、オブジェクトのアドレス、親クラス ローダー、ロードされたクラスのサイズなどを出力します。

jmap -heap pid を使用して、使用されている GC アルゴリズム、ヒープ構成パラメータ、各世代のヒープ メモリ使用量など、プロセスのヒープ メモリ使用量を表示します。たとえば、次の例をご覧ください。

 root@ubuntu:/# jmap -heap 21711
プロセス ID 21711に接続しています。お待ちください...
デバッガーが正常に接続されました。
サーバーコンパイラが検出されました。
 JVMバージョンは20.10-b01です
 
スレッドローカルなオブジェクト割り当てを使用します。
 4スレッドによる並列GC 
 
ヒープ構成:
最小ヒープ空き率 = 40
最大ヒープ空き率 = 70
最大ヒープサイズ = 2067791872 (1972.0MB)
新しいサイズ = 1310720 (1.25MB)
最大新規サイズ = 17592186044415 MB
古いサイズ = 5439488 (5.1875MB)
新しい比率 = 2
生存率 = 8
パーマサイズ = 21757952 (20.75MB)
最大パーミッションサイズ = 85983232 (82.0MB) 
 
ヒープ使用量:
 PS 若い世代
エデンスペース:
容量 = 6422528 (6.125MB)
使用済み = 5445552 (5.1932830810546875MB)
空き= 976976 (0.9317169189453125MB)
 84.78829520089286% 使用済み
から 空間：
容量 = 131072 (0.125MB)
使用済み = 98304 (0.09375MB)
空き= 32768 (0.03125MB)
 75.0%使用
に 空間：
容量 = 131072 (0.125MB)
使用済み = 0 (0.0MB)
無料= 131072 (0.125MB)
 0.0% 使用済み
PS 旧世代
容量 = 35258368 (33.625MB)
使用済み = 4119544 (3.9287033081054688MB)
空き= 31138824 (29.69629669189453MB)
 11.683876009235595% 使用済み
PSパーマ生成
容量 = 52428800 (50.0MB)
使用済み = 26075168 (24.867218017578125MB)
空き= 26353632 (25.132781982421875MB)
 49.73443603515625% 使用済み
....

jmap -histo[:live] pid を使用して、ヒープ メモリ内のオブジェクトの数とサイズの統計ヒストグラムを表示します。 live が含まれる場合、次のようにライブ オブジェクトのみがカウントされます。

 root@ubuntu:/# jmap -histo:live 21711 |もっと
num #インスタンス #バイト クラス名-------------------------------------------------  
 1: 38445 5597736 <constMethodKlass>
 2: 38445 5237288 <メソッドクラス>
 3: 3500 3749504 <定数プールクラス>
 4: 60858 3242600 <symbolKlass>
 5: 3500 2715264 <インスタンスクラスクラス>
 6: 2796 2131424 <定数プールキャッシュクラス>
 7: 5543 1317400 [私
8: 13714 1010768 [C
 9: 4752 1003344 [B
 10: 1225 639656 <メソッドデータクラス>
 11: 14194 454208 java.lang.String
 12: 3809 396136 java.lang.クラス
13: 4979 311952 [S
 14: 5598 287064 [[私
15: 3028 266464 java.lang.reflect.メソッド
16: 280 163520 <objArrayKlassKlass>
 17: 4355 139360 java.util.HashMap$エントリ
18: 1869 138568 [Ljava.util.HashMap$Entry;
 19: 2443 97720 java.util.LinkedHashMap$エントリ
20: 2072 82880 java.lang.ref.SoftReference
 21: 1807 71528 [Ljava.lang.Object;
 22: 2206 70592 java.lang.ref.WeakReference
 23: 934 52304 java.util.LinkedHashMap
 24: 871 48776 java.beans.メソッド記述子
25: 1442 46144 java.util.concurrent.ConcurrentHashMap$HashEntry
 26: 804 38592 java.util.HashMap
 27: 948 37920 java.util.concurrent.ConcurrentHashMap$セグメント
28: 1621 35696 [Ljava.lang.Class;
 29: 1313 34880 [Ljava.lang.String;
 30: 1396 33504 java.util.LinkedList$エントリ
31: 462 33264 java.lang.reflect.フィールド
32: 1024 32768 java.util.Hashtable$Entry
 33: 948 31440 [Ljava.util.concurrent.ConcurrentHashMap$HashEntry;

クラス名はオブジェクト タイプで、次のようになります。

 Bバイト
C文字 
 Dダブル 
 Fフロート 
私は 
 J ロング
Z ブール値
[ 配列、例えば [I はint []を意味します
[L+クラス名その他のオブジェクト

もう 1 つの一般的な状況は、jmap を使用してプロセスのメモリ使用量をファイルにダンプし、jhat を使用してそれを分析して表示することです。 jmap dump コマンドの形式は次のとおりです。

 jmap -dump:format=b,file=dumpFileName pid

上記のプロセス ID 21711 もダンプしました。

 root@ubuntu:/# jmap -dump:format=b,file=/tmp/dump.dat 21711
ヒープを/tmp/dump.datにダンプしています...
ヒープダンプファイルが作成されました

ダンプされたファイルは、MAT や VisualVM などのツールを使用して表示できます。ここでは jhat を使用して表示します。

 root@ubuntu:/# jhat -port 9998 /tmp/dump.dat
 /tmp/dump.datから読み込んでいます...
ダンプ ファイルは Tue Jan 28 17:46:14 CST 2014 に作成されました。スナップショットを読み取り、解決しています...
 132207 個のオブジェクトを解決しています...
参照を追跡すると、26 個のドットが予想されます........................
重複参照の削除.............................
スナップショットが解決されました。
ポート 9998でHTTP サーバーを起動しました。サーバーの準備が整いました。

ダンプ ファイルが大きすぎる場合は、最大ヒープ メモリを指定するために -J-Xmx512m などのパラメータ (つまり、jhat -J-Xmx512m -port 9998 /tmp/dump.dat) を追加する必要がある場合があります。次に、ブラウザにホストアドレス 9998 を入力して表示します。

上記の赤枠で囲んだ部分を自分で探索することができます。最後の項目は OQL (Object Query Language) をサポートします。

D. jstat (JVM 統計監視ツール)

構文の形式は次のとおりです。

 jstat [ 一般オプション |出力オプション vmid [間隔[秒|ミリ秒] [カウント]] ]

vmid は Java 仮想マシン ID であり、通常は Linux/Unix システム上のプロセス ID です。間隔はサンプリング時間間隔です。 count はサンプルの数です。たとえば、次の出力は、サンプリング間隔が 250 ミリ秒でサンプリング数が 4 の GC 情報を示しています。

ルート@ubuntu:/# jstat -gc 21711 250 4
 S0C S1C S0U S1U EC EU OC OU PC PU YGC YGCT FGC FGCT GCT
 192.0 192.0 64.0 0.0 6144.0 1854.9 32000.0 4111.6 55296.0 25472.7 702 0.431 3 0.218 0.649
 192.0 192.0 64.0 0.0 6144.0 1972.2 32000.0 4111.6 55296.0 25472.7 702 0.431 3 0.218 0.649
 192.0 192.0 64.0 0.0 6144.0 1972.2 32000.0 4111.6 55296.0 25472.7 702 0.431 3 0.218 0.649
 192.0 192.0 64.0 0.0 6144.0 2109.7 32000.0 4111.6 55296.0 25472.7 702 0.431 3 0.218 0.649

上記の列の意味を理解するには、まず JVM ヒープ メモリ レイアウトを確認します。

次のことがわかります。

ヒープメモリ = 若い世代 + 古い世代 + 永久世代
若い世代 = エデンエリア + 2 つのサバイバーエリア ( FromとTo )

それでは、各列の意味を説明しましょう。

 S0C、S1C、S0U、S1U: サバイバー 0/1 ゾーンの容量と使用法
EC、EU: エデン地域の容量と使用状況
OC、OU: 旧世代の容量と使用量
PC、PU: 永久発電容量と使用量
YGC、YGT: 若い世代のGC時間とGC時間
FGC、FGCT:フルGC 回数とフルGC 期間
GCT: 合計GC時間

E. hprof (ヒープ/CPU プロファイリング ツール)

Hprof は CPU 使用率を表示し、ヒープメモリの使用量をカウントできます。

構文の形式は次のとおりです。

 java -agentlib:hprof[=オプション] ToBeProfiledClass
 java -Xrunprof[:options] プロファイル対象クラス
javac -J-agentlib:hprof[=オプション] ToBeProfiledClass

完全なコマンド オプションは次のとおりです。

オプション 名前 および値の説明デフォルト 
 --------------------- ----------- -------  
ヒープ=ダンプ|サイト|すべてヒーププロファイリングすべて 
 cpu=サンプル|回|古いCPU使用率オフ 
 monitor=y|n モニター競合 n
 format=a|b text(txt)または バイナリ 出力​
file=<file> java.hprof[.txt]ファイルにデータを書き込みます
net=<host>:<port> ソケット経由でデータを送信 
 depth=<サイズ> スタックトレースの深さ 4
 interval=<ms> サンプル間隔（ミリ秒） 10
 cutoff=<値>出力カットオフポイント 0.0001
 lineno=y|n トレースの行番号?ええ
thread=y|nトレース内のスレッドですか?ん
doe=y|n 終了時にダンプしますか?ええ
msa=y|n Solaris マイクロステートアカウンティング n
力=y|n力 出力  <ファイル> yへ
verbose=y|n ダンプに関するメッセージを出力します y

公式ガイドからの例をいくつか紹介します。

CPU 使用率サンプリング プロファイリングの例 (cpu=samples):

 java -agentlib:hprof=cpu=samples,interval=20,depth=3 こんにちは

上記は、スタック深度 3 で 20 ミリ秒ごとにサンプリングされた CPU 消費情報です。生成されたプロファイル ファイル名は java.hprof.txt で、現在のディレクトリにあります。

CPU 使用時間プロファイリングの例 (cpu=times)。 CPU 使用率サンプリング プロファイルと比較すると、各メソッド呼び出しの開始と終了に至るまで、より詳細な CPU 消費情報を取得できます。その実装ではバイトコード インジェクション テクノロジー (BCI) を使用します。

 javac -J-agentlib:hprof=cpu=times Hello.java

ヒープ割り当てプロファイリングの例 (heap=sites):

 javac -J-agentlib:hprof=heap=sites Hello.java

上記のヒープ割り当てプロファイリングよりも詳細なヒープ ダンプ情報を生成できるヒープ ダンプ (heap=dump) の例:

 javac -J-agentlib:hprof=heap=dump Hello.java