こんにちは、寺岡です。
今回は、アプリケーションのトラブルを調査する際に役立つスレッドダンプについて書いてみたいと思います。

スレッドダンプって何？

スレッドダンプとは、ある時点の全てのスレッドのスタックトレースを出力したものです。

スタックトレースとは現在のスレッドのメソッドの呼び出し階層を出力したもので、例外が発生した時なんかによく見かけるアレのことです。

javaプロセス内部では複数のスレッドが並列に処理を行っています。
Tomcatなどのサーブレットは複数のスレッドを使ってリクエストを処理しますし、シングルスレッドのシンプルなアプリケーションでもGCなどの処理は専用のスレッドが処理を行っています。

スレッドダンプを取得するとは、プロセス内の全スレッドに対して「ちょっとお前ら、今何やってるの？」と聞いて回るようものです。

スレッドダンプを取る前に……

とりあえずtopコマンドくらいは叩いておきましょう。

特に気をつけてみたい箇所に背景色をつけています。

右上のロードアベレージがCPUコア数を大幅に超過しており、プロセスのCPU利用率が高い状態が続いている場合、そのプロセスが何らかの計算処理でCPUを使いきっている可能性が高いです。
CPU利用率の最大はCPUコア数×100%となることに注意しましょう。

CPUに余裕があるのに処理が遅い場合、ディスクIO、ネットワーク転送やロック待ちなどに原因がある可能性があります。ディスクIOに問題がある場合はロードアベレージとiowaitが共に高くなる傾向がありますので気に留めておくと良いでしょう。

topコマンドで調査できる事はまだありますが、問題の処理が終わってしまう前に急いでスタックトレースの取得にかかります。
出力内容をファイルに書き出しておいて、後で落ち着いて確認するのも良いでしょう。

また、スレッドダンプを取得するにはまずjavaプロセスのプロセスIDを調べる必要があります。
ctrl+c でtopコマンドを抜ける前に、疑わしいjavaプロセスのプロセスIDをメモ（or クリップボードにコピー）しておくようにしましょう。
プロセスIDはpsコマンドや、javaプロセスのプロセスIDを調べるためのjpsコマンドで取得しても構いません。

スレッドダンプの取得

javaプロセスのスレッドダンプを取るにはjstackコマンドを利用します。

jstackコマンドにパスが通っていない場合はjstackコマンドを探してフルパスで実行してください。
普通はJavaのインストールディレクトリのbinの中(例えば/usr/java/jdkXXXX/bin/jstack)にあります。
また、jstackコマンドの実行は、対象のjavaプロセスを実行しているユーザで行うようにしましょう。

スレッドダンプはjavaプロセスにSIGQUITシグナルを送信することでも取得できます。
この場合は、スレッドダンプはjavaプロセスの標準出力やエラー出力に出力されますので、ログファイルなどから確認することになります。
プロセスに間違ったシグナルを送ってしまう危険なども考慮すると、可能であればjstackコマンドを利用したほうが良いでしょう。

スレッドダンプの取得には、それほど大きなオーバーヘッドを必要としません。
「何かおかしいかも？」と感じた場合は、問題のスレッドがボトルネックとなる処理を抜けてしまう前に取得しておくと良いでしょう。
以下のように、適度に間隔を開けて数回取得してファイルに保存しておくと調査の際に有用です。

スレッドダンプと似たようなものに、現在のメモリ状況を出力するヒープダンプがあります。
こちらもメモリリークなどの調査に役立つ情報ですが、ヒープダンプを取得する際、利用中のメモリ量に応じて停止時間が発生するため十分注意するようにしましょう。

スレッドダンプを調べる前に……

マルチスレッドアプリケーションでは沢山のスレッドが協調して処理を行っているため、可能であれば問題のスレッドのスレッドIDを特定しておきたいところです。
アプリケーションのログファイルなどを見て問題のスレッドに目星をつけておくと調査がぐっと楽になります。

スレッドダンプを読む

