記一次由delete語(yǔ)句導(dǎo)致的MySQL死鎖分析

公司某個(gè)業(yè)務(wù)是視頻會(huì)議方向的，在執(zhí)行業(yè)務(wù)的自動(dòng)化測(cè)試的過(guò)程中，發(fā)現(xiàn)會(huì)出現(xiàn)偶發(fā)性的創(chuàng)建會(huì)議失敗的問(wèn)題。查看業(yè)務(wù)日志發(fā)現(xiàn)，竟然發(fā)生了死鎖：

Deadlock found when trying to get lock; try restarting transaction
Caused by: com.mysql.cj.jdbc.exceptions.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction

于是乎，連接上業(yè)務(wù)數(shù)據(jù)庫(kù)，開(kāi)始了一次死鎖分析之路。

?

為描述方便，如無(wú)特殊指定，下面提到的“數(shù)據(jù)庫(kù)”、"MySQL"，均指使用了InnoDB存儲(chǔ)引擎的MySQL數(shù)據(jù)庫(kù)，測(cè)試使用的MySQL版本是 5.7，數(shù)據(jù)庫(kù)隔離級(jí)別為默認(rèn)的可重復(fù)讀（Repeated Read）級(jí)別

?

獲取死鎖信息

通過(guò) show engine innodb status 命令， 導(dǎo)出相關(guān)的死鎖日志出來(lái)查看。下面為截取出來(lái)的死鎖日志，為了脫敏對(duì)庫(kù)名和關(guān)鍵信息做了一些處理，不影響對(duì)死鎖的分析。

------------------------

LATEST DETECTED DEADLOCK

------------------------

2022-10-31 16:22:00 0x7fb7780d5700

*** (1) TRANSACTION:

TRANSACTION 272174, ACTIVE 0 sec fetching rows

mysql tables in use 1, locked 1

LOCK WAIT 18 lock struct(s), heap size 1136, 58 row lock(s), undo log entries 41

MySQL thread id 298, OS thread handle 140425685493504, query id 5479767 172.18.70.114 root updating

delete from session where id in (x'B41D1ACB485A4E599A687E4AB1C36648' , x'8B2845485D584A3EB38B6D7143AF0979' , x'72A0BF611835464B9F1F13E3A7EE9923' , x'B626729F75AA42CEBA86C07880F9A3DA' , x'4567EC174BAD41A5A7B6587B7FDB6DFD' , x'DB71BC0D218A46678FE9B64ABBCE7212' , x'338A697F27EC4EFC832BBFC109D34505' , x'3B3DE6A8C48940239907F7D4FAFB5418' , x'CF06F6E7AFC247BC914242E7F7D93FE3')

*** (1) WAITING FOR THIS LOCK TO BE GRANTED:

RECORD LOCKS space id 132 page no 3 n bits 120 index PRIMARY of table `session` trx id 272174 lock_mode X waiting

Record lock, heap no 52 PHYSICAL RECORD: n_fields 57; compact format; info bits 0

