记录一次生产上的MySQL死锁
2021-09-28T21:47:42.250008+08:00 141618429 [Note] InnoDB: Transactions deadlock detected, dumping detailed information.
2021-09-28T21:47:42.250028+08:00 141618429 [Note] InnoDB:
*** (1) TRANSACTION:
TRANSACTION 6713685063, ACTIVE 0 sec fetching rows
mysql tables in use 1, locked 1
LOCK WAIT 30484 lock struct(s), heap size 2728144, 92357 row lock(s)
MySQL thread id 141617133, OS thread handle 140435493652224, query id 25388365425 xx.xx.xx.xx XXXXX updating
UPDATE commandmsg SET RetryKey = 1901d5b2-2463-4454-8107-7760dbd4d0b5, DataChange_LastTime = NOW() WHERE (MsgStatus = 0 AND (DataChange_LastTime <= 2021-09-28 21:46:42.023 && ExpectExecuteTime <= 2021-09-28 21:46:42.023)) OR (MsgStatus = 1 AND (RetryKey = OR (RetryKey != AND DataChange_LastTime <= 2021-09-28 21:42:42.023))) LIMIT 10
2021-09-28T21:47:42.250073+08:00 141618429 [Note] InnoDB: *** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 395311 page no 527191 n bits 104 index PRIMARY of table `xxxxxdb`.`xx_xxxx_xxxxx` trx id 6713685063 lock_mode X locks rec but not gap waiting
Record lock, heap no 33 PHYSICAL RECORD: n_fields 17; compact format; info bits 0
2021-09-28T21:47:42.251187+08:00 141618429 [Note] InnoDB: *** (2) TRANSACTION:
TRANSACTION 6713685118, ACTIVE 0 sec updating or deleting, thread declared inside InnoDB 4999
mysql tables in use 1, locked 1
3 lock struct(s), heap size 1136, 2 row lock(s), undo log entries 1
MySQL thread id 141618429, OS thread handle 140434330167040, query id 25388365636 10.96.95.20 w_carorderm updating
UPDATE `xx_xxx_commandmsg` SET `MsgId`=87b22a12-9d97-4d75-a5cc-02573ceb9b99, `Content`=xxxxxxx, `xxxx`=1, `xxxx`=3, `LockKey`=xxxxxxxxxxxx, `xxxxx`=1, `xxxxx`=xxxx, `xxxxx`=xxxxxxx, `RetryKey`=, `OrderID`=xxxxxxxxxx, `FirstExecuteTime`=2021-09-28 21:47:41.873, `ExpectExecuteTime`=2021-09-28 21:47:42, `DataChange_CreateTime`=2021-09-28 21:47:42 WHERE `Id`=31545069
2021-09-28T21:47:42.251228+08:00 141618429 [Note] InnoDB: *** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 395311 page no 527191 n bits 104 index PRIMARY of table `xxxxxx`.`commandmsg` trx id 6713685118 lock_mode X locks rec but not gap
Record lock, heap no 33 PHYSICAL RECORD: n_fields 17; compact format; info bits 0
2021-09-28T21:47:42.252384+08:00 141618429 [Note] InnoDB: *** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 395311 page no 17497 n bits 328 index MsgStatus_CommandType of table `xxxxxx`.`commandmsg` trx id 6713685118 lock_mode X locks rec but not gap waiting
Record lock, heap no 261 PHYSICAL RECORD: n_fields 3; compact format; info bits 0
2021-09-28T21:47:42.252608+08:00 141618429 [Note] InnoDB: *** WE ROLL BACK TRANSACTION (2)
分析
日志中出现的关键词介绍：
idx_MsgStatus: a nonclustered index, index for column MsgStatus.
idx_Primary: a clustered index,the primary key of this table.
Transaction(1) is a wide range of data update, it hit the idx_MsgStatus.
Transaction(2) is a exact match of data update, it hit the idx_Primary.
从日志分析可以看出 Transaction(1)做了以下的事情：
1.对非聚集idx_MsgStatus加X锁
2.然后对idx_Primary加X锁
2.1 对idx_Primary加锁时发现Transaction(2)已经持有了该索引的X锁
- 等待
Transaction(2)释放锁
而Transaction(2)干了：
1.对idx_Primary加X锁
2.对非聚集idx_MsgStatus加X锁
2.1 发现Transaction(1)已经持有了该索引的X锁
3.mysql发现了存在死锁，于是rollback了Transaction(2)
总结：一次经典的死锁
How to avoid？
代码设计的烂，不应该在业务高峰期出现批量的update情况
