Trouble 20: GCで予期しない動作が行われます
＜Q20-1＞JMSを利用しているプロジェクトにて、何度もフルGCが実行されてしまいます。
JMSのメソッドを呼び出すたびに、GCが実行されてしまいますが、JMSの呼び出し時には、必ずGCが発生するのでしょうか。
また、Javaの起動引数に "-XX:+DisableExplicitGC" オプションをつけてフルGC（ガベージコレクション）が発生しないようにすると、JMSでメモリリークが発生してしまわないでしょうか。
| ＜発生環境＞ |
| JDK |
Java 1.5.x |
| AP |
JBoss3.2.7 |
- ＜A20-1＞
- フルGCを実行しているのは、JMSが利用しているRMIです。
RMIはGCを定期的に(1分毎に)実行しており、パフォーマンス低下の原因となるため、Bug Databaseにも登録されています。
参考URL：
http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=6200091
Java6ではSystem.gc()の頻度が1時間になっているため、同様の問題は発生しません。
また、BugDatabaseでは、それ以前のバージョンについては起動オプションを指定し、10分～1時間程度にすることが推奨されています。
なお、-XX:+DisableExplicitGCを付けても、JMSではメモリリークは発生しません。
＜Q20-2＞ヒープ領域のメモリを殆ど使用していないのにFull GCに非常に時間がかかってしまいます。
ヒープ領域のメモリは殆ど使用していないにも関わらず、
Full GCの完了に非常に時間がかかる場合があります。
またファイル処理・DB処理をしていないにも関わらず、
Full GC時にディスクへのアクセスが発生します。
※JDK1.5.0で動作確認を行いました。
| ＜発生環境＞ |
| OS |
Windows XP |
| JDK |
any |
- ＜A20-2＞
- これはヒープ領域を大量に確保しているJavaプロセスが長時間実行される場合に
発生する問題です。
Javaでは、プロセスの起動時にJavaプロセスが利用するヒープ領域の確保を行います。
そのため、ヒープ領域を大量に確保するJavaプロセスでは、
ヒープ領域のうち実際に使っているメモリは少なくても、
ヒープ領域は大量に確保されている状態になります。
OSの設定によっては、一定時間利用されていないヒープ領域の一部がディスクに書き出され、
実メモリ上から無くなる場合があります。
一方、JavaのFull GCではJavaのヒープ領域の全スキャンを行います。
その結果、ヒープ領域の一部がディスクに書き出された状態でFull GCが発生すると、
ディスクに書き出されたヒープをスキャンするために、
ディスクから実メモリへの読み込みが発生します。
一般にディスクアクセスには非常に時間がかかるため、
通常短時間で終わるJavaのFull GCが、非常に長い時間のかかる処理に変わってしまいます。
この問題はヒープ領域のサイズが大きいほど顕著に現れます。
このためヒープ領域のサイズを必要最低限のサイズに設定することで、
問題発生時の影響を抑えることができます。
Javaプロセスのヒープ領域のサイズは-Xms, -Xmxオプションで指定できます。
この記事の詳細な情報をJTSメールマガジンにて配信しています。
情報を取得したい方は、メールマガジンのバックナンバーを参照して下さい。
＜Q20-3＞-verbose:gcで出力される情報がたりません。
ガベージコレクションがパフォーマンス上のボトルネックになっています。
解析のため起動オプションに「-verbose:gc」を指定しましたが、GCがかかった時刻もGCの場所も出力されないため、解析が難航しています。
なにか良い手はありませんか？
| ＜発生環境＞ |
| OS |
Any |
| JDK |
JDK1.4 |
| Vender |
Sun |
- ＜A20-3＞
- 「-XX:+PrintGCTimeStamps」と「-XX:+PrintGCDetails」を指定することで、それぞれGCのタイムスタンプとGCの詳細情報が得られます。
(例1) -verbose:gcのみ
[GC 2198K->150K(3520K), 0.0200894 secs]
意味：
・GCにより、トータルヒープ使用サイズが2198KBから150KBになった
・GCによる停止時間は0.0200894秒
(例2) -XX:+PrintGCTimeStamps、-XX:+PrintGCDetailsを指定
4.12082: [GC 4.12096: [DefNew: 2048K->0K(2112K), 0.0003650 secs] 2198K->150K(3520K), 0.0004982 secs]
意味：
・アプリケーションを起動してから 4.12082秒経過
・New世代のガベージコレクションで New世代の使用サイズが2048KBから0KBになった
・マイナーコレクション(New世代のみを対象としたGC)による停止時間は0.0003650秒
・トータルヒープ使用サイズは2198KBから150KBになった
・全ガベージコレクションによる停止時間は0.0004982秒
またその他の主要なGC関連オプションとして、以下のようなものがあります。
| オプション |
得られる情報 |
| -Xloggc:filename |
GC情報をファイル出力 |
| -XX:+PrintTenuringDistribution |
オブジェクトの年齢情報 |
| -XX:+TraceGen0Time |
New世代の累積GC回数、総時間、平均時間 |
| -XX:+TraceGen1Time |
Old世代の累積GC回数、総時間、平均時間 |
| -XX:+PrintHeapAtGC |
GC前後のヒープ情報 |
ひととおり出力情報を参照しておくと、後々役立つでしょう。
注意：本文書の内容に誤りがあり、またこの文書によって不利益を被っても、
エスエムジー株式会社は一切関知いたしません。
Copyright(c) SMG Co., Ltd. All Rights Reserved.