スポンサーリンク

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

java tool マルチスレッド


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

  • （１）普通に動作中：緑
  • （２）ロックを保持しながら動作中：オレンジ
  • （３）ロック待ちのウェイト状態：赤

などの状態を遷移する。

もし（３）が長く続いたら，デッドロックが発生しているとわかる。


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

その使い方。

（１）スレッドの同期に失敗しているプログラム

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

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


Callee.java（２つのスレッドから共通して呼ばれるクラス）

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（スレッドとして２つインスタンス化するクラス）

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()をかける。


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

２つのCallerのスレッド（t1, t2）が１つのCalleeを呼び出す。


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

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


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クラスにおける計算結果が１億に到達するよりも前に，t1, t2 の２スレッドの間で制御が入れ替わってしまうのだ。

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

（２）正しく動くマルチスレッドアプリ

このばらつきを防ぐためには，２スレッドから共通して呼び出されているクラスのメソッドを 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

こんな感じになる。

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

（３）samuraiの使い方

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


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

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

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

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

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

   java hoge.Main > out.log

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


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

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...


　

language_and_engineering 読者になる

広告を非表示にする
スポンサーリンク
スポンサーリンク