526互联

mysql死锁日志

发布时间 2024-01-11 16:36:33作者: caibaotimes

发生死锁，第一时间查看死锁日志

在分析日志前，我们要知道InnoDB中锁在日志中具体显示的数据类型，平时我们常接触到的是Record Locks（记录锁），Gap Locks（间隙锁），Next-Key Locks和Insert Intention Locks（插入意向锁）。这四种锁对应的死锁如下：

  • 记录锁（LOCK_REC_NOT_GAP）: lock_mode X locks rec but not gap
  • 间隙锁（LOCK_GAP）: lock_mode X locks gap before rec
  • Next-key 锁（LOCK_ORNIDARY）: lock_mode X
  • 插入意向锁（LOCK_INSERT_INTENTION）: lock_mode X locks gap before rec insert intention

注意删除和更新InnoDB内部也是要进行读操作的

既然死锁已经发生，也完全不要慌啊，按我说着做，一定能找到原因然后解决

触发下面这条命令获取到线索

SHOW ENGINE INNODB STATUS;

执行后你会得到一段让人看了有点迷迷的死锁日志，具体我们该怎么分析死锁，可以分成一下三步

  • 查看发生死锁的事务（一）信息（包括持有的锁，等待的锁）
  • 查看发生死锁的事务（二）信息（包括持有的锁，等待的锁）
  • 查看回滚的是事务（一）还是事务（二），做好异常业务恢复的方案
  • 根据mysql的加锁机制分析发生的死锁的原因

由于死锁日志过于长，下面的日志只截取部分有用的记录

------------------------
LATEST DETECTED DEADLOCK
-------------------------10-14 15:51:34 0x1a00
发生死锁的事务（一）
*** () TRANSACTION:
TRANSACTION 32828384, ACTIVE 0 sec fetching rows
mysql tables in use 1, locked 1
LOCK WAIT lock struct(s), heap size 1128, 285 row lock(s)
MySQL thread id 67826762, OS thread handle 8548, query id 987590925 WIN-6Q9NIAJLCDR 172.27.15.57 swgj updating
事务（一）导致死锁的sql  // 事务一最后一条执行的sql信息
update xxx
     SET STATUS = '',
        DESCRIPTION = 'xxx',
        MODIFY_TIME = '-10-14 15:51:35.707' 
     WHERE  BATCH_NO = 'xxx'
        and SFSB = ''
事务（一）持有的锁
*** () HOLDS THE LOCK(S):
RECORD LOCKS space id page no 82 n bits 104 index PRIMARY of RECORD LOCKS trx id 32828384 lock_mode X
事务（一）持有锁的数据记录信息 （supremum虚拟最大记录）
Record lock, heap no PHYSICAL RECORD: n_fields 1; compact format; info bits 0
: len 8; hex 73757072656d756d; asc supremum;;
事务（一）持有锁的数据记录信息 （哪一行数据被锁了）
Record lock, heap no PHYSICAL RECORD: n_fields 29; compact format; info bits 0
0: len 30; hex 30663730333038302d313164662d346439642d626338662d393439333333; asc 0f703080-11df-4d9d-bc8f-949333; (total 36 bytes);
1: len 6; hex 0000015129e1; asc    Q) ;;
2: len 7; hex 010000402103cd; asc    @!  ;;
3: len 6; hex 313635303036; asc 165006;;
 .....
 .....
事务（一）等待的锁
*** () WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id page no 37 n bits 112 index PRIMARY of table `swgj`.`spgl_xmspsxblxxxxb` trx id 32828384 lock_mode X waiting
事务（一）等待锁的数据记录信息
Record lock, heap no PHYSICAL RECORD: n_fields 29; compact format; info bits 0
0: len 30; hex 32643736613832362d343763362d343861332d613038662d343539333061; asc 2d76a826-47c6-48a3-a08f-45930a; (total 36 bytes);
1: len 6; hex 000001f4ebdd; asc       ;;
2: len 7; hex 820000402b3c96; asc    @+< ;;
3: SQL NULL;
 .....
 .....
 发生死锁的事务（二）
 *** () TRANSACTION:
TRANSACTION 32828381, ACTIVE 5 sec inserting
mysql tables in use 1, locked 1
LOCK WAIT lock struct(s), heap size 24696, 137 row lock(s), undo log entries 724
MySQL thread id 67826766, OS thread handle 12700, query id 987590958 WIN-6Q9NIAJLCDR 172.27.15.57 swgj update
事务（二）导致死锁的sql
insert into xxx
     ( ID, BATCH_NO, DFSJZJ,... ) 
     values ( 'xxx', 'xxx','xxx' )
