Mysql死锁分析案例（一）

概况

小编在工作中偶遇Deadlock的问题,这个对程序员而言是可怕,尤其是对一个从没有遇到过这个问题的小编来说真的是瑟瑟发抖,不过问题总的解决,所以还是要一步步分析一步步排查,这就是成长,哈哈。

问题

为了能脱离小编所在业务，并能完整的描述问题。小编模拟了得问题如下:

Mysql 版本为8.0

-- 创建表结构
CREATE TABLE t(
    `id` int NOT NULL AUTO_INCREMENT,
    `s_id` int(11) NOT NULL COMMENT 'student_id 学生Id',
    `name` varchar(40) COLLATE utf8_bin DEFAULT NULL COMMENT '姓名',
  PRIMARY KEY (`id`),
  KEY `idx_s_id` (`s_id`)
) ENGINE=InnoDB AUTO_INCREMENT=1 DEFAULT CHARSET=utf8 COLLATE=utf8_bin ;

-- 初始化数据
INSERT INTO t(s_id,name)  VALUES(1,'name1'),(2,'name2'),(3,'name3'),(4,'name4'),(5,'name5'),(6,'name6'),(7,'name7'),(8,'name8'),(9,'name9'),(10,'name10');
session1 session2
start transaction -
update t set name=‘cName11‘ where s_id=11； ## ==s_id=11不存在== start transaction
- update t set name=‘cName12‘ where s_id=12； ## s_id=12不存在
INSERT INTO t(s_id,name) VALUES(11,‘name11‘) ## ==waitting -
- INSERT INTO t(s_id,name) VALUES(12,‘name12‘)
- ERROR 1213 (40001): Deadlock found when trying to get lock; try restarting transaction

好了，进过上述步骤之后，出现了可怕的Deadlock,我看使用命令查看 SHOW ENGINE InnoDB status \G;

mysql> SHOW ENGINE InnoDB status \G;
*************************** 1. row ***************************
  Type: InnoDB
  Name:
Status:
=====================================
2019-07-29 10:59:40 0x7f47a0117700 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 16 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 57 srv_active, 0 srv_shutdown, 27956 srv_idle
srv_master_thread log flush and writes: 0
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 58
OS WAIT ARRAY INFO: signal count 63
RW-shared spins 19, rounds 30, OS waits 11
RW-excl spins 13, rounds 51, OS waits 0
RW-sx spins 1, rounds 1, OS waits 0
Spin rounds per wait: 1.58 RW-shared, 3.92 RW-excl, 1.00 RW-sx
------------------------
LATEST DETECTED DEADLOCK
------------------------
2019-07-29 10:56:58 0x7f47a0117700
*** (1) TRANSACTION:
TRANSACTION 98735, ACTIVE 28 sec inserting
mysql tables in use 1, locked 1
LOCK WAIT 3 lock struct(s), heap size 1136, 2 row lock(s), undo log entries 1
MySQL thread id 9, OS thread handle 139945604609792, query id 1491 localhost root update
INSERT INTO t(s_id,name) VALUES(11,'name11')
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 136 page no 5 n bits 80 index idx_s_id of table `jackpot1`.`t` trx id 98735 lock_mode X insert intention waiting
Record lock, heap no 1 PHYSICAL RECORD: n_fields 1; compact format; info bits 0
 0: len 8; hex 73757072656d756d; asc supremum;;

*** (2) TRANSACTION:
TRANSACTION 98734, ACTIVE 40 sec inserting
mysql tables in use 1, locked 1
3 lock struct(s), heap size 1136, 2 row lock(s), undo log entries 1
MySQL thread id 8, OS thread handle 139945604904704, query id 1492 localhost root update
INSERT INTO t(s_id,name) VALUES(12,'name12')
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 136 page no 5 n bits 80 index idx_s_id of table `jackpot1`.`t` trx id 98734 lock_mode X
Record lock, heap no 1 PHYSICAL RECORD: n_fields 1; compact format; info bits 0
 0: len 8; hex 73757072656d756d; asc supremum;;

*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 136 page no 5 n bits 80 index idx_s_id of table `jackpot1`.`t` trx id 98734 lock_mode X insert intention waiting
Record lock, heap no 1 PHYSICAL RECORD: n_fields 1; compact format; info bits 0
 0: len 8; hex 73757072656d756d; asc supremum;;

