Hello World! ソーシャルネットワーク事業部の、jyukutyoこと阪田です。

僕らのアプリケーションでOutOfMemoryError(OOME)が発生しました!ログからある程度原因は推測できましたが、確信は持てません。そこでヒープダンプを解析することにしました。

前提

よく言われていることですので確認にはなりますが、JVMの起動オプションに必ず-XX:-HeapDumpOnOutOfMemoryErrorをつけましょう。これでOOME発生時に自動的にヒープダンプが取られます。 また、OOME発生後はJVMの動作は保証されませんので、発生したら必ずJVMを再起動しましょう!

本題

OOMEが発生したサーバに入ると、ヒープダンプがファイルとして出力されています。Javaを実行したディレクトリに「java_pid9999.hprof」という形式のファイルがあります。とても大きいサイズのファイルで、今回は4.3GBでした。

さて、ヒープダンプの内容から分析したいのですが、ヒープダンプの解析はツールの助けを借りなければとても進められません。いくつかツールがありますが、今回は「Eclipse Memory Analyzer(mat)」を使うことにしました。matはhttps://eclipse.org/mat/からダウンロードできます。Eclipse Foundationが作成しているツールなのでEclipseプラグインとしてUpdate Managerからインストールすることもできますし、スタンドアローン版もあります。

今回はスタンドアローン版を使いました。では実際に起きたOOMEのヒープダンプを使いながら、matを使って分析していきたいと思います!

matを起動すると、以下のような画面が表示されます。

スクリーンショット 2015-01-09 16.06.26

メニューのFile -> Open Heap Dumpでヒープダンプのファイルを選択します。次に、ダイアログが出るので「Leak Suspects Report」を選びます。今回はメモリリークを疑っているためです。

スクリーンショット 2015-01-09 16.24.29

しばらく解析処理が走った後、Overview画面が表示されます。さっそくでリークの疑いがどこにあるのか見てみましょう。Overview画面の下部にある、ReportsからLeak Suspectsをクリックしてください。Leak Suspects画面が表示されます。

スクリーンショット 2015-01-08 18.17.53

おや、(a)が3.4GBを占めており、「Problem Susp…(Suspect)」となっています。どうも問題があるようです。Problem Suspect 1を開いてみます。

スクリーンショット 2015-01-09 16.36.46

net.rubyeye.xmemcached.impl.MemcachedTCPSessionのインスタンスが600あり、ヒープの85.28%を占めています!これはxmemcachedというmemcachedのJavaクライアントに含まれるものです。1つのインスタンスで200MB弱もヒープを使っているものがあるようですね。 ほかのビューも見てみます。

スクリーンショット 2015-01-08 18.20.48

スクリーンショット 2015-01-08 18.19.59

スクリーンショット 2015-01-08 18.19.37

スクリーンショット 2015-01-08 18.18.56

どのビューを見ても、今回はxmemcachedが何らかの理由で大量のヒープを使ってしまっているということを表しています。ここからさらに原因を…となるのですが、matを使った分析はここで終わりです。 なお、memcached自体を調べたところ、こちらにはとくに問題がありませんでした。memcachedクライアントの変更を考えています。

まとめ

matを使うと、ヒープダンプを可視化してくれるため、分析の大きな助けとなります。もしアプリケーションでOOMEが発生したら、すぐにmatをダウンロードして解析させましょう! ではみなさん楽しいJVMライフをお過ごしください!

関連するかもしれない記事