0: len 16; hex 965b1face74948039ab0dd8da6daa71d; asc [ IH ;;

..... // 省略一些不重要的字段信息
  

*** (2) TRANSACTION:

TRANSACTION 272193, ACTIVE 0 sec inserting

mysql tables in use 1, locked 1

7 lock struct(s), heap size 1136, 3 row lock(s), undo log entries 4

MySQL thread id 300, OS thread handle 140425969882880, query id 5479930 172.18.70.114 root update

insert into session_endpoint (...) values (...)

*** (2) HOLDS THE LOCK(S):

RECORD LOCKS space id 132 page no 3 n bits 120 index PRIMARY of table `session` trx id 272193 lock_mode X locks rec but not gap

Record lock, heap no 52 PHYSICAL RECORD: n_fields 57; compact format; info bits 0

0: len 16; hex 965b1face74948039ab0dd8da6daa71d; asc [ IH ;;

... // 省略一些不重要的字段信息


  

*** (2) WAITING FOR THIS LOCK TO BE GRANTED:

RECORD LOCKS space id 136 page no 3 n bits 88 index PRIMARY of table `session_endpoint` trx id 272193 lock_mode X locks gap before rec insert intention waiting

Record lock, heap no 4 PHYSICAL RECORD: n_fields 63; compact format; info bits 32

0: len 16; hex 4230c997ef754048ba46c254ac88d8c2; asc B0 u@H F T ;;

... // 省略一些不重要的字段信息


15: len 16; hex 72a0bf611835464b9f1f13e3a7ee9923; asc r a 5FK #;;

... // 省略一些不重要的字段信息


*** WE ROLL BACK TRANSACTION (2)

------------

TRANSACTIONS

------------

從這份日志中，我們捕捉到一些關(guān)鍵信息：

1. 事務(wù)1 中的session表在執(zhí)行delete操作的時(shí)候被阻塞了，而且這條SQL在等待X鎖 (lock mode X waiting)

delete from session where id in (x'B41D1ACB485A4E599A687E4AB1C36648' , x'8B2845485D584A3EB38B6D7143AF0979' , x'72A0BF611835464B9F1F13E3A7EE9923' , x'B626729F75AA42CEBA86C07880F9A3DA' , x'4567EC174BAD41A5A7B6587B7FDB6DFD' , x'DB71BC0D218A46678FE9B64ABBCE7212' , x'338A697F27EC4EFC832BBFC109D34505' , x'3B3DE6A8C48940239907F7D4FAFB5418' , x'CF06F6E7AFC247BC914242E7F7D93FE3')

*** (1) WAITING FOR THIS LOCK TO BE GRANTED:

RECORD LOCKS space id 132 page no 3 n bits 120 index PRIMARY of table `session` trx id 272174 lock_mode X waiting

Record lock, heap no 52 PHYSICAL RECORD: n_fields 57; compact format; info bits 0

2. 事務(wù)2 中的session_endpoint表在執(zhí)行insert操作的時(shí)候被阻塞了，而且這條插入SQL在等待插入意向鎖（lock_mode X locks gap before rec insert intention waiting）

*** (2) TRANSACTION:

TRANSACTION 272193, ACTIVE 0 sec inserting

mysql tables in use 1, locked 1

7 lock struct(s), heap size 1136, 3 row lock(s), undo log entries 4

MySQL thread id 300, OS thread handle 140425969882880, query id 5479930 172.18.70.114 root update

insert into session_endpoint (...) values (...)


*** (2) WAITING FOR THIS LOCK TO BE GRANTED:

RECORD LOCKS space id 136 page no 3 n bits 88 index PRIMARY of table `session_endpoint` trx id 272193 lock_mode X locks gap before rec insert intention waiting

Record lock, heap no 4 PHYSICAL RECORD: n_fields 63; compact format; info bits 32

3. 從下面的日志中，還可以知道，現(xiàn)在事務(wù)2在session這個(gè)表中持有了一把記錄鎖

*** (2) HOLDS THE LOCK(S):

RECORD LOCKS space id 132 page no 3 n bits 120 index PRIMARY of table `session` trx id 272193 lock_mode X locks rec but not gap

Record lock, heap no 52 PHYSICAL RECORD: n_fields 57; compact format; info bits 0

另外，還可以得到一些其他的信息：

1. 數(shù)據(jù)庫(kù)的隔離級(jí)別是可重復(fù)讀（Repeated Read）
2. 業(yè)務(wù)正在執(zhí)行創(chuàng)建會(huì)議的流程時(shí)拋出了數(shù)據(jù)庫(kù)死鎖的異常，并造成了創(chuàng)建會(huì)議這個(gè)事務(wù)的回滾。
3. 受影響的表是session和session endpoint兩個(gè)表，session: session_endpoint 數(shù)量關(guān)系是 1:n 的關(guān)系，即1個(gè)session對(duì)應(yīng)多個(gè)session_endpoint，其中session_endpoint通過(guò) session id與其關(guān)聯(lián)。

為方便說(shuō)明，列出簡(jiǎn)化后的兩個(gè)表的DDL如下

CREATE TABLE `session`
(
    `id`                    binary(16) NOT NULL,
    `code`                  varchar(64)         DEFAULT NULL,
    `topic`                 varchar(255)        DEFAULT NULL,
    PRIMARY KEY (`id`),
    KEY `code_idx` (`code`)
) ENGINE = InnoDB
  DEFAULT CHARSET = utf8mb4;

CREATE TABLE `session_endpoint`
(
    `id`                        binary(16)   NOT NULL,
    `nickname`                  varchar(100)          DEFAULT NULL,
    `session_id`                binary(16)            DEFAULT NULL,
    PRIMARY KEY (`id`),
    KEY `session_id_idx` (`session_id`)
) ENGINE = InnoDB
  DEFAULT CHARSET = utf8mb4;

分析死鎖信息

光從這死鎖日志里獲取到的信息就感覺(jué)很奇怪。因?yàn)槿罩局酗@示，事務(wù)1中的session表在等待鎖，事務(wù)2中的session_endpoint表在等待鎖，兩個(gè)不同的表在等待行鎖，竟然導(dǎo)致了死鎖。在網(wǎng)上搜尋了大量的死鎖相關(guān)的文章，多數(shù)都是在分析如何在一個(gè)表上形成死鎖，這和現(xiàn)在遇到的問(wèn)題很不一樣。沒(méi)辦法，只能從看到的業(yè)務(wù)SQL進(jìn)行分析。事務(wù)1阻塞的SQL是一個(gè)批量刪除session的SQL，在視頻會(huì)議的業(yè)務(wù)場(chǎng)景中，往往是通過(guò)定時(shí)器批量清理以保證沒(méi)有用戶(hù)的會(huì)議能正常結(jié)束。追蹤業(yè)務(wù)代碼的邏輯發(fā)現(xiàn)，批量刪除session的邏輯如下：

@Transactional(rollbackFor = Exception.class)
public void clearSessions(List<UUID> sessionIds) {
 sessionEndpointRepository.deleteSessionEndpointBySessionIds(sessionIds);
 sessionRepository.deleteSessionByIds(sessionIds);
}

這里會(huì)先根據(jù)sessionId列表批量刪除視頻會(huì)議中的端點(diǎn)數(shù)據(jù)，再批量刪除視頻會(huì)議，且這兩行代碼在一個(gè)事務(wù)里面。這里和session_endpoint表出現(xiàn)了關(guān)聯(lián)，會(huì)不會(huì)是因?yàn)檫@里的刪除端點(diǎn)先執(zhí)行，然后插入端點(diǎn)的數(shù)據(jù)后執(zhí)行導(dǎo)致事務(wù)2中的插入SQL發(fā)生了阻塞呢？從執(zhí)行的業(yè)務(wù)代碼來(lái)看，這種情況的可能性非常大。從死鎖日志里看涉及兩個(gè)表，現(xiàn)在的信息貌似比較容易分析session_endpoint表相關(guān)SQL的問(wèn)題，先單獨(dú)分析對(duì)session_endpoint表的記錄造成阻塞的原因。

