MySQL死鎖問題如何分析

時間  2019-11-06
標籤 mysql 死鎖 問題 如何 分析 欄目 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 A和Session 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 A和Session 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;
複製代碼

    而後整個死鎖造成過程就根據死鎖日誌給還原出來了。

題外話

寫文章挺累的，有時候你以爲閱讀挺流暢的，那實際上是背後無數次修改的結果。若是你以爲不錯請幫忙轉發一下，萬分感謝～ 這裏是個人公衆號「咱們都是小青蛙」，裏邊有更多技術乾貨，時不時扯一下犢子，歡迎關注：

相關文章
相關標籤/搜索
每日一句
    每一个你不满意的现在，都有一个你没有努力的曾经。
本站公眾號
   歡迎關注本站公眾號,獲取更多信息
聯繫我們 最近搜索 最新文章 沪ICP备13005482号-10 MyBatis教程 SQL 教程 MySQL教程 Java 教程 Thymeleaf 教程 Hibernate教程 Spring教程 Redis教程