线上死锁分析解决纪实

栏目: 数据库 · 发布时间: 5年前

内容简介:服务发生死锁,死锁检测时间较长,31s后死锁检测出来事务才得以回滚,期间不断有相同请求进来,造成死锁越来越复杂,并且服务端线程池中的所有线程都在等待锁,最后造成服务端线程池无空闲线程,拒绝服务。首先奉上 InnoDB 日志如果看不懂日志,可以参考

服务发生死锁,死锁检测时间较长,31s后死锁检测出来事务才得以回滚,期间不断有相同请求进来,造成死锁越来越复杂,并且服务端线程池中的所有线程都在等待锁,最后造成服务端线程池无空闲线程,拒绝服务。

注意:单条 SQL 也是一个事务,也会和其他事务发生死锁。

原因分析

首先奉上 InnoDB 日志

------------------------
LATEST DETECTED DEADLOCK
------------------------
2019-05-16 15:38:17 0x7f121830f700
*** (1) TRANSACTION:
TRANSACTION 161027737922, ACTIVE 0 sec fetching rows
mysql tables in use 1, locked 1
LOCK WAIT 88 lock struct(s), heap size 24784, 1412 row lock(s), undo log entries 2
MySQL thread id 42610991, OS thread handle 139701841643264, query id 40446554160 10.7.23.224 promotio_e0a1 updating
/*id:6d7cc9a7*/DELETE FROM `campaignmockqueue` WHERE `campaignid`=52327710 and `addtime` <= 1557992297
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 1975 page no 5280 n bits 1272 index idx_campid of table `promotion`.`campaignmockqueue` trx id 161027737922 lock_mode X waiting
*** (2) TRANSACTION:
TRANSACTION 161027729748, ACTIVE 31 sec inserting
mysql tables in use 1, locked 1
7 lock struct(s), heap size 1136, 7 row lock(s), undo log entries 14
MySQL thread id 42610752, OS thread handle 139715692001024, query id 40446554260 10.43.174.209 promotio_e0a1 update
/*id:dfdc4b66*/INSERT INTO `campaignmockqueue`(
           `campaignid`, `addtime`
        )
        VALUES
          
            (52327709, 1557992297)
         , 
            (52327709, 1559383140)
         , 
            (52327709, 1557992296)
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 1975 page no 5280 n bits 1272 index idx_campid of table `promotion`.`campaignmockqueue` trx id 161027729748 lock_mode X locks rec but not gap
*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 1975 page no 5271 n bits 1272 index idx_campid of table `promotion`.`campaignmockqueue` trx id 161027729748 lock_mode X locks gap before rec insert intention waiting
*** WE ROLL BACK TRANSACTION (2)

如果看不懂日志,可以参考 这个文章

我们先来看看 事务1事务2 分别持有什么锁,又在等待什么锁。由于日志是在事务 1 的角度来打印的,所以我们只能看到事务 2 持有 lock_mode X locks rec but not gap 锁,在等待 lock_mode X locks gap before rec insert intention 锁。

lock_mode X locks rec but not gap 就是写记录锁,只锁了单条记录。

lock_mode X locks gap before rec insert intention 就是一个插入意向锁,目标是在对应的间隙上(不包括记录本身)加锁。

通过事务 2 的锁信息我们可以推测出事务 1 的锁持有信息,因此就有了下面的图。

事务 1 当前拥有的应该是间隙 A 和 记录X 组成的 nexy-key 锁 ,现在正在等待的是间隙 b 的锁。

DELETE FROM `campaignmockqueue` WHERE `campaignid`=52327710 and `addtime` <= 1557992297

线上死锁分析解决纪实

事务 2 当前拥有的应该是 记录 Y 的 X锁, 间隙 D 的插入意向锁, 间隙 C 的插入意向锁 ,现在正在等待的是间隙 e 的 间隙插入意向锁(也有可能是 记录 Y 的 record lock)。

INSERT INTO `campaignmockqueue`(`campaignid`, `addtime` )VALUES (52327709, 1557992297) , (52327709, 1559383140), (52327709, 1557992296)

线上死锁分析解决纪实

由于 next-key 锁 和 插入意向锁互斥,所以事务 1 在等待事务 2 释放 C, Y, D;事务 2 在等待事务 1 释放 A。 这样看来正好符合 InnoDB 中的 log。

模拟流程

个人认为 由于 next-key 锁和 Gap 锁不是一种锁,因此必然存在时间差,这种时间差在并发量很大的情况下才会凸显出来。