分析session_endpoint表相關(guān)SQL執(zhí)行阻塞的原因

假設(shè)剛剛所說(shuō)的先刪session_endpoint記錄，再插入一條session_endpoint的記錄成立，那么它的處理流程是：

按理說(shuō)，刪除端點(diǎn)時(shí)，加的是記錄鎖，只會(huì)對(duì)刪除的端點(diǎn)進(jìn)行加鎖，而插入端點(diǎn)時(shí)，會(huì)加插入意向鎖，插入意向鎖是INSERT過(guò)程中的一種特殊的間隙鎖。雖然插入意向鎖會(huì)和記錄鎖沖突，但是在這個(gè)例子中，事務(wù)1 加的記錄鎖，鎖的是要被刪除的記錄，而插入意向鎖鎖的是即將要插入的間隙，這兩個(gè)鎖理論上是不沖突的。我們知道，MySQL在刪除某一條記錄的時(shí)候，并不是直接從頁(yè)中刪除，而是會(huì)把這條記錄標(biāo)記為已刪除，已刪除的記錄仍然會(huì)保留在頁(yè)中。所以，如果此時(shí)要插入的這條記錄，剛好插入到已刪除的記錄上，那就會(huì)出現(xiàn)插入意向鎖和記錄鎖沖突的情況了。

如何證明問(wèn)題中的插入SQL剛好插入到已刪除的記錄上呢？可以從兩個(gè)方面印證：

1. 從事務(wù)2的等待鎖的日志中可以看到：

RECORD LOCKS space id 136 page no 3 n bits 88 index PRIMARY of table `session_endpoint` trx id 272193 lock_mode X locks gap before rec insert intention waiting

Record lock, heap no 4 PHYSICAL RECORD: n_fields 63; compact format; info bits 32

事務(wù)2 在執(zhí)行插入語(yǔ)句，但是要插入的位置，info bits 32 表示這條記錄已經(jīng)被標(biāo)記為已刪除。從MySQL 5.7 的源碼中也可以知道，32是一個(gè)表示已刪除的標(biāo)志位

// storage/innobase/include/rem0rec.h

/* The deleted flag in info bits */  
#define REC_INFO_DELETED_FLAG  0x20UL /* when bit is set to 1, it means the  
                                   record has been delete marked */

