スタックトレース/スレッドダンプの読み方その1 – VM 内部スレッドと main スレッド

しかし、スレッドダンプは取得しただけでは役に立ちません。
もちろん、スレッドダンプは解析して初めてトラブルシューティングやチューニングに役立つものです。

そこで、今回からは具体的にスレッドダンプの中身を見ていきましょう。

説明に使うアプリケーションはこんな感じ。起動したら "Hello World! と表示して10秒間スリープするという簡単なもの。

1:
2:
3:
4:
5:
6:
7:
8:
9:

public class ThreadTest1{
  public static void main(String args[]) throws Exception {
    System.out.println("Hello World!");
    method1();
  }
  private static void method1() throws Exception {
    Thread.sleep(10000);
  }
}

Unix でコンパイル、実行、スレッドダンプの取得をするとこんな感じになります。

$ java -cp . ThreadTest1
$ javac ThreadTest1.java
$ java -cp . ThreadTest1 > ThreadTest1.out 2>&1 &
[1] 445
$ kill -3 445
$
[1]+ Done java -cp . ThreadTest1 >ThreadTest1.out 2>&1
$ cat ThreadTest1.out
Hello World!
Full thread dump Java HotSpot(TM) Client VM (1.5.0_06-64 mixed mode, sharing):

“Low Memory Detector” daemon prio=5 tid=0x0050a600 nid=0x1816a00 runnable [0x00000000..0x00000000]

“CompilerThread0” daemon prio=9 tid=0x00509cb0 nid=0x1816600 waiting on condition [0x00000000..0xf0b06358]

“Signal Dispatcher” daemon prio=9 tid=0x00509840 nid=0x1816200 waiting on condition [0x00000000..0x00000000]

“Finalizer” daemon prio=8 tid=0x00509020 nid=0x1810200 in Object.wait() [0xf0a04000..0xf0a04ab0]
at java.lang.Object.wait(Native Method)
– waiting on <0x26580360> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:116)
– locked <0x26580360> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:132)
at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)

“Reference Handler” daemon prio=10 tid=0x00508c30 nid=0x180f200 in Object.wait() [0xf0983000..0xf0983ab0]
at java.lang.Object.wait(Native Method)
– waiting on <0x26580a50> (a java.lang.ref.Reference$Lock)
at java.lang.Object.wait(Object.java:474)
at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116)
– locked <0x26580a50> (a java.lang.ref.Reference$Lock)

“main” prio=5 tid=0x005013a0 nid=0x1804c00 waiting on condition [0xf07ff000..0xf08002c0]
at java.lang.Thread.sleep(Native Method)
at ThreadTest1.method1(ThreadTest1.java:7)
at ThreadTest1.main(ThreadTest1.java:4)

“VM Thread” prio=9 tid=0x00508450 nid=0x1803c00 runnable

“VM Periodic Task Thread” prio=9 tid=0x0050bcb0 nid=0x1813000 waiting on condition

“Exception Catcher Thread” prio=10 tid=0x005015e0 nid=0x1805000 runnable

Full thread dump.. から始まっている行以降がスレッドダンプになります。

JVM の種類、バージョンにより若干フォーマットは異なりますが、だいたい似たような形式になります。
Sun、HP、Apple、BEAの VM のうちどれか一つ慣れた VM で解析経験を積んでおけば他の JVM のスレッドダンプを読むのに困ることはないでしょう。
ただし、IBM の VM はかなり独特のフォーマットになっており独自の解析技術が必要になります。

スレッドダンプは文字通り JVM 内に存在する全てのスレッドをダンプ(中身を書き出すこと)したものです。
上記の例では"Low Memory Detector", "CompilerThread0", "Signal Dispatcher", "Finalizer", "Reference Handler", "main", "VM Thread", "VM Periodic Task Thread" と、計９個のスレッドがあることがわかります。

一つ一つのスレッドはスレッド名を含むヘッダ部分と、at .. という行が連なっているスタックトレース部分に別れます。

ユーザーの書いた main() メソッドのあるクラス – 今回の場合 ThreadTest クラス – は "main" スレッドで実行されます。

お気づきかと思いますが、今回のアプリケーションはマルチスレッドのアプリケーションではないのに９つものスレッドがあります。
これは JVM 内部で利用するためのスレッドもダンプされているためです。

内部的に勝手に生成されるスレッドの数、名前は JVM やバージョンによって異なります。
スタックトレースのないものや、スタックに記載されているクラス名が全部 java.* となっているものは大抵 VM 内部のスレッドですので無視して問題ありません。

ですので今回の例で興味深いのは "main" スレッドのにみになります。

以下に "main" スレッドのダンプだけを抽出します。

なにやら細々と情報が書いてあって構えてしまいますが、通常注目すべきなのは３点。
スレッド名(*1)、スレッドの状態(*2)、そしてスタックトレース(*3)です。
今回の例では main がスレッド名、waiting on condition がスレッドの状態、at java.lang.Thread.sleep 以降がスタックトレースになります。

"main"*1 prio=5 tid=0x005013a0 nid=0x1804c00 waiting on condition*2 [0xf07ff000..0xf08002c0]
at java.lang.Thread.sleep(Native Method)*3
at ThreadTest1.method1(ThreadTest1.java:7)
at ThreadTest1.main(ThreadTest1.java:4)

スレッドの状態、スタックトレースの詳しい説明については次号！

・Java – スレッドダンプの取り方その1 / スレッドダンプの取り方
・Java – スレッドダンプの取り方その2 / Linux だと java プロセスがいっぱい！？
・Java – スレッドダンプの取り方その3 / Windows サービスとして登録している場合は？
・Java – スレッドダンプの取り方その4 / WebLogic Server とスレッドダンプ

yusuke.blog

プログラムと、ゲームと、諸々と

スタックトレース/スレッドダンプの読み方その1 – VM 内部スレッドと main スレッド

関連