线上频出 MySQL 死锁问题！分享一下自己教科书般的排查和分析过程

2.核心错误的调用方法是哪个，即事务开始的方法是哪个?

30 行：at org.example.manager.impl.BizManagerImpl.transactionMoney(BizManagerImpl.java:25) ~[classes/:na] 31 行：at

【一线大厂Java面试题解析+后端开发学习笔记+最新架构讲解视频+实战项目源码讲义】
浏览器打开：qq.cn.hn/FTf 免费领取

org.example.manager.impl.BizManagerImpl

824241b9.invoke() ~[classes/:na]

过滤了 jdk 类、spring 类、mybatis 类后，得到核心的业务错误代码（30~31 行），31 行为 Spring 的代理执行，30 行才是真正最开始执行业务代码：BizManagerImpl.transactionMoney

1.2 数据库死锁日志

===============

接着去查看该库对应的数据库死锁日志，使用命令：show innodb engine status，过滤掉非重要的日志后如下：

LATEST?DETECTED?DEADLOCK

2020-07-14?23:34:29?0x7f958f1d5700

***?(1)?TRANSACTION:

TRANSACTION?95146580,?ACTIVE?2?sec?starting?index?read

mysql?tables?in?use?1,?locked?1

LOCK?WAIT?4?lock?struct(s),?heap?size?1136,?5?row?lock(s),?undo?log?entries?2

MySQL?thread?id?6264489,?OS?thread?handle?140273305761536,?query?id?837446998?10.10.59.164?root?updating

UPDATE?test_table?SET?money?=?money?+?5?WHERE?user_id?=?5

***?(1)?WAITING?FOR?THIS?LOCK?TO?BE?GRANTED:

RECORD?LOCKS?space?id?71816?page?no?4?n?bits?80?index?idx_user_id?of?table?mall.test_table?trx?id?95146580?lock_mode?X?locks?rec?but?not?gap?waiting

Record?lock,?heap?no?3?PHYSICAL?RECORD:?n_fields?2;?compact?format;?info?bits?0

0:?len?8;?hex?8000000000000005;?asc?????????;;

1:?len?8;?hex?8000000000000006;?asc?????????;;

***?(2)?TRANSACTION:

TRANSACTION?95146581,?ACTIVE?2?sec?starting?index?read

mysql?tables?in?use?1,?locked?1

4?lock?struct(s),?heap?size?1136,?5?row?lock(s),?undo?log?entries?2

MySQL?thread?id?6264490,?OS?thread?handle?140280327919360,?query?id?837446999?10.10.59.164?root?updating

UPDATE?test_table?SET?money?=?money?+?4?WHERE?user_id?=?4

***?(2)?HOLDS?THE?LOCK(S):

RECORD?LOCKS?space?id?71816?page?no?4?n?bits?80?index?idx_user_id?of?table?mall.test_table?trx?id?95146581?lock_mode?X?locks?rec?but?not?gap

Record?lock,?heap?no?3?PHYSICAL?RECORD:?n_fields?2;?compact?format;?info?bits?0

0:?len?8;?hex?8000000000000005;?asc?????????;;

1:?len?8;?hex?8000000000000006;?asc?????????;;

Record?lock,?heap?no?5?PHYSICAL?RECORD:?n_fields?2;?compact?format;?info?bits?0

0:?len?8;?hex?8000000000000001;?asc?????????;;

1:?len?8;?hex?8000000000000002;?asc?????????;;

***?(2)?WAITING?FOR?THIS?LOCK?TO?BE?GRANTED:

RECORD?LOCKS?space?id?71816?page?no?4?n?bits?80?index?idx_user_id?of?table?mall.test_table?trx?id?95146581?lock_mode?X?locks?rec?but?not?gap?waiting

Record?lock,?heap?no?2?PHYSICAL?RECORD:?n_fields?2;?compact?format;?info?bits?0

0:?len?8;?hex?8000000000000004;?asc?????????;;

1:?len?8;?hex?8000000000000005;?asc?????????;;