*** WE ROLL BACK TRANSACTION (2)
------------
TRANSACTIONS
------------
Trx id counter 98736
Purge done for trx's n:o < 98721 undo n:o < 15 state: running but idle
History list length 74
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 421420599174496, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421420599173592, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421420599172688, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421420599170880, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 98735, ACTIVE 190 sec
4 lock struct(s), heap size 1136, 3 row lock(s), undo log entries 1
MySQL thread id 9, OS thread handle 139945604609792, query id 1491 localhost root
TABLE LOCK table `jackpot1`.`t` trx id 98735 lock mode IX
RECORD LOCKS space id 136 page no 5 n bits 80 index idx_s_id of table `jackpot1`.`t` trx id 98735 lock_mode X
Record lock, heap no 1 PHYSICAL RECORD: n_fields 1; compact format; info bits 0
 0: len 8; hex 73757072656d756d; asc supremum;;

RECORD LOCKS space id 136 page no 5 n bits 80 index idx_s_id of table `jackpot1`.`t` trx id 98735 lock_mode X insert intention
Record lock, heap no 1 PHYSICAL RECORD: n_fields 1; compact format; info bits 0
 0: len 8; hex 73757072656d756d; asc supremum;;

RECORD LOCKS space id 136 page no 5 n bits 80 index idx_s_id of table `jackpot1`.`t` trx id 98735 lock_mode X locks gap before rec
Record lock, heap no 12 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
 0: len 4; hex 8000000b; asc     ;;
 1: len 4; hex 8000000b; asc     ;;

--------
FILE I/O
--------
I/O thread 0 state: waiting for completed aio requests (insert buffer thread)
I/O thread 1 state: waiting for completed aio requests (log thread)
I/O thread 2 state: waiting for completed aio requests (read thread)
I/O thread 3 state: waiting for completed aio requests (read thread)
I/O thread 4 state: waiting for completed aio requests (read thread)
I/O thread 5 state: waiting for completed aio requests (read thread)
I/O thread 6 state: waiting for completed aio requests (write thread)
I/O thread 7 state: waiting for completed aio requests (write thread)
I/O thread 8 state: waiting for completed aio requests (write thread)
I/O thread 9 state: waiting for completed aio requests (write thread)
Pending normal aio reads: [0, 0, 0, 0] , aio writes: [0, 0, 0, 0] ,
 ibuf aio reads:, log i/o's:, sync i/o's:
Pending flushes (fsync) log: 0; buffer pool: 0
18651 OS file reads, 1447 OS file writes, 760 OS fsyncs
0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 105, seg size 107, 2 merges
merged operations:
 insert 18, delete mark 0, delete 0
discarded operations:
 insert 0, delete mark 0, delete 0
Hash table size 34679, node heap has 2 buffer(s)
Hash table size 34679, node heap has 2 buffer(s)
Hash table size 34679, node heap has 0 buffer(s)
Hash table size 34679, node heap has 0 buffer(s)
Hash table size 34679, node heap has 1 buffer(s)
Hash table size 34679, node heap has 0 buffer(s)
Hash table size 34679, node heap has 2 buffer(s)
Hash table size 34679, node heap has 5 buffer(s)
0.00 hash searches/s, 0.00 non-hash searches/s
---
LOG
---
Log sequence number          1130751648
Log buffer assigned up to    1130751648
Log buffer completed up to   1130751648
Log written up to            1130751648
Log flushed up to            1130751648
Added dirty pages up to      1130751648
Pages flushed up to          1130751648
Last checkpoint at           1130751648
427 log i/o's done, 0.00 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total large memory allocated 137363456
Dictionary memory allocated 597484
Buffer pool size   8192
Free buffers       1024
Database pages     7156
Old database pages 2621
Modified db pages  0
Pending reads      0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 21371, not young 75108
0.00 youngs/s, 0.00 non-youngs/s
Pages read 18577, created 194, written 796
0.00 reads/s, 0.00 creates/s, 0.00 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 7156, unzip_LRU len: 0
I/O sum[0]:cur[0], unzip sum[0]:cur[0]
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
0 read views open inside InnoDB
Process ID=1, Main thread ID=139945114007296 , state=sleeping
Number of rows inserted 226, updated 459, deleted 71, read 7457495
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================

