Claude Media
Claudeでスレッドダンプを解析する — jstackを3回取って詰まりを絞る

Claudeでスレッドダンプを解析する — jstackを3回取って詰まりを絞る

jstackを数秒おきに3回取り、同じスタックで止まるスレッドとロック待ちの連鎖を抜き出してClaude Codeに読ませる手順。個人情報や接続文字列を伏せる前処理も付けます。

JVMのスレッド詰まりは、スレッドダンプを1回取っただけでは判断しにくい障害です。BLOCKEDのスレッドが並んでいても、数百ミリ秒後には動き出すかもしれません。

そこで、数秒おきに3回取って比べます。3回とも同じ場所で止まっているスレッドと、そのスレッドが待っているロックの持ち主を先に機械で抜き出し、その結果とダンプ本体をClaude Codeに渡して読み解かせます。

手順

スレッドダンプ解析の流れ

  1. 1

    ダンプを3回取る

    生のダンプは作業ディレクトリの外に置きます。

  2. 2

    スクリプトで絞る

    同じ場所で止まるスレッドと、ロック待ちの連鎖を抜き出します。

  3. 3

    伏せ字にする

    Claudeに渡すのは、伏せ字にしたダンプだけです。

  4. 4

    claude -p に読ませる

    結果とダンプ本体を依頼文と一緒に渡します。

  5. 5

    答えを確かめる

    行番号とロックのアドレスをダンプで引き直します。

ダンプを3回取る

jstack は、指定したJavaプロセスの各スレッドのスタックトレースを出力するJDK付属のコマンドです。-l を付けると、ロックについての追加情報も出力されます。対象のプロセスIDは jps で調べられます。

JDK 21のマニュアルには、jstack は実験的でサポート対象外のコマンドであり、将来のJDKで使えなくなる可能性があると書かれています。本番で使うJDKのバージョンで、手順を一度試しておく必要があります。

PID=$(jps | awk '/MyApp/ {print $1}')   # MyAppは対象の主クラス名
RAW=~/dumps-raw                          # 作業ディレクトリの外
mkdir -p "$RAW" dumps/redacted
for i in 1 2 3; do
  jstack -l "$PID" > "$RAW/dump$i.txt"
  sleep 3
done

3秒という間隔は、この記事での設定です。公式に推奨値があるわけではありません。処理が秒単位で動くアプリなら3秒で十分に差が出ます。バッチのように分単位で動くものは、間隔を伸ばします。

~/dumps-raw には生のダンプが入ります。Claudeに渡すのは、あとで作る作業ディレクトリ内の dumps/redacted 側だけです。

手元で動かした題材

手順を確かめるため、次の状況を作った小さなJavaプログラムを、OpenJDK 17.0.3(Corretto)で動かしました。

  • cache-loader が、キャッシュ用のロックを持ったまま長く眠っている
  • http-exec-1〜3 が、そのロックを待っている
  • order-sync と stock-sync が、互いのロックを待つデッドロックになっている
  • metrics-tick は、50ミリ秒ごとにsleepして動き続ける

このうち、障害として見たいのは最初の3つです。4つ目は、見た目は止まっているのに正常なスレッドとして混ぜてあります。

3回とも同じ場所で止まるスレッドを抜く

ダンプは、スレッドごとに "名前" #番号 … で始まるブロックが並ぶ形式です。ブロックから「名前・状態・先頭の数フレーム」を取り出し、3回とも一致したスレッドだけを出力します。

import re, sys
 
def load(path):
    threads = {}
    for blk in re.split(r'\n(?=")', open(path).read()):
        m = re.match(r'"([^"]+)"', blk)
        st = re.search(r'Thread\.State: (\S+)', blk)
        if not m or not st or m.group(1) in threads:
            continue  # deadlock節の重複ブロックは読み飛ばす
        frames = [re.sub(r'0x[0-9a-f]+', '0x…', l.strip())
                  for l in blk.splitlines()
                  if l.strip().startswith(('at ', '- waiting', '- locked'))]
        threads[m.group(1)] = (st.group(1), tuple(frames[:6]))
    return threads
 
dumps = [load(p) for p in sys.argv[1:]]
for name, sig in dumps[0].items():
    if all(d.get(name) == sig for d in dumps) and sig[0] != 'RUNNABLE':
        print(f"{name} | {sig[0]} | {sig[1][0]}")