事务1 事务2
INSERT INTO campaignmockqueue 记录 Y
DELETE FROM campaignmockqueue 获取了 A 的间隙锁还没获取 next-key 锁
INSERT INTO campaignmockqueue ( campaignid , addtime )VALUES (52327709, 1557992297) , (52327709, 1559383140), (52327709, 1557992296) (阻塞)
DELETE FROM campaignmockqueue 获取 next-key 锁 (阻塞)

验证猜想

上面的情况仅仅是推测,如果我们能拿到 INSERT 语句角度的死锁日志就好了。搜寻了一下 InnoDB 日志,得到了下面的日志,通过交叉分析,可以验证了我们的猜想。

------------------------
LATEST DETECTED DEADLOCK
------------------------
2019-05-16 03:02:36 0x7f11eebd8700
*** (1) TRANSACTION:
TRANSACTION 161022641521, ACTIVE 0 sec inserting
mysql tables in use 1, locked 1
LOCK WAIT 5 lock struct(s), heap size 1136, 3 row lock(s), undo log entries 2
MySQL thread id 42518313, OS thread handle 139715027216128, query id 40270385508 10.7.224.35 promotio_e0a1 update
/*id:dfdc4b66*/INSERT INTO `campaignmockqueue`(
`campaignid`, `addtime`
)
VALUES

(52247612, 1557946956)
, 
(52247612, 1557936000)
, 
(52247612, 1558022399)
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 1975 page no 4904 n bits 1264 index addtime of table `promotion`.`campaignmockqueue` trx id 161022641521 lock_mode X locks gap before rec insert intention waiting
*** (2) TRANSACTION:
TRANSACTION 161022641523, ACTIVE 0 sec fetching rows
mysql tables in use 1, locked 1
4 lock struct(s), heap size 1136, 3 row lock(s), undo log entries 1
MySQL thread id 42543917, OS thread handle 139714996569856, query id 40270385509 10.7.23.224 promotio_e0a1 updating
/*id:6d7cc9a7*/DELETE FROM `campaignmockqueue` WHERE `campaignid`=52247612 and `addtime` <= 1557946956
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 1975 page no 4904 n bits 1264 index addtime of table `promotion`.`campaignmockqueue` trx id 161022641523 lock_mode X
*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 1975 page no 4904 n bits 1264 index addtime of table `promotion`.`campaignmockqueue` trx id 161022641523 lock_mode X waiting
*** WE ROLL BACK TRANSACTION (2)

解决方案

DELETE FROM campaignmockqueue 不使用 idx_campid 这个索引加锁,而使用唯一主键来做操作,和 insert 操作使用不同的索引,来避免这个问题。

参考文档

  1. 何登成的技术博客 » MySQL 加锁处理分析
  2. mysql并发insert死锁问题——gap、插入意向锁冲突 - hebaodan的博客 - OSCHINA
  3. MySQL 中的锁 [ 黄小豆的博客 ]
  4. MySQL 源码再看 INSERT 加锁流程 - aneasystone’s blog
  5. Innodb死锁日志分段解读-如何阅读死锁日志 - 奎因&华洛 - CSDN博客
  6. [MySQL DELETE 删除语句加锁分析 | | For DBA

以上就是本文的全部内容,希望对大家的学习有所帮助,也希望大家多多支持 码农网

查看所有标签

猜你喜欢:

本站部分资源来源于网络,本站转载出于传递更多信息之目的,版权归原作者或者来源机构所有,如转载稿涉及版权问题,请联系我们

Web开发敏捷之道

Web开发敏捷之道

Sam Ruby、Dave Thomas、David Heineme Hansson / 慕尼黑Isar工作组、骆古道 / 机械工业出版社 / 2012-3-15 / 59.00元

本书第1版曾荣获Jolt大奖“最佳技术图书”奖。在前3版的内容架构基础上,第4版增加了关于Rails中新特性和最佳实践的内容。本书从逐步创建一个真正的应用程序开始,然后介绍Rails的内置功能。全书分为3部分,第一部分介绍Rails的安装、应用程序验证、Rails框架的体系结构,以及Ruby语言的知识;第二部分用迭代方式创建应用程序,然后依据敏捷开发模式搭建测试案例,最终用Capistrano完成......一起来看看 《Web开发敏捷之道》 这本书的介绍吧!

在线进制转换器
在线进制转换器

各进制数互转换器

MD5 加密
MD5 加密

MD5 加密工具

HEX HSV 转换工具
HEX HSV 转换工具

HEX HSV 互换工具