A.6.6 ハングアップやスローダウンの原因を調べる

Java VMには、フルスレッドダンプを出力する機能が備わっています。その機能の一部として、デッドロックを検出する機能が実装されています。

フルスレッドダンプを出力する方法には、以下の3つがあります。

シグナルQUITを送信する
- LinuxまたはOracle Solarisの場合
- 情報は、対象のJavaプロセスの標準出力に出力される
Ctrl-Breakを送信する、またはthdumpコマンドを使う
- Windowsの場合
- 情報は、対象のJavaプロセスの標準出力に出力される
jstackコマンドを使う
- 情報は、jstackコマンドの標準出力に出力される（動作中に出力される一部のトレース情報は、標準エラー出力に出力されることがある）

例

フルスレッドダンプを出力する方法の例を示します。

シグナルQUITを送信する例
```
$ kill -QUIT <プロセスID>
```
thdumpコマンドを使う例
```
> thdump -p <プロセスID>
```
jstackコマンドを使う例
```
> jstack <プロセスID>
```

どれかの方法でフルスレッドダンプを出力した場合に、デッドロックを検出すると、次のような情報が出力されます。

Found one Java-level deadlock:
=============================
"Thread-2":
  waiting to lock monitor 0x0599d364 (object 0x0fd1f2f8, a java.lang.Object),
  which is held by "Thread-0"
"Thread-0":
  waiting to lock monitor 0x065338fc (object 0x0fd1f300, a java.lang.Object),
  which is held by "Thread-1"
"Thread-1":
  waiting to lock monitor 0x0599df94 (object 0x0fd1f308, a java.lang.Object),
  which is held by "Thread-2"

Java stack information for the threads listed above:
===================================================
"Thread-2":
        at com.fujitsu.demo.DeadLocking$ThreadC.run(DeadLocking.java:57)
        - waiting to lock <0x0fd1f2f8> (a java.lang.Object)
        - locked <0x0fd1f308> (a java.lang.Object)
"Thread-0":
        at com.fujitsu.demo.DeadLocking$ThreadA.run(DeadLocking.java:29)
        - waiting to lock <0x0fd1f300> (a java.lang.Object)
        - locked <0x0fd1f2f8> (a java.lang.Object)
"Thread-1":
        at com.fujitsu.demo.DeadLocking$ThreadB.run(DeadLocking.java:43)
        - waiting to lock <0x0fd1f308> (a java.lang.Object)
        - locked <0x0fd1f300> (a java.lang.Object)

Found 1 deadlock.

この情報は、3つスレッド「Thread-0」「Thread-1」「Thread-2」のあいだでデッドロックが発生していることを示しています。

それぞれのスレッドは、オブジェクトのロックを獲得した状態で、ほかのスレッドが保持しているロックを獲得しようとして、処理が止まっています。

つまり、次の図のような三すくみ状態に陥っていることが分かります。

図A.28 デッドロックの状態

そのため、これらのスレッドの処理を見直して、デッドロックが発生しないように、プログラムを修正する必要があります。

デッドロックが検出されなかった場合は、どのメソッドが原因でハングアップやスローダウンが発生しているか、フルスレッドダンプの情報から確認します。

ハングアップやスローダウンが発生しているスレッドを特定するために、フルスレッドダンプを複数回採取します（目安は3回以上）。そして、採取したフルスレッドダンプの情報を比較して、ハングアップやスローダウンの発生箇所を調べます。
フルスレッドダンプの採取方法については、「A.6.6.1 デッドロックの検出」を参照してください。

例えば、jstackコマンドを使って、次の例のようにフルスレッドダンプ情報を別々のファイルに保存します。そして、diffなどのOS付属ツールを使ってファイル同士を比較すると、フルスレッドダンプを簡単に比較できます。

jstack 5732 > threaddump-1.txt
jstack 5732 > threaddump-2.txt
jstack 5732 > threaddump-3.txt

シグナルやthdumpコマンドを使ってフルスレッドダンプを採取した場合は、1回ごとの出力結果を、それぞれ別のファイルにコピーすると、同様に比較できます。

ここでは、上記のように、3回分のフルスレッドダンプを、それぞれ別のファイルに保存しているものとして説明します。

diffなどのOS付属ツールを使って、フルスレッドダンプの情報を、時系列で比較してください。

diff -u threaddump-1.txt threaddump-2.txt

比較の結果、変化が見られない場合は、ソケット接続の待ちうけ（accept）、I/O待ち（readなど）、ロックの取得待ちなどで止まっているスレッドを探します。それらのスレッドが、アプリケーションのハングアップやスローダウンを引き起こしている可能性があります。

次の例では、「Thread-0」で呼び出したメソッドjava.net.ServerSocket#accept()が、ソケットの接続を待っている状態で停止していることが分かります。この待ち受け処理が適切かどうかなど、プログラムを見直す必要があります。

"Thread-0" prio=6 tid=0x0656dc00 nid=0x115c runnable [0x065df000..0x065dfd94]
   java.lang.Thread.State: RUNNABLE
        at java.net.PlainSocketImpl.socketAccept(Native Method)
        at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:384)
        - locked <0x0fd28c48> (a java.net.SocksSocketImpl)
        at java.net.ServerSocket.implAccept(ServerSocket.java:453)
        at java.net.ServerSocket.accept(ServerSocket.java:421)
        at com.fujitsu.demo.Hangup$Worker.run(Hangup.java:36)

ポイント

ネイティブメソッドを実行中のスレッドの状態は、「runnable」と表示されます。ネイティブメソッドの先で処理が遅延したり、停止したりしていても、Java VMはそれを検知できないからです。
「runnable」と表示されているスレッドであっても、ネイティブメソッドを実行中の場合は、ハングアップやスローダウンの可能性を検討してください。

Java VisualVMを使った調査

フルスレッドダンプは、Java VisualVMを使って採取することもできます。詳しくは、JDKドキュメントを参照してください。

A.6.6 ハングアップやスローダウンの原因を調べる

A.6.6.1 デッドロックの検出

A.6.6.2 ハングアップやスローダウンの調査