前言
如果我們的業(yè)務(wù)處在一個(gè)非常初級(jí)的階段,并發(fā)程度比較低,那么我們可以幾年都遇不到一次死鎖問(wèn)題的發(fā)生,反之,我們業(yè)務(wù)的并發(fā)程度非常高,那么時(shí)不時(shí)爆出的死鎖問(wèn)題肯定讓我們非常撓頭。不過(guò)在死鎖問(wèn)題發(fā)生時(shí),很多沒(méi)有經(jīng)驗(yàn)的同學(xué)的第一反應(yīng)就是成為一只鴕鳥(niǎo):這玩意兒很高深,我也看不懂,聽(tīng)天由命吧,又不是一直發(fā)生。其實(shí)如果大家認(rèn)真研讀了我們之前寫(xiě)的3篇關(guān)于MySQL中語(yǔ)句加鎖分析的文章,加上本篇關(guān)于死鎖日志的分析,那么解決死鎖問(wèn)題應(yīng)該也不是那么摸不著頭腦的事情了。
準(zhǔn)備工作
為了故事的順利發(fā)展,我們需要建一個(gè)表:
CREATE TABLE hero (
id INT,
name VARCHAR(100),
country varchar(100),
PRIMARY KEY (id),
KEY idx_name (name)
) Engine=InnoDB CHARSET=utf8;
我們?yōu)閔ero表的id列創(chuàng)建了聚簇索引,為name列創(chuàng)建了一個(gè)二級(jí)索引。這個(gè)hero表主要是為了存儲(chǔ)三國(guó)時(shí)的一些英雄,我們向表中插入一些記錄:
INSERT INTO hero VALUES
(1, 'l劉備', '蜀'),
(3, 'z諸葛亮', '蜀'),
(8, 'c曹操', '魏'),
(15, 'x荀彧', '魏'),
(20, 's孫權(quán)', '吳');
現(xiàn)在表中的數(shù)據(jù)就是這樣的:
mysql> SELECT * FROM hero;
+----+------------+---------+
| id | name | country |
+----+------------+---------+
| 1 | l劉備 | 蜀 |
| 3 | z諸葛亮 | 蜀 |
| 8 | c曹操 | 魏 |
| 15 | x荀彧 | 魏 |
| 20 | s孫權(quán) | 吳 |
+----+------------+---------+
5 rows in set (0.00 sec)
準(zhǔn)備工作就做完了。
創(chuàng)建死鎖情景
我們先創(chuàng)建一個(gè)發(fā)生死鎖的情景,在Session A和Session B中分別執(zhí)行兩個(gè)事務(wù),具體情況如下:
我們分析一下:
- 從第③步中可以看出,Session A中的事務(wù)先對(duì)hero表聚簇索引的id值為1的記錄加了一個(gè)X型正經(jīng)記錄鎖。
- 從第④步中可以看出,Session B中的事務(wù)對(duì)hero表聚簇索引的id值為3的記錄加了一個(gè)X型正經(jīng)記錄鎖。
- 從第⑤步中可以看出,Session A中的事務(wù)接著想對(duì)hero表聚簇索引的id值為3的記錄也加了一個(gè)X型正經(jīng)記錄鎖,但是與第④步中Session B中的事務(wù)加的鎖沖突,所以Session A進(jìn)入阻塞狀態(tài),等待獲取鎖。
- 從第⑥步中可以看出,Session B中的事務(wù)想對(duì)hero表聚簇索引的id值為1的記錄加了一個(gè)X型正經(jīng)記錄鎖,但是與第③步中Session A中的事務(wù)加的鎖沖突,而此時(shí)Session A和Session B中的事務(wù)循環(huán)等待對(duì)方持有的鎖,死鎖發(fā)生,被MySQL服務(wù)器的死鎖檢測(cè)機(jī)制檢測(cè)到了,所以選擇了一個(gè)事務(wù)進(jìn)行回滾,并向客戶端發(fā)送一條消息:
ERROR 1213 (40001): Deadlock found when trying to get lock; try restarting transaction
以上是我們從語(yǔ)句加了什么鎖的角度出發(fā)來(lái)進(jìn)行死鎖情況分析的,但是實(shí)際應(yīng)用中我們可能壓根兒不知道到底是哪幾條語(yǔ)句產(chǎn)生了死鎖,我們需要根據(jù)MySQL在死鎖發(fā)生時(shí)產(chǎn)生的死鎖日志來(lái)逆向定位一下到底是什么語(yǔ)句產(chǎn)生了死鎖,從而再優(yōu)化我們的業(yè)務(wù)。
查看死鎖日志
設(shè)計(jì)InnoDB的大叔給我們提供了SHOW ENGINE INNODB STATUS命令來(lái)查看關(guān)于InnoDB存儲(chǔ)引擎的一些狀態(tài)信息,其中就包括了系統(tǒng)最近一次發(fā)生死鎖時(shí)的加鎖情況。在上邊例子中的死鎖發(fā)生時(shí),我們運(yùn)行一下這個(gè)命令:
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)
------------
...省略了好多其他信息
我們只關(guān)心最近發(fā)生的死鎖信息,所以就把以LATEST DETECTED DEADLOCK這一部分給單獨(dú)提出來(lái)分析一下。下邊我們就逐行看一下這個(gè)輸出的死鎖日志都是什么意思:
首先看第一句:
2019-06-20 13:39:19 0x70000697e000
這句話的意思就是死鎖發(fā)生的時(shí)間是:2019-06-20 13:39:19,后邊的一串十六進(jìn)制0x70000697e000表示的操作系統(tǒng)為當(dāng)前session分配的線程的線程id。
然后是關(guān)于死鎖發(fā)生時(shí)第一個(gè)事務(wù)的有關(guān)信息:
*** (1) TRANSACTION:
# 為事務(wù)分配的id為30477,事務(wù)處于ACTIVE狀態(tài)已經(jīng)10秒了,事務(wù)現(xiàn)在正在做的操作就是:“starting index read”
TRANSACTION 30477, ACTIVE 10 sec starting index read
# 此事務(wù)使用了1個(gè)表,為1個(gè)表上了鎖(此處不是說(shuō)為該表加了表鎖,只要不是進(jìn)行一致性讀的表,都需要加鎖,具體怎么加鎖請(qǐng)看加鎖語(yǔ)句分析或者小冊(cè)章節(jié))
mysql tables in use 1, locked 1
# 此事務(wù)處于LOCK WAIT狀態(tài),擁有3個(gè)鎖結(jié)構(gòu)(2個(gè)行鎖結(jié)構(gòu),1個(gè)表級(jí)別X型意向鎖結(jié)構(gòu),鎖結(jié)構(gòu)在小冊(cè)中重點(diǎn)介紹過(guò)),heap size是為了存儲(chǔ)鎖結(jié)構(gòu)而申請(qǐng)的內(nèi)存大?。ㄎ覀兛梢院雎裕?,其中有2個(gè)行鎖的結(jié)構(gòu)
LOCK WAIT 3 lock struct(s), heap size 1160, 2 row lock(s)
# 本事務(wù)所在線程的id是2(MySQL自己命名的線程id),該線程在操作系統(tǒng)級(jí)別的id就是那一長(zhǎng)串?dāng)?shù)字,當(dāng)前查詢(xún)的id為46(MySQL內(nèi)部使用,可以忽略),還有用戶名主機(jī)信息
MySQL thread id 2, OS thread handle 123145412648960, query id 46 localhost 127.0.0.1 root statistics
# 本事務(wù)發(fā)生阻塞的語(yǔ)句
select * from hero where id = 3 for update
# 本事務(wù)當(dāng)前在等待獲取的鎖:
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
# 等待獲取的表空間ID為151,頁(yè)號(hào)為3,也就是表hero的PRIMAY索引中的某條記錄的鎖(n_bits是為了存儲(chǔ)本頁(yè)面的鎖信息而分配的一串內(nèi)存空間,小冊(cè)中有詳細(xì)介紹),該鎖的類(lèi)型是X型正經(jīng)記錄鎖(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
# 該記錄在頁(yè)面中的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 ;;
從這個(gè)信息中可以看出,Session A中的事務(wù)為2條記錄生成了鎖結(jié)構(gòu),但是其中有一條記錄上的X型正經(jīng)記錄鎖(rec but not gap)并沒(méi)有獲取到,沒(méi)有獲取到鎖的這條記錄的位置是:表空間ID為151,頁(yè)號(hào)為3,heap_no為2。當(dāng)然,設(shè)計(jì)InnoDB的大叔還貼心的給出了這條記錄的詳細(xì)情況,它的主鍵值為80000003,這其實(shí)是InnoDB內(nèi)部存儲(chǔ)使用的格式,其實(shí)就代表數(shù)字3,也就是該事務(wù)在等待獲取hero表聚簇索引主鍵值為3的那條記錄的X型正經(jīng)記錄鎖。
然后是關(guān)于死鎖發(fā)生時(shí)第二個(gè)事務(wù)的有關(guān)信息:
其中的大部分信息我們都已經(jīng)介紹過(guò)了,我們就挑重要的說(shuō):
*** (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
# 表示該事務(wù)獲取到的鎖信息
*** (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 ;;
# 表示該事務(wù)等待獲取的鎖信息
*** (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 ;;
從上邊的輸出可以看出來(lái),Session B中的事務(wù)獲取了hero表聚簇索引主鍵值為3的記錄的X型正經(jīng)記錄鎖,等待獲取hero表聚簇索引主鍵值為1的記錄的X型正經(jīng)記錄鎖(隱含的意思就是這個(gè)hero表聚簇索引主鍵值為1的記錄的X型正經(jīng)記錄鎖已經(jīng)被SESSION A中的事務(wù)獲取到了)。
看最后一部分:
*** WE ROLL BACK TRANSACTION (2)
最終InnoDB存儲(chǔ)引擎決定回滾第2個(gè)事務(wù),也就是Session B中的那個(gè)事務(wù)。
死鎖分析的思路
1、查看死鎖日志時(shí),首先看一下發(fā)生死鎖的事務(wù)等待獲取鎖的語(yǔ)句都是啥。
本例中,發(fā)現(xiàn)SESSION A發(fā)生阻塞的語(yǔ)句是:
select * from hero where id = 3 for update
SESSION B發(fā)生阻塞的語(yǔ)句是:
select * from hero where id = 1 for update
然后切記:到自己的業(yè)務(wù)代碼中找出這兩條語(yǔ)句所在事務(wù)的其他語(yǔ)句。
2、找到發(fā)生死鎖的事務(wù)中所有的語(yǔ)句之后,對(duì)照著事務(wù)獲取到的鎖和正在等待的鎖的信息來(lái)分析死鎖發(fā)生過(guò)程。
從死鎖日志中可以看出來(lái),SESSION A獲取了hero表聚簇索引id值為1的記錄的X型正經(jīng)記錄鎖(這其實(shí)是從SESSION B正在等待的鎖中獲取的),查看SESSION A中的語(yǔ)句,發(fā)現(xiàn)是下邊這個(gè)語(yǔ)句造成的(對(duì)照著語(yǔ)句加鎖分析那三篇文章):
select * from hero where id = 1 for update;
還有SESSION B獲取了hero表聚簇索引id值為3的記錄的X型正經(jīng)記錄鎖,查看SESSION B中的語(yǔ)句,發(fā)現(xiàn)是下邊這個(gè)語(yǔ)句造成的(對(duì)照著語(yǔ)句加鎖分析那三篇文章):
select * from hero where id = 3 for update;
然后看SESSION A正在等待hero表聚簇索引id值為3的記錄的X型正經(jīng)記錄鎖,這個(gè)是由于下邊這個(gè)語(yǔ)句造成的:
select * from hero where id = 3 for update;
然后看SESSION B正在等待hero表聚簇索引id值為1的記錄的X型正經(jīng)記錄鎖,這個(gè)是由于下邊這個(gè)語(yǔ)句造成的:
select * from hero where id = 1 for update;
然后整個(gè)死鎖形成過(guò)程就根據(jù)死鎖日志給還原出來(lái)了。
總結(jié)
以上就是這篇文章的全部?jī)?nèi)容了,希望本文的內(nèi)容對(duì)大家的學(xué)習(xí)或者工作具有一定的參考學(xué)習(xí)價(jià)值,謝謝大家對(duì)腳本之家的支持。
您可能感興趣的文章:- Mysql查看死鎖與解除死鎖的深入講解
- MySQL死鎖檢查處理的正常方法
- MySQL死鎖的產(chǎn)生原因以及解決方案
- MySQL死鎖套路之唯一索引下批量插入順序不一致
- 一個(gè)mysql死鎖場(chǎng)景實(shí)例分析
- 一次神奇的MySQL死鎖排查記錄
- MySQL數(shù)據(jù)庫(kù)之Purge死鎖問(wèn)題解析
- 詳解通過(guò)SQL進(jìn)行分布式死鎖的檢測(cè)與消除