找回密码
 会员注册
查看: 19|回复: 0

记一次MySQL死锁排查过程

[复制链接]

2万

主题

0

回帖

6万

积分

超级版主

积分
64454
发表于 2024-10-10 20:51:20 | 显示全部楼层 |阅读模式
记一次MySQL死锁排查过程 记一次MySQL死锁排查过程 钱森淼@贝壳找房 贝壳产品技术 贝壳产品技术 “贝壳产品技术公众号”作为贝壳官方产品技术号,致力打造贝壳产品、技术干货分享平台,面向互联网/O2O开发/产品从业者,每周推送优质产品技术文章、技术沙龙活动及招聘信息等。欢迎大家关注我们。 242篇内容 2021年01月06日 15:58 故障背景国庆期间,收到一条从未见过的报警,后面间歇性地又报出类似的偶现报警,便忽然来了兴致,摘了其中一条,探究一下其中的故事。……{"message":"SQLSTATE[40001]:Serializationfailure:1213Deadlockfoundwhentryingtogetlock;tryrestartingtransaction(SQL:update`user_feed_26`set`notification`=1,`mtime`=2020-10-0309:11:11where`user_id`=2000000126212250and`action`in(resblock_weekly,bizcircle_weekly,district_weekly)and`notification`=0)","context":{"exception":{"errorInfo":["40001",1213,"Deadlockfoundwhentryingtogetlock;tryrestartingtransaction"]}}}从日志的字面意思来看,显然,是MySQL数据库在执行事务时,发现了死锁的情况,那么这种死锁是如何产生的,背后又潜藏着怎样的隐患,又该如何去解决呢,我们一起来排查一下~排查过程雾里看花刚开始收到这个报警,第一反应,是有不同事务互相锁,结果产生了死锁。那么坏了,十有八九是某个代码片段里写的逻辑出了问题。但是排查了一整圈,涉及到这个sql的代码,既没有开启事务,更没有多个事务,那么代码的bug基本上就可以排除了。那么这些个事务是怎么来的呢?众所周知,MySQL的事务支持与存储引擎有关,MyISAM不支持事务,INNODB支持事务,更新时采用的是行级锁。由于我们的数据库采用的是INNODB引擎,意味着,会将update语句当做一个事务来处理。那难道是更新同一条数据,出现的冲突吗?于是找DBA同学要来了死锁日志(数据库版本:5.7.24 事务隔离级别为RR)。事务一日志:***(1)TRANSACTION:TRANSACTION6286508066,ACTIVE0secupdatingordeletingmysqltablesinuse1,locked1LOCKWAIT9lockstruct(s),heapsize1136,14rowlock(s),undologentries1MySQLthreadid189619143,OSthreadhandle140619931252480,queryid114880319610.200.18.103ke_informationupdatingupdate`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_modeXlocksgapbeforerecinsertintentionwaitingRecordlock,heapno93PHYSICALRECORD:n_fields5;compactformat;infobits00: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:RECORDLOCKSspaceid2229pageno263938nbits264indexidx_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;infobits00: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,threaddeclaredinsideInnoDB4980mysqltablesinuse1,locked112lockstruct(s),heapsize1136,22rowlock(s),undologentries3MySQLthreadid189619144,OSthreadhandle140620050204416,queryid114880319710.200.17.37pt_userupdatingUPDATE`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_modeXlocksgapbeforerecRecordlock,heapno83PHYSICALRECORD:n_fields5;compactformat;infobits00:len8;hex80071afd5112d89a;ascQ;;1:len4;hex6465616c;ascdeal;;2:len1;hex81;asc;;3:len12;hex313034313032363731333238;asc104102671328;;4:len4;hex95e14632;ascF2;;Recordlock,heapno93PHYSICALRECORD:n_fields5;compactformat;infobits00: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_modeXlocksgapbeforerecinsertintentionwaitingRecordlock,heapno87PHYSICALRECORD:n_fields5;compactformat;infobits320: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_modeXlocksgapbeforerecRecordlock,heapno83PHYSICALRECORD:n_fields5;compactformat;infobits00:len8;hex80071afd5112d89a;ascQ;;1:len4;hex6465616c;ascdeal;;2:len1;hex81;asc;;3:len12;hex313034313032363731333238;asc104102671328;;4:len4;hex95e14632;ascF2;;Recordlock,heapno93PHYSICALRECORD:n_fields5;compactformat;infobits00: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;infobits00:len8;hex80071afd5112d89a;ascQ;;1:len14;hex6f6e5f7368656c665f616761696e;ascon_shelf_again;;2:len1;hex81;asc;;3:len12;hex313034313033373433363737;asc104103743677;;4:len4;hex95f12ab5;asc*;;lock_mode X locks gap before rec 表示这是一个排他锁,并且是一个间隙锁***(2)WAITINGFORTHISLOCKTOBEGRANTED:RECORDLOCKSspaceid2229pageno263938nbits264indexidx_user_idoftable`lianjia_user_feed`.`user_feed_26`trxid6286508067lock_modeXlocksgapbeforerecinsertintentionwaitingRecordlock,heapno87PHYSICALRECORD:n_fields5;compactformat;infobits320: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=xxxwhereid=id;避免在同一时间点运行多个对同一表进行读写的脚本,特别注意加锁且操作数据量比较大的语句;我们经常会有一些定时脚本,避免它们在同一时间点运行;如本次事件所示,Gap 锁往往是程序中导致死锁的真凶,由于默认情况下 MySQL 的隔离级别是 RR,所以如果能确定幻读和不可重复读对应用的影响不大,可以考虑将隔离级别改成 RC,可以避免 Gap 锁导致的死锁。参考阅读:1.https://www.cnblogs.com/suminem/p/13267828.html 预览时标签不可点 后端27后端 · 目录#后端上一篇PHP配置化读取优化方案下一篇Druid在贝壳的应用实践关闭更多小程序广告搜索「undefined」网络结果
回复

使用道具 举报

您需要登录后才可以回帖 登录 | 会员注册

本版积分规则

QQ|手机版|心飞设计-版权所有:微度网络信息技术服务中心 ( 鲁ICP备17032091号-12 )|网站地图

GMT+8, 2024-12-27 01:19 , Processed in 0.362279 second(s), 25 queries .

Powered by Discuz! X3.5

© 2001-2024 Discuz! Team.

快速回复 返回顶部 返回列表