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