2014年2月15日土曜日

javaのOutOfMemory時のヒープの分析にチャレンジ(jhat)

javaアプリでOUtOfMemoryが出ているので、ちょっとヒープの中身を見てみた。

環境は以下の通り

 ・OOMの出た環境
  OS:CentOS 6.4(64bit)
  tomcat:6.0.35
  Java:1.6.0_30

 ・解析につかったPC(自作PC)
  OS:Windows8.1
  CPU:3.2GHz 1P4C
  MEMORY:16GB
  Tool:Java1.7標準でついてくるjhatとEclipseのMemoryAnalyzer

まずはjhatで試してみた。

1.解析対象となるヒープのダンプデータをゲット

 hprofによるheapdumpの取得をする。今回は事前に仕込んでいたが、Javaの起動引数で

  -XX:+HeapDumpOnOutOfMemoryError

 をつけると、OOMが出たときに、java_pid[xxxx.]hprofというヒープのダンプが出力される。
 別途の監視システムでOutOfMemoryが出たら自動再起動という仕組みを入れている場合は、
 出力仕切る前にサービス再起動されてしまうので、要注意。

 今回ヒープが大きかった(Heap 2GB/Perm 512MB)からか、hprofのサイズが3GBにもなった。

 ※参考
   http://docs.oracle.com/javase/jp/7/technotes/samples/hprof.html

2.jhatにかましてみる

 上記でゲットしたhprofファイルをjhatで開いてみる。

 #jhat  java_pid24328.hprof

 結構いいPCを使っているなのだが、CPUが張り付いた。でもっていつまでたっても終わらない。
 プロセスを見るとメモリが(PrivateWorkingSet)が3GB付近で止まっている。何か怪しい・・
 ということで、オプションをつけて再度確認

 #jhat  -J-verbose:gc java_pid24328.hprof
 
 GCが結構な頻度で実行されている。

 #jhat  -J-verbose:gc -J-mx6000m -J-ms6000m java_pid24328.hprof

 で再実行。さっきよりはもちろん頻度は落ちたが、まだFullGCが出る(そしてFullGC 1回に15秒くらいかかっている)。だんだんFullGCの頻度が上がってきた。。まだ足りないか・・
 
 #jhat  -J-verbose:gc -J-mx10000m -J-ms10000m java_pid24328.hprof

 Dump file created Wed Feb 12 19:45:24 JST 2014
 [GC 2560512K->2161709K(9814016K), 1.7790619 secs]
 [GC 4722221K->4292917K(9814016K), 2.2919729 secs]
 [GC 6853429K->6801901K(9814016K), 2.9861100 secs]
 [Full GC 6801901K->6401515K(9814016K), 27.1854356 secs]
 Snapshot read, resolving...
 Resolving 56763698 objects...
 [Full GC 8962027K->6641624K(9814016K), 29.9023006 secs]
 [Full GC 9202136K->6313543K(9814016K), 27.5518345 secs]
 Chasing references, expect 11352 dots................................
 ........................................................................................................................
 (ドットが11352個出たのかな)
 ........................................................................................................................
 Snapshot resolved.
 Started HTTP server on port 7000
 Server is ready.

で完了した。結構時間かかった。こんなのサーバ上でやれないですね(hprofの出力を絞ればいいのかな)。

3.結果をみる

 ブラウザで、http://127.0.0.1:7000/ で見てみる。

 これだとよくわからないなぁとおもったので、最後のほうにある「Show heap histogram」をクリックしてみたら、、これまたレスポンスが返ってこない。。(GCが出ているわけでもない)。
10分たってもレスポンスが返ってこないので、、諦めました。やはりでかすぎたのかな。ということで、次回MemoryAnalyzerに期待。


0 件のコメント:

コメントを投稿