0x20UL中的 UL 表示這是一個(gè)無(wú)符號(hào)Long類(lèi)型的數(shù)字，0x20是16進(jìn)制表示，換算成十進(jìn)制剛好是32。

2. 從事務(wù)1 刪除的session中可以看到，通過(guò)主鍵刪除的session中，有一個(gè)ID為 72a0bf611835464b9f1f13e3a7ee9923 的會(huì)議被刪除了，而這個(gè)ID正好在事務(wù)2中被刪除的session endponit記錄中可以找到，和業(yè)務(wù)代碼也是對(duì)應(yīng)上的。

由此可以證明，事務(wù)2要插入的session endpoint記錄，剛好就插在了事務(wù)1要?jiǎng)h除的session endpoint的記錄上，而事務(wù)1還沒(méi)提交，也就是說(shuō)，已刪除的session endpoint記錄上的記錄鎖還沒(méi)釋放，所以插入意向鎖和記錄鎖沖突，導(dǎo)致了事務(wù)2在session endpoint這個(gè)表上插入SQL的等待。

分析session表相關(guān)SQL執(zhí)行阻塞的原因

造成session_endpoint表相關(guān)的SQL執(zhí)行阻塞的原因找到了，可session表相關(guān)的SQL執(zhí)行阻塞又是為什么呢？還是對(duì)日志進(jìn)行分析：

1. 從死鎖日志上看，session的執(zhí)行流程和session endpoint并不一樣。事務(wù)1 阻塞的SQL是刪除session的SQL，說(shuō)明刪除session并未執(zhí)行。
2. 從報(bào)錯(cuò)的業(yè)務(wù)日志上看，是在創(chuàng)建會(huì)議的請(qǐng)求中拋出來(lái)的數(shù)據(jù)庫(kù)死鎖的異常，而創(chuàng)建會(huì)議的流程中，和session相關(guān)的操作就是插入一條新的session記錄，而且從死鎖日志和業(yè)務(wù)日志上看，要插入的這條session記錄主鍵為 965b1face74948039ab0dd8da6daa71d，說(shuō)明事務(wù)2的插入session已經(jīng)完成了，但是事務(wù)沒(méi)有提交。

由此推斷，很可能是因?yàn)椴迦胄碌膕ession記錄造成了刪除session的SQL發(fā)生了阻塞。假設(shè)這個(gè)猜想成立的話(huà)，那么整個(gè)死鎖流程是怎么形成的呢？結(jié)合上面的分析，整個(gè)死鎖形成的流程需要滿(mǎn)足：

1. 事務(wù)1先刪除session endponit，事務(wù)2往已標(biāo)記刪除的session endpoint記錄中插入一條新記錄，此時(shí)會(huì)造成事務(wù)2阻塞
2. 事務(wù)2 先插入一條session記錄，事務(wù)1再執(zhí)行批量刪除session，此時(shí)造成事務(wù)1阻塞（先假設(shè)這種情況成立）

所以，可以推斷出整個(gè)死鎖形成的流程如下：

從流程上可以看出，事務(wù)1和事務(wù)2互相等待獲取對(duì)方持有的鎖，最終導(dǎo)致了死鎖，這個(gè)流程和已有的日志也是吻合的。

可問(wèn)題又來(lái)了，要插入的session記錄的id，并不在刪除的session的id列表中，那為什么插入SQL會(huì)影響到刪除的SQL呢？只要能解釋這個(gè)問(wèn)題，整個(gè)死鎖流程就能分析清楚了。在搜尋了大量的資料之后，并沒(méi)有任何的資料提到與此相關(guān)的場(chǎng)景，而且對(duì)于這種根據(jù)id批量刪除的SQL加鎖分析，更是少之又少，一時(shí)之間陷入了僵局。當(dāng)看到張師傅通過(guò)調(diào)試MySQL源碼來(lái)分析加鎖過(guò)程的博客時(shí)，意識(shí)到在網(wǎng)上沒(méi)有相關(guān)資料輔助分析，且從已有的日志沒(méi)有辦法解釋清楚原因的情況下，只能靠自己手動(dòng)復(fù)現(xiàn)并調(diào)試源碼進(jìn)行分析了，否則沒(méi)有實(shí)質(zhì)性的證據(jù)，靠推斷和猜測(cè)，始終無(wú)法說(shuō)服自己。

復(fù)現(xiàn)問(wèn)題與調(diào)試

