MySQL死锁问题如何分析

标签: 公众号文章mysql


若是咱们的业务处在一个很是初级的阶段,并发程度比较低,那么咱们能够几年都遇不到一次死锁问题的发生,反之,咱们业务的并发程度很是高,那么时不时爆出的死锁问题确定让咱们很是挠头。不过在死锁问题发生时,不少没有经验的同窗的第一反应就是成为一只鸵鸟:这玩意儿很高深,我也看不懂,听天由命吧,又不是一直发生。其实若是你们认真研读了咱们以前写的3篇关于MySQL中语句加锁分析的文章,加上本篇关于死锁日志的分析,那么解决死锁问题应该也不是那么摸不着头脑的事情了。sql

准备工做

为了故事的顺利发展,咱们须要建一个表:bash

CREATE TABLE hero (
    id INT,
    name VARCHAR(100),
    country varchar(100),
    PRIMARY KEY (id),
    KEY idx_name (name)
) Engine=InnoDB CHARSET=utf8;
复制代码

咱们为hero表的id列建立了聚簇索引,为name列建立了一个二级索引。这个hero表主要是为了存储三国时的一些英雄,咱们向表中插入一些记录:服务器

INSERT INTO hero VALUES
    (1, 'l刘备', '蜀'),
    (3, 'z诸葛亮', '蜀'),
    (8, 'c曹操', '魏'),
    (15, 'x荀彧', '魏'),
    (20, 's孙权', '吴');
复制代码

如今表中的数据就是这样的:session

mysql> SELECT * FROM hero;
+----+------------+---------+
| id | name       | country |
+----+------------+---------+
|  1 | l刘备      | 蜀      |
|  3 | z诸葛亮    | 蜀      |
|  8 | c曹操      | 魏      |
| 15 | x荀彧      | 魏      |
| 20 | s孙权      | 吴      |
+----+------------+---------+
5 rows in set (0.00 sec)
复制代码

准备工做就作完了。并发

建立死锁情景

咱们先建立一个发生死锁的情景,在Session ASession B中分别执行两个事务,具体状况以下:优化

image_1ddpitcafvd9147kqen1clhipc9.png-124.9kB

咱们分析一下:ui

  • 从第③步中能够看出,Session A中的事务先对hero表聚簇索引的id值为1的记录加了一个X型正经记录锁spa

  • 从第④步中能够看出,Session B中的事务对hero表聚簇索引的id值为3的记录加了一个X型正经记录锁操作系统

  • 从第⑤步中能够看出,Session A中的事务接着想对hero表聚簇索引的id值为3的记录也加了一个X型正经记录锁,可是与第④步中Session B中的事务加的锁冲突,因此Session A进入阻塞状态,等待获取锁。

  • 从第⑥步中能够看出,Session B中的事务想对hero表聚簇索引的id值为1的记录加了一个X型正经记录锁,可是与第③步中Session A中的事务加的锁冲突,而此时Session ASession B中的事务循环等待对方持有的锁,死锁发生,被MySQL服务器的死锁检测机制检测到了,因此选择了一个事务进行回滚,并向客户端发送一条消息:

    ERROR 1213 (40001): Deadlock found when trying to get lock; try restarting transaction
    复制代码

以上是咱们从语句加了什么锁的角度出发来进行死锁状况分析的,可是实际应用中咱们可能压根儿不知道究竟是哪几条语句产生了死锁,咱们须要根据MySQL在死锁发生时产生的死锁日志来逆向定位一下究竟是什么语句产生了死锁,从而再优化咱们的业务。

查看死锁日志

设计InnoDB的大叔给咱们提供了SHOW ENGINE INNODB STATUS命令来查看关于InnoDB存储引擎的一些状态信息,其中就包括了系统最近一次发生死锁时的加锁状况。在上边例子中的死锁发生时,咱们运行一下这个命令:

mysql> SHOW ENGINE INNODB STATUS\G
...省略了好多其余信息
------------------------
LATEST DETECTED DEADLOCK
------------------------
2019-06-20 13:39:19 0x70000697e000
*** (1) TRANSACTION:
TRANSACTION 30477, ACTIVE 10 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 3 lock struct(s), heap size 1160, 2 row lock(s)
MySQL thread id 2, OS thread handle 123145412648960, query id 46 localhost 127.0.0.1 root statistics
select * from hero where id = 3 for update
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 171 page no 3 n bits 72 index PRIMARY of table `dahaizi`.`hero` trx id 30477 lock_mode X locks rec but not gap waiting
Record lock, heap no 3 PHYSICAL RECORD: n_fields 5; compact format; info bits 0
 0: len 4; hex 80000003; asc     ;;
 1: len 6; hex 000000007517; asc     u ;;
 2: len 7; hex 80000001d0011d; asc        ;;
 3: len 10; hex 7ae8afb8e8919be4baae; asc z         ;;
 4: len 3; hex e89c80; asc    ;;

