记一次神奇的MySQL死锁排查

数据库 MySQL
说起Mysql死锁,之前写过一次有关Mysql加锁的基本介绍,对于一些基本的Mysql锁或者死锁都有一个简单的认识,可以看下这篇文章为什么开发人员需要了解数据库锁。

 背景

说起Mysql死锁,之前写过一次有关Mysql加锁的基本介绍,对于一些基本的Mysql锁或者死锁都有一个简单的认识,可以看下这篇文章为什么开发人员需要了解数据库锁。有了上面的经验之后,本以为对于死锁都能手到擒来,没想到再一个阳光明媚的下午报出了一个死锁,但是这一次却没想象的那么简单。

问题初现

在某天下午,突然系统报警,抛出个异常:

仔细一看好像是事务回滚异常,写着的是因为死锁回滚,原来是个死锁问题,由于我对Mysql锁还是有一定了解的,于是开始主动排查这个问题。

首先在数据库中查找Innodb Status,在Innodb Status中会记录上一次死锁的信息,输入下面命令: 

  1. SHOW ENGINE INNODB STATUS 

死锁信息如下,sql信息进行了简单处理: 

  1. ------------------------  
  2. LATEST DETECTED DEADLOCK  
  3. ------------------------  
  4. 2019-02-22 15:10:56 0x7eec2f468700  
  5. *** (1) TRANSACTION:  
  6. TRANSACTION 2660206487, ACTIVE 0 sec starting index read  
  7. mysql tables in use 1, locked 1  
  8. LOCK WAIT 2 lock struct(s), heap size 1136, 1 row lock(s)  
  9. MySQL thread id 31261312, OS thread handle 139554322093824, query id 11624975750 10.23.134.92 erp_crm__6f73 updating  
  10. /*id:3637ba36*/UPDATE tenant_config SET  
  11.        open_card_point =  0  
  12.        where tenant_id = 123  
  13. *** (1) WAITING FOR THIS LOCK TO BE GRANTED:  
  14. RECORD LOCKS space id 1322 page no 534 n bits 960 index uidx_tenant of table `erp_crm_member_plan`.`tenant_config` trx id 2660206487 lock_mode X locks rec but not gap waiting 
  15.  *** (2) TRANSACTION:  
  16. TRANSACTION 2660206486, ACTIVE 0 sec starting index read  
  17. mysql tables in use 1, locked 1  
  18. 3 lock struct(s), heap size 1136, 2 row lock(s)  
  19. MySQL thread id 31261311, OS thread handle 139552870532864, query id 11624975758 10.23.134.92 erp_crm__6f73 updating  
  20. /*id:3637ba36*/UPDATE tenant_config SET  
  21.        open_card_point =  0  
  22.        where tenant_id = 123  
  23. *** (2) HOLDS THE LOCK(S):  
  24. RECORD LOCKS space id 1322 page no 534 n bits 960 index uidx_tenant of table `erp_crm_member_plan`.`tenant_config` trx id 2660206486 lock mode S  
  25. *** (2) WAITING FOR THIS LOCK TO BE GRANTED:  
  26. RECORD LOCKS space id 1322 page no 534 n bits 960 index uidx_tenant of table `erp_crm_member_plan`.`tenant_config` trx id 2660206486 lock_mode X locks rec but not gap waiting 
  27.  *** WE ROLL BACK TRANSACTION (1)  
  28. ------------ 

给大家简单的分析解释一下这段死锁日志,事务1执行Update语句的时候需要获取uidx_tenant这个索引再where条件上的X锁(行锁),事务2执行同样的Update语句,也在uidx_tenant上面想要获取X锁(行锁),然后就出现了死锁,回滚了事务1。当时我就很懵逼,回想了一下死锁产生的必要条件:

1、互斥。

2、请求与保持条件。

3、不剥夺条件。

4、循环等待。

从日志上来看事务1和事务2都是取争夺同一行的行锁,和以往的互相循环争夺锁有点不同,怎么看都无法满足循环等待条件。经过同事提醒,既然从死锁日志中不能进行排查,那么就只能从业务代码和业务日志从排查。这段代码的逻辑如下: 

  1. public int saveTenantConfig(PoiContext poiContext, TenantConfigDO tenantConfig) {  
  2.         try {  
  3.             return tenantConfigMapper.saveTenantConfig(poiContext.getTenantId(), poiContext.getPoiId(), tenantConfig);  
  4.         } catch (DuplicateKeyException e) {  
  5.             LOGGER.warn("[saveTenantConfig] 主键冲突,更新该记录。context:{}, config:{}", poiContext, tenantConfig);  
  6.             return tenantConfigMapper.updateTenantConfig(poiContext.getTenantId(), tenantConfig);  
  7.         }  
  8.     } 

这段代码的意思是保存一个配置文件,如果发生了唯一索引冲突那么就会进行更新,当然这里可能写得不是很规范,其实可以用 

  1. insert into ...   
  2. on duplicate key update  

