jstackによるスレッド診断の実践ガイド
jstackはJava仮想機械の現在のスレッドスナップショット(スレッドダンプ)を生成するツールです。スレッドの長時間停止、CPU使用率の上昇、デッドロック、応答不能などの問題を特定するための重要なツールです。
1. コマンドパラメータの詳細
基本構文:jstack [options] <PID>
| **パラメータ** | **例** | **機能** |
|---|---|---|
| **なし** | jstack 1234 |
**最も一般的**。標準的なスレッドスタックを出力。 |
| **-l** | jstack -l 1234 |
**詳細出力**。ロックに関する追加情報を表示(例:Ownable Synchronizers、ReentrantLockなど)。推奨。 |
| **-F** | jstack -F 1234 |
**強制出力**。プロセスが応答しない場合に強制的にスタックを出力。**注意:プロセスの停止時間が長くなる可能性あり。慎重に使用。** |
| **リダイレクト** | jstack 1234 > dump.log |
出力をファイルに保存し、オフライン分析や同僚への共有に便利。 |
2. スレッドダンプログの読み方(解説図)
1行の標準スレッドログには多くの情報が含まれており、「分解」して理解する必要があります。
ログ例:
"http-nio-8080-exec-1" #12 daemon prio=5 os_prio=0 tid=0x00007f... nid=0x1a2b waiting on condition [0x00007f...]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
...
各フィールドの解説:
- スレッド名 (
"http-nio-8080-exec-1"): スレッドの名称。実践的アドバイス: スレッドプールにカスタム名を設定(例:order-process-thread)すると、問題の特定が容易になる。 - daemon: 守護スレッドかどうかのフラグ。
- prio=5: Javaレベルでの優先度。
- tid: Javaメモリ内のスレッドID。
- nid (
0x1a2b): 重要フィールド! オペレーティングシステムレベルのスレッドID(16進数)。
- 主な用途:Linuxの
top -Hpで表示されるPID(10進数)とこのスタックを関連付ける。
- Status: スレッドの大まかな状態。
- java.lang.Thread.State: 具体的なJavaスレッド状態(以下の詳細参照)。
3. 核心スレッド状態(Thread State)の詳細
問題解決の核心となるため、以下の状態の違いを理解する必要があります。
| **状態** | **意味** | **リスクレベル** | **調査方法** |
|---|---|---|---|
| **RUNNABLE** | 実行中、またはCPUタイムスライスを待っている、またはシステムコール(ネットワーク読み込みなど)を行っている。 | ⭐️ / ⭐️⭐️⭐️ | 大量のスレッドが同じコード位置でRUNNABLEの場合、性能ボトルネックまたは無限ループの可能性。 |
| **BLOCKED** | **ブロック状態**。synchronizedロックの取得を待っている。 | ⭐️⭐️⭐️⭐️⭐️ | **高リスク**。並行性が激しく、長期間解放されないと雪崩効果を引き起こす。 |
| **WAITING** | 無限に待機。wait()、join()、LockSupport.park()を呼び出した。 |
⭐️⭐️ | 他のスレッドによる目覚め(notify/unpark)が必要。スレッドプールの空きスレッドであれば正常。 |
| **TIMED_WAITING** | 時間制限付き待機。sleep(t)やwait(t)を呼び出した。 |
⭐️ | 通常は正常。しかし大量のスレッドがsleepしていると応答が遅くなる。 |
4. クラシックなシナリオ分析
シナリオ1:CPU使用率100%(高負荷コードの特定)
jstackの典型的な使用例で、Linuxコマンドと組み合わせて使用します。
- プロセスの特定:
top(PIDが10997と仮定) - スレッドの特定:
top -Hp 10997で%CPUが最も高いスレッドを確認(11005と仮定) - 進数変換:11005を16進数に変換
Bash
printf "%x\n" 11005
# 出力: 2aff
- 正確な検索:
Bash
jstack 10997 | grep -A 20 "2aff"
結果の解釈:
堆積トップのコードがCPUを過剰に消費しているロジックです。よくある原因には複雑な計算、無限ループ、大量の文字列結合、頻繁なGC(スタックにGCスレッドが表示される)などがあります。
シナリオ2:デッドロック(Deadlock)
2つのスレッドがお互いに必要なロックを保持しているとデッドロックになります。jstackは自動的に検出し、ログ末尾に表示します。
ログの特徴:
キーワード「Found one Java-level deadlock」で検索。
Found one Java-level deadlock:
=============================
"Thread-A":
waiting to lock monitor 0x000000005... (object 0x000000076...)
locked 0x000000075...
"Thread-B":
waiting to lock monitor 0x000000075... (object 0x000000075...)
locked 0x000000076...
解決策:スタックに表示されたクラス名と行番号に基づき、ロック順序を最適化するかtryLockを使用する。
シナリオ3:アプリケーションが応答しないがCPU使用率が低い(外部リソースの遅延)
アプリケーションが突然リクエストを処理できなくなったが、CPU使用率がほぼゼロ。これはスレッドが外部リソースの待機にかかっていることが原因です。
分析手順:
- スタックをエクスポート:
jstack <PID> > dump.log - スレッド状態を統計:
Bash
grep "java.lang.Thread.State" dump.log | sort | uniq -c
- RUNNABLE状態のスレッドが多い場合、CPU使用率が低い場合は、Socket読み取りにかかっているか確認:
at java.net.SocketInputStream.socketRead0(Native Method)
結論:データベースクエリが極めて遅い、Redisの遅延、または呼び出された外部HTTPインターフェースが応答していない可能性がある。
シナリオ4:大量のBLOCKED(ロック競合)
大量のスレッドがBLOCKED (on object monitor)状態で、同じオブジェクトアドレスを待っている場合。
"Thread-5" prio=5 tid=0x01... nid=0x2... blocked
- waiting to lock <0x0000000780a000b0> (a java.lang.Object)
- waiting for monitor entry [0x00000000...]
分析:ロック<0x0000000780a000b0>を保持しているスレッドを検索(locked <0x0000000780a000b0>で検索),それがなぜ遅いか確認(IOや複雑な計算など)。
5. 高度なテクニックと注意点
- 複数回のサンプリング(重要)
一度のダンプは瞬間的なスナップショットです。スレッドが本当に停止しているか疑う場合は、5秒おきに3回jstackを実行することを推奨。
- 3回の結果で同じコード行に停止している場合、本当に停止している。
- 変化している場合は、ただ遅いだけで実行中。
- 代替ツール:jcmd
JDK8以降では、公式にjcmdを使用することを推奨しています。
jcmd <PID> Thread.print
- オンライン分析ツール
オンライン可視化ツール:
- FastThread.io(業界最高、推奨)
- JProfiler / VisualVM(ローカルGUIツール)