*** (2) TRANSACTION:
TRANSACTION 30478, ACTIVE 8 sec starting index read
mysql tables in use 1, locked 1
3 lock struct(s), heap size 1160, 2 row lock(s)
MySQL thread id 3, OS thread handle 123145412927488, query id 47 localhost 127.0.0.1 root statistics
select * from hero where id = 1 for update
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 171 page no 3 n bits 72 index PRIMARY of table `dahaizi`.`hero` trx id 30478 lock_mode X locks rec but not gap
Record lock, heap no 3 PHYSICAL RECORD: n_fields 5; compact format; info bits 0
 0: len 4; hex 80000003; asc     ;;
 1: len 6; hex 000000007517; asc     u ;;
 2: len 7; hex 80000001d0011d; asc        ;;
 3: len 10; hex 7ae8afb8e8919be4baae; asc z         ;;
 4: len 3; hex e89c80; asc    ;;

*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 171 page no 3 n bits 72 index PRIMARY of table `dahaizi`.`hero` trx id 30478 lock_mode X locks rec but not gap waiting
Record lock, heap no 2 PHYSICAL RECORD: n_fields 5; compact format; info bits 0
 0: len 4; hex 80000001; asc     ;;
 1: len 6; hex 000000007517; asc     u ;;
 2: len 7; hex 80000001d00110; asc        ;;
 3: len 7; hex 6ce58898e5a487; asc l      ;;
 4: len 3; hex e89c80; asc    ;;

*** WE ROLL BACK TRANSACTION (2)
------------
...省略了好多其余信息
复制代码

咱们只关心最近发生的死锁信息,因此就把以LATEST DETECTED DEADLOCK这一部分给单独提出来分析一下。下边咱们就逐行看一下这个输出的死锁日志都是什么意思:

  • 首先看第一句:

    2019-06-20 13:39:19 0x70000697e000
    复制代码

    这句话的意思就是死锁发生的时间是:2019-06-20 13:39:19,后边的一串十六进制0x70000697e000表示的操做系统为当前session分配的线程的线程id。

  • 而后是关于死锁发生时第一个事务的有关信息:

    *** (1) TRANSACTION:
    
    # 为事务分配的id为30477,事务处于ACTIVE状态已经10秒了,事务如今正在作的操做就是:“starting index read”
    TRANSACTION 30477, ACTIVE 10 sec starting index read
    
    # 此事务使用了1个表,为1个表上了锁(此处不是说为该表加了表锁,只要不是进行一致性读的表,都须要加锁,具体怎么加锁请看加锁语句分析或者小册章节)
    mysql tables in use 1, locked 1
    
    # 此事务处于LOCK WAIT状态,拥有3个锁结构(2个行锁结构,1个表级别X型意向锁结构,锁结构在小册中重点介绍过),heap size是为了存储锁结构而申请的内存大小(咱们能够忽略),其中有2个行锁的结构
    LOCK WAIT 3 lock struct(s), heap size 1160, 2 row lock(s)
    
    # 本事务所在线程的id是2(MySQL本身命名的线程id),该线程在操做系统级别的id就是那一长串数字,当前查询的id为46(MySQL内部使用,能够忽略),还有用户名主机信息
    MySQL thread id 2, OS thread handle 123145412648960, query id 46 localhost 127.0.0.1 root statistics
    
    # 本事务发生阻塞的语句
    select * from hero where id = 3 for update
    
    # 本事务当前在等待获取的锁:
    *** (1) WAITING FOR THIS LOCK TO BE GRANTED:
    
    # 等待获取的表空间ID为151,页号为3,也就是表hero的PRIMAY索引中的某条记录的锁(n_bits是为了存储本页面的锁信息而分配的一串内存空间,小册中有详细介绍),该锁的类型是X型正经记录锁(rec but not gap)
    RECORD LOCKS space id 171 page no 3 n bits 72 index PRIMARY of table `dahaizi`.`hero` trx id 30477 lock_mode X locks rec but not gap waiting
    
    # 该记录在页面中的heap_no为2,具体的记录信息以下:
    Record lock, heap no 3 PHYSICAL RECORD: n_fields 5; compact format; info bits 0
    
    # 这是主键值
    0: len 4; hex 80000003; asc     ;;
    
    # 这是trx_id隐藏列
    1: len 6; hex 000000007517; asc     u ;;
    
    # 这是roll_pointer隐藏列
    2: len 7; hex 80000001d0011d; asc        ;;
    
    # 这是name列
    3: len 10; hex 7ae8afb8e8919be4baae; asc z         ;;
    
    # 这是country列
    4: len 3; hex e89c80; asc    ;;
    复制代码

    从这个信息中能够看出,Session A中的事务为2条记录生成了锁结构,可是其中有一条记录上的X型正经记录锁(rec but not gap)并无获取到,没有获取到锁的这条记录的位置是:表空间ID为151,页号为3,heap_no为2。固然,设计InnoDB的大叔还贴心的给出了这条记录的详细状况,它的主键值为80000003,这实际上是InnoDB内部存储使用的格式,其实就表明数字3,也就是该事务在等待获取hero表聚簇索引主键值为3的那条记录的X型正经记录锁。

  • 而后是关于死锁发生时第二个事务的有关信息:

    其中的大部分信息咱们都已经介绍过了,咱们就挑重要的说:

    *** (2) TRANSACTION:
    TRANSACTION 30478, ACTIVE 8 sec starting index read
    mysql tables in use 1, locked 1
    3 lock struct(s), heap size 1160, 2 row lock(s)
    MySQL thread id 3, OS thread handle 123145412927488, query id 47 localhost 127.0.0.1 root statistics
    select * from hero where id = 1 for update
    
    # 表示该事务获取到的锁信息
    *** (2) HOLDS THE LOCK(S):
    RECORD LOCKS space id 171 page no 3 n bits 72 index PRIMARY of table `dahaizi`.`hero` trx id 30478 lock_mode X locks rec but not gap
    Record lock, heap no 3 PHYSICAL RECORD: n_fields 5; compact format; info bits 0
    
    # 主键值为3
    0: len 4; hex 80000003; asc     ;;
    1: len 6; hex 000000007517; asc     u ;;
    2: len 7; hex 80000001d0011d; asc        ;;
    3: len 10; hex 7ae8afb8e8919be4baae; asc z         ;;
    4: len 3; hex e89c80; asc    ;;
    
    # 表示该事务等待获取的锁信息
    *** (2) WAITING FOR THIS LOCK TO BE GRANTED:
    RECORD LOCKS space id 171 page no 3 n bits 72 index PRIMARY of table `dahaizi`.`hero` trx id 30478 lock_mode X locks rec but not gap waiting
    Record lock, heap no 2 PHYSICAL RECORD: n_fields 5; compact format; info bits 0
    
    # 主键值为1
    0: len 4; hex 80000001; asc     ;;
    1: len 6; hex 000000007517; asc     u ;;
    2: len 7; hex 80000001d00110; asc        ;;
    3: len 7; hex 6ce58898e5a487; asc l      ;;
    4: len 3; hex e89c80; asc    ;;
    复制代码

    从上边的输出能够看出来,Session B中的事务获取了hero表聚簇索引主键值为3的记录的X型正经记录锁,等待获取hero表聚簇索引主键值为1的记录的X型正经记录锁(隐含的意思就是这个hero表聚簇索引主键值为1的记录的X型正经记录锁已经被SESSION A中的事务获取到了)。

  • 看最后一部分:

    *** WE ROLL BACK TRANSACTION (2)
    复制代码

    最终InnoDB存储引擎决定回滚第2个事务,也就是Session B中的那个事务。

