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