same.py として保存し、3つのダンプを渡します。

python3 same.py ~/dumps-raw/dump1.txt ~/dumps-raw/dump2.txt ~/dumps-raw/dump3.txt

題材のプログラムでは、次の出力になりました。

main | TIMED_WAITING | at java.lang.Thread.sleep(java.base@17.0.3/Native Method)
Finalizer | WAITING | at java.lang.Object.wait(java.base@17.0.3/Native Method)
Common-Cleaner | TIMED_WAITING | at java.lang.Object.wait(java.base@17.0.3/Native Method)
cache-loader | TIMED_WAITING | at java.lang.Thread.sleep(java.base@17.0.3/Native Method)
http-exec-1 | BLOCKED | at Demo.worker(Demo.java:6)
http-exec-2 | BLOCKED | at Demo.worker(Demo.java:6)
http-exec-3 | BLOCKED | at Demo.worker(Demo.java:6)
order-sync | BLOCKED | at Demo.lambda$main$1(Demo.java:11)
stock-sync | BLOCKED | at Demo.lambda$main$2(Demo.java:12)
metrics-tick | TIMED_WAITING | at java.lang.Thread.sleep(java.base@17.0.3/Native Method)

落とし穴

3回同じスタックでも、止まっているとは限らない

metrics-tick は動き続けているのに、3回とも Thread.sleep の同じ行に見えています。短い間隔で眠るスレッドは、いつ取っても同じ場所にいるからです。main や Finalizer のような待機中のJVM内部スレッドも同じです。

詰まりの手がかりになるのは、BLOCKEDで、しかも waiting to lock の行を持つスレッドです。TIMED_WAITINGは「待ち時間つきで眠っている」状態で、それだけでは問題の証拠になりません。ただし cache-loader もTIMED_WAITINGで、BLOCKEDのスレッドが待つロックを持っています。状態だけで外さず、次のロックの連鎖で誰が何を持っているかまで見て判断します。

この絞り込みは候補を減らすためのもので、結論ではありません。残った候補をどう読むかは、次のロックの連鎖で決めます。

ロック待ちの連鎖を抜き出す

BLOCKEDのスレッドのブロックには - waiting to lock <アドレス> が、ロックを持つスレッドのブロックには - locked <アドレス> が出ます。アドレスをキーにつなげば、「誰が誰を待っているか」の一覧になります。

import re, sys
txt = open(sys.argv[1]).read()
owner, waits = {}, set()
for blk in re.split(r'\n(?=")', txt):
    m = re.match(r'"([^"]+)"', blk)
    if not m: continue
    for a in re.findall(r'- locked <(0x[0-9a-f]+)>', blk):
        owner[a] = m.group(1)
    for a in re.findall(r'- waiting to lock <(0x[0-9a-f]+)>', blk):
        waits.add((m.group(1), a))
for w, a in sorted(waits):
    print(f"{w} -> {a} held by {owner.get(a, '?')}")

chain.py として保存し、最後のダンプに当てます。

python3 chain.py ~/dumps-raw/dump3.txt
http-exec-1 -> 0x000000061eb93188 held by cache-loader
http-exec-2 -> 0x000000061eb93188 held by cache-loader
http-exec-3 -> 0x000000061eb93188 held by cache-loader
order-sync -> 0x000000061eb931a8 held by stock-sync
stock-sync -> 0x000000061eb93198 held by order-sync

読み方は2通りです。

  • 3本のHTTPスレッドは、すべて cache-loader が持つ同じロックを待っています。連鎖の根は cache-loader で、このスレッド自身は誰も待たずに眠っています
  • order-sync と stock-sync は互いを待つ輪になっています。輪は、待ちの連鎖に根が無い形です

デッドロックは、jstack が自分で検出して書き出します。題材のダンプには、末尾に Found one Java-level deadlock: の節があり、order-sync と stock-sync がそれぞれ相手が持つロックを待っていることが載っていました。輪ができているかは、この節の有無でまず判定できます。

このスクリプトが読むのは、waiting to lock と locked の2種類の行だけです。それ以外の書式の待ちは拾えないので、依頼ではダンプ本体も一緒に渡します。

Claudeに渡す前に伏せる

