読者です 読者をやめる 読者になる 読者になる
スポンサーリンク

Javaで,各スレッドの状態を可視化するツール (マルチスレッドアプリでデッドロックを検出する)

java tool マルチスレッド


マルチスレッドなアプリケーションで,各スレッドの状態は

  • (1)普通に動作中:緑
  • (2)ロックを保持しながら動作中:オレンジ
  • (3)ロック待ちのウェイト状態:赤

などの状態を遷移する。

もし(3)が長く続いたら,デッドロックが発生しているとわかる。


こういった複数スレッドの状態を調査するツールとして,フリーの「samurai」がある。

その使い方。

(1)スレッドの同期に失敗しているプログラム

まずは,ロックを使わないプログラムの例。

hogeというフォルダの中に,次のクラスを用意:


Callee.java(2つのスレッドから共通して呼ばれるクラス)

package hoge;

class Callee{
	private static long sum;
	
	// ここのsynchronizedの有無で実行結果が全く違う

	public static void echo( String caller )
	{
		// sumを初期化し,1を1憶回足す
		sum = 0;
		for( long i = 0; i < 100000000; i ++ )
		{
			sum += 1;
		}
		System.out.println( caller + "による計算結果:" + sum );
	}
}


Caller.java(スレッドとして2つインスタンス化するクラス)

package hoge;

class Caller implements Runnable{
	
	private String name;
	
	public Caller( String name ){
		this.name = name;
	}
	
	public void run(){
		for( int i = 0; i < 10; i ++ )
		{
			// 計算を実行
			Callee.echo( name );
		}
	}
}


Main.java(スレッドを作成するメインクラス)

package hoge;

public class Main{
	public static void main( String[] args ){
		
		Caller caller1 = new Caller( "caller1" );
		Thread t1 = new Thread( caller1, "1st_thread" );
		t1.start();
		
		Caller caller2 = new Caller( "caller2" );
		Thread t2 = new Thread( caller2, "2nd_thread" );
		t2.start();
	}
}

Javaでスレッドを立てる一つの方法として,RunnableなクラスをThreadに渡してstart()をかける。


2つのCallerクラスがスレッドとして別個に動く。

2つのCallerのスレッド(t1, t2)が1つのCalleeを呼び出す。


Calleeは,呼び出されたら数字の「1億」を毎回出力するはず。

しかしここではスレッドを同期していないのでうまくいかない。