按照上面的分析，只要能證明往session插入的記錄，會(huì)阻塞session的批量刪除操作，就能把整個(gè)死鎖流程解釋清楚了。為了弄清楚這個(gè)流程，需要對(duì)MySQL源碼進(jìn)行調(diào)試。

為盡可能真實(shí)地模擬出問(wèn)題所在的場(chǎng)景，需要往數(shù)據(jù)庫(kù)里面插入真正有問(wèn)題的id值（曾經(jīng)嘗試過(guò)用字符串作為id去復(fù)現(xiàn)但并不能復(fù)現(xiàn)），模擬session的DDL在上面已經(jīng)列出，現(xiàn)列出初始化的插入語(yǔ)句如下：

insert into `session`(id, code, topic) values
(0x338A697F27EC4EFC832BBFC109D34505, '84709989', '84709989'),
(0x3B3DE6A8C48940239907F7D4FAFB5418, '32700709', '32700709'),
(0x4567EC174BAD41A5A7B6587B7FDB6DFD, '34106954', '34106954'),
(0x72A0BF611835464B9F1F13E3A7EE9923, '50241728', '50241728'),
(0x8B2845485D584A3EB38B6D7143AF0979, '23785170', '23785170'),
(0xB41D1ACB485A4E599A687E4AB1C36648, '16264951', '16264951'),
(0xB626729F75AA42CEBA86C07880F9A3DA, '38992827', '38992827'),
(0xCF06F6E7AFC247BC914242E7F7D93FE3, '44151024', '44151024'),
(0xDB71BC0D218A46678FE9B64ABBCE7212, '98073250', '98073250');

檢查一下數(shù)據(jù)庫(kù)隔離級(jí)別是否為可重復(fù)讀，以及數(shù)據(jù)庫(kù)的版本是否為5.7 （因?yàn)闃I(yè)務(wù)中使用的數(shù)據(jù)庫(kù)版本為5.7）

# 查詢(xún)數(shù)據(jù)庫(kù)隔離級(jí)別
select @@tx_isolation;

# 查詢(xún)數(shù)據(jù)庫(kù)版本
select @@version;

一切準(zhǔn)備就緒。下面針對(duì)先插入session，再批量刪除session的場(chǎng)景設(shè)計(jì)SQL的執(zhí)行過(guò)程。按上述分析，需要有兩個(gè)事務(wù)T1和T2，T2先插入一條session記錄，T1再批量刪除session記錄，如果此時(shí)批量刪除session記錄的SQL被阻塞的話(huà)，就說(shuō)明上述的分析是成立的。由此可得到這樣一個(gè)SQL執(zhí)行流程：

按照這樣的流程執(zhí)行下來(lái)，發(fā)現(xiàn)的確在執(zhí)行第3步的SQL時(shí)被阻塞了：

從實(shí)驗(yàn)結(jié)果來(lái)看，在執(zhí)行第3步的時(shí)候，的確被阻塞了，說(shuō)明上面的分析是成立的。

可是在這個(gè)場(chǎng)景下，為什么會(huì)導(dǎo)致阻塞呢？這兩個(gè)SQL執(zhí)行時(shí)，對(duì)應(yīng)的id都是不一樣的。按MySQL批量刪除的處理邏輯，MySQL會(huì)逐條記錄遍歷后再進(jìn)行刪除，既然執(zhí)行這條SQL時(shí)阻塞住了，那么很可能在刪除某條記錄時(shí)在等待鎖。為了找到這條記錄，先對(duì)id進(jìn)行排序（因?yàn)榧词箓魅胍粋€(gè)亂序的id列表，MySQL也會(huì)先對(duì)id列表進(jìn)行排序再進(jìn)行遍歷，所以為了能找到刪除哪條記錄被阻塞，這里先人工進(jìn)行排序），再逐步在T1中增加刪除的主鍵，最終發(fā)現(xiàn)在刪除這樣一個(gè)主鍵記錄集時(shí)會(huì)發(fā)生阻塞：

delete from session where id in (
x'338A697F27EC4EFC832BBFC109D34505',
x'3B3DE6A8C48940239907F7D4FAFB5418',
x'4567EC174BAD41A5A7B6587B7FDB6DFD',
x'72A0BF611835464B9F1F13E3A7EE9923'
);

問(wèn)題的規(guī)模也縮小了一半，接下來(lái)就只能通過(guò)調(diào)試來(lái)對(duì)這個(gè)問(wèn)題進(jìn)行分析了。

