このページで解決しない高度なJavaのシステム障害はJaTSにお任せください

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ではメモリリークは発生しません。
Page Top

<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メールマガジンにて配信しています。
 情報を取得したい方は、メールマガジンのバックナンバーを参照して下さい。

Page Top

<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前後のヒープ情報

ひととおり出力情報を参照しておくと、後々役立つでしょう。
Page Top

注意:本文書の内容に誤りがあり、またこの文書によって不利益を被っても、
Acroquest Technology 株式会社は一切関知いたしません。

  • 現象別Index
  • 原因別Index

Find Bugsバグ詳細

Find Bugs Bug Descriptions日本語版

RSSで更新情報を取得する

RSSとは、ホームページの更新情報を配信する為のフォーマットです。
RSSを利用すると、登録したページの情報が更新された場合に、更新情報を自動的に受け取る事ができます。

詳細

弊社小森が執筆致しました

Javaでオブジェクト指向開発

Javaプログラミング言語習得において、新人プログラマーの最初の障害は「オブジェクト指向の壁」です。
本書は、Javaのソフトウェア開発を中心に事業を発展させてきたAcroquest社の新人教育セミナーを加筆・書籍化したもので、大卒の新人に対して、ゼロからJava言語を教えてきた実績をフィードバックしています。

メールマガジン配信中

Javaトラブルシューティングのメルマガをはじめました!是非ご購読ください

詳細