MySQL打印死锁日志

本文涉及的产品
RDS MySQL Serverless 基础系列,0.5-2RCU 50GB
云数据库 RDS MySQL,集群系列 2核4GB
推荐场景:
搭建个人博客
云数据库 RDS PostgreSQL,集群系列 2核4GB
简介: 在 MySQL 运维过程中,难免会遇到 MySQL 死锁的情况,一旦线上业务日渐复杂,各种业务操作之间往往会产生锁冲突,有些会导致死锁异常。这种死锁异常一般要在特定时间特定数据和特定业务操作才会复现,有时候处理起来毫无头绪,一般只能从死锁日志下手。本篇文章我们一起来看下 MySQL 的死锁日志。

1.手动打印死锁日志


当业务发生死锁时,首先是线上错误日志报警发现死锁异常,也会提示一些堆栈信息,然后会反馈到数据库层面进行排查。我们一般会在命令行执行 show engine innodb status\G 来输出死锁日志,\G 的作用是将查询到的结果,每行显示一个字段和字段值,方便查看。


show engine innodb status 是 MySQL 提供的一个用于查看 innodb 引擎系统信息的工具。它会输出大量的内部信息,内容分为很多小段,每一段对应 innodb 存储引擎不同部分的信息,其中 LATEST DETECTED DEADLOCK 部分显示的最近一次的死锁信息。

下面我们手动制造一次死锁,来看一下死锁日志相关信息:

------------------------
LATEST DETECTED DEADLOCK
------------------------
2021-11-10 17:03:10 0x7fb040672700
*** (1) TRANSACTION:
TRANSACTION 46913, ACTIVE 142 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 4 lock struct(s), heap size 1136, 3 row lock(s), undo log entries 1
MySQL thread id 2997198, OS thread handle 140394973071104, query id 9145673 localhost root updating
update test_tb set stu_name = 'lisi' where stu_id = 1006
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 224 page no 4 n bits 80 index uk_stu_id of table `testdb`.`test_tb` trx id 46913 lock_mode X locks rec but not gap waiting
Record lock, heap no 7 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
 0: len 4; hex 800003ee; asc     ;;
 1: len 4; hex 80000006; asc     ;;
*** (2) TRANSACTION:
TRANSACTION 46914, ACTIVE 103 sec starting index read
mysql tables in use 1, locked 1
4 lock struct(s), heap size 1136, 3 row lock(s), undo log entries 1
MySQL thread id 2997201, OS thread handle 140394971473664, query id 9145681 localhost root updating
update test_tb set age = 21  where stu_id = 1005
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 224 page no 4 n bits 80 index uk_stu_id of table `testdb`.`test_tb` trx id 46914 lock_mode X locks rec but not gap
Record lock, heap no 7 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
 0: len 4; hex 800003ee; asc     ;;
 1: len 4; hex 80000006; asc     ;;
*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 224 page no 4 n bits 80 index uk_stu_id of table `testdb`.`test_tb` trx id 46914 lock_mode X locks rec but not gap waiting
Record lock, heap no 6 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
 0: len 4; hex 800003ed; asc     ;;
 1: len 4; hex 80000005; asc     ;;
*** WE ROLL BACK TRANSACTION (2)
# 以上为原文 下面增加个人分析
------------------------
LATEST DETECTED DEADLOCK
------------------------
2021-11-10 17:03:10 0x7fb040672700 #这里显示了最近一次发生死锁的日期和时间
*** (1) TRANSACTION: #死锁相关的第一个事务
TRANSACTION 46913, ACTIVE 142 sec starting index read
#这行表示事务id为46913,事务处于活跃状态142s,starting index read表示正在使用索引读取数据行
mysql tables in use 1, locked 1
#这行表示该事务正在使用1个表,且涉及锁的表有1个
LOCK WAIT 4 lock struct(s), heap size 1136, 3 row lock(s), undo log entries 1
#这行表示在等待4把锁,占用内存1136字节,涉及3行记录
MySQL thread id 2997198, OS thread handle 140394973071104, query id 9145673 localhost root updating
#这行表示该事务的线程ID信息,操作系统句柄信息,连接来源、用户
update test_tb set stu_name = 'lisi' where stu_id = 1006
#这行表示事务执行的最后一条SQL信息
*** (1) WAITING FOR THIS LOCK TO BE GRANTED: #事务1想要获取的锁
RECORD LOCKS space id 224 page no 4 n bits 80 index uk_stu_id of table `testdb`.`test_tb` trx id 46913 lock_mode X locks rec but not gap waiting
#这行信息表示等待的锁是一个record lock,空间id是224,页编号为4,大概位置在页的80位处,锁发生在表testdb.test_tb的uk_stu_id索引上,是一个X锁,但是不是gap lock,waiting表示正在等待锁
Record lock, heap no 7 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
 0: len 4; hex 800003ee; asc     ;;
 1: len 4; hex 80000006; asc     ;;
