如何阅读死锁日志

Posted 2021-05-01 有赞coder

文 | 杨一 on 运维

一、前言

工欲善其事必先利其器，前面分析了很多死锁案例，并没有详细的介绍如何通过死锁日志来诊断死锁的成因。本文将介绍如何读懂死锁日志，尽可能的获取信息来辅助我们解决死锁问题。

二、日志分析

2.1 场景

为了更好的学习死锁日志，我们需要提前了解死锁场景：MySQL 5.6 事务隔离级别为 RR。

 
   
   
 

  
    
    
  
CREATE TABLE `ty` (
  
    
    
  
  `id` int(11) NOT NULL AUTO_INCREMENT,
  
    
    
  
  `a` int(11) DEFAULT NULL,
  
    
    
  
  `b` int(11) DEFAULT NULL,
  
    
    
  
  PRIMARY KEY (`id`),
  
    
    
  
  KEY `idxa` (`a`)
  
    
    
  
) ENGINE=InnoDB AUTO_INCREMENT=8 DEFAULT CHARSET=utf8mb4;
  
    
    
  
insert into ty(a,b) values(2,3),(5,4),(6,7);
 
   
   
 

2.2 测试用例

2.3 我们通过 show engine innodb status 查看的日志是最新一次记录死锁的日志

 
   
   
 

  
    
    
  
------------------------
  
    
    
  
LATEST DETECTED DEADLOCK
  
    
    
  
------------------------
  
    
    
  
2017-09-09 22:34:13 7f78eab82700
  
    
    
  
*** (1) TRANSACTION: ##事务1
  
    
    
  
TRANSACTION 462308399, ACTIVE 33 sec starting index read 
  
    
    
  
mysql tables in use 1, locked 1
  
    
    
  
LOCK WAIT 2 lock struct(s), heap size 360, 1 row lock(s)
  
    
    
  
MySQL thread id 3525577, OS thread handle 0x7f896cc4b700, query id 780039657 localhost root updating
  
    
    
  
delete from ty where a=5
  
    
    
  
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
  
    
    
  
RECORD LOCKS space id 219 page no 4 n bits 72 index `idxa` of table `test`.`ty` trx id 462308399 lock_mode X waiting
  
    
    
  
*** (2) TRANSACTION:
  
    
    
  
TRANSACTION 462308398, ACTIVE 61 sec inserting, thread declared inside InnoDB 5000
  
    
    
  
mysql tables in use 1, locked 1
  
    
    
  
5 lock struct(s), heap size 1184, 4 row lock(s), undo log entries 2
  
    
    
  
MySQL thread id 3525490, OS thread handle 0x7f78eab82700, query id 780039714 localhost root update
  
    
    
  
insert into ty(a,b) values(2,10)
  
    
    
  
*** (2) HOLDS THE LOCK(S):
  
    
    
  
RECORD LOCKS space id 219 page no 4 n bits 72 index `idxa` of table `test`.`ty` trx id 462308398 lock_mode X
  
    
    
  
*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
  
    
    
  
RECORD LOCKS space id 219 page no 4 n bits 72 index `idxa` of table `test`.`ty` trx id 462308398 lock_mode X locks gap before rec insert intention waiting
  
    
    
  
*** WE ROLL BACK TRANSACTION (1)
 
   
   
 

2.4 日志分析

 
   
   
 

  
    
    
  
*** (1) TRANSACTION: #事务1
  
    
    
  
TRANSACTION 462308399, ACTIVE 33 sec starting index read
 
   
   
 

事务编号为 462308399，活跃 33 秒，*starting index read * 表示事务状态为根据索引读取数据。常见的其他状态：

1. fetching rows 表示事务状态在 rowsearchfor_mysql 中被设置，表示正在查找记录

2. updating or deleting 表示事务已经真正进入了 Update/delete 的函数逻辑（rowupdatefor_mysql）

3. thread declared inside InnoDB 说明事务已经进入 innodb 层。通常而言不在 innodb 层的事务大部分是会被回滚的

mysql tables in use 1, 说明当前的事务使用一个表。

locked 1 表示表上有一个表锁,对于 DML 语句为 LOCK_IX

LOCK WAIT 2 lock struct(s), heap size 360, 1 row lock(s)