hogeの上のフォルダから

   javac hoge/*.java

でコンパイルし,

   java hoge.Main

で実行すると

caller1による計算結果:164566433
caller2による計算結果:18402613
caller1による計算結果:124639149
caller2による計算結果:131277170
caller2による計算結果:157027493
caller1による計算結果:3797677
caller2による計算結果:124834262
caller1による計算結果:127815118
caller2による計算結果:144191277
caller1による計算結果:15608907
caller2による計算結果:125138662
caller1による計算結果:12472891
caller1による計算結果:130966163
caller2による計算結果:8613450
caller2による計算結果:123556362
caller1による計算結果:12745602
caller2による計算結果:121351264
caller1による計算結果:17146756
caller1による計算結果:137233440
caller2による計算結果:147522871

こんな結果になる。

毎回,Calleeクラスにおける計算結果が1億に到達するよりも前に,t1, t2 の2スレッドの間で制御が入れ替わってしまうのだ。

そのため,sumの値が両方のスレッドから操作されておかしい値になる。

(2)正しく動くマルチスレッドアプリ

このばらつきを防ぐためには,2スレッドから共通して呼び出されているクラスのメソッドを synchronized にする。

Javaマルチスレッド・排他処理
http://www.ne.jp/asahi/hishidama/home...


修正版 Callee.java

package hoge;

class Callee{
	private static long sum;
	
	// ここのsynchronizedの有無で実行結果が全く違う
	synchronized public static void echo( String caller )
	{
		// sumを初期化し,1を1憶回足す
		sum = 0;
		for( long i = 0; i < 100000000; i ++ )
		{
			sum += 1;
		}
		System.out.println( caller + "による計算結果:" + sum );
	}
}

コンパイルし直して実行すると

caller1による計算結果:100000000
caller2による計算結果:100000000
caller1による計算結果:100000000
caller2による計算結果:100000000
caller1による計算結果:100000000
caller2による計算結果:100000000
caller1による計算結果:100000000
caller2による計算結果:100000000
caller1による計算結果:100000000
caller2による計算結果:100000000
caller1による計算結果:100000000
caller1による計算結果:100000000
caller2による計算結果:100000000
caller1による計算結果:100000000
caller1による計算結果:100000000
caller2による計算結果:100000000
caller1による計算結果:100000000
caller2による計算結果:100000000
caller2による計算結果:100000000
caller2による計算結果:100000000

こんな感じになる。

一方のスレッドが計算している間,もう一方のスレッドは割り込みをせず,待機していてくれる。(その待機がずっと続いたらデッドロック。)

(3)samuraiの使い方

各スレッドの状態を可視化しよう。


まずは,スレッドダンプを出力する。

そのためにはプログラム実行中にコマンドプロンプト上でCtrl + Breakを押下すればよい。

Java - スレッドダンプの取り方
http://yusuke.homeip.net/diary/2006/0...

スレッドダンプは任意のタイミングで SIGQUIT シグナルを送る(Unix)、または キーボードで Ctrl+Break を押下する(Windows)ことで取得できます。

そのダンプ結果を保存するために,クラス実行時に

   java hoge.Main > out.log

のように,出力をログに書き出すようにする。


実行開始し,コマンドプロンプト上でCtrl + Breakを1秒〜2秒おきに繰り返し押下。

Mainの実行終了時には,out.logに下記のような情報が詰め込まれる。

2009-01-04 18:26:35
Full thread dump Java HotSpot(TM) Client VM (11.0-b16 mixed mode, sharing):

"DestroyJavaVM" prio=6 tid=0x00316c00 nid=0xe0 waiting on condition [0x00000000..0x0093fd4c]
   java.lang.Thread.State: RUNNABLE

"2nd_thread" prio=6 tid=0x02b45400 nid=0x12b4 waiting for monitor entry [0x02ecf000..0x02ecfb14]
   java.lang.Thread.State: BLOCKED (on object monitor)
	at hoge.Callee.echo(Callee.java:10)
	- waiting to lock <0x26a283a0> (a java.lang.Class for hoge.Callee)
	at hoge.Caller.run(Caller.java:14)
	at java.lang.Thread.run(Unknown Source)

"1st_thread" prio=6 tid=0x02b54800 nid=0x17e4 runnable [0x02e7f000..0x02e7fb94]
   java.lang.Thread.State: RUNNABLE
	at hoge.Callee.echo(Callee.java:11)
	- locked <0x26a283a0> (a java.lang.Class for hoge.Callee)
	at hoge.Caller.run(Caller.java:14)
	at java.lang.Thread.run(Unknown Source)

"Low Memory Detector" daemon prio=6 tid=0x02b22400 nid=0x9f8 runnable [0x00000000..0x00000000]
   java.lang.Thread.State: RUNNABLE

"CompilerThread0" daemon prio=10 tid=0x02b19000 nid=0x100c waiting on condition [0x00000000..0x02d8f6c0]
   java.lang.Thread.State: RUNNABLE

"Attach Listener" daemon prio=10 tid=0x02b17800 nid=0xa08 runnable [0x00000000..0x00000000]
   java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" daemon prio=10 tid=0x02b16800 nid=0x910 waiting on condition [0x00000000..0x00000000]
   java.lang.Thread.State: RUNNABLE

"Finalizer" daemon prio=8 tid=0x02ad4000 nid=0x12a4 in Object.wait() [0x02c9f000..0x02c9fa14]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	- waiting on <0x229e0b28> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(Unknown Source)
	- locked <0x229e0b28> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(Unknown Source)
	at java.lang.ref.Finalizer$FinalizerThread.run(Unknown Source)

"Reference Handler" daemon prio=10 tid=0x02acf400 nid=0x1080 in Object.wait() [0x02c4f000..0x02c4fb14]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	- waiting on <0x229e0a30> (a java.lang.ref.Reference$Lock)
	at java.lang.Object.wait(Object.java:485)
	at java.lang.ref.Reference$ReferenceHandler.run(Unknown Source)
	- locked <0x229e0a30> (a java.lang.ref.Reference$Lock)

"VM Thread" prio=10 tid=0x02acdc00 nid=0xdf4 runnable 

"VM Periodic Task Thread" prio=10 tid=0x02b23400 nid=0x1088 waiting on condition 

この情報をかんたんに可視化する。


下記サイトから,samurai.jar をダウンロード。

侍 - ログ , スレッドダンプ解析ツール
http://yusuke.homeip.net/samurai/ja/i...

コマンドラインから,

   java -jar samurai.jar

でこのJARを起動。

侍のウィンドウが開くので,out.logをドラッグ&ドロップ。

「スレッドダンプ」のタブで,冒頭のような画像が見られる。
真っ赤な行があったらデッドロック。


なお,out.logの内容が書き換わると,変更がリアルタイムで侍の画面上に反映される。


余談

もしCtrl + Breakが面倒なら,SendSignal.exeというツールで代替操作ができる。

Javaプロセスのスレッドダンプを取るツール(ツール検索編)
http://d.hatena.ne.jp/Jagi/20060515/1...

sendSignal
http://www.latenighthacking.com/proje...

使い方は,java.exe(VM)の該当プロセスに向けて

   SendSignal 3932

のようにプロセスIDを指定してやればよい。

なおシグナル送信対象としてjava.exe以外のプログラムを指定すると Ctrl + C(強制終了)と同効果とみなされるので注意。



また,ダンプログの読み方などは下記URLが参考になる。

スレッドダンプの読み方 その1 - VM 内部スレッドと main スレッド
http://yusuke.homeip.net/diary/2008/0...

スレッドダンプの森で覚えた 死のロックへの違和感
http://www.atmarkit.co.jp/fjava/rensa...

Thread.State
http://java.sun.com/j2se/1.5.0/ja/doc...