スレッドダンプは、スタックトレースの形をしているので無害に見えます。ただ、jstack が1フレームごとに出すのは、クラス名・メソッド名・バイトコードの位置・行番号です。変数の値や引数は出ません。それでも次のものがダンプに残る余地があります。

  • アプリが付けたスレッド名。接続先のURL、ユーザーのメールアドレス、リクエストのパスを名前に入れる実装がある
  • 社内のパッケージ名やクラス名
  • スレッド名に入ったホスト名やIPアドレス

次のシェルスクリプトで、よくある形を置き換えます。

#!/bin/sh
# usage: redact.sh dump.txt > dump.redacted.txt
sed -E \
  -e 's#(jdbc:[a-z0-9]+://)[^ "?]+#\1<HOST>#g' \
  -e 's#(user|password|passwd|pwd|token|secret|api[_-]?key)=[^&" ]+#\1=<REDACTED>#Ig' \
  -e 's#([A-Za-z0-9._%+-]+)@([A-Za-z0-9.-]+\.[a-z]{2,})#<EMAIL>#g' \
  -e 's#([0-9]{1,3}\.){3}[0-9]{1,3}#<IP>#g' \
  "$1"

動作は、ダミーのスレッド名を3行書いた入力で確かめました。出力は次のとおりです。

"HikariPool-1 connection adder" #31 prio=5
"worker jdbc:postgresql://<HOST>?user=<REDACTED>&password=<REDACTED>" #32
"<EMAIL> <IP>" #33

1行目のように、伏せる必要のない名前は変わりません。題材の実際のダンプにこのスクリプトを通した出力は、元のダンプと差がありませんでした。ロックのアドレス(0x…)や Demo.java:6 のような行番号は、変換されません。連鎖をたどるのに必要なので、変換されると困るところです。

3つのダンプすべてに通します。

for i in 1 2 3; do
  ./redact.sh "$RAW/dump$i.txt" > "dumps/redacted/dump$i.txt"