死锁分析的思路

  1. 查看死锁日志时,首先看一下发生死锁的事务等待获取锁的语句都是啥。

    本例中,发现SESSION A发生阻塞的语句是:

    select * from hero where id = 3 for update
    复制代码

    SESSION B发生阻塞的语句是:

    select * from hero where id = 1 for update
    复制代码

    而后切记:到本身的业务代码中找出这两条语句所在事务的其余语句

  2. 找到发生死锁的事务中全部的语句以后,对照着事务获取到的锁和正在等待的锁的信息来分析死锁发生过程。

    从死锁日志中能够看出来,SESSION A获取了hero表聚簇索引id值为1的记录的X型正经记录锁(这实际上是从SESSION B正在等待的锁中获取的),查看SESSION A中的语句,发现是下边这个语句形成的(对照着语句加锁分析那三篇文章):

    select * from hero where id = 1 for update;
    复制代码

    还有SESSION B获取了hero表聚簇索引id值为3的记录的X型正经记录锁,查看SESSION B中的语句,发现是下边这个语句形成的(对照着语句加锁分析那三篇文章):

    select * from hero where id = 3 for update;
    复制代码

    而后看SESSION A正在等待hero表聚簇索引id值为3的记录的X型正经记录锁,这个是因为下边这个语句形成的:

    select * from hero where id = 3 for update;
    复制代码

    而后看SESSION B正在等待hero表聚簇索引id值为1的记录的X型正经记录锁,这个是因为下边这个语句形成的:

    select * from hero where id = 1 for update;
    复制代码

    而后整个死锁造成过程就根据死锁日志给还原出来了。

题外话

写文章挺累的,有时候你以为阅读挺流畅的,那实际上是背后无数次修改的结果。若是你以为不错请帮忙转发一下,万分感谢~ 这里是个人公众号「咱们都是小青蛙」,里边有更多技术干货,时不时扯一下犊子,欢迎关注:

相关文章
相关标签/搜索