***?WE?ROLL?BACK?TRANSACTION?(2)

关键点总结如下：

1.该库中最近一次死锁发生的时间是什么时候？

4 行：2020-07-14 23:34:29 0x7f958f1d5700 得知，最近一次死锁发生在 2020-07-14 23:34:29

2.该次死锁导致的两个事务的重要信息？

12 行：RECORD LOCKS space id 71816 page no 4 n bits 80 index idx_user_id of table mall.test_table trx id 95146580 lock_mode X locks rec but not gap waiting 得知，事务 1 等待的锁为：lock_mode X locks rec but not gap waiting

24 行：RECORD LOCKS space id 71816 page no 4 n bits 80 index idx_user_id of table mall.test_table trx id 95146581 lock_mode X locks rec but not gap 得知，事务 2 持有的锁为：lock_mode X locks rec but not gap

34 行：RECORD LOCKS space id 71816 page no 4 n bits 80 index idx_user_id of table mall.test_table trx id 95146581 lock_mode X locks rec but not gap waiting 得知，事务 2 等待的锁为：lock_mode X locks rec but not gap waiting

39 行：*** WE ROLL BACK TRANSACTION (2)得知，最后回滚的是事务 1

从 12、24、34 行：index idx_user_id of table mall.test_table 得知：导致该次死锁的索引为：idx_user_id

3.能知道导致死锁的两个具体 SQL 吗？

不能，产生死锁的情况各式各样，事务中的 SQL 可能不止有两个 SQL，单从死锁日志是没法知道具体原因的，必须要结合业务代码查看事务上下文查看

2. 理论知识

============

排查过程中发现有个特点，影响的都是是线上的大用户。由于当时我很久没看死锁相关的理论知识，因此先去了解下相关死锁的基本知识。

2.1 死锁的条件

=============

1. 互斥条件：一个资源每次只能被一个进程使用。

2. 占有且等待：一个进程因请求资源而阻塞时，对已获得的资源保持不放。

3. 不可强行占有：进程已获得的资源，在未使用完之前，不能强行剥夺。

4. 循环等待条件：若干进程之间形成一种头尾相接的循环等待资源关系。

破坏死锁也很简单，四个条件破一个即可。（本案例是破坏的 4）

2.2 数据库的锁类型

===============

数据库的死锁比较复杂，主要是由 Insert、Update（其实在开发中 Delete 或 For Update 是不怎么不考虑的，因为在实际业务代码中我们一般不会有 Delete 或 For Update 的操作，删除都是物理删除，for update 建议少用，除非你知道非用不可）。InnoDB 的锁：

1. 共享锁与独占锁（S、X）

2. 意向锁

3. 记录锁（Record Locks）

4. 间隙锁（Gap Locks）

5. Next-Key Locks

6. 插入意向锁

7. 自增锁

8. 空间索引断言锁

这里参考了官网的 Innodb 锁分类，从死锁日志的 lock_mode X locks rec but not gap ，大致能知道，这里可能涉及了 X 锁、记录锁、间隙锁（但是有个 not，说明不涉及）。

3. 从死锁日志分析

===============

分析之前先得到该表的建表语句：show create table test_table;：

CREATE?TABLE?test_table?(

id?bigint(20)?NOT?NULL?AUTO_INCREMENT,

money?bigint(20)?NOT?NULL,

user_id?bigint(20)?NOT?NULL,

PRIMARY?KEY?(id),

KEY?idx_user_id?(user_id)

)?ENGINE=InnoDB?AUTO_INCREMENT=5?DEFAULT?CHARSET=utf8

接着结合死锁日志、锁的种类、建表语句得出以下模糊的结论：

1.从死锁日志的 10、12 行结合建表索引得知

10 行：UPDATE test_table SET money = money + 5 WHERE user_id = 512 行：RECORD LOCKS space id 71816 page no 4 n bits 80 index idx_user_id of table mall.test_table trx id 95146580