*** (2) TRANSACTION: #死锁相关的第一个事务
TRANSACTION 46914, ACTIVE 103 sec starting index read
#这行表示事务2的id为46914,事务处于活跃状态103s
mysql tables in use 1, locked 1
#正在使用1个表,涉及锁的表有1个
4 lock struct(s), heap size 1136, 3 row lock(s), undo log entries 1
#涉及4把锁,3行记录
MySQL thread id 2997201, OS thread handle 140394971473664, query id 9145681 localhost root updating
#事务2的线程ID信息,操作系统句柄信息,连接来源、用户
update test_tb set age = 21  where stu_id = 1005
#第二个事务的SQL
*** (2) HOLDS THE LOCK(S): # 事务2持有的锁 正是事务1想要获取的锁
RECORD LOCKS space id 224 page no 4 n bits 80 index uk_stu_id of table `testdb`.`test_tb` trx id 46914 lock_mode X locks rec but not gap
Record lock, heap no 7 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
 0: len 4; hex 800003ee; asc     ;;
 1: len 4; hex 80000006; asc     ;;
*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 224 page no 4 n bits 80 index uk_stu_id of table `testdb`.`test_tb` trx id 46914 lock_mode X locks rec but not gap waiting
Record lock, heap no 6 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
 0: len 4; hex 800003ed; asc     ;;
 1: len 4; hex 80000005; asc     ;;
#上面这部分是事务二正在等待的锁,从信息上看,等待的是同一个表,同一个索引,同一个page上的record lock X锁,但是heap no位置不同,即不同的行上的锁
*** WE ROLL BACK TRANSACTION (2) #表示事务2被回滚

从死锁日志中可以看到关联的两个事务相关信息,当一个事务持有了其他事务需要的锁,同时又想获得其他事务持有的锁时,等待关系上就会产生循环,Innodb 不会显示所有持有和等待的锁,但死锁日志也显示了相关的信息来帮你确定,排查死锁发生的索引,这对于你确定能否避免死锁有较大的价值。


2.自动保存死锁日志


从上面内容我们知道 MySQL 的死锁可以通过 show engine innodb status 来查看,但是这个命令需要手动执行并且只能显示最新的一条死锁,该方式无法完全捕获到系统发生的死锁信息。那有没有办法记录所有的死锁日志呢,我们来看下 MySQL 的系统参数。


MySQL 系统内部提供一个 innodb_print_all_deadlocks 参数,该参数默认是关闭的,开启后可以将死锁信息自动记录到 MySQL 的错误日志中。下面我们来看下这个参数的作用:

# 查看参数是否开启
mysql> show variables like 'innodb_print_all_deadlocks';
+----------------------------+-------+
| Variable_name              | Value |
+----------------------------+-------+
| innodb_print_all_deadlocks | OFF   |
+----------------------------+-------+
# 开启innodb_print_all_deadlocks,此参数是全局参数,可以动态调整。记得要加入到配置文件中
mysql> set global innodb_print_all_deadlocks = 1;
Query OK, 0 rows affected (0.00 sec)
mysql> show variables like 'innodb_print_all_deadlocks';
+----------------------------+-------+
| Variable_name              | Value |
+----------------------------+-------+
| innodb_print_all_deadlocks | ON    |
+----------------------------+-------+

建议将 innodb_print_all_deadlocks 参数设置为 1 ,这样每次发生死锁后,系统会自动将死锁信息输出到错误日志中,需要注意的是打开此参数后,只会记录死锁部分信息而不会记录 innodb 其他相关信息,即只会记录 show engine innodb status 中的 LATEST DETECTED DEADLOCK 部分。


其实 InnoDB 存储引擎还提供有 InnoDB Monitor 监视器,可以定期将 InnoDB 的状态信息输出到错误日志中,主要由 innodb_status_output 和 innodb_status_output_locks 参数控制,这两个系统变量是用来启用标准 InnoDB 监控和 InnoDB 锁监控的,开启后会将监控结果输出错误日志中,大约每隔 15 秒产生一次输出,输出内容与 show engine innodb status 一致。不过这会导致错误日志暴增,一般不建议开启这两个参数。


总结:


本篇文章介绍了 MySQL 死锁日志的获取方法,发生死锁后,可以根据死锁日志还获取相关信息。开启 innodb_print_all_deadlocks 参数可以自动将死锁信息输出到错误日志中,有助于我们及时发现并处理死锁异常。

