エスエムジーでは、Java全般を対象にしたトラブルシューティングサービス「JaTS」を提供しています。 この記事では、前回に引き続き、JaTSにて蓄積したトラブル事例とその解決ノウハウの一部をお送りしている「Javaトラブルシューティングメールマガジン」(JTSMM)の総集編として、過去2ヶ月のトラブル事例と追加情報をダイジェストとして提供いたします。
8月~9月にかけて、JTSMMでは以下のトラブルを扱いました。
 ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄
■「メモリリークしているオブジェクトが一般的なため、発生箇所が特定できません。」【JTSMM vol.005-006】
________________________________
[問題]
長時間プログラムを実行することで、メモリリークが発生していることは確認できました。
しかし、メモリリークしているオブジェクトjava.util.Dateがプログラムの様々な場所で使われており、メモリリークの発生箇所を特定できません。
[解説]
以下の理由でメモリリークしているオブジェクトの特定が困難な場合があります。
- 該当クラスがソースコードの様々な場所で使われている
- データ構造が複雑で該当クラスと関連するクラスが分からない
このような場合には、該当クラスがどの場所で利用され、メモリリークしているかを分析する必要があります。
今回はパフォーマンスの低下が少なく網羅的な調査ができる、Javaのヒープダンプ結果についてjhatを利用した解析方法を紹介します。
■jhatを使ったヒープダンプの解析
ヒープダンプ結果の解析はJDK6.0より追加になったコマンドjhatを使います。jhatコマンドは次のように利用します。
> jhat heap.bin
jhatの起動が完了したら、ブラウザで、http://localhost:7000/ にアクセスします。その後、以下の手順でヒープダンプの解析を行います。
- 該当クラスのインスタンス数を確認します。
- 複数の該当クラスのうち1つのインスタンス情報を表示します。
- インスタンスの参照元を確認します。
- 関連している該当クラスのインスタンス数を調べます。
- ヒープ全体のインスタンス数と比較します。
今回は画像を示しながらjhatの使い方をお伝えします。
説明には、メールマガジン vol.005に掲載したサンプルプログラムを利用します。
また、ヒープダンプの取得方法についても、メールマガジン vol.005をご覧ください。
- 該当クラスのインスタンス数を確認 トップページには、次のように表示されているはずです。
- 複数の該当クラスのうち1つのインスタンス情報を表示 "instances of class java.util.Date"という文字列の"instances"のリンクをクリックすると、java.util.Dateの全インスタンス情報が表示されます。
- インスタンスの参照元を確認 表示されたインスタンス情報の"Reference to this object"に注目します。
- 3の結果から、該当クラスのインスタンス数を確認 1~3の操作で、メモリリークが発生している可能性が高いクラスを確認することができました。しかし、そのクラスのインスタンスが原因だと特定するために は、ヒープ全体でのインスタンス数を調べる必要があります。今回は、3で確認したLinkedHashMapの要素数を調べる必要があります。
- ヒープ全体のインスタンス数と比較し、原因を特定 1で確認したヒープ全体でのjava.util.Dateのインスタンス数と4で確認したLinkedHashMapが管理する java.util.Dateのインスタンス数が同じ値になっているため、LinkedHashMapの要素数増加がメモリリークの原因と考えられます。
"Show instance counts for all classes (including platform)"をクリックして各クラスのインスタンス数を確認します。
他のクラスのインスタンス数に比べるとjava.util.Dateのインスタンスが桁違いに大量に発生していることがわかります。

java.util.Dateのインスタンスの一つをクリックして、詳細情報を表示します。

これはこのインスタンスの参照元一覧を示しています。 今回の場合は一つしか参照元がないため、この参照元インスタンスをクリックして辿っていきます。

辿ったリンクの先も、何かしらのクラスのインスタンス情報になっています。
今回は「Arrays of 679 objects」となっているように、679個の要素を持つ配列だと分かります。
更にこのインスタンス情報から、順に参照元を辿っていくことが出来ます。

先ほどの配列は、elementDataというメンバ名でjava.util.ArrayListのインスタンスから参照されているようです。
このArrayListも1つのインスタンスから参照されていますので、参照元を辿っていきます。

java.util.LinkedHashMapの内部クラスのインスタンスにたどり着きました。
"References to this object"から3箇所から参照されていることが分かりますが、ここでは1番目に表示されている「before」フィールドのインスタンスを参照元として辿っていきます。

先ほどと同じくjava.util.LinkedHashMapの内部クラスです。
先ほどとほぼ同じ3箇所から参照されていることが分かるため、「before」以外の参照を辿ることにします。次は、「Element 3662 of [...]」を辿ります。

配列のインスタンス情報にも参照元へのリンクがあるため、さらに参照元を辿ります。

