批量扣款任务卡死后,单笔扣款接口也全挂了
7 月 5 号早上 9 点 12 分,监控开始告警:/api/deduct 接口响应时间从 60 毫秒飙到 30 秒全部超时。同时 DBA 在群里说,account 表上有锁等待,已经持续 4 分钟。
第一反应是数据库慢查询。但登上机器看,应用这边 CPU 只有 6%,Tomcat 的 200 个线程里 187 个处于 BLOCKED 状态。这不像慢查询,像死锁。
jstack 直接给出了答案
抓一份线程栈:
$ jps -l
2831 /app/settle-service.jar
$ jstack -l 2831 > /tmp/stack.txt
$ tail -40 /tmp/stack.txt
jstack 自己就带死锁检测,输出到文件末尾:
Found one Java-level deadlock:
=============================
"batch-deduct-thread-2":
waiting to lock monitor 0x00007f9a34003e58 (object 0x00000006c1a2b3f0, a com.xxx.settle.AccountLockManager),
which is held by "http-nio-8080-exec-77"
"http-nio-8080-exec-77":
waiting to lock monitor 0x00007f9a34005f18 (object 0x00000006c1a2b410, a com.xxx.settle.AccountLockManager),
which is held by "batch-deduct-thread-2"
Java stack information for the threads listed above:
===================================================
"batch-deduct-thread-2" #92 prio=5 os_prio=0 tid=0x00007f9a1c2e0000 nid=0x8f21 waiting for monitor entry
java.lang.Thread.State: BLOCKED (on object monitor)
at com.xxx.settle.AccountLockManager.lock(AccountLockManager.java:44)
- waiting to lock <0x00000006c1a2b3f0> (a com.xxx.settle.AccountLockManager)
at com.xxx.settle.BatchDeductTask.process(BatchDeductTask.java:88)
...
"http-nio-8080-exec-77" #181 daemon prio=5 os_prio=0 tid=0x00007f9a1d104000 nid=0x3a7b waiting for monitor entry
java.lang.Thread.State: BLOCKED (on object monitor)
at com.xxx.settle.AccountLockManager.lock(AccountLockManager.java:44)
- waiting to lock <0x00000006c1a2b410> (a com.xxx.settle.AccountLockManager)
at com.xxx.settle.DeductService.deduct(DeductService.java:63)
at com.xxx.settle.DeductController.deduct(DeductController.java:31)
...
Found 1 deadlock.
-l 参数是必须的,不加它只打印线程的锁信息,不会做死锁检测分析。
死锁确实存在,但只有 2 个线程互相锁。那另外 185 个 BLOCKED 的线程是怎么回事?它们是被这两个线程连带堵住的——批量任务占着连接池的连接,接口线程拿不到连接,全堵在 DruidDataSource.getConnection 上。所以现象是"接口全挂",根因只有两个线程。
锁顺序不一致
出问题的 AccountLockManager 是我写的,为了在应用层保护账户余额,避免并发扣款。它给每个账户分配一把锁:
@Component
public class AccountLockManager {
private final ConcurrentHashMap<Long, ReentrantLock> locks = new ConcurrentHashMap<>();
public ReentrantLock getLock(Long accountId) {
return locks.computeIfAbsent(accountId, k -> new ReentrantLock());
}
}
然后业务代码这么用:
// 单笔扣款:先锁付款方,再锁收款方
public void deduct(Long fromId, Long toId, BigDecimal amount) {
ReentrantLock fromLock = lockManager.getLock(fromId);
ReentrantLock toLock = lockManager.getLock(toId);
fromLock.lock();
toLock.lock();
try {
accountMapper.deduct(fromId, amount);
accountMapper.add(toId, amount);
} finally {
toLock.unlock();
fromLock.unlock();
}
}
// 批量任务:遍历账户列表,逐个加锁
public void process(List<TransferBill> bills) {
// bills 里 fromId 和 toId 的顺序,取决于运营上传的 Excel
for (TransferBill bill : bills) {
ReentrantLock fromLock = lockManager.getLock(bill.getFromId());
ReentrantLock toLock = lockManager.getLock(bill.getToId());
fromLock.lock();
toLock.lock();
...
}
}
看起来两边都是"先 from 后 to",顺序一致。问题在于批量任务处理的是转账,而单笔接口处理的是扣款,两个语义的 from/to 是反的。运营上传的那批 Excel 里,A 账户作为收款方出现在第 3 行、作为付款方出现在第 17 行,批量任务就先锁了 to(A) 再锁 from(B);同时单笔接口来了一笔 B→A 的扣款,先锁 from(B) 再锁 to(A)。
两边拿着各自的锁等对方,经典死锁。
修复方式很简单:加锁前对 accountId 排序,保证全局的加锁顺序一致。
public void transfer(Long id1, Long id2, TransferCallback callback) {
// 按 id 大小排序,无论调用方怎么传,加锁顺序都一样
long first = Math.min(id1, id2);
long second = Math.max(id1, id2);
ReentrantLock lock1 = lockManager.getLock(first);
ReentrantLock lock2 = lockManager.getLock(second);
lock1.lock();
try {
if (first != second) {
lock2.lock();
}
try {
callback.doTransfer();
} finally {
if (first != second) {
lock2.unlock();
}
}
} finally {
lock1.unlock();
}
}
那个 first != second 的判断是因为 ReentrantLock 是可重入的,转出转入同一个账户时会重复加锁,虽然不会死锁但会加重入计数,unlock 次数对不上就麻烦了。
数据库锁和 JVM 锁交叉的坑
修完上面这个我以为完事了,压测的时候又碰到一次。这次 jstack 里的形态不一样:
"batch-deduct-thread-5" #95 prio=5 os_prio=0 tid=0x00007f9a1c2e3000 nid=0x8f24 runnable
java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(Native Method)
at com.mysql.cj.protocol.a.NativeProtocol.readMessage(NativeProtocol.java:555)
at com.xxx.settle.BatchDeductTask.process(BatchDeductTask.java:112)
- locked <0x00000006c1a2b3f0> (a com.xxx.settle.AccountLockManager)
这个线程是 RUNNABLE 状态,jstack 检测不出死锁——因为 JVM 层面它只是在等网络 IO,并没有阻塞在 monitor 上。它持着 JVM 锁,在等数据库的行锁。
而数据库那边的死锁日志是这样的:
------------------------
LATEST DETECTED DEADLOCK
------------------------
2019-07-08 14:33:21 0x7f2c8c0e9700
*** (1) TRANSACTION:
TRANSACTION 4218934, ACTIVE 12 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 3 lock struct(s), heap size 1136, 2 row lock(s)
UPDATE account SET balance = balance - 100.00 WHERE id = 1002
*** (2) TRANSACTION:
TRANSACTION 4218935, ACTIVE 11 sec starting index read
UPDATE account SET balance = balance + 100.00 WHERE id = 1001
*** (2) HOLDS THE LOCK(S): ...
*** WE ROLL BACK TRANSACTION (2)
MySQL 有死锁检测,会主动回滚其中一个事务(innodb_lock_wait_timeout 默认 50 秒,但死锁检测是立即触发的)。所以数据库这边不会永久卡住,回滚之后抛 DeadlockLoserDataAccessException。
真正麻烦的是这种组合:线程 A 持 JVM 锁 L1,等数据库行锁 R1;线程 B 持数据库行锁 R1,等 JVM 锁 L1。这种情况下 JVM 检测不到死锁(B 在 monitor 上等,A 在 socket 上等,不构成 monitor 环),数据库也检测不到(A 还没发出 SQL)。两边都干等,直到数据库连接超时或 JVM 锁等待超时。
我们的连接超时配的是 30 秒,所以这个 case 是等 30 秒报错退出,不是永久卡死。但 187 个线程堵着,损失已经造成了。
解决办法是让加锁顺序在 JVM 和数据库两个层面保持一致。我的做法是:
- 应用层锁和数据库操作,都按账户 ID 升序执行,SQL 里的
WHERE id IN (...)也保证顺序。 - 加超时。应用层锁用
tryLock(3, TimeUnit.SECONDS)替代lock(),拿不到就快速失败,避免无限堆积:
public boolean transferWithTimeout(long id1, long id2, TransferCallback callback) {
long first = Math.min(id1, id2);
long second = Math.max(id1, id2);
ReentrantLock lock1 = lockManager.getLock(first);
ReentrantLock lock2 = lockManager.getLock(second);
try {
if (!lock1.tryLock(3, TimeUnit.SECONDS)) {
log.warn("lock timeout, accountId={}", first);
return false;
}
try {
if (first != second && !lock2.tryLock(3, TimeUnit.SECONDS)) {
log.warn("lock timeout, accountId={}", second);
return false;
}
try {
callback.doTransfer();
return true;
} finally {
if (first != second) {
lock2.unlock();
}
}
} finally {
lock1.unlock();
}
} catch (InterruptedException e) {
Thread.currentThread().interrupt();
return false;
}
}
改完之后我写了个压测脚本,20 个线程随机做 5000 次双向转账(A→B 和 B→A 各一半),跑三轮:
| 版本 | 完成笔数 | 死锁次数 | lock 超时失败 | 平均耗时 |
|---|---|---|---|---|
| 修复前(随机顺序) | 2,841 / 5000 | 7 次 JVM 死锁 | 0 | — |
| 仅排序 | 5000 / 5000 | 0 | 0 | 18 ms |
| 排序 + tryLock | 4,967 / 5000 | 0 | 33 次 | 19 ms |
第三行那 33 次超时失败是 tryLock 主动放弃的,业务上重试即可,总比整池线程堵死强。生产上我把超时设成了 3 秒,实际观察下来失败率 0.02%,重试一次就成功。
再加一道保险:让程序自己发现死锁
修完之后我还是不放心。死锁这种问题,靠人定期 jstack 是不靠谱的,得让程序自己盯着。ThreadMXBean 提供了现成的 API:
@Component
public class DeadlockDetector {
private static final Logger log = LoggerFactory.getLogger(DeadlockDetector.class);
private final ThreadMXBean threadMxBean = ManagementFactory.getThreadMXBean();
private final ScheduledExecutorService scheduler =
Executors.newSingleThreadScheduledExecutor(
new ThreadFactoryBuilder().setNameFormat("deadlock-detect-%d").build());
@PostConstruct
public void start() {
// 每 30 秒检测一次
scheduler.scheduleAtFixedRate(this::detect, 30, 30, TimeUnit.SECONDS);
}
private void detect() {
long[] deadlocked = threadMxBean.findDeadlockedThreads();
// ↑ 这个方法能检测"可能造成死锁的线程循环等待",
// 比 findMonitorDeadlockedThreads 更全面(后者只管 synchronized)
if (deadlocked == null || deadlocked.length == 0) {
return;
}
log.error("DEADLOCK DETECTED, thread count={}", deadlocked.length);
ThreadInfo[] infos = threadMxBean.getThreadInfo(deadlocked, true, true);
StringBuilder sb = new StringBuilder();
for (ThreadInfo info : infos) {
sb.append("\n--- ").append(info.getThreadName())
.append(" (id=").append(info.getThreadId())
.append(", state=").append(info.getThreadState()).append(")")
.append("\n waiting on: ").append(info.getLockName())
.append("\n owned by : ").append(info.getLockOwnerName());
for (StackTraceElement e : info.getStackTrace()) {
sb.append("\n at ").append(e);
}
}
log.error(sb.toString());
// 同时把完整的 jstack 输出存一份到文件,方便事后分析
dumpAllThreads();
}
}
这个检测器上线之后,我们在预发环境又抓到一次死锁,是另一个同事新写的优惠券核销逻辑,锁顺序同样没统一。这次在上线前就发现了。
有个坑要注意:findDeadlockedThreads() 在 JDK 8 上,如果线程是在等待 AbstractOwnableSynchronizer(也就是 ReentrantLock 这类)造成的循环等待,它能检测出来;但如果环里有线程在等 socket IO(就像上面那个数据库锁交叉的 case),它检测不出来。所以它不是万能的,只是多一层防护。
另外说一下 BLOCKED 和 WAITING 在 jstack 里的区别,我刚开始老搞混:
BLOCKED (on object monitor):线程在进入synchronized块时拿不到锁,被动阻塞。它的waiting to lock <0x...>指向它想要的锁。WAITING (parking):线程主动调用了LockSupport.park()(ReentrantLock.lock()、Object.wait()最终都走这里)。它可以被unpark唤醒。TIMED_WAITING (parking):带超时的 park,比如tryLock(3, SECONDS)、Thread.sleep()。
所以判断死锁要看 BLOCKED 和 WAITING 里那些带 waiting to lock 的线程,它们构成环才是死锁。纯 WAITING (parking) 且没有 waiting to lock 的,多半是线程池里的空闲线程,正常。
排查死锁的固定动作
总结下我现在遇到"线程 BLOCKED / 接口全挂"时的处理顺序:
jstack -l <pid> > /tmp/stack.txt,先看文件末尾有没有Found one Java-level deadlock。有就直接看是哪两个 monitor。- 没有的话,
grep -c 'BLOCKED' /tmp/stack.txt数一下阻塞线程数,再grep -A 3 'BLOCKED' | grep 'waiting to lock'看它们都在等哪个对象地址。如果大量线程等同一个地址,通常是某个长事务或者外部调用把锁持有者卡住了,不是死锁。 - 隔 5 秒再抓一份,对比两次的
nid状态。真死锁的线程状态不会变化,慢查询导致的阻塞会看到进展。 - 顺手看一眼数据库:
SHOW ENGINE INNODB STATUS\G的LATEST DETECTED DEADLOCK段,以及SELECT * FROM information_schema.INNODB_LOCK_WAITS。
最后一步很重要。这次的第二个 case 就是纯 JVM 层面看不出来的,必须两边对着看。跨资源的死锁,单边工具都无能为力。
留个问题
关于《一次线上死锁排查:jstack 定位与修复》里这个坑,你当时是怎么处理的?欢迎在评论区聊聊你踩过的类似情况。