生产环境mysql死锁日志分析

为了offer 2021-12-08

4391

前言

死锁日志解读

死锁日志分析

开启mysql锁监控

◆ 前言

本文需要mysql锁的知识，可以看这篇文章：要让初学者都能懂的mysql锁讲解

最近在复习mysql锁的知识，昨天查看了线上的mysql innodb日志

命令:

show engine innodb status;
复制

发现了死锁，下面是死锁日志，我把表名隐藏了。

◆ 死锁日志解读

以下是死锁日志，前言的命令就可以查看

LATEST DETECTED DEADLOCK
------------------------
2021-11-19 16:50:10 0x7f55c0343700
*** (1) TRANSACTION:
TRANSACTION 68912, ACTIVE 10 sec inserting
mysql tables in use 12, locked 12
LOCK WAIT 8466 lock struct(s), heap size 811216, 152144 row lock(s), undo log entries 1
MySQL thread id 76893, OS thread handle 140005772797696, query id 1446455 127.0.0.1 root Sending data
// 这里把表名隐藏了
INSERT INTO XXX (in_out,
                                     organ_id,
                                     area_id,
                                     vehicle_id,
                                     list_number,
                                     license_plate,
                                     vehicle_number,
                                     list_type_id,
                                     weight_type,
                                     flow_type_id,
                                     supplier_id,
                                     specification_id,
                                     geometry_id,
                                     gross_weight,
                                     tare,
                                     buckle_percent,
                                     buckle_weight,
                                     net_weight,


*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 181 page no 16781 n bits 304 index list_number of table `szjz_pro`.`material_weight` trx id 68912 lock_mode X locks gap before rec insert intention waiting
Record lock, heap no 197 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
 0: len 23; hex e694b63230323131303237313433363034333933373039; asc    20211027143604393709;;
 1: len 8; hex 800000000007cfb9; asc         ;;


*** (2) TRANSACTION:
TRANSACTION 68913, ACTIVE 9 sec setting auto-inc lock
mysql tables in use 12, locked 12
8464 lock struct(s), heap size 811216, 152143 row lock(s)
MySQL thread id 76909, OS thread handle 140006273595136, query id 1446519 119.3.185.17 root Sending data
// 这里把表名隐藏了
INSERT INTO XXX (in_out,
                                     organ_id,
                                     area_id,
                                     vehicle_id,
                                     list_number,
                                     license_plate,
                                     vehicle_number,
                                     list_type_id,
                                     weight_type,
                                     flow_type_id,
                                     supplier_id,
                                     specification_id,
                                     geometry_id,
                                     gross_weight,
                                     tare,
                                     buckle_percent,
                                     buckle_weight,
                                     net_weight,


*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 181 page no 16781 n bits 304 index list_number of table `szjz_pro`.`material_weight` trx id 68913 lock mode S locks gap before rec
Record lock, heap no 6 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
 0: len 23; hex e694b63230323131303236313931393333353336383030; asc    20211026191933536800;;
 1: len 8; hex 800000000007cc16; asc         ;;




*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
TABLE LOCK table `szjz_pro`.`表名` trx id 68913 lock mode AUTO-INC waiting
*** WE ROLL BACK TRANSACTION (2)
复制

我们只需要解读关键的信息

LATEST DETECTED DEADLOCK ：这表示是死锁，展示了最后一次死锁，也就是最新的。

TRANSACTION 68912, ACTIVE 10 sec inserting: 表示事务id为68912 正在插入，活跃10s，我这里是插入就是inserting ，除了inserting 还有以下几个:

starting index read 表示事务状态为根据索引读取数据
fetching rows 表示事务状态在row_search_for_mysql中被设置，表示正在查找记录。
updating or deleting 表示事务已经真正进入了Update/delete的函数逻辑（row_update_for_mysql）
thread declared inside InnoDB 说明事务已经进入innodb层。通常而言不在innodb层的事务大部分是会被回滚的。

mysql tables in use 12, locked 12 :说明当前的事务使用12个表。locked 12 表示有12个表锁,对于DML语句为LOCK_IX

LOCK WAIT 8466 lock struct(s), heap size 811216, 152144 row lock(s), undo log entries 1 : LOCK WAIT表示正在等待锁, 8466 lock struct(s) 表示trx->trx_locks锁链表的长度为8466，每个链表节点代表该事务持有的一个锁结构。

heap size 811216 : 表示事务分配的锁堆内存大小,一般没有什么具体的用处。
152144 row lock(s): 表示当前事务持有的锁的个数

下面这是事务正在等待所锁的sql语句，可惜不会显示完整的

INSERT INTO XXX (in_out,
                                     organ_id,
                                     area_id,
                                     vehicle_id,
                                     list_number,
                                     license_plate,
                                     vehicle_number,
                                     list_type_id,
                                     weight_type,
                                     flow_type_id,
                                     supplier_id,
                                     specification_id,
                                     geometry_id,
                                     gross_weight,
                                     tare,
                                     buckle_percent,
                                     buckle_weight,
                                     net_weight,
复制

*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 181 page no 16781 n bits 304 index list_number of table `szjz_pro`.`表名` trx id 68912 lock_mode X locks gap before rec insert intention waiting
Record lock, heap no 197 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
 0: len 23; hex e694b63230323131303237313433363034333933373039; asc    20211027143604393709;;
 1: len 8; hex 800000000007cfb9; asc         ;;
复制

这段说事务1正在等待list_number的插入意向锁

locks gap before rec 表示为gap锁
locks rec but not gap 表示为记录锁
insert intention 表示为插入意向锁
waiting 表示锁等待

*** (2) TRANSACTION:
TRANSACTION 68913, ACTIVE 9 sec setting auto-inc lock
mysql tables in use 12, locked 12
复制

*** (2) TRANSACTION: 表示事务2 括号里面是1就是事务1

事务2设置自增锁（auto-inc lock）活跃9s。

有些解读了的就不解读了。

*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 181 page no 16781 n bits 304 index list_number of table `szjz_pro`.`表名` trx id 68913 lock mode S locks gap before rec
复制

上面表示事务2持有了list_number 的间隙共享锁，可惜看不到这个字段的值，只能找到代码分析

*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
TABLE LOCK table `szjz_pro`.`material_weight` trx id 68913 lock mode AUTO-INC waiting
*** WE ROLL BACK TRANSACTION (2)
复制

上面显示事务2在等待自增锁，然后回滚了事务2（如果出现死锁的情况，mysql会自动检测到了两个会话互相等待锁的情况，然后把开销最小的会话去做回滚操作）

◆ 死锁日志分析

上面的日志总结就是：

事务1等待插入意向锁，事务2持有间隙锁等待自增锁（间隙锁和间隙锁并不冲突，插入意向锁和间隙锁冲突）

但是事务2是insert啊，怎么会有间隙锁？

mysql官网说：

这是官网的文档：https://dev.mysql.com/doc/refman/5.6/en/innodb-locks-set.html

insert操作是排他记录锁，没有间隙锁，插入前需要加插入意向锁。

但是 INSERT当发生重复键错误时，将在要更新的行上放置排他锁而不是共享锁。对重复的主键值采用独占索引记录锁。对重复的唯一键值采用独占的 next-key 锁。

list_number 就是设置的唯一索引。

认为可能是list_number这个唯一索引的值冲突了。因为代码不是我写的，我也没找到代码，所以找不到具体原因。

还有就是自增锁的问题：他需要锁表，但是其他的表锁还没释放，应该是事务1把这张表锁住了。

以下是死锁问题的原因猜想图：

◆ 开启mysql锁监控

使用show engine innodb status; 只能看到最后一次死锁的信息，想每次发生死锁都记录下来：

在MySQL 5.6/5.7或MariaDB 10.0/10.1版本中，在my.cnf配置文件里加入：innodb_print_all_deadlocks=1 输出死锁日志到error.log(也就是错误日志)

或者使用命令 set global innodb_print_all_deadlocks=on

监控锁信息：

在mysql处理死锁问题时，由于show engine innodb status输出来的死锁日志无事务上下文，并不能很好地诊断相关事务所持有的所有锁信息，包括：锁个数、锁类型等。于是，需要能查看到更详细的事务锁占用情况。

该类监控机制默认是关闭状态，分析问题需要查看监控日志时再开启，因为输出生成会导致某些性能下降，每15s输出到错误日志文件

开启锁监控方式：

自mysql 5.6.16以上，可以通过设置系统参数(innodb_status_output_locks)的方式开启或者关闭标准监控。

set GLOBAL innodb_status_output=ON;

set GLOBAL innodb_status_output_locks=ON; // 开启锁监视

set GLOBAL innodb_status_output_locks=OFF; // 关闭锁监视

注：前提需要开启 innodb_status_output

可以查看mysql官网文档：https://dev.mysql.com/doc/refman/5.7/en/innodb-enabling-monitors.html

mysql

文章转载自为了offer，如果涉嫌侵权，请发送邮件至：contact@modb.pro进行举报，并提供相关证据，一经查实，墨天轮将立刻删除相关内容。

生产环境mysql死锁日志分析

评论

相关阅读