スレッドダンプの取り方は前に説明した通りです。
#二年近く前ですが・・・
しかし、スレッドダンプは取得しただけでは役に立ちません。
もちろん、スレッドダンプは解析して初めてトラブルシューティングやチューニングに役立つものです。
そこで、今回からは具体的にスレッドダンプの中身を見ていきましょう。
説明に使うアプリケーションはこんな感じ。起動したら "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" スレッドのダンプだけを抽出します。
"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)
なにやら細々と情報が書いてあって構えてしまいますが、通常注目すべきなのは３点。
スレッド名(*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 とスレッドダンプ
トラックバックURL http://yusuke.homeip.net/diary/.action?entry=1209569290756
