7.14.2　利用状況の推移の調査

(1)　Explicitヒープの利用状況の推移

JavaVMの-XX:HitachiExplicitMemoryLogLevelオプションに「normal」を指定します。これによって，次のタイミングでExplicitヒープの利用状況が出力されます。

• GC発生時（定期的）

• Explicitメモリブロックの明示解放処理時

• Explicitメモリブロックの自動解放処理時

また，JavaVMの-XX:HitachiExplicitMemoryLogLevelオプションに「verbose」を指定すると，「normal」で出力されるタイミングに加えて，次のタイミングでExplicitヒープの利用状況が出力されるようになります。

• ExplicitMemory.newInstanceメソッドなどによるExplicitメモリブロックへのオブジェクト生成時

出力例を次に示します。

[ENS]<Thu Oct 21 14:55:50 2007>[EH: 12672K->12800K(12800K/65536K)][E/F/D: 200/0/0][cause:GC][CF: 0]
[ENS]<Thu Oct 21 14:55:50 2007>[EH: 12800K->12800K(12800K/65536K), 0.1124626 secs][E/F/D: 200/0/0]\
[DefNew::Eden: 0K->0K(243600K)][DefNew::Survivor: 0K->0K(17400K)][Tenured: 103400K->103400K(556800K)]\
[target:584K/0K/584K][cause:Migrate]

背景色付きの太字で示した「EH:」で始まる部分が，Explicitヒープの利用状況を示します。ログに出力された内容のうち，Explicitヒープの利用状況を示す行には，必ず背景色付きの太字に該当する情報が含まれます。この値をグラフなどに記してプロットすることによって，利用状況の推移を確認できます。

この例の場合，「cause:」で始まる部分に示すとおり，一つ目の[ENS]で始まる行はCopyGC（GC）発生時に出力されたログであり，二つ目の[ENS]で始まる行はExplicitメモリブロックの自動解放処理（Migrate）時に出力されたログであることがわかります。1行目のログでは，CopyGC発生前のExplicitヒープの利用済みサイズは12,672キロバイト，発生後のExplicitヒープの利用済みサイズは12,800キロバイトであることがわかります。2行目のログでは，Explicitヒープの利用済みサイズは12,800キロバイト，Explicitメモリブロックの自動解放処理に0.1124626秒掛かったことがわかります。

なお，利用状況を示すログの先頭は，[ENS]または[EVS]で開始されます。この文字列でイベントログをフィルタリングすると，利用状況を確認しやすくなります。

ページの先頭へ

(2)　Explicitメモリブロックごとの利用状況の推移

JavaVMの-XX:HitachiExplicitMemoryLogLevelオプションに「verbose」を指定します。これによって，次のタイミングでサイズ変化のあったExplicitメモリブロックの利用状況が出力されます。

• Explicitメモリブロックへのオブジェクト移動時

• Explicitメモリブロックへのオブジェクト生成時

出力例を示します。

[ENS]<Thu Oct 21 14:55:50 2007>[EH: 11422K->12800K(12800K/65536K)][E/F/D: 200/0/0][cause:GC][CF: 0]
[EVS]["REM2" eid=2/R: 0K->88K(128K)]["REM3" eid=3/R: 30K->230K(256K)]["REM6" eid=6/R: 30K->200K(256K)]\
["Session1" eid=8/R: 30K->250K(256K)]["Session2" eid=10/R: 30K->250K(256K)]
[EVS]["Session3" eid=12/R: 30K->510K(512K)]

背景色付きの太字で示した部分が，「"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]\
[DefNew::Eden: 0K->0K(243600K)][DefNew::Survivor: 12K->0K(17400K)][Tenured: 103400K->103400K(556800K)][cause:Reclaim]
[EVS]["REM2" eid=2/R: 320K]["BEM3" eid=5/B: 320K]["BEM1" eid=7/B: 384K]

背景色付きの太字で示した部分が，解放された「"REM2"」という名称のExplicitメモリブロックの情報を示しています。「320K」は，解放されたメモリのサイズ（確保済みだったExplicitメモリブロックのサイズ）です。

これらの値をグラフなどに記してプロットすることによって，Explicitメモリブロックごとの利用状況の推移を確認できます。なお，個々のExplicitメモリブロックのサイズは，解放するまで単調増加します。

ページの先頭へ