ガーベジ・コレクション(GC)に関するデータを分析して、GCにかかる時間や、Javaヒープの使用量などを調べる方法について説明します。
GCに関する重要なデータは、GCログです。GCログを参照すると、各GCの処理時間、GCの発生頻度、Javaヒープ使用量の変化などを調べることができます。
GCログを出力するには、Javaの起動オプションに、次のオプションを追加してください。
JDK/JRE 7の場合:-verbose:gc -XX:+UseFJverbose
JDK/JRE 8の場合:-verbose:gc -XX:+PrintGCDetails -XX:+PrintGCTimeStamps
オプションを指定すると、次のようなGC発生時の情報が、標準出力に出力されます。
図A.4 GCログの例(JDK/JRE 7 パラレルGCの場合)
GCログの解析で特に注目するのは、図A.4 GCログの例(JDK/JRE 7 パラレルGCの場合)に示す6個の情報です。
(1) Java VMが起動されてからの経過時間。単位は秒
(2) GCの種別
(3) GC処理実行後のNew世代領域に存在するオブジェクトの総量。単位はバイト
(4) GC処理実行後のOld世代領域に存在するオブジェクトの総量。単位はバイト
(5) (3)と(4)の合計
(6) GC処理に要した時間。単位は秒
ポイント
JDK/JRE 7ではオプション-XX:FJverboseTimeを使うと、(1)の情報に日時を含めることもできます。詳しくは、“チューニングガイド”の“ログ出力における時間情報のフォーマット指定機能”を参照してください。
GCログは、アプリケーションの開発中や運用中を問わず、トラブル発生時の重要な情報です。上記オプションを常に設定することをお薦めします。
GCログを出力することによって、パフォーマンスが低下することは、ほとんどありません。
JDK/JRE 7でJava監視機能を有効にしている場合は、アプリケーションが起動したあとでも、GCログの出力設定を変更できます。
詳しくは、「A.5.8 VMオプションの変更」を参照してください。
まず、処理時間(図A.4 GCログの例(JDK/JRE 7 パラレルGCの場合)の(6))が長いGCがあるかどうかを確認します(以降の説明では、処理時間が長いGCのことを「長時間GC」と表現します)。
ポイント
GCの処理時間として許容される値はアプリケーションによって異なりますが、1秒以上かかるようなGCは、アプリケーションの性能に影響している可能性が考えられます。
アプリケーションに、レスポンス遅延などの問題が発生している場合は、長時間GCの発生時刻と問題の発生時間を照らし合わせます。それらが一致する場合、GCによってアプリケーションが長時間停止し、性能問題を引き起こした可能性が考えられます。
そのような場合は、長時間GCの発生を防ぐように、Javaヒープをチューニングしてください。チューニングに関する詳しい説明は、“チューニングガイド”を参照してください。
JDK/JRE 7
“JDK/JRE 7のチューニング” - “チューニング方法” - “Javaヒープのチューニング”
JDK/JRE 8
“JDK/JRE 8のチューニング” - “チューニング方法” - “Javaヒープのチューニング”
アプリケーションの性能に影響するような長時間GCが存在しない場合は、生存オブジェクト量の推移を確認します。
ここでは、GC処理実行後に存在するオブジェクトのことを、便宜的に「生存オブジェクト」と表現します。
生存オブジェクトの量は、GCログ(図A.4 GCログの例(JDK/JRE 7 パラレルGCの場合))の(5)に当たります。この値をプロットしてグラフを作成すると、生存オブジェクトの量が増加傾向にあるかどうかが分かります。
以下は、生存オブジェクトの量をプロットしてグラフを作成した例です。
図A.5 生存オブジェクト量が増加傾向にある例
生存オブジェクトの量が増え続けている場合は、メモリリークが発生している可能性があります。
そのような場合は、「A.6.5 メモリリークを分析する」を参照して、メモリリークが発生しているかどうかを調べてください。
動作中のプロセスに対してjstatコマンドを使うと、Javaヒープの使用状況を分析できます。jstatコマンドは、JDKに付属しています。
ただし、jstatは、定期的にJavaプロセスの情報を採取するツールです。GCログのように、GC処理実行後のJavaヒープの使用量(生存オブジェクトの量)を正確に調べるのには向いていませんので、注意してください。
jstatコマンドでJavaヒープの使用状況を調べるには、次のようにコマンドを実行します。
図A.6 jstatコマンド実行の例
ポイント
「-h」オプションを使うと、定期的にヘッダが表示されるので、出力が長くなっても、どの列が何を示すのか分かります。
図A.6 jstatコマンド実行の例のようにjstatコマンドを実行すると、次のような結果を得られます。ここで注目すべきは、OUの列です。OUは、Old世代領域の使用量を示しています。
図A.7 jstatコマンドの実行結果の例(JDK7)
この例では、Old世代領域の使用量が、増加しつづけています。これは、生存オブジェクトが増え続けていることを意味しています。つまり、メモリリークが発生している可能性が考えられます。