首页 数据库技术 正文
一条从未见过的报警，开启曲折的MySQL死锁排查

 2022-10-27    366  

故障背景

国庆期间，收到一条从未见过的报警，后面间歇性地又报出类似的偶现报警，便忽然来了兴致，摘了其中一条，探究一下其中的故事。

***(1)TRANSACTION:
TRANSACTION6286508066,ACTIVE0secupdatingordeleting
mysqltablesinuse1,locked1
LOCKWAIT9lockstruct(s),heapsize1136,14rowlock(s),undologentries1
MySQLthreadid189619143,OSthreadhandle140619931252480,queryid114880319610.200.18.103ke_informationupdating
update`user_feed_26`set`notification`=1,`mtime`='2020-10-0309:11:11'where`user_id`=2000000126212250and`action`in('resblock_weekly','bizcircle_weekly','district_weekly')and`notification`=0
***(1)WAITINGFORTHISLOCKTOBEGRANTED:
RECORDLOCKSspaceid2229pageno263938nbits264indexidx_user_idoftable`lianjia_user_feed`.`user_feed_26`trxid6286508066lock_modeXlocksgapbeforerecinsertintentionwaiting
Recordlock,heapno93PHYSICALRECORD:n_fields5;compactformat;infobits0
0:len8;hex80071afd5112d89a;ascQ;;
1:len14;hex6f6e5f7368656c665f616761696e;ascon_shelf_again;;
2:len1;hex81;asc;;
3:len12;hex313034313033373433363737;asc104103743677;;
4:len4;hex95f12ab5;asc*;;

从日志的字面意思来看，显然，是MySQL数据库在执行事务时，发现了死锁的情况，那么这种死锁是如何产生的，背后又潜藏着怎样的隐患，又该如何去解决呢，我们一起来排查一下~

排查过程

雾里看花

刚开始收到这个报警，第一反应，是有不同事务互相锁，结果产生了死锁。那么坏了，十有八九是某个代码片段里写的逻辑出了问题。但是排查了一整圈，涉及到这个sql的代码，既没有开启事务，更没有多个事务，那么代码的bug基本上就可以排除了。

那么这些个事务是怎么来的呢？众所周知，MySQL的事务支持与存储引擎有关，MyISAM不支持事务，INNODB支持事务，更新时采用的是行级锁。由于我们的数据库采用的是INNODB引擎，意味着，会将update语句当做一个事务来处理。那难道是更新同一条数据，出现的冲突吗？于是找DBA同学要来了死锁日志（数据库版本：5.7.24 事务隔离级别为RR）。

事务一日志：

***(1)TRANSACTION:
TRANSACTION6286508066,ACTIVE0secupdatingordeleting
mysqltablesinuse1,locked1
LOCKWAIT9lockstruct(s),heapsize1136,14rowlock(s),undologentries1
MySQLthreadid189619143,OSthreadhandle140619931252480,queryid114880319610.200.18.103ke_informationupdating
update`user_feed_26`set`notification`=1,`mtime`='2020-10-0309:11:11'where`user_id`=2000000126212250and`action`in('resblock_weekly','bizcircle_weekly','district_weekly')and`notification`=0
***(1)WAITINGFORTHISLOCKTOBEGRANTED:
RECORDLOCKSspaceid2229pageno263938nbits264indexidx_user_idoftable`lianjia_user_feed`.`user_feed_26`trxid6286508066lock_modeXlocksgapbeforerecinsertintentionwaiting
Recordlock,heapno93PHYSICALRECORD:n_fields5;compactformat;infobits0
0:len8;hex80071afd5112d89a;ascQ;;
1:len14;hex6f6e5f7368656c665f616761696e;ascon_shelf_again;;
2:len1;hex81;asc;;
3:len12;hex313034313033373433363737;asc104103743677;;
4:len4;hex95f12ab5;asc*;;

由日志可以看出，事务一执行的sql语句是：

update`user_feed_26`set`notification`=1,`mtime`='2020-10-0309:11:11'where`user_id`=2000000126212250and`action`in('resblock_weekly','bizcircle_weekly','district_weekly')and`notification`=0

在等待的锁是：

***(1)WAITINGFORTHISLOCKTOBEGRANTED:
ECORDLOCKSspaceid2229pageno263938nbits264indexidx_user_idoftable`lianjia_user_feed`.`user_feed_26`trxid6286508066lock_modeXlocksgapbeforerecinsertintentionwaiting

这里显示的是事务在等待什么锁。RECORD LOCKS 表示记录锁，并且可以看出要加锁的索引为idx_user_id，space id为2229，page no为263938，lock_mode X 标识该记录锁为排它锁，insert intention waiting 表示要加的锁为插入意向锁，并处于锁等待状态。

Recordlock,heapno93PHYSICALRECORD:n_fields5;compactformat;infobits0
0:len8;hex80071afd5112d89a;ascQ;;
1:len14;hex6f6e5f7368656c665f616761696e;ascon_shelf_again;;
2:len1;hex81;asc;;
3:len12;hex313034313033373433363737;asc104103743677;;
4:len4;hex95f12ab5;asc*;;