事务 1 的 UPDATE test_table SET money = money + 5 WHERE user_id = 5 语句在等待锁：它通过普通索引 idx_user_id 更新，先获取了 user_id=5 的 X 锁，接着去申请对应行的主键（Record Lock）的行锁但是被阻塞（waiting），并不包括间隙锁（not gap）。具体是哪个主键我们并不清楚。

2.从死锁日志的 22、24 行结合建表索引得知

22 行：UPDATE test_table SET money = money + 4 WHERE user_id = 424 行：Record lock, heap no 3 PHYSICAL RECORD: n_fields 2; compact format; info bits 0

事务 2 的 UPDATE test_table SET money = money + 4 WHERE user_id = 4 语句在持有锁：它通过普通索引 idx_user_id 更新，先获取了 user_id=4 的 X 锁，接着去申请对应行的主键（Record Lock）的行锁成功了，并不包括间隙锁（not gap）。具体是成功的哪个主键我们并不清楚。

3.从死锁日志的 22、34 行结合建表索引得知

22 行：UPDATE test_table SET money = money + 4 WHERE user_id = 434 行：RECORD LOCKS space id 71816 page no 4 n bits 80 index idx_user_id of table mall.test_table trx id 95146581 lock_mode X locks rec but not gap waiting

事务 2 的 UPDATE test_table SET money = money + 4 WHERE user_id = 4 语句在等待锁：它通过普通索引 idx_user_id 更新，先获取了 user_id=4 的 X 锁，接着去申请对应行的主键（Record Lock）的行锁但是被阻塞（waiting），并不包括间隙锁（not gap）。具体是哪个主键我们并不清楚。

模糊结论肯定是有问题的，最大的问题在于导致的 SQL 语句不正确，即：死锁的原因是真实的，但是具体是因为哪些 SQL 导致的死锁是不清楚的。接着我们整理得到了以下可能有问题的表格：

事务 1 事务 2 某些 SQL 某些 SQL 某个 SQL 的 user_id = 5 新更新操作被阻塞了某个 SQL 的 user_id = 4 获得了锁但是又阻塞了某些 SQL 某些 SQL

可以得知，其实单从死锁日志分析是比较片面的，因为 user_id 为 4、5 这两个 update 操作是不会有互相阻塞的问题，肯定是有别的 SQL 因此，我们需要额外从业务日志分析才能还原完整的现场。

4. 从业务日志分析

===============

从死锁日志是不能完全知道导致的关键 SQL 和故障现场的整体流程，因此我们要借助业务日志来完成最后对故障现场的分析：通过前面对业务日志的分析，我们知道最关键的调用方法是 BizManagerImpl.transactionMoney，查看对应源码：

@Override

@Transactional

public?boolean?transactionMoney(List<TransactionReqVO>?transactionReqVOList)?throws?Exception?{

for?(TransactionReqVO?transactionReqVO?:?transactionReqVOList)?{

//?模拟业务操作

Thread.sleep(1000);

int?updateCount?=?testTableService.update(transactionReqVO.getUserId(),?transactionReqVO.getMoney());

if?(updateCount?==?0)?{

log.error("转账异常："?+?transactionReqVO);

}

}

return?true;

}

可以知道，应该是 for 循环事务的问题，但是具体是哪些 user_id 是不清楚的，接着我们查看业务日志的上下文，通过全链路 traceId（模拟） 做搜索，得到以下的日志：

[ConsumerThread2] org.example.controller.TestController : 全局链路跟踪 id:2 的日志：[TransactionReqVO(userId=4, money=4), TransactionReqVO(userId=2, money=2), TransactionReqVO(userId=5, money=5)]

[ConsumerThread1] org.example.controller.TestController : 全局链路跟踪 id:1 的日志：[TransactionReqVO(userId=5, money=5), TransactionReqVO(userId=1, money=1), TransactionReqVO(userId=4, money=4)]

分析到这一步，我们已经可以还原死锁场景了，事务流程图如下：

5. 业务日志、死锁日志结合分析

=====================

将死锁日志分析得出的不正确表格加上业务日志分析得出正确表格，我们得出最终带有理解的最终正确的事务表格：