难得真实的生产数据库死锁问题排查过程记录-51CTO.COM

以下是笔者看网上并结合自己的经历整理所得。真真切切的发生的事情。希望能帮助到你

这是一个真实的生产问题，经过长时间的排查和多次寻求 DBA 的帮助，最终我自己花了一个月的时间才定位到这个问题。问题非常有意思，值得大家关注。

问题现象

某天晚上，同事正在发布时，突然线上出现大量报警，其中很多是关于数据库死锁的。报警提示信息如下：

{"errorCode":"SYSTEM_ERROR","errorMsg":"nested exception is org.apache.ibatis.exceptions.PersistenceException:

 Error updating database. Cause: ERR-CODE: [TDDL-4614][ERR_EXECUTE_ON_MYSQL]

 Deadlock found when trying to get lock;

 The error occurred while setting parameters\n### SQL:

   update fund_transfer_stream set gmt_modified=now(),state = ? where fund_transfer_order_no = ? and seller_id = ? and state = 'NEW'

通过报警，我们基本可以确定发生死锁的数据库和数据库表。现在先来介绍一下本文案例中涉及的数据库相关信息。

问题背景

使用的数据库是 MySQL 5.7，引擎是 InnoDB，事务隔离级别是 READ-COMMITED。

数据库版本查询方法：

SELECT version();

引擎查询方法：

show create table fund_transfer_stream;

建表语句中会显示存储引擎信息，形如：ENGINE=InnoDB

事务隔离级别查询方法：

select @@tx_isolation;

事务隔离级别设置方法（只对当前 Session 生效）：

set session transaction isolation level read committed;

★
PS：请注意，如果数据库是分库的，以下几条 SQL 语句需要在单个库中执行，而不是在逻辑库中执行。

以下是发生死锁的表的结构及部分索引情况（已隐去部分无关字段和索引）：

CREATE TABLE `fund_transfer_stream` (
  `id` bigint(20) unsigned NOT NULL AUTO_INCREMENT COMMENT '主键',
  `gmt_create` datetime NOT NULL COMMENT '创建时间',
  `gmt_modified` datetime NOT NULL COMMENT '修改时间',
  `pay_scene_name` varchar(256) NOT NULL COMMENT '支付场景名称',
  `pay_scene_version` varchar(256) DEFAULT NULL COMMENT '支付场景版本',
  `identifier` varchar(256) NOT NULL COMMENT '唯一性标识',
  `seller_id` varchar(64) NOT NULL COMMENT '卖家Id',
  `state` varchar(64) DEFAULT NULL COMMENT '状态', `fund_transfer_order_no` varchar(256)
  DEFAULT NULL COMMENT '资金平台返回的状态',
  PRIMARY KEY (`id`),
  KEY `idx_seller` (`seller_id`),
  KEY `idx_seller_transNo` (`seller_id`,`fund_transfer_order_no`(20))
  ) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COMMENT='资金流水';

该数据库具有三个索引，包括一个聚簇索引（主键索引）和两个非聚簇索引（非主键索引）。

聚簇索引：

PRIMARY KEY (`id`)

非聚簇索引：

KEY `idx_seller` (`seller_id`),

KEY `idx_seller_transNo` (`seller_id`,`fund_transfer_order_no`(20))

以上两个索引中，实际上 idx_seller_transNo 已经覆盖了 idx_seller。由于历史原因，该表在引入 idx_seller 之后才引入了 idx_seller_transNo。

死锁日志

当数据库发生死锁时，可以通过以下命令获取死锁日志：

show engine innodb status

发生死锁，第一时间查看死锁日志，得到死锁日志内容如下：

Transactions deadlock detected, dumping detailed information.
2019-03-19T21:44:23.516263+08:00 5877341 [Note] InnoDB:

*** (1) TRANSACTION:
TRANSACTION 173268495, ACTIVE 0 sec fetching rows
mysql tables in use 1, locked 1
LOCK WAIT 304 lock struct(s), heap size 41168, 6 row lock(s), undo log entries 1
MySQL thread id 5877358, OS thread handle 47356539049728, query id 557970181 11.183.244.150 fin_instant_app updating

update `fund_transfer_stream` set `gmt_modified` = NOW(), `state` = 'PROCESSING' where ((`state` = 'NEW') AND (`seller_id` = '38921111') AND (`fund_transfer_order_no` = '99010015000805619031958363857'))
2019-03-19T21:44:23.516321+08:00 5877341 [Note] InnoDB:

*** (1) HOLDS THE LOCK(S):
RECORD LOCKS space id 173 page no 13726 n bits 248 index idx_seller_transNo of table `xxx`.`fund_transfer_stream` trx id 173268495 lock_mode X locks rec but not gap
  Record lock, heap no 168 PHYSICAL RECORD: n_fields 3; compact format; info bits 0

  2019-03-19T21:44:23.516565+08:00 5877341 [Note] InnoDB:

  *** (1) WAITING FOR THIS LOCK TO BE GRANTED:
  RECORD LOCKS space id 173 page no 12416 n bits 128 index PRIMARY of table `xxx`.`fund_transfer_stream` trx id 173268495 lock_mode X locks rec but not gap waiting
    Record lock, heap no 56 PHYSICAL RECORD: n_fields 17; compact format; info bits 0
    2019-03-19T21:44:23.517793+08:00 5877341 [Note] InnoDB:

    *** (2) TRANSACTION:
    TRANSACTION 173268500, ACTIVE 0 sec fetching rows, thread declared inside InnoDB 81
    mysql tables in use 1, locked 1
    302 lock struct(s), heap size 41168, 2 row lock(s), undo log entries 1
    MySQL thread id 5877341, OS thread handle 47362313119488, query id 557970189 11.131.81.107 fin_instant_app updating

    update `fund_transfer_stream_0056` set `gmt_modified` = NOW(), `state` = 'PROCESSING' where ((`state` = 'NEW') AND (`seller_id` = '38921111') AND (`fund_transfer_order_no` = '99010015000805619031957477256'))
    2019-03-19T21:44:23.517855+08:00 5877341 [Note] InnoDB:

    *** (2) HOLDS THE LOCK(S):
    RECORD LOCKS space id 173 page no 12416 n bits 128 index PRIMARY of table `fin_instant_0003`.`fund_transfer_stream_0056` trx id 173268500 lock_mode X locks rec but not gap
      Record lock, heap no 56 PHYSICAL RECORD: n_fields 17; compact format; info bits 0

      2019-03-19T21:44:23.519053+08:00 5877341 [Note] InnoDB:

      *** (2) WAITING FOR THIS LOCK TO BE GRANTED:
      RECORD LOCKS space id 173 page no 13726 n bits 248 index idx_seller_transNo of table `fin_instant_0003`.`fund_transfer_stream_0056` trx id 173268500 lock_mode X locks rec but not gap waiting
        Record lock, heap no 168 PHYSICAL RECORD: n_fields 3; compact format; info bits 0

        2019-03-19T21:44:23.519297+08:00 5877341 [Note] InnoDB: *** WE ROLL BACK TRANSACTION (2)

简要解读死锁日志，可以得到以下信息：

导致死锁的两条 SQL 语句分别是：

update `fund_transfer_stream_0056`
set `gmt_modified` = NOW(), `state` = 'PROCESSING'
where ((`state` = 'NEW') AND (`seller_id` = '38921111') AND (`fund_transfer_order_no` = '99010015000805619031957477256'))

和

update `fund_transfer_stream_0056`
set `gmt_modified` = NOW(), `state` = 'PROCESSING'
where ((`state` = 'NEW') AND (`seller_id` = '38921111') AND (`fund_transfer_order_no` = '99010015000805619031958363857'))

事务 1 持有 idx_seller_transNo 索引的锁，正在等待获取 PRIMARY 索引的锁。
事务 2 持有 PRIMARY 索引的锁，正在等待获取 idx_seller_transNo 索引的锁。
由于事务 1 和事务 2 之间发生了循环等待，导致了死锁的发生。
事务 1 和事务 2 当前持有的锁模式均为：lock_mode X locks rec but not gap。

两个事务对记录都加了 X 锁，且没有加间隙锁（No Gap 锁），即它们都在针对特定行记录进行锁定。

X 锁：排他锁、又称写锁。若事务 T 对数据对象 A 加上 X 锁，事务 T 可以读 A 也可以修改 A，其他事务不能再对 A 加任何锁，直到 T 释放 A 上的锁。这保证了其他事务在 T 释放 A 上的锁之前不能再读取和修改 A。

与之对应的是 S 锁：共享锁，又称读锁，若事务 T 对数据对象 A 加上 S 锁，则事务 T 可以读 A 但不能修改 A，其他事务只能再对 A 加 S 锁，而不能加 X 锁，直到 T 释放 A 上的 S 锁。这保证了其他事务可以读 A，但在 T 释放 A 上的 S 锁之前不能对 A 做任何修改。

Gap Lock：间隙锁，锁定一个范围，但不包括记录本身。GAP 锁的目的，是为了防止同一事务的两次当前读，出现幻读的情况。

Next-Key Lock：1+2，锁定一个范围，并且锁定记录本身。对于行的查询，都是采用该方法，主要目的是解决幻读的问题。

问题排查

根据目前已知的数据库相关信息以及死锁日志，可以做出一些简单的判断。

首先，此次死锁与 Gap 锁和 Next-Key Lock 无关。因为我们的数据库使用的是 RC（READ-COMMITED）事务隔离级别，这种级别不会添加 Gap 锁。死锁日志前面也提到了这一点。

接下来，需要查看代码，详细了解我们的事务实现方式。以下是核心代码及相关 SQL：

@Transactional(rollbackFor = Exception.class)
public int doProcessing(String sellerId, Long id, String fundTransferOrderNo) {
    fundTreansferStreamDAO.updateFundStreamId(sellerId, id, fundTransferOrderNo);
    return fundTreansferStreamDAO.updateStatus(sellerId, fundTransferOrderNo, FundTransferStreamState.PROCESSING.name());
}

该代码的目的是先后修改同一条记录的两个不同字段，updateFundStreamId SQL：

update fund_transfer_stream
        set gmt_modified=now(),fund_transfer_order_no = #{fundTransferOrderNo}
        where id = #{id} and seller_id = #{sellerId}

updateStatus SQL：

update fund_transfer_stream
    set gmt_modified=now(),state = #{state}
    where fund_transfer_order_no = #{fundTransferOrderNo} and seller_id = #{sellerId}
    and state = 'NEW'

可以看到，我们的同一个事务中执行了两条 Update 语句，这里分别查看下两条 SQL 的执行计划：

图片

updateFundStreamId 执行的时候使用到的是 PRIMARY 索引。

图片

updateStatus 执行的时候使用到的是 idx_seller_transNo 索引。

通过执行计划，我们发现 updateStatus 其实是有两个索引可以用的，执行的时候真正使用的是 idx_seller_transNo 索引。这是因为MySQL 查询优化器是基于代价（cost-based）的查询方式。因此，在查询过程中，最重要的一部分是根据查询的 SQL 语句，依据多种索引，计算查询需要的代价，从而选择最优的索引方式生成查询计划。

我们查询执行计划是在死锁发生之后做的，事后查询的执行计划和发生死锁那一刻的索引使用情况并不一定相同的。但是，我们结合死锁日志，也可以定位到以上两条 SQL 语句执行的时候使用到的索引。即 updateFundStreamId 执行的时候使用到的是 PRIMARY 索引，updateStatus 执行的时候使用到的是 idx_seller_transNo 索引。

有了以上已知信息，我们现在可以开始排查死锁的原因及其根本原理了。通过分析死锁日志，并结合我们的代码和数据库表结构，我们发现主要问题出在我们的 idx_seller_transNo 索引上：

KEY `idx_seller_transNo` (`seller_id`,`fund_transfer_order_no`(20))

索引创建语句中，我们使用了前缀索引，为了节约索引空间，提高索引效率，我们只选择了 fund_transfer_order_no 字段的前 20 位作为索引值。

因为 fund_transfer_order_no 只是普通索引，而非唯一性索引。又因为在一种特殊情况下，会有同一个用户的两个 fund_transfer_order_no 的前 20 位相同，这就导致两条不同的记录的索引值一样（因为 seller_id 和 fund_transfer_order_no(20)都相同）。

就如本文中的例子，发生死锁的两条记录的 fund_transfer_order_no 字段的值：99010015000805619031958363857 和 99010015000805619031957477256 这两个就是前 20 位相同的。

图片

那么为什么 fund_transfer_order_no 的前 20 位相同会导致死锁呢？

加锁原理

我们就拿本次的案例来看一下 MySQL 数据库加锁的原理是怎样的，本文的死锁背后又发生了什么。我们在数据库上模拟死锁场景，执行顺序如下：

事务 1	事务 2	执行结果
begin
update fund_transfer_stream set gmt_modified=now(),fund_transfer_order_no = '99010015000805619031958363857' where id = 1 and seller_id = 3111095611;		执行成功
	begin
	update fund_transfer_stream set gmt_modified=now(),fund_transfer_order_no = '99010015000805619031957477256' where id = 2 and seller_id = 3111095611;	执行成功
update fund_transfer_stream set gmt_modified = NOW(), state = 'PROCESSING' where ((state = 'NEW') AND (seller_id = '3111095611') AND (fund_transfer_order_no = '99010015000805619031958363857'));		阻塞
	update fund_transfer_stream set gmt_modified = NOW(), state = 'PROCESSING' where ((state = 'NEW') AND (seller_id = '3111095611') AND (fund_transfer_order_no = '99010015000805619031957477256'));	死锁

在 MySQL 中，行级锁并不是直接锁定记录，而是通过锁定索引来实现的。索引分为主键索引和非主键索引两种情况：

操作主键索引：如果一条 SQL 语句操作了主键索引，MySQL 会直接锁定这条主键索引。
操作非主键索引：如果一条 SQL 语句操作了非主键索引，MySQL 会先锁定该非主键索引，然后再锁定相关的主键索引。

这种策略确保了 MySQL 在实施行级锁时能够有效地控制并发访问，从而避免出现数据不一致或者数据丢失的情况。

主键索引的叶子节点存的是整行数据。在 InnoDB 中，主键索引也被称为聚簇索引（clustered index）

非主键索引的叶子节点的内容是主键的值，在 InnoDB 中，非主键索引也被称为非聚簇索引（secondary index）

所以，本文的示例中涉及到的索引结构（索引是 B+树，简化成表格了）如图：

图片

死锁的发生与否，并不在于事务中有多少条 SQL 语句，关键在于：两个或更多的会话加锁的顺序不一致。接下来看看上面例子中两个事务的加锁顺序是怎样的。

图片

下图是分解图，每一条 SQL 执行的时候加锁情况：

图片

结合以上两张图，我们发现了导致死锁的原因：事务 1 执行 update1 占用 PRIMARY = 1 的锁 ——> 事务 2 执行 update1 占有 PRIMARY = 2 的锁；事务 1 执行 update2 占有 idx_seller_transNo = (3111095611，99010015000805619031)的锁，尝试占有 PRIMARY = 2 锁失败（阻塞）；事务 2 执行 update2 尝试占有 idx_seller_transNo = (3111095611，99010015000805619031)的锁失败（死锁）；

事务在使用非主键索引作为 WHERE 条件进行 UPDATE 时，会先对该非主键索引进行加锁，然后查询该非主键索引对应的所有主键索引，再对这些主键索引进行加锁。

解决方法

至此，我们已经清楚地分析了导致死锁的根本原理及其背后的机制。因此，解决这个问题并不复杂。

我们可以从两个方面入手，分别是修改索引和修改代码（包括 SQL 语句）。

在修改索引方面：只需将 idx_seller_transNo 索引中 fund_transfer_order_no 的前缀长度调整为较小的值，比如改成 50，就可以避免死锁的发生。

然而，修改了 idx_seller_transNo 索引的前缀长度后，要注意确保在实际执行 update 语句时，MySQL 查询优化器确实选择了使用 fund_transfer_order_no 索引。如果优化器在代价分析后仍然决定使用索引 KEY idx_seller(seller_id)，那么死锁问题仍可能存在，这与本文中的原理类似。

因此，根本解决方案是修改代码：

所有 update 都通过主键 ID 进行。
在同一个事务中，避免出现多条 update 语句修改同一条记录。

思考总结

在死锁发生后的一周内，我几乎每天都会抽空进行研究。问题很早就被定位到了，并且修改方案也已经有了，但是其中的原理一直没有搞清楚。

我做过很多种推断和假设，但每一次都被自己推翻。最终，我意识到还是需要通过实践来验证我的想法。因此，我在本地安装了数据库，在实际操作中进行了多次测试，并实时查看数据库的锁情况。使用命令 show engine innodb status; 可以查看详细的锁信息。最终，我才彻底搞清楚了背后的原理。

简要总结几点思考：

遇到问题时，不要仅凭猜测！重要的是亲自复现问题，然后再进行分析。
不要忽视上下文！刚开始我只看死锁日志，却忽略了代码中可能执行了另一条 SQL 语句（updateFundStreamId）。
理论知识再丰富，关键时刻也不一定能够想得起来！
遇到坑，大多是自己挖的！