最終的にLinkedHashMapまで辿ることができました。
ここまでの内容から、LinkedHashMapのインスタンスで要素が増加していることが、メモリ使用量増加の原因になっている可能性が高くなります。
ヒープ内の解析には、ヒープダンプ内のオブジェクト情報を、jhatが提供している解析言語OQLを使うのが便利です。 トップページから"Execute Object Query Language (OQL) query"をクリックし、以下のクエリを実行します。 表示される結果がLinkedHashMapに関連しているjava.util.Dateのインスタンス数です。

このように多機能なjhatですが、現在のjhatには大きな制限があります。
現在公開されているJDK 6.0u7までのjhatでは、ファイルアクセスの実装に問題があるため、データサイズが2GBを超えるダンプファイルの解析に失敗します。 このため、ヒープメモリの使用量が2GBを超過したプロセスのヒープダンプについて、jhatで解析することは出来ません。
2GB以上のダンプファイルを解析した場合には、コンソールに以下のエラーメッセージが表示され、異常終了します。
$ jhat -J-mx512m java_pid24928.hprof.1218444379104 Reading from java_pid24928.hprof.1218444379104... Dump file created Mon Aug 11 17:46:48 JST 2008 java.io.IOException: Bad record length of -1997781102 at byte 0xa4f089 of file. at com.sun.tools.hat.internal.parser.HprofReader.read(HprofReader.java:192) at com.sun.tools.hat.internal.parser.Reader.readFile(Reader.java:79) at com.sun.tools.hat.Main.main(Main.java:143)
この不具合すでにbugdatabaseにも報告されています。先日公開されたJava6の最新版、Java6u10にて修正されています。
このため、現時点では正式リリース前となりますが、2G以上のヒープダンプを取得する場合には、Java6u10nのインストールが必要になります。 この問題については、Bug Databaseにも登録されています。
[参考]http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=6614052
 ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄ ̄
[対策]
■「メモリを大量確保しないアプリケーションでOutOfMemoryErrorが発生しました。」【JTSMM vol.007】
________________________________
[問題]
複数のWebアプリケーションをtomcat上で動かしています。 メモリを大量確保していないアプリケーションばかりなのですが、長時間運用しているとOutOfMemoryErrorが発生してしまい、tomcatが異常終了してしまいます。
[解説]
この現象はJava VMのPermanent領域が大量に必要な場合に発生します。
tomcatなどのように、起動した後に外部のjarファイルを読み込んで実行する仕組みをもったプログラムの場合、起動した後にもPermanent領域への情報追加が行われる場合があります。
この情報追加が大量に行われるプログラムの場合には、デフォルトで決められたPermanent領域が枯渇してしまい、ヒープが枯渇した場合と同じように、OutOfMemoryErrorが発生して、プログラムが強制終了してしまいます。
Permanent領域のサイズを指定するには-XX:MaxPermSizeオプションを利用します。-Xmxオプションはヒープのメモリサイズを設定するオプションですので、Permanent領域のサイズとは別になることにご注意ください。
Permanent領域のデフォルトでのサイズはJavaのバージョンやモードによって異なります。
permanent領域のOutOfMemoryErrorは、発生時にはスタックトレースから発生箇所が特定できます。しかし、発生前に問題の兆候を確認したりするには、jstatなどを使いメモリ使用量の変化を解析する必要があります。
通常この処理は定型的な処理が確定しておらず、また、リアルタイムに解析が行えないため、手間がかかります。
当社のENdoSnipeでは、メモリリーク検出機能を提供し、従来の方法に比べて容易に行うことが可能です。 プログラムにENdoSnipeを適用することで、下図のようにメモリリークの発生をグラフィカルに確認することができます。
ENdoSnipeは、他にも、システムを診断しパフォーマンスに影響を与える各種問題を検出する機能など、障害解析/障害解決に役立つ様々な機能を備えています。詳細は、ENdoSnipeの製品ページをご覧下さい。
FindBugsのバグ詳細の日本語訳を公開しました
メルマガ vol.007 でもお伝えしましたが、SMGではJTSMMの発行と並行して、FindBugsのバグ詳細についての日本語版の公開を始めました。
FindBugs は、事実上Java開発の必須ツールとなりつつある静的解析ツールですが、レポートとして出力されるバグのパターン(バグ詳細)が英語で記述されているた め、英語が母国語でない日本の開発者にとっては簡単には対処策が分からないのが実情だと思います。そこで、日本国内におけるFindBugsの効果的利用 のため、バグ詳細を順次日本語訳し、公開を行うことにいたしました。リリースされたばかりのFindBugs 1.3.5の追加バグ詳細も含め、全バグ詳細を公開する予定ですので、開発の効率化にご活用ください。
FindBugsバグ詳細の日本語版はこちらからご覧ください。
以上、Vol.007までのJTSMMのダイジェストをお送りしました。
Javaトラブルシューティングメールマガジンは、2週間を目処に不定期で無料配信しております。メールマガジンの無料配信登録は、こちらから行うことができます。メールマガジンでは、これからもJavaのトラブル解決に役立つ情報をお届けして参ります。
ダイジェストにつきましては、次回は11月末を予定しております。ご期待下さい。