现象描述
客户在夜间批量执行数据处理时发生了死锁现象，是由不同的会话并发删除数据引起的，这个问题原因是比较简单，但想通过这个案例让大家熟悉如何去排查死锁问题，如何去阅读死锁日志这才是目的。通过模拟用户死锁现象后，死锁日志如下:
1***(1)TRANSACTION:2TRANSACTION39474,ACTIVE58secstartingindexread3mysqltablesinuse1,locked14LOCKWAIT3lockstruct(s),heapsize1200,4rowlock(s),undologentries35MySQLthreadid9,OSthreadhandle123145525800960,queryid77localhostrootupdating6DELETEFROMt1WHEREid=47***(1)WAITINGFORTHISLOCKTOBEGRANTED:8RECORDLOCKSspaceid114pageno4nbits80indexPRIMARYoftable`dhy`.`t1`trxid39474lock_modeXlocksrecbutnotgapwaiting9Recordlock,heapno5PHYSICALRECORD:n_fields4;compactformat;infobits32100:len4;hex00000004;asc;;111:len6;hex000000009a33;asc3;;122:len7;hex02000001471399;ascG;;133:len2;hex6464;ascdd;;1415***(2)TRANSACTION:16TRANSACTION39475,ACTIVE46secstartingindexread17mysqltablesinuse1,locked1183lockstruct(s),heapsize1200,4rowlock(s),undologentries319MySQLthreadid10,OSthreadhandle123145526104064,queryid78localhostrootupdating20DELETEFROMt1WHEREid=321***(2)HOLDSTHELOCK(S):22RECORDLOCKSspaceid114pageno4nbits80indexPRIMARYoftable`dhy`.`t1`trxid39475lock_modeXlocksrecbutnotgap23Recordlock,heapno5PHYSICALRECORD:n_fields4;compactformat;infobits32240:len4;hex00000004;asc;;251:len6;hex000000009a33;asc3;;262:len7;hex02000001471399;ascG;;273:len2;hex6464;ascdd;;2829Recordlock,heapno6PHYSICALRECORD:n_fields4;compactformat;infobits32300:len4;hex00000005;asc;;311:len6;hex000000009a33;asc3;;322:len7;hex02000001471375;ascGu;;333:len2;hex6565;ascee;;3435Recordlock,heapno7PHYSICALRECORD:n_fields4;compactformat;infobits32360:len4;hex00000006;asc;;371:len6;hex000000009a33;asc3;;382:len7;hex02000001471351;ascGQ;;393:len2;hex6666;ascff;;4041***(2)WAITINGFORTHISLOCKTOBEGRANTED:42RECORDLOCKSspaceid114pageno4nbits80indexPRIMARYoftable`dhy`.`t1`trxid39475lock_modeXlocksrecbutnotgapwaiting43Recordlock,heapno4PHYSICALRECORD:n_fields4;compactformat;infobits32440:len4;hex00000003;asc;;451:len6;hex000000009a32;asc2;;462:len7;hex01000001462e1f;ascF.;;473:len2;hex6363;asccc;;4849***WEROLLBACKTRANSACTION(2)
如何阅读死锁日志
要排查死锁问题我们就要学会如何查看死锁日志，但MySQL死锁日志看起来并不是很直观需要我们一步一步耐心分析。
我们将上面的死锁日志拆分阅读，我们可以得出以下信息:
两个事务的事务ID
TRANSACTION 39474
TRANSACTION 39475
事务39474在执行delete语句是发生了锁等待
1DELETEFROMt1WHEREid=42***(1)WAITINGFORTHISLOCKTOBEGRANTED:3RECORDLOCKSspaceid114pageno4nbits80indexPRIMARYoftable`dhy`.`t1`trxid39474lock_modeXlocksrecbutnotgapwaiting4Recordlock,heapno5PHYSICALRECORD:n_fields4;compactformat;infobits3250:len4;hex00000004;asc;;//聚集索引的值61:len6;hex000000009a33;asc3;;//事务ID72:len7;hex02000001471399;ascG;;//undo记录83:len2;hex6464;ascdd;;//非主键字段的值
通过以上信息可以得出事务39474执行delete语句时，锁等待发生在申请ID=4这条记录上的X锁“lock_mode X locks rec but not gap waiting”
事务39475持有锁的信息
1***(2)HOLDSTHELOCK(S):2RECORDLOCKSspaceid114pageno4nbits80indexPRIMARYoftable`dhy`.`t1`trxid39475lock_modeXlocksrecbutnotgap3Recordlock,heapno5PHYSICALRECORD:n_fields4;compactformat;infobits3240:len4;hex00000004;asc;;51:len6;hex000000009a33;asc3;;62:len7;hex02000001471399;ascG;;73:len2;hex6464;ascdd;;89Recordlock,heapno6PHYSICALRECORD:n_fields4;compactformat;infobits32100:len4;hex00000005;asc;;111:len6;hex000000009a33;asc3;;122:len7;hex02000001471375;ascGu;;133:len2;hex6565;ascee;;1415Recordlock,heapno7PHYSICALRECORD:n_fields4;compactformat;infobits32160:len4;hex00000006;asc;;171:len6;hex000000009a33;asc3;;182:len7;hex02000001471351;ascGQ;;193:len2;hex6666;ascff;;
事务39475持有在ID=4，5，6上X锁
事务39475同样在执行delete语句时发生了所等待
1***(2)TRANSACTION:2TRANSACTION39475,ACTIVE46secstartingindexread3mysqltablesinuse1,locked143lockstruct(s),heapsize1200,4rowlock(s),undologentries35MySQLthreadid10,OSthreadhandle123145526104064,queryid78localhostrootupdating6DELETEFROMt1WHEREid=378***(2)WAITINGFORTHISLOCKTOBEGRANTED:9RECORDLOCKSspaceid114pageno4nbits80indexPRIMARYoftable`dhy`.`t1`trxid39475lock_modeXlocksrecbutnotgapwaiting10Recordlock,heapno4PHYSICALRECORD:n_fields4;compactformat;infobits32110:len4;hex00000003;asc;;121:len6;hex000000009a32;asc2;;132:len7;hex01000001462e1f;ascF.;;143:len2;hex6363;asccc;;
申请ID=3上的X锁时发生了所等待，执行的语句是:DELETE FROM t1 WHERE id = 3，那么可以得出39474在id=3上持有了X锁，但是在死锁日志中并没有显示出事务39474持有锁的信息
那么这两个事务加锁的顺序应是:
1. 事务39474持有了id=3上的X锁
2. 事务39475持有了id=4上的X锁
3. 事务39474申请id=4上X锁时发生了锁等待执行的语句是:DELETE FROM t1 WHERE id = 4
4. 事务39475申请id=3上X锁时触发了死锁，因为此时双方都在申请对方持有的锁不能进行下去了。
事务2被回滚
1***WEROLLBACKTRANSACTION(2)
事务39475持有ID = 4， 5， 6上的X锁是由哪个语句引起的，无法直观从死锁日志里看出。可以通过打开general日志或者binlog或者业务代码来查看整个事务逻辑
实验步骤及表结构
搭建可按实验步骤自己模拟测试，表结构及数据如下:
1CREATETABLEt1(idintunsignedNOTNULLPRIMARYKEY,c12varchar(10));3INSERTINTOt1VALUES(1,'aa'),(2,'bb'),(3,'cc'),(4,'dd'),(5,'ee'),(6,'ff');
操作步骤如表所示:
总结
这个案例根本原因是两个会话同时删除数据时，没有控制好删除的顺序造成了死锁，这就需要我们在做应用开发时对数据库操作一定要注意操作数据的前后关系、是否有数据依赖、会话之间是否会操作相同的数据。
通过这个案例我们也了解到了应如何去阅读和分析死锁日志。
《深入浅出MGR》视频课程
戳此小程序即可直达B站
/medialist/play/1363850082?business=space_collection&business_id=343928&desc=0
文章推荐：
MySQL内存为什么不断增高，怎么让它释放
MySQL 存储过程运行的内存管理
无损半同步复制下，主从切换后数据一致吗？
数据中间件如何与MySQL数据同步？
MySQL 8.0.30，一个值得上车MGR的版本
RC隔离级别下，死锁案例分析
浅析MySQL死锁检测
MySQL内存管理机制浅析
想看更多技术好文，点个“在看”吧！