在如下代碼處加斷點(diǎn)進(jìn)行調(diào)試。

源碼位置：storage/innobase/lock/lock0lock.cc

因?yàn)檫@是一個(gè)比較底層的鎖函數(shù)，在SQL執(zhí)行的過(guò)程中，MySQL需要對(duì)SQL進(jìn)行統(tǒng)計(jì)，將統(tǒng)計(jì)數(shù)據(jù)插入系統(tǒng)表里面，也會(huì)經(jīng)過(guò)這個(gè)函數(shù)，所以干擾的數(shù)據(jù)會(huì)比較多。所以這里加了一個(gè)條件斷點(diǎn)，只有我們自己的表執(zhí)行到這里的時(shí)候，才會(huì)停在斷點(diǎn)處：

(size_t) strcmp(index->table_name, "t_debug_lock/session") == 0

然后執(zhí)行批量刪除的SQL時(shí)，可以看到斷點(diǎn)停留在了設(shè)置的位置上

從圖中可以看到，此時(shí)的mode值是3，mode的值其實(shí)是等于 鎖類(lèi)型 和 鎖模式 進(jìn)行或運(yùn)算得到的。對(duì)于鎖類(lèi)型和鎖模式的定義，在源碼中是這樣的：

// 鎖模式定義:  `storage/innobase/include/lock0types.h`
enum lock_mode {  
       LOCK_IS = 0,   /* intention shared */  
       LOCK_IX,       /* intention exclusive */  
       LOCK_S,               /* shared */  
       LOCK_X,               /* exclusive */  
       LOCK_AUTO_INC, /* locks the auto-inc counter of a table  
                     in an exclusive mode */       LOCK_NONE,     /* this is used elsewhere to note consistent read */  
       LOCK_NUM = LOCK_NONE, /* number of lock modes */  
       LOCK_NONE_UNSET = 255  
};

// 鎖類(lèi)型定義: `storage/innobase/include/lock0lock.h`
#define LOCK_MODE_MASK  0xFUL
#define LOCK_TABLE      16
#define LOCK_REC       32
#define LOCK_TYPE_MASK  0xF0UL
#if LOCK_MODE_MASK & LOCK_TYPE_MASK  
# error "LOCK_MODE_MASK & LOCK_TYPE_MASK"  
#endif  
  
#define LOCK_WAIT      256

/* Precise modes */  
#define LOCK_ORDINARY  0            // 對(duì)應(yīng)網(wǎng)上所說(shuō)的Next-key鎖
#define LOCK_GAP        512         // 對(duì)應(yīng)間隙鎖
#define LOCK_REC_NOT_GAP 1024       // 對(duì)應(yīng)記錄鎖
#define LOCK_INSERT_INTENTION 2048  // 對(duì)應(yīng)插入意向鎖
#define LOCK_PREDICATE  8192
#define LOCK_PRDT_PAGE  16384

而在斷點(diǎn)處顯示，模式mode=3，則說(shuō)明此時(shí)的 mode = LOCK_X | LOCK_ORDINARY。這個(gè)算法并不是猜測(cè)出來(lái)的，而是有代碼為證：

從堆棧可以看出，在進(jìn)入斷點(diǎn)處代碼之前，mode值正是LOCK_X和LOCK_ORDINARY進(jìn)行或運(yùn)算得到的。

這只能證明執(zhí)行刪除的時(shí)候，會(huì)加上LOCK_X鎖，還需要繼續(xù)找到代碼阻塞的位置才行。因?yàn)檫@刪除的是一個(gè)id列表，會(huì)執(zhí)行很多相似的流程，而在刪除最后一條記錄的時(shí)候會(huì)阻塞，我們需要找到最后一條記錄的執(zhí)行流程。可是這個(gè)session表里的id是binary格式，并不能很好地從調(diào)試信息中辨別出來(lái)，因此只能通過(guò)調(diào)試信息中的這個(gè)字段來(lái)進(jìn)行對(duì)比：

先復(fù)制這個(gè)rec字段的地址，然后通過(guò) MemoryView，打印出這個(gè)地址下的16進(jìn)制數(shù)字

通過(guò)紅框里面的16進(jìn)制數(shù)字和刪除SQL中的id： 338A697F27EC4EFC832BBFC109D34505 進(jìn)行對(duì)比，兩者完全一致。可以確定此時(shí)正在執(zhí)行第一條記錄的刪除。通過(guò)這種方式，我們可以直接定位到最后一條記錄（0x72A0BF611835464B9F1F13E3A7EE9923）被刪除的流程。