1 row in set (0.00 sec)

ERROR:
No query specified

我们从关键字LATEST DETECTED DEADLOCK开始看发现

  • (1) TRANSACTION: (1) WAITING FOR THIS LOCK TO BE GRANTED
  • (2) TRANSACTION: (2) HOLDS THE LOCK(S): (2) WAITING FOR THIS LOCK TO BE GRANTED:
    可以看出是在执行INSERT语句的时候发生Deadlock的，但还是无法确定为什么出现问题，这时我们表performance_schema.data_locks通过查看
-- 第一次执行INSERT时执行，打印lock的情况
mysql> SELECT `ENGINE`,THREAD_ID,EVENT_ID,OBJECT_SCHEMA,OBJECT_NAME,INDEX_NAME,OBJECT_INSTANCE_BEGIN,LOCK_TYPE,LOCK_MODE,LOCK_STATUS,LOCK_DATA FROM performance_schema.data_locks ;
+--------+-----------+----------+---------------+-------------+------------+-----------------------+-----------+-----------+-------------+------------------------+
| ENGINE | THREAD_ID | EVENT_ID | OBJECT_SCHEMA | OBJECT_NAME | INDEX_NAME | OBJECT_INSTANCE_BEGIN | LOCK_TYPE | LOCK_MODE | LOCK_STATUS | LOCK_DATA              |
+--------+-----------+----------+---------------+-------------+------------+-----------------------+-----------+-----------+-------------+------------------------+
| INNODB |        48 |      119 | jackpot1      | t           | NULL       |       139945536711608 | TABLE     | IX        | GRANTED     | NULL                   |
| INNODB |        48 |      119 | jackpot1      | t           | idx_s_id   |       139945536708664 | RECORD    | X         | GRANTED     | supremum pseudo-record |
| INNODB |        47 |      150 | jackpot1      | t           | NULL       |       139945536705784 | TABLE     | IX        | GRANTED     | NULL                   |
| INNODB |        47 |      150 | jackpot1      | t           | idx_s_id   |       139945536702744 | RECORD    | X         | GRANTED     | supremum pseudo-record |
| INNODB |        47 |      151 | jackpot1      | t           | PRIMARY    |       139945536703776 | RECORD    | X         | GRANTED     | supremum pseudo-record |
+--------+-----------+----------+---------------+-------------+------------+-----------------------+-----------+-----------+-------------+------------------------+
5 rows in set (0.00 sec)

-- 第二次执行INSERT时执行，打印lock的情况
mysql> SELECT `ENGINE`,THREAD_ID,EVENT_ID,OBJECT_SCHEMA,OBJECT_NAME,INDEX_NAME,OBJECT_INSTANCE_BEGIN,LOCK_TYPE,LOCK_MODE,LOCK_STATUS,LOCK_DATA FROM performance_schema.data_locks ;
+--------+-----------+----------+---------------+-------------+------------+-----------------------+-----------+--------------------+-------------+------------------------+
| ENGINE | THREAD_ID | EVENT_ID | OBJECT_SCHEMA | OBJECT_NAME | INDEX_NAME | OBJECT_INSTANCE_BEGIN | LOCK_TYPE | LOCK_MODE          | LOCK_STATUS | LOCK_DATA              |
+--------+-----------+----------+---------------+-------------+------------+-----------------------+-----------+--------------------+-------------+------------------------+
| INNODB |        47 |      150 | jackpot1      | t           | NULL       |       139945536705784 | TABLE     | IX                 | GRANTED     | NULL                   |
| INNODB |        47 |      150 | jackpot1      | t           | idx_s_id   |       139945536702744 | RECORD    | X                  | GRANTED     | supremum pseudo-record |
| INNODB |        47 |      151 | jackpot1      | t           | PRIMARY    |       139945536703776 | RECORD    | X                  | GRANTED     | supremum pseudo-record |
| INNODB |        47 |      152 | jackpot1      | t           | PRIMARY    |       139945536704120 | RECORD    | X,GAP              | GRANTED     | 14                     |
| INNODB |        47 |      152 | jackpot1      | t           | idx_s_id   |       139945536704464 | RECORD    | X,INSERT_INTENTION | GRANTED     | supremum pseudo-record |
| INNODB |        47 |      152 | jackpot1      | t           | idx_s_id   |       139945536704808 | RECORD    | X,GAP              | GRANTED     | 12, 14                 |
+--------+-----------+----------+---------------+-------------+------------+-----------------------+-----------+--------------------+-------------+------------------------+
6 rows in set (0.00 sec)
  • 分析第一次执行

    我们发现EVENT_ID为119和150为执行update产生的先是表级别执行IX Lock，然后行级别执行Next-Key Lock，这里的字段LOCK_DATA内容supremum pseudo-record很重要，我通过在Mysql官方文档上查询得意思为

