次のような場合には,ログに出力された内容やAPIで取得した内容を基に,メモリサイズをチューニングします。
これらの場合に必要な確認・調査方法について説明します。
Explicitヒープのある時点での利用状況(スナップショット)を調査する方法には,スレッドダンプを確認する方法と,Java APIで情報を取得する方法があります。
Explicit Heap Status |
Explicitヒープの利用状況の推移を調査する方法には,明示管理ヒープ機能のイベントログを確認する方法と,Java APIで情報を取得する方法があります。Java APIを使用する方法については,「(1) Explicitヒープのある時点での利用状況(スナップショット)の調査」で示したAPIを使用します。
ここでは,明示管理ヒープ機能のイベントログを使用した調査方法について説明します。
JavaVMの-XX:HitachiExplicitMemoryLogLevelオプションに「normal」を指定します。これによって,次のタイミングでExplicitヒープの利用状況が出力されます。
また,JavaVMの-XX:HitachiExplicitMemoryLogLevelオプションに「verbose」を指定すると,「normal」で出力されるタイミングに加えて,次のタイミングでExplicitヒープの利用状況が出力されるようになります。
出力例を次に示します。
[ENS]<Thu Oct 21 14:55:50 2007>[EH: 12672K->12800K(12800K/65536K)][E/F/D: 200/0/0][cause:GC][CF: 0] |
太字で示した「EH:」で始まる部分が,Explicitヒープの利用状況を示します。ログに出力された内容のうち,Explicitヒープの利用状況を示す行には,必ず太字に該当する情報が含まれます。この値をグラフなどに記してプロットすることによって,利用状況の推移を確認できます。
なお,利用状況を示すログの先頭は,[ENS]または[EVS]で開始されます。この文字列でイベントログをフィルタリングすると,利用状況を確認しやすくなります。
JavaVMの-XX:HitachiExplicitMemoryLogLevelオプションに「verbose」を指定します。これによって,次のタイミングでサイズ変化のあったExplicitメモリブロックの利用状況が出力されます。
出力例を示します。
[ENS]<Thu Oct 21 14:55:50 2007>[EH: 11422K->12800K(12800K/65536K)][E/F/D: 200/0/0][cause:GC][CF: 0] |
太字で示した部分が,「"REM2"」という名称の一つのExplicitメモリブロックについての利用状況を示します。
また,-XX:HitachiExplicitMemoryLogLevelオプションに「verbose」を指定した場合,Explicitメモリブロックの解放時に,解放したExplicitメモリブロックの情報が出力されます。出力例を示します。
[ENS]<Tue Jul 24 01:23:51 2007>[EH: 12800K->11776K(11776K/65536K), 0.1129602 secs][E/F/D: 523/0/0]¥ |
太字で示した部分が,解放された「"REM2"」という名称のExplicitメモリブロックの情報を示しています。「320K」は,解放されたメモリのサイズ(確保済みだったExplicitメモリブロックのサイズ)です。
これらの値をグラフなどに記してプロットすることによって,Explicitメモリブロックごとの利用状況の推移を確認できます。なお,個々のExplicitメモリブロックのサイズは,解放するまで単調増加します。
Explicitヒープあふれが発生した場合の確認と対処について説明します。
Explicitヒープあふれとは,次の状態を示します。
Explicitヒープあふれが発生すると,発生後に領域を拡張しようとしたExplicitメモリブロックのサブ状態が,「Enable」から「Disable」に変わります。「Disable」になったExplicitメモリブロックには,オブジェクトを配置できません。
Explicitヒープあふれが発生しているかどうかは,明示管理ヒープ機能のイベントログまたはスレッドダンプの内容から調査できます。また,Java APIで取得した情報で確認することもできます。
Explicitヒープあふれが発生した場合は,次の対処を実施してください。
Explicitヒープあふれが発生した場合の対処
ここでは,Explicitヒープあふれが発生しているかどうかの確認方法について説明します。
明示管理ヒープ機能のイベントログで調査をするためには,あらかじめJavaVMの-XX:HitachiExplicitMemoryLogLevelオプションに「normal」を指定しておく必要があります。これによって,ガーベージコレクションが発生するごとに,明示管理ヒープ機能のイベントログにExplicitメモリブロックの利用状況が出力されるようになります。
出力例を示します。
[ENS]<Thu Oct 21 14:55:50 2007>[EH: 12672K->12800K(12800K/65536K)][E/F/D: 200/0/0][cause:GC][CF: 0] |
太字で示した部分が,Explicitメモリブロックの数を示しています。「E」および「D」は,Explicitメモリブロックのサブ状態である「Enable」および「Disable」を表します。「Disable」のExplicitメモリブロックがある場合は,Explicitヒープあふれが発生しています。この例の場合は,「Enable」のExplicitメモリブロックが200個あり,「Disable」のExplicitメモリブロックはないことがわかります。なお,「Disable」のExplicitメモリブロックがある場合は,Explicitヒープ最大サイズとの関係を確認してください。Explicitヒープ最大サイズまでに余裕があるときには,OSからのメモリ確保に失敗していることが考えられます。
また,JavaVMの-XX:HitachiExplicitMemoryLogLevelオプションに「verbose」を指定した場合,Explicitメモリブロックのサブ状態が「Disable」になった要因も出力されます。
出力例を示します。
[EVO]<Tue Jul 24 01:23:51 2007>[alloc failed(Disable)][EH: 32760K(0K)/32768K/65536K][E/F/D: 321/0/1][cause:GC]¥ |
この例は,Explicitヒープあふれが発生した場合の例です。
太字で示した部分のうち,[alloc failed(Disable)]が,Explicitメモリブロックのサブ状態が「Disable」になった要因を示します。["BasicExplicitMemory-3" eid=3/B: 128K(0K)/128K]は,「Disable」になったExplicitメモリブロックの情報を示します。また,[EVO][Thread: 0x00035a60]で始まる行は,イベントが発生した時のスタックトレースを表しています。ただし,ガーベージコレクションによるオブジェクトの移動でExplicitヒープあふれが発生した場合,スタックトレースは出力されません。
cjdumpsvコマンドなどを使用してスレッドダンプを出力することによって,各Explicitメモリブロックのサブ状態を出力できます。
出力例を次に示します。
Explicit Heap Status |
太字で示した部分が,それぞれのExplicitメモリブロックのサブ状態を表しています。
次に示すメソッドを使用して,Explicitメモリブロックのサブ状態を調査できます。
これらのメソッド両方の戻り値がfalseの場合,そのExplicitメモリブロックのサブ状態はDisableと判断できます。
Explicitメモリブロックの初期化が失敗した場合の確認と対処について説明します。
Explicitメモリブロックの数が最大になると,それ以上Explicitメモリブロックを初期化できなくなります。
この場合は,Explicitメモリブロックの数を減らしてください。
ここでは,Explicitメモリブロックの初期化が失敗しているかどうかの確認方法について説明します。
明示管理ヒープ機能イベントログで調査をするためには,あらかじめJavaVMの-XX:HitachiExplicitMemoryLogLevelオプションに「normal」を指定しておく必要があります。これによって,ガーベージコレクションが発生するごとに,Explicitメモリブロックの初期化に失敗した回数が明示管理ヒープ機能イベントログに出力されるようになります
出力例を示します。
[ENS]<Thu Oct 21 14:55:50 2007>[EH: 12672K->12800K(12800K/65536K)][E/F/D: 200/0/0][cause:GC][CF: 0] |
太字で示した部分が,前回の出力から今回の出力までの間にExplicitメモリブロックの初期化に失敗した回数です。この例の場合は,「0」です。初期化失敗が発生していない,問題のない状態です。
また,JavaVMの-XX:HitachiExplicitMemoryLogLevelオプションに「verbose」を指定した場合,Explicitメモリブロックの初期化失敗イベントについての情報も出力されます。
出力例を示します。
[EVO]<Tue Jul 24 01:23:51 2007>[Creation failed][EH: 32760K(0K)/32768K/65536K][E/F/D: 65535/0/0][Thread: 0x00035a60] |
太字で示した部分で,Explicitメモリブロック初期化に失敗したことが確認できます。また,[EVO][Thread: 0x00035a60]で始まる行は,イベントが発生した時のスタックトレースを示しています。
さらに,JavaVMの-XX:HitachiExplicitMemoryLogLevelオプションに「debug」を指定した場合,初期化に失敗したイベント以外のExplicitメモリブロック初期化イベントの詳細情報が出力されます。Explicitメモリブロック数が一定以上になると,初期化は失敗します。このため,初期化に失敗する前の初期化イベントの情報が,調査に役立つことがあります。
出力例を次に示します。
[EVO]<Tue Jul 24 01:23:51 2007>[Created]["BasicExplicitMemory-2" eid=2(0x1234568)/B][Thread: 0x00035a60] |
太字で示した部分で,Explicitメモリブロック初期化イベントであることが確認できます。また,[EDO][Thread: 0x00035a60]で始まる行は,イベントが発生した時のスタックトレースを示しています。
スレッドダンプで出力された情報からは,Explicitメモリブロック初期化失敗の直接要因は確認できませんが,Explicitメモリブロックの個数は調べられます。
出力例を次に示します。
Explicit Heap Status |
太字で示した部分がExplicitメモリブロックの個数を示しています。
次に示すメソッドを使用して,Explicitメモリブロックの個数を調査できます。
ただし,このAPIでは,Explicitメモリブロック初期化失敗の直接の要因は確認できません。
Explicitメモリブロックの解放処理時に,解放対象のExplicitヒープ内のオブジェクトに対する参照があると,参照されているオブジェクトおよびそのオブジェクトから直接または間接的に参照されているオブジェクトがJavaヒープに移動します。オブジェクトは,Tenured領域に優先的に移動されます。このため,移動が多いとTenured領域の利用済みサイズが増加して,フルガーベージコレクション発生の要因となってしまいます。
Javaヒープへの移動が発生したかどうかは,日立JavaVMログファイルの拡張verbosegc情報または明示管理ヒープイベントログで調査できます。
明示管理ヒープ機能を利用しない場合,Tenured領域の利用済みサイズの増加は,コピーガーベージコレクションだけで発生します。このため,N回目のコピーガーベージコレクション終了後のTenured領域利用済みサイズは,N+1回目のコピーガーベージコレクション開始前のTenured領域利用済みサイズと一致します。
これに対して,ExplicitヒープからJavaヒープへのオブジェクトの移動が発生した場合は,Explicitヒープ解放時にTenured領域の利用済みサイズが増加します。この差分から,Explicitメモリブロック解放処理時にオブジェクトの移動が発生したことが確認できます。
N回目のコピーガーベージコレクション終了後のExplicitメモリブロック解放処理時にJavaヒープに移動したオブジェクトのサイズは,次の式で算出できます。
ExplicitヒープからJavaヒープに移動したオブジェクトのサイズ |
JavaVMの-XX:HitachiExplicitMemoryLogLevelオプションに「none」以外を指定した場合,Explicitメモリブロックの解放処理についてのログが出力されます。このログでは,Explicitメモリブロック解放処理時のTenured領域利用済みサイズの増加を直接確認できます。
出力例を次に示します。
[ENS]<Tue Jul 24 01:23:51 2007>[EH: 12800K->11776K(11776K/65536K), 0.1129602 secs][E/F/D: 523/0/0]¥ |
太字で示した部分のうち,[cause:Reclaim]は,Explicitメモリブロック解放処理時に出力された情報であることを示します。また,[DefNew::Eden: 0K->0K(243600K)][DefNew::Survivor: 0K->0K(17400K)][Tenured: 103400K->103464K(556800K)]の部分は,Explicitメモリブロック解放処理時のJavaヒープの変化を示しています。この例の場合は,Tenured領域のメモリサイズが103,400キロバイトから103,464キロバイトに,64キロバイト分増えています。このことから,Explicitメモリブロックの解放処理で,64キロバイトのオブジェクトがJavaヒープに移動していることがわかります。
また,JavaVMの-XX:HitachiExplicitMemoryLogLevelオプションに「verbose」を指定した場合,解放されたExplicitメモリブロックについての情報も出力されます。これによって,どのExplicitメモリブロックの解放でTenured領域利用済みサイズが増加したかを確認できます。
出力例を次に示します。
[ENS]<Tue Jul 24 01:23:51 2007>[EH: 12800K->11776K(11776K/65536K), 0.1129602 secs][E/F/D: 523/0/0]¥ |
太字で示した部分が,解放されたExplicitメモリブロックを示しています。出力内容から,Javaヒープに移動した64キロバイトのオブジェクトが,「REM2」「BEM3」「BEM1」のどれかのExplicitメモリブロックから移動したことがわかります。
さらに,JavaVMの-XX:HitachiExplicitMemoryLogLevelオプションに「debug」を指定した場合,解放処理をしたときに解放対象Explicitヒープ内のオブジェクトを参照していたオブジェクトが確認できます。
出力例を次に示します。
[EDO][eid=3: Reference to ClassZ(0x1234680), total 64K] |
[eid=3: Reference to ClassZ(0x1234680), total 64K]の部分から,次のことがわかります。
また,「ClassU(0x1233468)(Tenured)」の部分から,"ClassZ"のインスタンスを参照しているオブジェクトが"ClassU"のインスタンスであることがわかります。
これらの情報を基に,Explicitメモリブロック解放処理時にそのExplicitメモリブロック内のオブジェクトへの参照をなくすように,Javaプログラムを修正してください。