通過(guò)多次對(duì)比刪除記錄列表里面的流程發(fā)現(xiàn)，其主要流程集中在sql/sql_delete.cc中。核心代碼如下所示：

當(dāng)執(zhí)行到最后一條記錄時(shí)，發(fā)現(xiàn)并沒(méi)有阻塞，而是緊接著在循環(huán)中調(diào)用 info.read_record函數(shù)讀取到了下一條記錄（0x8B2845485D584A3EB38B6D7143AF0979）:

而這一條記錄正是我們刪除記錄列表里面，排在0x72A0BF611835464B9F1F13E3A7EE9923記錄后面的下一條記錄。同樣地，也對(duì)0x8B2845485D584A3EB38B6D7143AF0979這條記錄加了LOCK_X鎖。但是這條記錄并不是我們想要?jiǎng)h除的記錄，所以跳過(guò)了ha_delete_row函數(shù)的執(zhí)行，并執(zhí)行了unlock_row函數(shù)。

這個(gè)時(shí)候還沒(méi)進(jìn)入到代碼阻塞的地方，關(guān)鍵點(diǎn)來(lái)了，在unlock_row執(zhí)行完之后，并沒(méi)有執(zhí)行break，而是會(huì)繼續(xù)讀取新紀(jì)錄：

那這個(gè)時(shí)候會(huì)讀取到事務(wù)2插入的新session記錄（0x965b1face74948039ab0dd8da6daa71d），還是會(huì)讀取到這條記錄 0x8B2845485D584A3EB38B6D7143AF0979 的下一條記錄呢？代碼繼續(xù)往下執(zhí)行，此時(shí)進(jìn)入到一個(gè)關(guān)鍵函數(shù)中 row_search_mvcc

在row_search_mvcc函數(shù)中，會(huì)執(zhí)行到這一行，對(duì)聚簇索引上的記錄進(jìn)行檢查。

觀察到此時(shí)的rec已經(jīng)指向了事務(wù)2插入的新紀(jì)錄0x965b1face74948039ab0dd8da6daa71d，說(shuō)明上面繼續(xù)讀取新紀(jì)錄時(shí)，讀取到的是由事務(wù)2插入的新紀(jì)錄。這個(gè)時(shí)候正是要對(duì)這個(gè)記錄進(jìn)行加鎖（mode=LOCK_X, gap_mode=0, 即加了LOCK_X+LOCK_ORDINARY鎖）。

因?yàn)檫@條記錄已經(jīng)被事務(wù)2加了記錄鎖，所以這個(gè)時(shí)候想要再對(duì)同一條記錄加鎖，就會(huì)導(dǎo)致阻塞。從源碼上也可以看到，在檢測(cè)到鎖沖突的時(shí)候，會(huì)導(dǎo)致阻塞。最終阻塞的代碼位置，在這個(gè)地方：

源碼位置：storage/innobase/lock/lock0lock.cc的lock_rec_lock_slow函數(shù)

從調(diào)試的結(jié)果可以看到，當(dāng)T2插入了一條新記錄，T1再進(jìn)行批量刪除，就有可能導(dǎo)致T1阻塞。這也印證了一開(kāi)始的猜想，從而還原了整個(gè)死鎖的流程。

解決死鎖問(wèn)題

至此，死鎖的問(wèn)題原因已經(jīng)找到，那如何解決呢？這里再貼一下死鎖形成的過(guò)程：

既然死鎖是由于兩個(gè)事務(wù)對(duì)兩個(gè)表操作的順序不一致造成的互相等待，那么可以將T1對(duì)兩個(gè)表的操作順序調(diào)換一下，即第一步和第三步進(jìn)行調(diào)換，最終變成這樣：

理論上先驗(yàn)證下是否產(chǎn)生死鎖：

1. 假設(shè)T1先刪除session，T2插入session時(shí)發(fā)生了阻塞，那么T2的插入session_endpoint無(wú)法繼續(xù)進(jìn)行，但不影響T1繼續(xù)刪除session_endpoint，所以T1可以繼續(xù)執(zhí)行直到事務(wù)提交。此時(shí)處于session記錄上的鎖被釋放，T2可以獲取到鎖繼續(xù)執(zhí)行插入session_endpoint，因此不會(huì)造成死鎖。

