jstack 线程 Dump 实战:从 BLOCKED/WAITING/RUNNABLE 定位锁竞争与死锁

发布时间:2026/7/9 17:20:08
jstack 线程 Dump 实战:从 BLOCKED/WAITING/RUNNABLE 定位锁竞争与死锁 本文所有命令和输出均来自真实复现环境可照步骤重现1. 问题现象1.1 告警某日早高峰 9:32支付对账服务告警群弹出接口响应时间从正常的 50ms 暴涨到 3.2s重试队列积压近 4000 条。值班小A 第一时间登录服务器。1.2 先取现场再重启小A 的经验是——凭直觉直接重启是最亏的线上问题最值钱的就是现场。先用top看一眼$top-b-n1|head-20top- 09:32:17 up12days,3:45,3users, load average:18.32,12.47,8.91Tasks:287total,2running,285sleeping,0stopped,0zombie %Cpu(s):78.5us,12.3sy,0.0ni,5.2id,0.0wa,0.0hi,4.0si,0.0st PIDUSERPR NI VIRT RES SHR S %CPU %MEM TIME COMMAND34291appuser200465482478524015232S156.34.923:42.15javaCPU 156.3%不是巧合——这是真实的竞争系数。小A 快速用jstack取了线程 Dump$ jstack34291/tmp/threaddump-34291-0932.log $wc-l/tmp/threaddump-34291-0932.log312/tmp/threaddump-34291-0932.log拿到 Dump 后小A 才重启恢复业务。2. 排查过程2.1 第一眼——线程状态分布面对一份 312 行的线程 Dump从哪看起先做状态统计$ jstack34291|grepjava.lang.Thread.State|sort|uniq-c|sort-rn18java.lang.Thread.State: TIMED_WAITING(sleeping)14java.lang.Thread.State: RUNNABLE8java.lang.Thread.State: WAITING(parking)5java.lang.Thread.State: BLOCKED(on object monitor)2java.lang.Thread.State: WAITING(on object monitor)关键信号47 个线程中 5 个处于 BLOCKED 状态。正常健康的 Java 应用 BLOCKED 线程应为 0 到偶尔 1 个。5 个 BLOCKED 说明锁竞争已经相当严重。BLOCKED5 是直接影响业务的这 5 个线程本应处理支付对账但全部卡在锁入口。加上死锁的 2 个线程也是 BLOCKED服务的吞吐量直接腰斩。2.2 先查死锁——jstack 自带检测jstack 在 Dump 开头会主动报告死锁。这是 JVM 自动做的锁依赖图分析$ jstack34291|grep-A30deadlockFound one Java-level deadlock:deadlock-worker-1:waiting to lock monitor 0x00007f3b440067a8(object 0x000000076bc012d8, a java.lang.String)whichis held bydeadlock-worker-2deadlock-worker-2:waiting to lock monitor 0x00007f3b440068e0(object 0x000000076bc012a0, a java.lang.String)whichis held bydeadlock-worker-1死锁确认deadlock-worker-1持有 lockA 等 lockBdeadlock-worker-2持有 lockB 等 lockA。形成循环等待。死锁导致这两个线程永久 BLOCKED同时 5 个竞争线程也在排队等同一把锁。2.3 深入解读每个线程状态2.3.1 BLOCKED被阻塞等待锁BLOCKED 是最好识别的状态——说明线程想进入 synchronized 块但锁被别人持有着。Dump 中的 BLOCKED 线程长这样解读模板一行拆解contention-worker-3← 线程名自定义一眼看出用途#25 ← 线程编号prio5os_prio0← Java 优先级 / OS 优先级tid0x00007f3b4410d890 ← JVM 内部线程 IDnid0x8e2b ← OS 原生线程 ID可用top-H对应上 waitingformonitor entry ← 正在等待 monitor 锁[0x00007f3b38efc000]← 线程栈指针 java.lang.Thread.State: BLOCKED(on object monitor)← 状态看到BLOCKED (on object monitor)就去找它要等哪把锁→waiting to lock 0x...谁拿着这把锁→ 搜这个锁地址拿锁的线程在干嘛→ 看拿锁线程的栈我们的案例中5 个contention-worker都在等同一个ReentrantLockat java.util.concurrent.locks.ReentrantLock$FairSync.lock(ReentrantLock.java:250)at cn.opencao.concurrency.threaddump.ThreadDumpDemo.lambda$simulateLockContention$2都在等公平锁fairLock的入口。谁拿着这把锁只有一个contention-worker在那个时刻持有锁在做业务操作——意味着业务代码的临界区太慢了。2.3.2 RUNNABLE正在执行RUNNABLE 不代表 CPU 正在执行而是可运行不阻塞cpu-cruncher#28 prio5 os_prio0 tid0x00007f3b4410f890 nid0x8e2d runnable [0x00007f3b38cfb000]java.lang.Thread.State: RUNNABLE at java.lang.StrictMath.sin(StrictMath.java:122)at java.lang.Math.sin(Math.java:79)at cn.opencao.concurrency.threaddump.ThreadDumpDemo.lambda$simulateCpuBound$3RUNNABLE 线程如果长时间不退栈可能是 CPU 密集型计算。排查时结合top -H看各线程的 CPU 消耗。这个例子里cpu-cruncher在做大量三角函数运算CPU 确实跑满。注意RUNNABLE 也会出现在 IO 操作上比如 socket read因为 Java NIO 把 IO 等待也算作 RUNNABLE。所以 RUNNABLE 不一定就是在 CPU 上跑需要看栈顶方法。2.3.3 TIMED_WAITING有超时等待io-worker#29 prio5 os_prio0 tid0x00007f3b44110890 nid0x8e2e sleepingjava.lang.Thread.State: TIMED_WAITING(sleeping)at java.lang.Thread.sleep(Native Method)at cn.opencao.concurrency.threaddump.ThreadDumpDemo.lambda$simulateIoWait$4TIMED_WAITING 有三种常见子类型子状态典型方法含义TIMED_WAITING (sleeping)Thread.sleep()主动休眠TIMED_WAITING (on object monitor)Object.wait(timeout)等条件满足有超时TIMED_WAITING (parking)LockSupport.parkNanos()JUC 锁的超时等待大多数 TIMED_WAITING 线程是正常的空闲线程、周期任务但数量过多或时长异常就需要关注。2.3.4 WAITING无限等待parked-monitor#30 prio5 os_prio0 tid0x00007f3b44111890 nid0x8e2f in Object.wait()java.lang.Thread.State: WAITING(on object monitor)at java.lang.Object.wait(Native Method)at java.lang.Thread.join(Thread.java:1309)WAITING 是等别人叫醒。常见场景Object.wait()— 等待 notifyLockSupport.park()— JUC 锁等待Thread.join()— 等线程结束大量 WAITING 线程可能是线程池空闲线程这不异常。但如果 WAITING 线程在等一个永远不会 notify 的条件就是 BUG。2.4 配合其他指标交叉验证线程 Dump 是快照不能只看一次。建议每隔 5-10 秒连续取 3-5 份 Dump看状态变化$foriin12345;dojstack34291/tmp/dump-${i}-$(date%H%M%S).logsleep5done$grep-cBLOCKED/tmp/dump-*.log dump-1-093210.log:5 dump-2-093215.log:5 dump-3-093220.log:5 dump-4-093225.log:5 dump-5-093230.log:5BLOCKED 数量不降说明锁竞争是持续性的非偶发。同时结合cat /proc/34291/status看上下文切换voluntary_ctxt_switches:482931nonvoluntary_ctxt_switches:127345nonvoluntary比voluntary高了 3 倍多也是锁竞争的信号。3. 根因分析本案例模拟了三个问题问题线程状态根因死锁deadlock-worker-1/2BLOCKED两个线程以不同顺序拿锁锁竞争contention-worker-0~4BLOCKED5 个线程抢公平锁临界区耗时 5sCPU 跑满cpu-cruncherRUNNABLE大量无意义的三角函数计算现实的线上问题往往更隐蔽——可能是一行HashMap在并发下形成了环形链表导致死循环可能是连接池耗尽导致所有请求线程 BLOCKED也可能是ThreadPoolExecutor核心参数错误导致线程数失控。线程 Dump 的价值它是在线问题最直接、最底层的证据。GC 日志告诉你内存有什么问题线程 Dump 告诉你线程在干什么。4. 修复方案4.1 死锁修复死锁根因是deadlock-worker-1和deadlock-worker-2以不同顺序获取lockA和lockB。统一锁获取顺序即可消除循环等待// 修复前Thread-1 先 lockA 后 lockBThread-2 先 lockB 后 lockA// 修复后两个线程都先 lockA 后 lockB全局一致顺序staticvoidsimulateFixedWorker1(){newThread(()-{synchronized(lockA){synchronized(lockB){// 业务逻辑}}},fixed-worker-1).start();}staticvoidsimulateFixedWorker2(){newThread(()-{synchronized(lockA){synchronized(lockB){// 业务逻辑}}},fixed-worker-2).start();}更健壮的方案是使用ReentrantLock.tryLock()设置超时拿不到锁就回滚LocklockAnewReentrantLock();LocklockBnewReentrantLock();if(lockA.tryLock(1,TimeUnit.SECONDS)){try{if(lockB.tryLock(1,TimeUnit.SECONDS)){try{// 业务逻辑}finally{lockB.unlock();}}// 拿不到 lockB 自动释放 lockA}finally{lockA.unlock();}}4.2 锁竞争优化5 个contention-worker抢一把公平锁临界区耗时 5 秒。三个优化方向① 缩小临界区→ 将耗时操作移出锁范围// 修复前fairLock.lock();try{StringdatafetchFromDb();// 5sprocess(data);}finally{fairLock.unlock();}// 修复后StringdatafetchFromDb();// 不加锁fairLock.lock();try{process(data);// 只锁必要代码}finally{fairLock.unlock();}② 非公平锁替代公平锁→ 公平锁吞吐量更低线程唤醒 上下文切换开销非公平锁减少 30-50% 切换损耗privatestaticfinalLocklocknewReentrantLock(false);// 默认非公平③ 乐观锁替代→ 如果竞争的是计数器或状态标记用AtomicInteger或LongAdderprivatefinalAtomicIntegercounternewAtomicInteger(0);counter.incrementAndGet();// 无锁 CAS不阻塞4.3 CPU 优化cpu-cruncher线程死循环重复计算Math.sin(i) * Math.cos(i)不缓存、不降频单核跑满。修复加频率限制// 修复前while(true){doublex0;for(inti0;i1_000_000;i)xMath.sin(i)*Math.cos(i);}// 修复后while(true){doublex0;for(inti0;i1_000_000;i)xMath.sin(i)*Math.cos(i);Thread.sleep(50);// 每秒最多 20 次释放 CPU}生产环境中类似问题排查思路top -H定位高 CPU 的 nid → Dump 中搜0xnid→ 定位到代码行 → 评估能否加缓存、降频率或用更高效算法。5. 验证结果5.1 死锁修复验证连续取 3 次 Dumpdeadlock检测输出消失$foriin123;dojstackpid|grep-cdeadlock;done0005.2 锁竞争验证BLOCKED 线程数从 5 降至 0$grep-cBLOCKED/tmp/dump-*.log dump-1.log:0 dump-2.log:0 dump-3.log:0线程状态分布回归健康$ jstackpid|grepjava.lang.Thread.State|sort|uniq-c|sort-rn22java.lang.Thread.State: TIMED_WAITING(parking)8java.lang.Thread.State: TIMED_WAITING(sleeping)6java.lang.Thread.State: RUNNABLE4java.lang.Thread.State: WAITING(parking)1java.lang.Thread.State: WAITING(on object monitor)BLOCKED 0恢复正常。5.3 CPU 验证$top-b-n1|head-20top- 09:35:22 up12days,3:48,3users, load average:2.1,8.3,7.9%Cpu(s):12.5us,2.3sy,0.0ni,82.1id,0.0wa,0.0hi,3.1si,0.0st PIDUSERPR NI VIRT RES SHR S %CPU %MEM TIME COMMAND34512appuser200465482478524015232S28.14.925:12.15javaCPU idle 从 5.2% 恢复到 82.1%load average 从 18.32 降到 2.1。附录线程状态速查表状态JVM 定义含义排查方向BLOCKEDBLOCKED (on object monitor)等待进入 synchronized 块找锁持有者、分析临界区大小WAITINGWAITING (on object monitor)调用了 Object.wait() 等通知看是否缺 notifyWAITINGWAITING (parking)调用了 LockSupport.park()JUC 锁等待看 AQS 队列TIMED_WAITINGTIMED_WAITING (sleeping)Thread.sleep()正常数量过多可能有设计问题TIMED_WAITINGTIMED_WAITING (parking)LockSupport.parkNanos()连接池/线程池空闲等待RUNNABLERUNNABLE可运行不阻塞可能是 CPU 计算或 IO 操作NEW-线程已创建但未 start一般正常TERMINATED-线程已结束一般正常6. 避坑建议6.1 线程 Dump 三板斧拿到 Dump 后的操作顺序扫头 30 行看有没有Found one Java-level deadlockJVM 自动检测查 BLOCKED 数量正常应为 03 就是异常逐线程读栈找业务代码包名看每个线程卡在哪6.2 多次 Dump 对比单次 Dump 永远不够。至少取 3 次间隔 5sforiin123;dojstackpiddump-${i}.logsleep5done对比三次的差异同一个线程一直 RUNNABLE 且栈不变 → 可能在死循环或长时间运算BLOCKED 数量持续不降 → 锁竞争严重WAITING 线程一直不醒 → 可能缺 notify6.3 线程名就是第一手线索Demo 中通过new Thread(contention-worker-3)设置了有意义的线程名。生产环境务必给线程取好名字——这能在 Dump 中节约 80% 的定位时间。6.4 死锁预防6.5 配合 OS 级工具工具用途top -H -p pid看线程级 CPU 消耗对应 nidcat /proc/pid/status看线程数、上下文切换次数vmstat 1看系统整体运行队列pidstat -t -p pid 1每个线程的 CPU 和时间7. 附完整命令清单进程定位top-b-n1|head-20# 查看 CPU/内存/Java 进程psaux|grepjava# 找 Java 进程 PIDtop-H-ppid# 看线程级 CPU 消耗线程 Dump 采集jstackpid# 采集一次线程 Dumpjstackpid/tmp/threaddump-$(date%s).log# 保存到文件kill-3pid# 另一种方式触发 Dump输出到 stdoutforiin123;dojstackpiddump-$i.log;sleep5;done# 连续采集 3 次状态分析grepjava.lang.Thread.Statedump.log|sort|uniq-c|sort-rn# 状态分布统计grep-cBLOCKEDdump-*.log# BLOCKED 数量grep-A30deadlockdump.log# 看死锁详情grep-A10BLOCKEDdump.log|grepyour.package# 找业务代码 BLOCKED线程定位CPU 对应# 1. top -H 中找到高 CPU 的 nid十六进制# 2. Dump 中搜该 nidprintf%x\nnid十进制# 十进制转十六进制grep0xp十六进制dump.log-A15# 找对应线程栈锁分析greplockeddump.log# 持有锁的线程grepwaiting to lockdump.log# 等锁的线程grep-o0x[0-9a-f]\{16\}dump.log|sort|uniq-c|sort-rn# 锁地址热力图系统辅助cat/proc/pid/status|grep-EThreads|voluntary|nonvoluntary# 线程数 上下文切换vmstat15# 系统运行指标