相关实践学习
如何快速连接云数据库RDS MySQL
本场景介绍如何通过阿里云数据管理服务DMS快速连接云数据库RDS MySQL,然后进行数据表的CRUD操作。
全面了解阿里云能为你做什么
阿里云在全球各地部署高效节能的绿色数据中心,利用清洁计算为万物互联的新世界提供源源不断的能源动力,目前开服的区域包括中国(华北、华东、华南、香港)、新加坡、美国(美东、美西)、欧洲、中东、澳大利亚、日本。目前阿里云的产品涵盖弹性计算、数据库、存储与CDN、分析与搜索、云通信、网络、管理与监控、应用服务、互联网中间件、移动服务、视频服务等。通过本课程,来了解阿里云能够为你的业务带来哪些帮助     相关的阿里云产品:云服务器ECS 云服务器 ECS(Elastic Compute Service)是一种弹性可伸缩的计算服务,助您降低 IT 成本,提升运维效率,使您更专注于核心业务创新。产品详情: https://www.aliyun.com/product/ecs
目录
相关文章
|
1天前
|
SQL 存储 关系型数据库
简单聊聊MySQL的三大日志(Redo Log、Binlog和Undo Log)各有什么区别
在MySQL数据库管理中,理解Redo Log(重做日志)、Binlog(二进制日志)和Undo Log(回滚日志)至关重要。Redo Log确保数据持久性和崩溃恢复;Binlog用于主从复制和数据恢复,记录逻辑操作;Undo Log支持事务的原子性和隔离性,实现回滚与MVCC。三者协同工作,保障事务ACID特性。文章还详细解析了日志写入流程及可能的异常情况,帮助深入理解数据库日志机制。
|
2天前
|
存储 SQL 关系型数据库
mysql的undo log、redo log、bin log、buffer pool
MySQL的undo log、redo log、bin log和buffer pool是确保数据库高效、安全和可靠运行的关键组件。理解这些组件的工作原理和作用,对于优化数据库性能和保障数据安全具有重要意义。通过适当的配置和优化,可以显著提升MySQL的运行效率和数据可靠性。
16 4
|
3天前
|
存储 SQL 关系型数据库
mysql的undo log、redo log、bin log、buffer pool
MySQL的undo log、redo log、bin log和buffer pool是确保数据库高效、安全和可靠运行的关键组件。理解这些组件的工作原理和作用,对于优化数据库性能和保障数据安全具有重要意义。通过适当的配置和优化,可以显著提升MySQL的运行效率和数据可靠性。
29 16
|
5天前
|
数据可视化 关系型数据库 MySQL
ELK实现nginx、mysql、http的日志可视化实验
通过本文的步骤,你可以成功配置ELK(Elasticsearch, Logstash, Kibana)来实现nginx、mysql和http日志的可视化。通过Kibana,你可以直观地查看和分析日志数据,从而更好地监控和管理系统。希望这些步骤能帮助你在实际项目中有效地利用ELK来处理日志数据。
164 90
|
18天前
|
关系型数据库 MySQL 数据库
MySQL日志
本文介绍了MySQL中三个重要的日志:binlog、redolog和undolog。binlog记录数据库更改操作,支持数据恢复、复制和审计;redolog保证事务的原子性和持久性,实现crash-safe;undolog用于事务回滚及MVCC的实现。每个日志都有其独特的作用和应用场景,确保数据库的稳定性和数据一致性。
|
3天前
|
缓存 Java 编译器
|
21天前
|
存储 缓存 关系型数据库
图解MySQL【日志】——Redo Log
Redo Log(重做日志)是数据库中用于记录数据页修改的物理日志,确保事务的持久性和一致性。其主要作用包括崩溃恢复、提高性能和保证事务一致性。Redo Log 通过先写日志的方式,在内存中缓存修改操作,并在适当时候刷入磁盘,减少随机写入带来的性能损耗。WAL(Write-Ahead Logging)技术的核心思想是先将修改操作记录到日志文件中,再择机写入磁盘,从而实现高效且安全的数据持久化。Redo Log 的持久化过程涉及 Redo Log Buffer 和不同刷盘时机的控制参数(如 `innodb_flush_log_at_trx_commit`),以平衡性能与数据安全性。
28 5
图解MySQL【日志】——Redo Log
|
23天前
|
存储 关系型数据库 MySQL
图解MySQL【日志】——Undo Log
Undo Log(回滚日志)是 MySQL 中用于实现事务原子性和一致性的关键机制。在默认的自动提交模式下,MySQL 隐式开启事务,每条增删改语句都会记录到 Undo Log 中。其主要作用包括:
35 0
|
1月前
|
存储 SQL 关系型数据库
MySQL日志详解——日志分类、二进制日志bin log、回滚日志undo log、重做日志redo log
MySQL日志详解——日志分类、二进制日志bin log、回滚日志undo log、重做日志redo log、原理、写入过程;binlog与redolog区别、update语句的执行流程、两阶段提交、主从复制、三种日志的使用场景;查询日志、慢查询日志、错误日志等其他几类日志
115 35
MySQL日志详解——日志分类、二进制日志bin log、回滚日志undo log、重做日志redo log
|
2月前
|
SQL 关系型数据库 MySQL
MySQL事务日志-Undo Log工作原理分析
事务的持久性是交由Redo Log来保证,原子性则是交由Undo Log来保证。如果事务中的SQL执行到一半出现错误,需要把前面已经执行过的SQL撤销以达到原子性的目的,这个过程也叫做"回滚",所以Undo Log也叫回滚日志。
123 7
MySQL事务日志-Undo Log工作原理分析