结合索引信息第二行 on_shelf_again 可以知道，这行锁的 action 字段是 on_shelf_again ;

事务二日志：

***(2)TRANSACTION:
TRANSACTION6286508067,ACTIVE0secupdatingordeleting,threaddeclaredinsideInnoDB4980
mysqltablesinuse1,locked1
12lockstruct(s),heapsize1136,22rowlock(s),undologentries3
MySQLthreadid189619144,OSthreadhandle140620050204416,queryid114880319710.200.17.37pt_userupdating
UPDATE`user_feed_26`SET`notification`='1',`mtime`='2020-10-0309:11:11'WHERE`user_id`='2000000126212250'AND`action`in('deal','price_changed','ting_shou','house_new_picture','house_new_vr','price_changed_rise','on_shelf_again')AND`notification`='0'
***(2)HOLDSTHELOCK(S):
RECORDLOCKSspaceid2229pageno263938nbits264indexidx_user_idoftable`lianjia_user_feed`.`user_feed_26`trxid6286508067lock_modeXlocksgapbeforerec
Recordlock,heapno83PHYSICALRECORD:n_fields5;compactformat;infobits0
0:len8;hex80071afd5112d89a;ascQ;;
1:len4;hex6465616c;ascdeal;;
2:len1;hex81;asc;;
3:len12;hex313034313032363731333238;asc104102671328;;
4:len4;hex95e14632;ascF2;;
Recordlock,heapno93PHYSICALRECORD:n_fields5;compactformat;infobits0
0:len8;hex80071afd5112d89a;ascQ;;
1:len14;hex6f6e5f7368656c665f616761696e;ascon_shelf_again;;
2:len1;hex81;asc;;
3:len12;hex313034313033373433363737;asc104103743677;;
4:len4;hex95f12ab5;asc*;;
***省略……
***(2)WAITINGFORTHISLOCKTOBEGRANTED:
RECORDLOCKSspaceid2229pageno263938nbits264indexidx_user_idoftable`lianjia_user_feed`.`user_feed_26`trxid6286508067lock_modeXlocksgapbeforerecinsertintentionwaiting
Recordlock,heapno87PHYSICALRECORD:n_fields5;compactformat;infobits32
0:len8;hex80071afd5112d89a;ascQ;;
1:len15;hex64697374726963745f7765656b6c79;ascdistrict_weekly;;
2:len1;hex80;asc;;
3:len8;hex3233303038373831;asc23008781;;
4:len4;hex95f63035;asc05;;

事务二的日志，相比于事务一多了持有锁的信息：

***(2)HOLDSTHELOCK(S):
RECORDLOCKSspaceid2229pageno263938nbits264indexidx_user_idoftable`lianjia_user_feed`.`user_feed_26`trxid6286508067lock_modeXlocksgapbeforerec
Recordlock,heapno83PHYSICALRECORD:n_fields5;compactformat;infobits0
0:len8;hex80071afd5112d89a;ascQ;;
1:len4;hex6465616c;ascdeal;;
2:len1;hex81;asc;;
3:len12;hex313034313032363731333238;asc104102671328;;
4:len4;hex95e14632;ascF2;;
Recordlock,heapno93PHYSICALRECORD:n_fields5;compactformat;infobits0
0:len8;hex80071afd5112d89a;ascQ;;
1:len14;hex6f6e5f7368656c665f616761696e;ascon_shelf_again;;
2:len1;hex81;asc;;
3:len12;hex313034313033373433363737;asc104103743677;;
4:len4;hex95f12ab5;asc*;;
***省略……

从日志看，事务二持有一个记录锁，RECORD LOCKS这是个记录锁，space id为2229，page no为263938 并且通过索引信息可以看出，事务二恰好持有事务一需要的那行记录锁，即：

Recordlock,heapno93PHYSICALRECORD:n_fields5;compactformat;infobits0
0:len8;hex80071afd5112d89a;ascQ;;
1:len14;hex6f6e5f7368656c665f616761696e;ascon_shelf_again;;
2:len1;hex81;asc;;
3:len12;hex313034313033373433363737;asc104103743677;;
4:len4;hex95f12ab5;asc*;;
lock_modeXlocksgapbeforerec表示这是一个排他锁，并且是一个间隙锁
***(2)WAITINGFORTHISLOCKTOBEGRANTED:
RECORDLOCKSspaceid2229pageno263938nbits264indexidx_user_idoftable`lianjia_user_feed`.`user_feed_26`trxid6286508067lock_modeXlocksgapbeforerecinsertintentionwaiting
Recordlock,heapno87PHYSICALRECORD:n_fields5;compactformat;infobits32
0:len8;hex80071afd5112d89a;ascQ;;
1:len15;hex64697374726963745f7765656b6c79;ascdistrict_weekly;;
2:len1;hex80;asc;;
3:len8;hex3233303038373831;asc23008781;;
4:len4;hex95f63035;asc05;;

