MySQL数据库死锁问题排查过程

✅数据库死锁问题排查过程

(这个问题我排查了很久,期间也找很多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 @@transaction_isolation

事务隔离级别设置方法(只对当前Session生效):
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='资金流水';

该数据库共有三个索引,1个聚簇索引(主键索引),2个非聚簇索(非主键索引)引。
聚簇索引:

PRIMARY KEY (`id`)

非聚簇索引:

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

以上两个索引,其实idx_seller_transNo已经覆盖到了idx_seller,由于历史原因,因为该表以seller_id分表,所以是先有的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)

1、导致死锁的两条SQL语句分别是:

2、事务1,持有索引idx_seller_transNo的锁,在等待获取PRIMARY的锁。
3、事务2,持有PRIMARY的锁,在等待获取idx_seller_transNo的锁。
4、因事务1和事务2之间发生循环等待,故发生死锁。
5、事务1和事务2当前持有的锁均为:lock_mode X locks rec but not gap

  • 所有update都通过主键ID进行。
    所以,根本解决办法就是改代码:
    所有update都通过主键ID进行。
    在同一个事务中,避免出现多条update语句修改同一条记录。
本作品采用《CC 协议》,转载必须注明作者和本文链接
MissYou-Coding
讨论数量: 1

所以我会这样来编写代码:

。。。。。。
 DB::beginTransaction();

 $record =  UserDirectRewardModel::query()
            ->where('level', $level)
            ->where('is_receive', 0)
            ->first();
 $newRecord = UserDirectRewardModel::lockForUpdate()->find( $record->id );
。。。。。。 
1个月前 评论

讨论应以学习和精进为目的。请勿发布不友善或者负能量的内容,与人为善,比聪明更重要!
Coding Peasant @ 互联网
文章
180
粉丝
8
喜欢
54
收藏
60
排名:645
访问:1.2 万
私信
所有博文
博客标签
社区赞助商