LOCK WAIT 表示正在等待锁， 2 lock struct(s) 表示 trx->trx_locks 锁链表的长度为 2，每个链表节点代表该事务持有的一个锁结构，包括表锁，记录锁以及 auto_inc 锁等。本案例中 2locks 表示 IX 锁和 lock_mode X (Next-key lock)

heap size 360 表示事务分配的锁堆内存大小,一般没有什么具体的用处。

1 row lock(s) 表示当前事务持有的行记录锁/gap 锁的个数。

delete from ty where a=5 表示事务 1 在执行的 sql ，不过比较悲伤的事情是 show engine innodb status 是查看不到完整的事务的 sql 的，通常显示当前正在等待锁的 sql。

 
   
   
 

  
    
    
  
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
  
    
    
  
RECORD LOCKS space id 219 page no 4 n bits 72 index `idxa` of table `test`.`ty` trx id 462308399 lock_mode X waiting
 
   
   
 

RECORD LOCKS 表示记录锁，space id 为 219，page号4 ，n bits 72 表示这个聚集索引记录锁结构上留有 72 个 Bit 位

表示事务 1 正在等待表 ty 上的 idxa 的 X 锁本案例中其实是 Next-Key lock

事务 2 的 log 和上面分析类似，

 
   
   
 

  
    
    
  
*** (2) HOLDS THE LOCK(S):
  
    
    
  
RECORD LOCKS space id 219 page no 4 n bits 72 index `idxa` of table `test`.`ty` trx id 462308398 lock_mode X
 
   
   
 

显示了事务 2 insert into ty(a,b) values(2,10) 持有了 a=5 的 Lock mode X |LOCK_GAP ，不过我们从日志里面看不到事务 2 执行的 delete from ty where a=5;这点也是造成 DBA 仅仅根据日志难以分析死锁的问题的根本原因。

 
   
   
 

  
    
    
  
*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
  
    
    
  
RECORD LOCKS space id 219 page no 4 n bits 72 index `idxa` of table `test`.`ty` trx id 462308398 lock_mode X locks gap before rec insert intention waiting
 
   
   
 

表示事务 2 的 insert 语句正在等待插入意向锁 lock_mode X locks gap before rec insert intention waiting (LOCK_X + LOCK_REC_GAP )

这里需要各位注意的是锁组合，类似 lock_mode X waiting ,lock_mode X,lock_mode X locks gap before rec insert intention waiting 是我们分析死锁的核心重点。如何理解锁组合呢？

首先我们要知道对于 MySQL 有两种常规锁模式：

 
   
   
 

  
    
    
  
LOCK_S（读锁，共享锁）
  
    
    
  
LOCK_X（写锁，排它锁）
 
   
   
 

最容易理解的锁模式，读加共享锁，写加排它锁。

有如下几种锁的属性：

 
   
   
 

  
    
    
  
LOCK_REC_NOT_GAP      （锁记录）
  
    
    
  
LOCK_GAP               (锁记录前的GAP）
  
    
    
  
LOCK_ORDINARY         （同时锁记录+记录前的GAP,也即是Next Key锁）
  
    
    
  
LOCK_INSERT_INTENTION （插入意向锁，其实是特殊的GAP锁）
 
   
   
 

锁的属性可以与锁模式任意组合。例如：

 
   
   
 

  
    
    
  
lock->type_mode       可以是Lock_X或者Lock_S 
  
    
    
  
locks gap before rec  表示为gap锁:lock->type_mode & LOCK_GAP
  
    
    
  
locks rec but not gap 表示为记录锁，非gap锁:lock->type_mode & LOCK_REC_NOT_GAP
  
    
    
  
insert intention      表示为插入意向锁:lock->type_mode & LOCK_INSERT_INTENTION
  
    
    
  
waiting               表示锁等待:lock->type_mode & LOCK_WAIT
 
   
   
 

三、小结

本文算是简单的死锁分析入门，能够提供部分死锁分析的所需要的技术知识。死锁分析确是一门技术活儿，想要透彻的分析死锁的成因，我们必须要了解造成死锁的业务逻辑 sql 的执行场景，MySQL 的锁机制,各种锁之间的兼容性,必要时还需要透彻的理解源码。

扩展阅读

1. 

2. 

3. 

-The End-

Vol.147

有赞技术团队

为 300 万商家，150 个行业，200 亿电商交易额

提供技术支持

微商城｜零售｜美业

技术博客：tech.youzan.com

The bigger the dream, 

the more important the team.