ログなどから問題のスレッドIDが分っている場合は、対象のスレッドのスタックトレースを、時系列を追って調べていくと良いでしょう。

スレッドダンプを見る場合は、複数回取得して内容を比較するようにしましょう。
一回スレッドダンプを取得しただけでは、対象のスレッドが偶然ボトルネックになっていないメソッドで処理を行っていた際のスタックを取得してしまう可能性があります。
一定の間隔取得したスレッドダンプを調べることで、処理に時間がかかっているメソッドを特定することができます。

問題のスレッドが分っていないときには、全スレッドのスタックトレースから疑わしいスレッドを絞り込んでいくことになります。
この時も、各スタックトレースの上部に記されているスレッドのStateや、実行しているミドルウェアのスレッド名のパターンなどからある程度対象スレッドを絞り込むと良いでしょう。

続いて、ありがちなトラブル発生時の実際のスタックトレースを例示してみます。

デッドロック

以下はJavaのsynchronized文を入れ子にして、デッドロックを発生させた際のスレッドダンプです。

Javaレベルでのデッドロックは、スレッドダンプ取得時に自動的に検出してくれるので、スレッドダンプの最後を見ればすぐに分ります。
この場合、外部からロックを解除することは難しいため、アプリケーションを再起動することになるでしょう。

ネットワークIO待ち

次は、長時間のSQLクエリの発行や、API通信などにより、スレッドがネットワークのレスポンスをまっている場合のスタックトレースです。

スタックトレースの先頭を見ると、このスレッドは現在socketRead0メソッドの処理中のようです。
何度スレッドダンプを取得しても常に同じスタックトレースが出力されるようなら、ネットワークのレスポンスを待ち続けている可能性が高いでしょう。

この場合、「大量のデータを取得しようとしている」「通信先のネットワーク処理が長くレスポンスが遅延している」「通信先との接続切れを検知できずに待ち続けている」など様々な要因が想定されます。
状況に応じて必要な対応は変わってきますので、処理の内容や（可能であれば）通信先サーバの状況を調査して判断する必要があります。

通信の切断を検知できなかった場合、ネットワーク通信のタイムアウトが設定されていないのであれば、永遠にレスポンスを待ち続けてしまうことになります。
JavaのHTTPUrlConnectionなどはデフォルトのタイムアウトが0（無限）となっていますので、適切な値を設定するようにしましょう。

UrlConnection#setConnectTimeout
UrlConnection#setReadTimeout

ループ中の正規表現コンパイル

こちらは、ループ中で正規表現のコンパイル処理を行った際のスタックトレースです。

デッドロックやネットワーク待ちと違い、この場合はCPU処理がボトルネックになります。
本記事で例示したtopコマンド結果のCPU利用率が高くなっているのは、この処理を実行中に取得したためです。

CPU処理で時間がかかっている場合、処理の進行の応じてスタックトレースが大きく変化していきますので、何度もスレッドダンプを取得してボトルネックを分析するようにしましょう。

スタックトレースを見ると分りますが、この処理ではString#replaceAll内で正規表現のコンパイルが行われてます。
Stringには引数にStringで正規表現パターンを指定するメソッドがいくつかありますが、これらは内部で正規表現のコンパイルが行われていることに注意しましょう。
大量に呼び出されない場合は大きなボトルネックにはなりませんが、ループ中に実行された場合は無視できない処理量になります。
コンパイル済みのPatternをstaticフィールドに用意してPattern#matcherを使うなど、可能な限りコンパイル処理の回数を減らすようにするべきです。

まとめ

今回サンプルで用意したスレッドダンプを取得した際に実行したサーブレットをgistにあげておきましたので興味のある方はご覧下さい。

スレッドダンプを調査するには、現象を再現させている間に複数回取得することが重要です。
根気強くjstackを叩き続け、お宝（問題再現中のスレッドダンプ）を掘り当てることができれば、アプリケーションの改善に大いに役に立ってくれるはずです。