bigywater.tech
Java · 343

jstack:从线程转储读取阻塞关系

线程转储里的每一行都是线索,但同样叫 WAITING 的线程可能卡在完全不同的地方。这篇用真实的 jstack 输出逐项对照,并实测 -l、cpu=、死锁段落和虚拟线程的转储方式。

189 → 249
jstack 加 -l 之后输出的行数(多出 Locked ownable synchronizers)
1088 / 1071 ms
spin 线程在连续两个 1 秒间隔里 cpu= 的增量
0 vs 3
jstack 与 jcmd Thread.dump_to_file(JSON)各能看到的虚拟线程数

四种等待在 jstack 里的写法

实测 · 本机执行输出
  jstack 输出共 189 行,27 个线程块(含 JVM 内部线程)
    "owner" daemon prio=5 cpu=0.04ms elapsed=1.61s waiting on condition  [0x000000017232a000]
       java.lang.Thread.State: TIMED_WAITING (sleeping)
      at java.lang.Thread.sleep0(Native Method)
      at java.lang.Thread.sleep(Thread.java:509)
      at Main.sl(Main.java:7)
      at Main.lambda$main$0(Main.java:9)
      - locked <0x00000070106162a8> (a java.lang.Object)
    "blocked-w" daemon prio=5 cpu=0.07ms elapsed=1.50s waiting for monitor entry  [0x0000000172536000]
       java.lang.Thread.State: BLOCKED (on object monitor)
      at Main.lambda$main$1(Main.java:10)
      - waiting to lock <0x00000070106162a8> (a java.lang.Object)
      at Main$$Lambda/0x0000008001000c28.run(Unknown Source)
      at java.lang.Thread.runWith(Thread.java:1596)
      at java.lang.Thread.run(Thread.java:1583)
    "waiter" daemon prio=5 cpu=0.04ms elapsed=1.50s in Object.wait()  [0x0000000172742000]
       java.lang.Thread.State: WAITING (on object monitor)
      at java.lang.Object.wait0(Native Method)
      - waiting on <0x00000070106162b8> (a java.lang.Object)
      at java.lang.Object.wait(Object.java:366)
      at java.lang.Object.wait(Object.java:339)
      at Main.lambda$main$2(Main.java:11)
    "sleeper" daemon prio=5 cpu=0.03ms elapsed=1.50s waiting on condition  [0x000000017294e000]
       java.lang.Thread.State: TIMED_WAITING (sleeping)
      at java.lang.Thread.sleep0(Native Method)
      at java.lang.Thread.sleep(Thread.java:509)
      at Main.sl(Main.java:7)
      at Main.lambda$main$3(Main.java:12)
      at Main$$Lambda/0x0000008001001220.run(Unknown Source)
    "lock-waiter" daemon prio=5 cpu=0.09ms elapsed=1.40s waiting on condition  [0x0000000172d66000]
       java.lang.Thread.State: WAITING (parking)
      at jdk.internal.misc.Unsafe.park(Native Method)
      - parking to wait for  <0x00000070106163c0> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)
      at java.util.concurrent.locks.LockSupport.park(LockSupport.java:221)
      at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:788)
      at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1024)
    "parker" daemon prio=5 cpu=0.12ms elapsed=1.40s waiting on condition  [0x0000000172f72000]
       java.lang.Thread.State: WAITING (parking)
      at jdk.internal.misc.Unsafe.park(Native Method)
      - parking to wait for  <0x0000007010400000> (a java.lang.String)
      at java.util.concurrent.locks.LockSupport.park(LockSupport.java:221)
      at Main.lambda$main$6(Main.java:15)
      at Main$$Lambda/0x0000008001001880.run(Unknown Source)
    "queue-taker" daemon prio=5 cpu=1.59ms elapsed=1.40s waiting on condition  [0x000000017338a000]
       java.lang.Thread.State: WAITING (parking)
      at jdk.internal.misc.Unsafe.park(Native Method)
      - parking to wait for  <0x0000007010470da0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
      at java.util.concurrent.locks.LockSupport.park(LockSupport.java:371)
      at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionNode.block(AbstractQueuedSynchronizer.java:519)
      at java.util.concurrent.ForkJoinPool.unmanagedBlock(ForkJoinPool.java:3780)
    "spin" daemon prio=5 cpu=1395.87ms elapsed=1.40s runnable  [0x000000017317e000]
       java.lang.Thread.State: RUNNABLE
      at Main.lambda$main$7(Main.java:16)
      at Main$$Lambda/0x0000008001001aa0.run(Unknown Source)
      at java.lang.Thread.runWith(Thread.java:1596)
      at java.lang.Thread.run(Thread.java:1583)

jstack -l