2. 假設(shè)T2先插入session，T1再批量刪除session，從上述的調(diào)試實(shí)驗(yàn)可以知道這里會(huì)造成T1阻塞，T1無(wú)法繼續(xù)執(zhí)行刪除session_endpoint的操作。但是不影響T2繼續(xù)執(zhí)行，T2在插入session之后會(huì)繼續(xù)插入session_endpoint，因?yàn)門(mén)1并沒(méi)有事先刪除session_endpoint，所以也就不會(huì)出現(xiàn)在一條標(biāo)記為已刪除的記錄上插入的問(wèn)題。因此T2可以完成session_endpoint的插入，最終T2事務(wù)提交，釋放了持有的鎖。T1獲取鎖之后，也可以繼續(xù)執(zhí)行，不會(huì)造成死鎖。

實(shí)際要修改的業(yè)務(wù)代碼也很簡(jiǎn)單，只需要調(diào)換一下代碼的執(zhí)行順序，先批量刪除session記錄，再批量刪除session_endpoint記錄

@Transactional(rollbackFor = Exception.class)
public void clearSessions(List<UUID> sessionIds) {
 sessionRepository.deleteSessionByIds(sessionIds);
 sessionEndpointRepository.deleteSessionEndpointBySessionIds(sessionIds);
}

這么修改之后，還要寫(xiě)一個(gè)簡(jiǎn)單的自動(dòng)化測(cè)試腳本來(lái)進(jìn)行驗(yàn)證。大致步驟如下：

1. 先通過(guò)代碼模擬客戶(hù)端不斷地加入會(huì)議、離開(kāi)會(huì)議，產(chǎn)生大量的無(wú)人的會(huì)議來(lái)嘗試讓問(wèn)題穩(wěn)定復(fù)現(xiàn)。
2. 經(jīng)過(guò)測(cè)試，在未修復(fù)這個(gè)問(wèn)題時(shí)，通過(guò)自動(dòng)化測(cè)試腳本復(fù)現(xiàn)，只需要幾分鐘的時(shí)間，就會(huì)暴露出 數(shù)據(jù)庫(kù)死鎖的問(wèn)題。
3. 接著將修改后的代碼發(fā)布到測(cè)試環(huán)境中，再用自動(dòng)化測(cè)試腳本復(fù)現(xiàn)，在產(chǎn)生了上千個(gè)無(wú)人的會(huì)議時(shí)，都沒(méi)有出現(xiàn)數(shù)據(jù)庫(kù)死鎖的情況，說(shuō)明修復(fù)方案是有效的。

至此，整個(gè)數(shù)據(jù)庫(kù)死鎖的問(wèn)題已經(jīng)得到了解決。解決這個(gè)問(wèn)題改動(dòng)的代碼非常簡(jiǎn)單，但是整個(gè)問(wèn)題的分析、推理和驗(yàn)證，都比較曲折。這其中也走了不少?gòu)澛罚ㄒ欢葢岩墒鞘褂玫臄?shù)據(jù)庫(kù)ORM框架做了什么騷操作導(dǎo)致的，但是最終也通過(guò)查看數(shù)據(jù)庫(kù)binlog日志的方式快速排除了這個(gè)可能性。網(wǎng)上的文章不一定都是正確的，還是要自己動(dòng)手調(diào)試源碼，靜下心來(lái)閱讀源碼中的注釋和文檔，才能找到問(wèn)題的原因所在。

遺留問(wèn)題

雖然問(wèn)題得到了解決，但是心中還有很多疑問(wèn)未得到解決。比如：

1. 為什么在遍歷到最后一條記錄（0x72A0BF611835464B9F1F13E3A7EE9923）的時(shí)候，并沒(méi)有立即退出循環(huán)而要再繼續(xù)往下找下一條記錄（0x8B2845485D584A3EB38B6D7143AF0979）呢？
2. 為什么在處理完最后一條記錄的下一條記錄（0x8B2845485D584A3EB38B6D7143AF0979）之后，還要繼續(xù)找下一條記錄呢？
3. 為什么會(huì)找到另一個(gè)事務(wù)中未提交的新插入的記錄（0x965b1face74948039ab0dd8da6daa71d）呢？

這些秘密都還藏在源碼里面，奈何水平有限，還沒(méi)領(lǐng)會(huì)得到這些問(wèn)題的答案，只能留待后續(xù)繼續(xù)分析源碼了。如果有哪位大佬知道答案或者有相關(guān)的思路，歡迎提出來(lái)一起探討一下。