事务（二）持有的锁
*** () HOLDS THE LOCK(S):
RECORD LOCKS space id page no 37 n bits 112 index PRIMARY of table `swgj`.`spgl_xmspsxblxxxxb` trx id 32828381 lock_mode X locks rec but not gap
事务（二）持有锁的数据记录信息
Record lock, heap no PHYSICAL RECORD: n_fields 29; compact format; info bits 0
0: len 30; hex 32643736613832362d343763362d343861332d613038662d343539333061; asc 2d76a826-47c6-48a3-a08f-45930a; (total 36 bytes);
1: len 6; hex 000001f4ebdd; asc       ;;
2: len 7; hex 820000402b3c96; asc    @+< ;;
3: SQL NULL;
 ...
 ...
事务（二）等待的锁
*** () WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id page no 82 n bits 104 index PRIMARY of table `swgj`.`spgl_xmspsxblxxxxb` trx id 32828381 lock_mode X locks gap before rec insert intention waiting
事务（二）等待锁的数据记录信息
Record lock, heap no PHYSICAL RECORD: n_fields 29; compact format; info bits 0
0: len 30; hex 30666435313133662d393462382d346636632d383362372d303463656536; asc 0fd5113f-94b8-4f6c-83b7-04cee6; (total 36 bytes);
1: len 6; hex 000001dbb470; asc      p;;
2: len 7; hex 020000013619a1; asc     6  ;;
3: len 6; hex 313636333830; asc 166380;;
 ...
 ...

分析日志

从数据库版本5.7、事务的隔离级别 REPEATABLE READ

官方文档明确指出在 REPEATABLE READ 隔离级别下，默认查询条件下是加 next-key locks (record locks + gap locks ) 或 gap locks，当查询条件使用了唯一索引时，只会对当前查询的唯一记录进行加锁，此时锁为 record locks

官方文档强势占位

MySQL 隔离级别

MySQL InnoDB 锁的类型

MySQL InnoDB 中不同 SQL 语句如何置锁

从死锁日志信息可以得出

  • 根据事务id大小可得出事务（二）32828381 比事务（一）32828384 先执行
  • 从日志中的 index PRIMARY 得出锁是加在主键索引上
  • 根据业务代码，事务（二）将执行 N 条同表插入 insert 语句，加上持有锁信息得出，事务（二）先插入了一条新数据A，并得到新数据A的行锁 Record Locks
  • 事务（一）执行 update 时直接阻塞，为什么呢，直接给出答案吧，因为这条 update 的查询条件是没有索引，导致需要所有的记录都要加 Record Locks 和 Gap Locks，接着由于事务（二）已经持有新数据A的行锁，导致无法上锁而阻塞等待
  • 事务（二）继续插入一条新数据B时获取 insert intention locks 阻塞等待，很显然，事务（一）抢先占有插入数据上下索引的 Gap Locks，死锁产生，MySQL提示错误，并回滚事务（二）让事务（一）提交

lock_mode X locks rec but not gap 对记录加的都是X 锁，No Gap锁，即对当行记录加锁(Record Lock)，并未加间隙锁。

Gap Lock：间隙锁，锁定一个范围，但不包括记录本身。GAP锁的目的，是为了防止同一事务的两次当前读，出现幻读的情况。

Next-Key Lock：1+2，锁定一个范围，并且锁定记录本身。对于行的查询，都是采用该方法，主要目的是解决幻读的问题。

其中：

TRANSACTION 32828384 是事务的id

ACTIVE 0 sec 活跃时间多少秒

fetching rows 表示事务状态在row_search_for_mysql中被设置，表示正在查找记录。

这个描述还有其他情况：

1、starting index read 事务当前正在根据索引读取数据

2、updating or deleting 表示事务已经真正进入了update/delete的函数逻辑(row_update_for_mysql)

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

需要重点关注(undo log entries 3)，事务修改的行数（undo log entries）

undo log entries 1

大约等于已经修改的记录数，每修改一行都会占用一个 undo log entries

事务处于 lock wait 状态 三个锁结构 2个行级锁

LOCK WAIT 3 lock struct(s), heap size 1136, 2 row lock(s)

mysql tables in use 1, locked 1，表示此事务使用了一个表，1个表锁

LOCK WAIT表示正在等待锁

MySQL thread id 67826762 这个是线程 id

query id 987590925 这个是查询id

RECORD LOCKS 表示持有的是行级锁

index PRIMARY 表示锁的是主键索引

table swgj.spgl_xmspsxblxxxxb 表示锁的是哪个表

**trx id 32828384 **，事务id，和上面的TRANSACTION相同。

lock_mode X locks，锁模式：排它锁。（X：排他锁，S：共享锁）

but not gap，非间隙锁

后面的0至 ...，代表锁的具体哪一行，0至...指的是表的第1至第...个字段

通过死锁日志，我们可以找到最终获得锁事务最后执行的 SQL，但是如果该事务执行了多条 SQL，这些信息就可能不够用的啦，我们需要完整的了解该事务所有执行的 SQL语句。这时，我们就需要从 binlog 日志中获取。