MultiLogAnalyzer (2)

Javaのスレッドダンプ解析について、軽く語ってみる。

スレッドダンプを取得すると、JavaVM上で動作している全てのスレッドの情報を得ることができる。
各スレッドについて、次のような行で、基本的な情報が表示される。

"D3D Screen Updater" daemon prio=8 tid=0x0670a000 nid=0x2da0 in Object.wait() [0x0649f000..0x0649f2f0]

これは、windows上のGUIアプリで取得したもの。
どう読み取ればよいかというと、こんな感じ。(言葉の意味が分からなければ、適当にググってくれ)

項目名 上記の場合の例 Javaプログラム上で取得しようとすると
名前 "D3D Screen Updater" Thread#getName()
デーモンスレッドか否か デーモンスレッド Thread#isDaemon()
優先度 8 Thread#getPriority()
スレッドID 0x0670a000 よう分からん
ネイティブID(OSにマッピングされているスレッドのID) 0x2da0 LinuxならLWPIDが該当/windowsは知らない
状態 in Object.wait() 下記表参照(Thread#getState()とは異なる)
スタックアドレスの範囲 0x0649f000〜0x0649f2f0 Java上では取得不可

で、特に注目したいのが、スレッドの状態。
次の中のいずれかが表示される。

状態値 適当すぎる意訳
allocated スレッドが生成された状態
initialized スレッドが初期化された状態
runnable スレッドが動作可能な状態
waiting for monitor entry スレッドが、モニタに入ろうとして待機している状態(ロック取得待ち)
waiting on condition スレッドが、とある状態に達するまで待たされている状態
in Object.wait() スレッドが、Object#wait()を呼び出して待機している状態
sleeping スレッドが、スリープ中の状態

スレッドダンプを解析するときは、状態が「waiting for monitor entry」とか、「waiting on condition」とか、「in Object.wait()」を探す。たとえばオブジェクトプールの数が十分でなく、プールからオブジェクトを取ろうとして詰まっていると、「in Object.wait()」の状態が多く出る。synchronizedブロックで排他制御で処理性能が劣化していたりすると、「waiting for monitor entry」が多く出る。

問題は、「in Object.wait()」だからと言って、必ずしもよろしくない状態だと決めつけられないこと。むしろ、多くの「in Object.wait()」は問題ない「in Object.wait()」。じゃあ、どうやって善悪を判断するかというと、スレッドのスタックとレースや名前から判断する。

たとえば、Tomcatなら、TP-Processorから始まるスレッドが、Apache/mod_jkからのリクエストを処理するスレッドになる。だから、こいつらで「in Object.wait()」なんて出ると、色々と思いを巡らせる。でも、「"D3D Screen Updater"」なんかは、基本が「in Object.wait()」なので、問題にはならない。

あと、スレッドダンプには、各スレッドが現在実行中の処理がスタックとレースで表示されるので、どこで排他制御を食らってるかとかを読み取る。この場所から、問題のある状態か否かを判断したりする。

この辺は、Javaプログラムのトラブルシュートを数回繰り返すと、どのスレッドがどの状態にあるのが普通で、何が普通じゃないかがだいたい感覚的に把握できたりする。そのうち、スレッドダンプをスクロールするだけで、故障原因を見つけられたりするようになる。それができるようになれば、網膜の残像だけでスレッドダンプを解析する男と呼ばれるようになるかも。

あと、スタックサイズとかは、処理の呼び出しの深さを確認したりするのに使う。スタックオーバーフローが良く発生するなら、このあたりの値を参考にして、スタックサイズを調整して回避できるかも。まあ、ふつうはそんな調整はお目にかかれない。てか、その前にプログラムを直す。Java6までは、Javaはスタックサイズが大きくならない傾向にあるから必要ないテクニックだけど、エスケープ解析がデフォルトオンになるJava7だと、役に立つかもしれないテクニック。

よくJavaプロセスが終了しないと聞かれる。そういうときは、デーモンでないスレッドを探したりする。

OSで取得した情報と付き合わせるときは、ネイティブIDをキーにしてExcelなんかで集計したりすると、非常に高度な解析テクを披露できるようになる。そうすると、ふつうのスレッドダンプ解析使いから一目置かれる存在になれる。ふつうはそこまで頑張らないけど、お金をもらえれば、すごく頑張ります。頑張りすぎたせいで、ベンダが半月かけて解析できなかったトラブルを、半日でシュンサツしてしまい、時間単金で解析したりしてるせいか、お客さんには喜ばれるけど売り上げ低くて上司からは怒られる破目になる。

詳しくは、そのうち。

で、それらのノウハウが微妙に凝縮されてるかもしれない、「Multi Log Analyzer for Java」を使うとどうなるか。

まだまだ凝縮度が足りない。