For the last interval, the next-key lock locks the gap above the largest
value in the index and the “supremum” pseudo-record having a value higher
than any value actually in the index. The supremum is not a real index
record, so, in effect, this next-key lock locks only the gap following the
largest index value.

我们google翻译一下

对于最后一个间隔，下一个键锁定将间隙锁定在索引中最大值之上，而“ supremum ”
伪记录的值高于索引中实际的任何值。supremum不是真正的索引记录，因此，实际上，
此下一键锁定仅锁定最大索引值之后的间隙。

就是说supremun是伪记录的值高于索引中实际任何值，说白了就是，在最大索引值的屁股后面，这个性质也就是Next-Key Lock
根据Next-Key Locks的定义如下

A next-key lock is a combination of a record lock on the index record and a gap lock on the gap before the index record.

InnoDB performs row-level locking in such a way that when it searches or scans a table index, it sets shared or exclusive locks on the index records it encounters. Thus, the row-level locks are actually index-record locks. A next-key lock on an index record also affects the “gap” before that index record. That is, a next-key lock is an index-record lock plus a gap lock on the gap preceding the index record. If one session has a shared or exclusive lock on record R in an index, another session cannot insert a new index record in the gap immediately before R in the index order.

这里有句注意了，我们要划重点，因为后面的分析需要用到
If one session has a shared or exclusive lock on record R in an index, another session cannot insert a new index record in the gap immediately before R in the index order.
意思就是

如果一个会话R在索引中具有共享或独占锁定记录 ，则另一个会话不能R在索引顺序之前的间隙中插入新索引记录 。

至此我们也就明白为什么第一条INSERT为什么会处于等待状态了，因为INSERT的时候需要等待Session2 update X锁的释放；若等待太久则Mysql会有自我保护功能提示超时放弃ERROR 1213 (40001): Deadlock found when trying to get lock; try restarting transaction

  • 分析第二次执行
    我们发现执行第二次INSERT就直接Deadlock,这里我们也就明白为什么了吧，因为Session1 INSERT 等待Session2 update的X锁释放，而Session2 INSERT 等待Session1 update的X锁释放，这就构成了典型的死锁。而Mysql会有ROLLBACK机制，任意回滚其中一个Session，也就意味着释放了其中的一个update hold X锁，让另一个Session成功执行完毕。

哦还有，这里 EVENT_ID 152的记录中LOCK_DATA字段内容12, 14又是什么意思呢？
答：非唯一索引对应的唯一索引值是GAP锁的特征Mysql官方文档可查，即12表示s_id,14表示id，

好了讲到这里这一次的Deadlock问题已经被解决了，我们来总结一下吧。

  • 1 遇到问题需要结合搜索引擎和经验一步步分析，耐心不要放弃。
  • 2 在平时的项目中尽量不要update不存在的记录

原文地址：https://www.cnblogs.com/chenshouchang/p/11266138.html

时间： 2024-11-09 01:43:50

Mysql死锁分析案例（一）的相关文章

一个最不可思议的MySQL死锁分析