也可以达到同样的效果,但是就算用这个其实也会发生死锁。看了代码之后同事又给我发了当时业务日志,

可以看见这里有三条同时发生的日志,说明都发生了唯一索引冲突进入了更新的语句,然后发生的死锁。到这里答案终于稍微有点眉目了。

这个时候再看我们的表结构如下(做了简化处理): 

  1. CREATE TABLE `tenant_config` (  
  2.   `id` bigint(21) NOT NULL AUTO_INCREMENT,  
  3.   `tenant_id` int(11) NOT NULL,  
  4.   `open_card_point` int(11) DEFAULT NULL,  
  5.   PRIMARY KEY (`id`),  
  6.   UNIQUE KEY `uidx_tenant` (`tenant_id`)  
  7. ENGINE=InnoDB  DEFAULT CHARSET=utf8mb4 ROW_FORMAT=COMPACT 

我们的tenant_id是用来做唯一索引,我们的插入和更新的where条件都是基于唯一索引来操作的。 

  1. UPDATE tenant_config SET  
  2.        open_card_point =  0  
  3.        where tenant_id = 123 

到了这里感觉插入的时候对唯一索引加锁有关系,接下来我们进行下一步的深入剖析。

深入剖析

上面我们说有三个事务进入update语句,为了简化说明这里我们只需要两个事务同时进入update语句即可,下面的表格展示了我们整个的发生过程:

小提示:S锁是共享锁,X锁是互斥锁。一般来说X锁和S,X锁都互斥,S锁和S锁不互斥。

我们从上面的流程中看见发生这个死锁的关键需要获取S锁,为什么我们再插入的时候需要获取S锁呢?因为我们需要检测唯一索引?在RR隔离级别下如果要读取那么就是当前读,那么其实就需要加上S锁。这里发现唯一键已经存在,这个时候执行update就会被两个事务的S锁互相阻塞,从而形成上面的循环等待条件。

小提示: 在MVCC中,当前读和快照读的区别:当前读每次需要加锁(可以使共享锁或者互斥锁)获取到***的数据,而快照读是读取的是这个事务开始的时候那个快照,这个是通过undo log去进行实现的。

这个就是整个死锁的原因,能出现这种死锁的还有一个情况,就是同一时间来三个插入操作,其中先插入的那个事务如果***回滚了,其余两个事务也会出现这种死锁。

解决方案

这里的核心问题是需要把S锁给干掉,这里有三个可供参考的解决方案:

  •  将RR隔离级别,降低成RC隔离级别。这里RC隔离级别会用快照读,从而不会加S锁。
  •  再插入的时候使用select * for update,加X锁,从而不会加S锁。
  •  可以提前加上分布式锁,可以利用Redis,或者ZK等等,分布式锁可以参考我的这篇文章。聊聊分布式锁

***种方法不太现实,毕竟隔离级别不能轻易的修改。第三种方法又比较麻烦。所以第二种方法是我们***确定的。

总结

说了这么多,***做一个小小的总结吧。排查死锁这种问题的时候有时候光看死锁日志有时候会解决不了问题,需要结合整个的业务日志,代码以及表结构来进行分析,才能得到正确的结果。当然上面有一些数据库锁的基本知识如果不了解可以查看我的另一篇文章为什么开发人员需要了解数据库锁。

***这篇文章被我收录于JGrowing-CaseStudy篇,一个全面,优秀,由社区一起共建的Java学习路线,如果您想参与开源项目的维护,可以一起共建,github地址为:https://github.com/javagrowing/JGrowing

麻烦给个小星星哟。 

责任编辑:庞桂玉 来源: 数据库开发
相关推荐

2017-12-19 14:00:16

数据库MySQL死锁排查

2021-05-13 08:51:20

GC问题排查

2023-04-06 07:53:56

Redis连接问题K8s

2023-01-04 18:32:31

线上服务代码

2023-10-11 22:24:00

DubboRedis服务器

2021-03-29 12:35:04

Kubernetes环境TCP

2021-11-23 21:21:07

线上排查服务

2023-04-06 10:52:18

2020-02-10 10:15:31

技术研发指标

2021-04-13 08:54:28

dubbo线程池事故排查

2022-11-16 08:00:00

雪花算法原理

2023-04-13 12:00:00

MySQLSQL线程

2019-09-10 10:31:10

JVM排查解决

2022-02-08 17:17:27

内存泄漏排查

2018-02-23 13:41:05

数据库MySQL数据恢复

2019-04-15 13:15:12

数据库MySQL死锁

2021-05-31 10:08:44

工具脚本主机

2020-06-12 13:26:03

线程池故障日志

2011-04-13 09:21:30

死锁SQL Server

2021-11-11 16:14:04

Kubernetes
点赞
收藏

51CTO技术栈公众号