同样，这里显示的是事务二在等待什么锁。RECORD LOCKS 表示记录锁，并且可以看出要加锁的索引为idx_user_id，space id为2229，page no为263938 lock_mode X 标识该记录锁为排它锁，insert intention waiting 表示要加的锁为插入意向锁，并处于锁等待状态。虽然，事务一的日志中没有标明它持有了哪些锁，但是结合事务二等待的锁结构中 district_weekly 字段来看，事务一是持有该锁的，因此，两个事务形成了互相等待锁释放的场景，从而形成了死锁。

那么疑问来了，两个sql：

#sql1:
update`user_feed_26`set`notification`=1,`mtime`='2020-10-0309:11:11'where`user_id`=2000000126212250and`action`in('resblock_weekly','bizcircle_weekly','district_weekly')and`notification`=0
#sql2:
UPDATE`user_feed_26`SET`notification`='1',`mtime`='2020-10-0309:11:11'WHERE`user_id`='2000000126212250'AND`action`in('deal','price_changed','ting_shou','house_new_picture','house_new_vr','price_changed_rise','on_shelf_again')AND`notification`='0'

明明两个语句的where条件不一样，也不交叉，为什么会占用彼此的锁呢？

山穷水复

为了验证这种case，我们在线下尝试进行复现。表结构如下：

#CREATETABLE`user_feed_26`(
`feed_id`int(10)NOTNULLAUTO_INCREMENT,
`user_id`bigint(20)NOTNULL,
……
PRIMARYKEY(`feed_id`),
KEY`idx_user_id`(`user_id`,`action`,`notification`,`feed_target`),
……
)ENGINE=InnoDBAUTO_INCREMENT=371826027DEFAULTCHARSET=utf8COMMENT='用户推送表';

但是无论如何，都是锁等待，而不会形成死锁。这是怎么回事呢？

带着怀疑的态度，我们查看了一下语句的执行计划：

通过执行计划我们发现，这里并没有走死锁日志里出现的那个idx_user_id索引，而是走的主键索引，因此并没有产生死锁。

大胆猜测：是因为模拟的数据量太小，导致并没有走复合索引。

于是，我们往线下模拟库里灌入了大概100w左右的随机数据，再次查看执行计划：

果然，当数据量变大之后，就会走对应的复合索引了。再经过一次尝试，果然复现出了线上那种死锁场景，但是问题来了，为什么会出现这种情况呢？

柳暗花明

为了了解背后真实的原理，我们再次研读了MySQL锁相关的资料，也得知了事情的真相。

首先，简单说一下MySQL加锁的基本原则：

  • 原则 1：加锁的基本单位是 next-key lock。next-key lock 是前开后闭区间；
  • 原则 2：查找过程中访问到的对象才会加锁。

优化 1：唯一索引上的等值查询加锁时，next-key lock 退化为行锁。

优化 2：非唯一索引上的等值查询加锁时，对where条件中的值所在区间向右（后）遍历时，该区间的右边界不满足等值条件的时候，next-key lock 退化为间隙锁。这个比较难理解，举个例子：

若在表ta的列a上有非唯一索引：index_a,该索引中存在的值为：1，1，3，3，7，9：当你执行select a from ta where ta.a=5时，就会从3开始往右（后）遍历，此时对应的 是(3,7]但是由于该区间的最后一个值7不满足=5的条件，因此该next-key lock就退化为gap lock (3,7)。

由此可知，当我们执行的update语句，在查询的时候，给对应的索引idx_user_id加上了间隙锁，从而互相之间产生了死锁。举个简单的例子说明一下：

  • 事务2执行了一个update, where 条件为3，因此获得了（1，3）的Gap锁；
  • 事务1也执行了一个update，where条件为5，因此获得了一个（5，+∞），同时等待（1，7）插入意向锁；
  • 事务2又执行了一个update，where条件为8，那么他将等待（5，+∞）。

于是乎，死锁就产生了。

那么，如何避免这种死锁再次发生呢？

通过唯一索引（一般主键都是）来更新，先通过select语句查出符合条件的记录的唯一索引，再通过唯一索引来更新。

selectidfromtablewherea=?andb=?;
updatetablesetcolumn=xxxwhereidid=id;

避免在同一时间点运行多个对同一表进行读写的脚本，特别注意加锁且操作数据量比较大的语句；我们经常会有一些定时脚本，避免它们在同一时间点运行；如本次事件所示，Gap 锁往往是程序中导致死锁的真凶，由于默认情况下 MySQL 的隔离级别是 RR，所以如果能确定幻读和不可重复读对应用的影响不大，可以考虑将隔离级别改成 RC，可以避免 Gap 锁导致的死锁。

  •  标签：  
  • MySQL
    •  

发表评论：

原文链接：https://77isp.com/post/10313.html

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

https://77isp.com/ 为 “云服务器技术网” 唯一官方服务平台，请勿相信其他任何渠道。

热门文章
热门标签
最新留言
友情链接

首页 IT运维空间 网云互联 1818IP网

本站资源均来自原创及互联网，仅供学习与参考，请勿用于商业和其他非法用途。如果侵犯了您的权益请与我们联系，我们将在24小时内删除。

苏ICP备2022008373号-1