Javaでなぜ問題が起きるのか 〜システムをきちんと運用するための基礎知識

第6回 Java VMの情報を取得する(後編)

この記事を読むのに必要な時間:およそ 3 分

スレッドダンプでスレッドの状態を確認する

スレッドがどの処理中にどのような状態になっているかを確認するためには,スレッドダンプを取得します。スレッドダンプは,ダンプした瞬間に各スレッドがどのメソッドを処理していて,どの状態にいるのかを取得します。

次のようなソースコードを例に,実際にスレッドダンプを取得してみましょう。スレッドプールへ処理を委譲して,処理の結果を出力するものです。処理は1分間休んだ後にHelloを返します。このソースコードは実働には耐えられませんが,スレッドダンプの結果をわかりやすくするために,このようにしています。

public class ThreadStatusSample {

    public static void main(String[] args) throws Exception {

        ExecutorService executor = Executors.newFixedThreadPool(1);
        Future<String> future = executor.submit(() -> {
                TimeUnit.MINUTES.sleep(1);
                return "Hello";
        });

        System.out.println(future.get());
        executor.shutdown();
    }
}

mainメソッドは,mainスレッドが実行します。newFixedThreadPoolメソッドは,スレッド数が1のスレッドプールを作成します。

mainスレッドは,submitメソッドでスレッドプールへ処理を委譲し,getメソッドで委譲した処理が終わるのを待機します。

次の図は,各スレッドの状態の変化を時間ごとに表したものです。

図1 各スレッドの状態の変化とスレッドダンプ

図1 各スレッドの状態の変化とスレッドダンプ

スレッドダンプを取得する方法はさまざまありますが,今回はjcmdを使用して取得します。jcmdに対象となるJavaプロセスのプロセスIDを指定し,Thread.printコマンドを指定することで,スレッドダンプを取得します。

スレッドダンプの例

> jcmd <プロセスID> Thread.print
"main" #1 prio=5 os_prio=0 tid=0x000000000271d800 nid=0x2ce4 waiting on condition [0x0000000002b5e000]
   java.lang.Thread.State: WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        - parking to wait for  <0x000000076b2f19b8> (a java.util.concurrent.FutureTask)
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
        at java.util.concurrent.FutureTask.awaitDone(FutureTask.java:429)
        at java.util.concurrent.FutureTask.get(FutureTask.java:191)
        at thread.ThreadStatusSample.main(ThreadStatusSample.java:28)

"pool-1-thread-1" #11 prio=5 os_prio=0 tid=0x000000001db47800 nid=0xa18 waiting on condition [0x000000001e37f000]
   java.lang.Thread.State: TIMED_WAITING (sleeping)
        at java.lang.Thread.sleep(Native Method)
        at java.lang.Thread.sleep(Thread.java:340)
        at java.util.concurrent.TimeUnit.sleep(TimeUnit.java:386)
        at thread.ThreadStatusSample.lambda$main$0(ThreadStatusSample.java:14)
        at thread.ThreadStatusSample$$Lambda$1/990368553.call(Unknown Source)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)
(略)

このスレッドダンプからは,mainとpool-1-thread-1の2つのスレッドがあり,それぞれ次の状態であることがわかります。

  • mainスレッドは,WAITING (parking),すなわち待機中である。具体的には,Futureインターフェースの実体であるFutureTaskクラスのgetメソッド内でスレッドプールに委譲している処理が終わるのを,sun.misc.Unsafeクラスのparkメソッドで待機中である
  • pool-1-thread-1スレッドは,TIMED_WAITING (sleeping),すなわち休み中である。具体的には,TimeUnitクラスのsleepメソッド内でThreadクラスのsleepメソッドを呼び出して,休み中である

スレッドダンプでは,処理の受付中,処理中,休み中,待機中の一部の情報を取得できます。スレッドダンプで得られる情報は取得した瞬間の情報なので,分析をするためには一定期間のうちに何度か取得して,推移を確認するのが一般的です。

ただし,情報の推移だけでは判断を誤ることがあるため注意が必要です。次の図は,先ほどスレッドプールへ委譲した処理を2回連続で実行した例です。スレッドダンプを4回取得しています。

図2 スレッドダンプからスレッドの状態変化を予測する

図2 スレッドダンプからスレッドの状態変化を予測する

最初の3回は,pool-1-thread-1は休み中で,4回目は処理中の状態です。この場合は,予測を誤ると,1回目のスレッドダンプから3回目のスレッドダンプまでを休み中と判断してしまいます。

予測を誤らないためには,次のようにして,スレッドの状態変化をより細かく記録します。

  • スレッドダンプをより細かい周期で取得する
  • (負荷がかかりますが)JVMへ接続してスレッドの変化をすべて記録する

しかし,すべてのスレッドの状態を記録するのは非常に高負荷になるほか,情報を取得することが負荷の中心となってしまい,本来のボトルネックが隠れてしまうことがあるため注意しましょう。すべての状態を記録するのではなく,まずは一定時間を超えた状態のみ記録することでボトルネックとなる状態を絞り込み,絞り込んだ状態のみをすべて記録するなどの対応が必要です。

次回は,アプリケーションが取得すべき情報について解説します。

著者プロフィール

伊藤智博(いとうちひろ)

日本オラクル(株)コンサルタント。

テクノロジストとしてJavaに関わる製品の技術支援をおもに担当し,Java Day TokyoやJavaOne San Franciscoなどでの講演も行う。得意分野は,Java全般を対象としたトラブルシューティングとパフォーマンスチューニング。最近は,Javaコミュニティへの支援や,Oracle製品とOSSの間を埋めるツールの作成を趣味としている。

ブログ:http://chiroito.blogspot.jp/
Twitter:@chiroito