实测 · 本机执行输出
  不加 -l:lock-owner 线程的最后 3 行:
      at Main$$Lambda/0x0000008001001440.run(Unknown Source)
      at java.lang.Thread.runWith(Thread.java:1596)
      at java.lang.Thread.run(Thread.java:1583)
  不加 -l:全文里 “Locked ownable synchronizers” 出现 0 次
  加 -l:lock-owner 线程的最后 3 行:
    
       Locked ownable synchronizers:
      - <0x00000070106163c0> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)
  加 -l:全文里 “Locked ownable synchronizers” 出现 20 次
  加 -l:lock-waiter 线程的最后 3 行:
    
       Locked ownable synchronizers:
      - None
  不加 -l 与加 -l 的行数: 189 → 249

用 cpu= 找忙线程

实测 · 本机执行输出
  线程                   第 1 次       第 2 次       第 3 次  (cpu= 毫秒)
  spin                1562.6      2650.8      3721.9
  VM Thread              1.0         1.2         1.4
  Attach Listener         0.7         0.8         1.0
  VM Periodic Task Thread         0.3         0.4         0.6
  Monitor Deflation Thread         0.1         0.1         0.1
  spin 线程在这两个 1 秒间隔里分别涨了 1088、1071 ms

jcmd Thread.print

实测 · 本机执行输出
  jcmd Thread.print:27 个线程块;jstack:27 个;线程名集合是否相同:True

死锁段落

实测 · 本机执行输出
  [不加 -l] 以 Found 开头的行:['Found one Java-level deadlock:', 'Found one Java-level deadlock:', 'Found 2 deadlocks.'];rl-1 出现在死锁段落里:True;“waiting for ownable synchronizer” 行数:2
  [加 -l] 以 Found 开头的行:['Found one Java-level deadlock:', 'Found one Java-level deadlock:', 'Found 2 deadlocks.'];rl-1 出现在死锁段落里:True;“waiting for ownable synchronizer” 行数:2
  不加 -l 的死锁段落(两个都是,节选):
    Found one Java-level deadlock:
    =============================
    "dl-1":
      waiting to lock monitor 0x0000007aab125960 (object 0x00000070106162d8, a java.lang.Object),
      which is held by "dl-2"
    "dl-2":
      waiting to lock monitor 0x0000007aab125a40 (object 0x00000070106162c8, a java.lang.Object),
      which is held by "dl-1"
    Java stack information for the threads listed above:
    ===================================================
    "dl-1":
    "dl-2":
    Found one Java-level deadlock:
    =============================
    "rl-1":
      waiting for ownable synchronizer 0x0000007010616420, (a java.util.concurrent.locks.ReentrantLock$NonfairSync),
      which is held by "rl-2"
    "rl-2":
      waiting for ownable synchronizer 0x00000070106163f0, (a java.util.concurrent.locks.ReentrantLock$NonfairSync),
      which is held by "rl-1"
    Java stack information for the threads listed above:
    ===================================================
    "rl-1":
    "rl-2":
    Found 2 deadlocks.

虚拟线程

实测 · 本机执行输出
  jstack 输出里名字为 vt-0/1/2 的线程块数: 0
  jcmd Thread.dump_to_file: Created <实验目录>
  JSON 的线程容器: [('<root>', 19), ('ForkJoinPool-1/jdk.internal.vm.SharedThreadContainer@6997d62', 3), ('java.util.concurrent.ThreadPoolExecutor@65b54208', 0), ('ForkJoinPool.commonPool/jdk.internal.vm.SharedThreadContainer@597d7f9', 0), ('java.util.concurrent.ScheduledThreadPoolExecutor@28a418fc', 1)]
  JSON 里找到 vt-* 线程: 3 ;其中一个的栈顶: java.base/java.lang.VirtualThread.parkNanos(VirtualThread.java:635)
  文本格式 dump_to_file 里 vt-* 出现次数: 3

分步演示

jstack
本步的对象

    本文用到的工具与边界

    • 本机 macOS 27 arm64 / OpenJDK(Temurin 17.0.20、Homebrew 21.0.12 与 27,每篇注明实际用的版本);用 javac 编译、java 直接运行,需要第三方库时用 Maven 解析依赖;计时用 System.nanoTime,数字每次运行会有小幅抖动。JDK 21.0.12,jstack / jcmd 都是命令行真实调用;转储里为排版去掉了 tid/nid 与模块版本前缀
    • 没有验证:JDK 17 与 27 的 jstack 输出差异、-l 对大量线程的转储耗时与停顿、被转储 JVM 在 safepoint 下卡住时 jstack 的行为、Linux 上的 nid 与 top -H 对应关系(这台是 macOS)
    京ICP备2026067502号-1京公网安备11010502063487号