一个最不可思议的MySQL死锁分析 死锁问题背景 做MySQL代码的深入分析也有些年头了,再加上自己10年左右的数据库内核研发经验,自认为对于MySQL/InnoDB的加锁实现了如指掌,正因如此,前段时间,还专门写了一篇洋洋洒洒的文章,专门分析MySQL的加锁实现细节:<MySQL加锁处理分析>. 但是,昨天"润洁"同学在<MySQL加锁处理分析>这篇博文下咨询的一个MySQL的死锁场景,还是彻底把我给难住了.此死锁,完全违背了本人原有的锁知识体系,让我百思不得

&lt;转&gt;一个最不可思议的MySQL死锁分析

1 死锁问题背景 1 1.1 一个不可思议的死锁 1 1.1.1 初步分析 3 1.2 如何阅读死锁日志 3 2 死锁原因深入剖析 4 2.1 Delete操作的加锁逻辑 4 2.2 死锁预防策略 5 2.3 剖析死锁的成因 6 3 总结 7 死锁问题背景 做MySQL代码的深入分析也有些年头了,再加上自己10年左右的数据库内核研发经验,自认为对于MySQL/InnoDB的加锁实现了如指掌,正因如此,前段时间,还专门写了一篇洋洋洒洒的文章,专门分析MySQL的加锁实现细节:<MySQL加锁处理分

MySQL死锁分析

1. 测试描述 环境说明:RHEL 6.4 x86_64 + MySQL 5.5.37,事务隔离级别为RC 测试表: mysql> show create table t1\G *************************** 1. row *************************** Table: t1 Create Table: CREATE TABLE `t1` ( `a` int(11) NOT NULL DEFAULT '0', `b` int(11) DEFAULT

Mysql 死锁问题

Innodb锁系统(4) Insert/Delete 锁处理及死锁示例分析 http://mysqllover.com/?p=431 关于innodb死锁 http://afei2.sinaapp.com/?p=172 一个最不可思议的MySQL死锁分析 http://hedengcheng.com/?p=844#_Toc378337496 Mysql 死锁问题

MySQL死锁案例分析与解决方案

现象: 数据库查询: SQL语句分析: mysql. 并发delete同一行记录,偶发死锁. delete from x_table where id=? 死锁分析: mysql的事务支持与存储引擎有关,MyISAM不支持事务,INNODB支持事务,更新时采用的是行级锁.这里采用的是INNODB做存储引擎,意味着会将update语句做为一个事务来处理.前面提到行级锁必须建立在索引的基础,这条更新语句用到了索引idx_1,所以这里肯定会加上行级锁. 行级锁并不是直接锁记录,而是锁索引,如果一条SQ

mysql 死锁案例及分析过程

我将分别从以下几个方面进行讲解mysql 死锁 的每一个案例,希望能够对你们有帮忙及启发 满足死锁的条件 原文地址:https://www.cnblogs.com/Shock-W/p/9349705.html

MySQL死锁问题实例分析及解决方法

MySQL死锁问题的相关知识是本文我们主要要介绍的内容,接下来我们就来一一介绍这部分内容,希望能够对您有所帮助. 1.MySQL常用存储引擎的锁机制 MyISAM和MEMORY采用表级锁(table-level locking) BDB采用页面锁(page-level locking)或表级锁,默认为页面锁 InnoDB支持行级锁(row-level locking)和表级锁,默认为行级锁 2.各种锁特点 表级锁:开销小,加锁快;不会出现死锁;锁定粒度大,发生锁冲突的概率最高,并发度最低 行级锁

Mysql死锁如何排查：insert on duplicate死锁一次排查分析过程

前言 遇到Mysql死锁问题,我们应该怎么排查分析呢?之前线上出现一个insert on duplicate死锁问题,本文将基于这个死锁问题,分享排查分析过程,希望对大家有帮助. 死锁案发还原 表结构: CREATE TABLE `song_rank` ( `id` int(11) NOT NULL AUTO_INCREMENT, `songId` int(11) NOT NULL, `weight` int(11) NOT NULL DEFAULT '0', PRIMARY KEY (`id`

MySQL死锁[转]

案例描述       在定时脚本运行过程中,发现当备份表格的sql语句与删除该表部分数据的sql语句同时运行时,mysql会检测出死锁,并打印出日志. 两个sql语句如下:       (1)insert into backup_table select * from source_table      (2)DELETE FROM source_table WHERE Id>5 AND titleWeight<32768 AND joinTime<'$daysago_1week'