done
grep -n '^"' dumps/redacted/*.txt | grep -i -E 'password|secret|token|[A-Za-z0-9._%+-]+@[A-Za-z0-9.-]+\.[a-z]{2,}'
grep -n -E 'com\.example\.' dumps/redacted/*.txt

最後の2つの grep は、置き換え漏れの確認です。1つ目は " で始まるスレッド名の行だけを見て、秘密を思わせる語と、残ったメールアドレスの形を探します。@ だけで探すと、java.base@17.0.3 のように全フレームに出るJDKのモジュール表記に当たってしまうため、メールの形に絞っています。2つ目は自社のパッケージ名の検索で、com.example. は例です。正規表現は名前と形に頼る検出なので、corp-billing のような社内サービス名や、k= のような別名のキーに入った値は拾えません。語は、自社のパッケージ名やサービス名、顧客名に差し替えて使います。0件になるまで確かめてから渡します。

個人関連情報としてどこまでをログに含めてよいかの線引きは、Claudeにログを渡す前に確認する個人関連情報の線引きが法令の面から整理しています。HARファイルから認証情報を消す同じ発想の前処理は、Claude CodeでHARファイルを解析し失敗リクエストを絞る手順にあります。

生のダンプをClaudeから遠ざける設定

伏せ字済みのファイルだけを渡すつもりでも、生のダンプがClaudeの手の届く場所にあれば、Claudeが自分でファイルを探して読む余地が残ります。手順で ~/dumps-raw に出力したのはそのためで、念のため .claude/settings.json に Read の拒否ルールも置いておきます。

{
  "permissions": {
    "deny": ["Read(~/dumps-raw/**)"]
  }
}

Read の拒否ルールは、Claudeの組み込みのファイルツールと、Bashのうち cat・head・tail・sed など認識されるファイルコマンド、およびリダイレクトの対象に効きます。一方、grep -r pattern . のようにファイルを名指ししないコマンドや、PythonやNodeのスクリプトがファイルを自分で開く場合には効きません。確実に止めたいなら、OSレベルで制限するサンドボックスを有効にします。

外に置くことが第一の対策で、上のルールは保険です。作業ディレクトリの中に置かざるをえない場合は、ルールのパスをその場所に合わせます。

依頼文と実行

claude -p は、標準入力を読みます。ダンプを nl -ba で行番号付きにして3つつなぎ、パイプで渡します。標準入力で渡せるのは10MBまでで、超えるとエラーで終了します。スレッド数が多くて超えそうなときは、ファイルにまとめてパスを依頼文に書く方法に切り替えます。

for f in dumps/redacted/dump?.txt; do
  echo "=== $f ==="
  nl -ba "$f"
done | claude -p "$(cat prompt.txt)"

prompt.txt は次のようにします。

標準入力は、同じJVMから約3秒間隔で取ったスレッドダンプ3回分
(jstack -l、行番号付き、dump1〜dump3)です。次を答えてください。
 
1. 3回とも同じスタックで止まっているスレッド
   (名前・状態・先頭3フレーム)。sleepや内部スレッドは除く
2. 各スレッドが待っているロックのアドレスと、その保持者
3. 待ちの連鎖の根(誰も待っていないロック保持者)と、輪(デッドロック)の有無
4. 各項目の根拠にした行を「dump番号:行番号」で引用
 
ダンプに書かれていないことは「推測」と明記し、原因は断定しないでください。

依頼文には、役に立つ指定が3つ入っています。

  • 「sleepや内部スレッドを除く」で、先ほどの metrics-tick のような誤検出を減らす
  • 根拠の行番号を求めて、出力を自分で突き合わせられるようにする
  • 書かれていないことは推測と明記させて、断定を避けさせる

自動化の場では、--bare を付けるとホストの設定ファイルやフックを読み込まずに起動できます。ただし --bare はサブスクリプションのログインを使わないので、ANTHROPIC_API_KEY を環境変数に設定する必要があります。この記事の手順は標準入力だけで足りるので、ツールの許可(--allowedTools)は不要です。

返ってきた答えを確かめる

Claudeの答えは、そのまま信じず、ダンプと突き合わせます。引用された行番号が実際にその内容かは、次のコマンドで確かめられます。

sed -n '120,130p' dumps/redacted/dump3.txt
grep -c '0x000000061eb93188' dumps/redacted/dump*.txt

1行目は、引用された範囲を直接読むコマンドです。2行目は、連鎖の要になるロックのアドレスが3つのダンプすべてに現れるかを数えます。別のアドレスを持ち出されていたら、読み違いを疑います。

Claudeの答えが、chain.py の出力と食い違った場合も見直しの合図です。chain.py は waiting to lock と locked の2種類しか読まないので、別の形の待ちが絡んでいる可能性があります。ダンプ本体の該当ブロックを開いて確かめます。

ここまでに出た結論は、「この3本が、このロックを待っている」というダンプ上の事実までです。なぜ cache-loader が長くロックを抱えているかは、ダンプには書かれていません。ソースの該当行(題材では Demo.slowLoad)を開いて、ロックの範囲と、ロックの中でやっている処理を確認する作業が次に来ます。

メモリが疑わしいときは別のダンプを使う

スレッドの詰まりではなく、メモリの使用量が問題のときに使うのは、ヒープダンプです。Claude Code自身のメモリを診断する手順は、Claude Codeの/heapdumpでメモリ使用量の高さを診断するにまとまっています。こちらは対象がClaude Codeのプロセスで、JVMのスレッドとは別の話です。

Minecraftサーバーの開発では、tickが10秒止まるとウォッチドッグがスレッドダンプを出力します。そのダンプを読む場面は、Claude CodeでMinecraftのPaperプラグインを作るで触れています。

まとめ

スレッド詰まりの調査は、ダンプを1回で判断せず、3回取って比べる形にすると進めやすくなります。比較と連鎖の抽出はスクリプトに任せ、Claudeにはその結果とダンプ本体を渡して読ませます。

渡す前の伏せ字処理と、生のダンプを作業ディレクトリの外に置くことが、この手順で一番手間のかかる部分です(外に置けない場合は拒否ルールで代える)。そのぶん、Claudeの答えは根拠の行番号つきで返してもらい、アドレスをダンプで引き直して確かめます。

参照した一次ソース

この記事の記述は、次の一次ソースと照合しています。更新時に参照先が変わった場合は一覧も更新します。

  1. code.claude.com/docs/en/headless
  2. docs.oracle.com/en/java/javase/21/docs/specs/man/jstack.html
  3. code.claude.com/docs/en/permissions
この記事を共有:XはてブLinkedIn