MySQL 死鎖日志分析


------------------------
LATEST DETECTED DEADLOCK
------------------------
2017-09-06 11:58:16 7ff35f5dd700
*** (1) TRANSACTION:
TRANSACTION 182335752, ACTIVE 0 sec inserting
mysql tables in use 1, locked 1
LOCK WAIT 11 lock struct(s), heap size 1184, 2 row lock(s), undo log entries 15
MySQL thread id 12032077, OS thread handle 0x7ff35ebf6700, query id 196418265 10.40.191.57 RW_bok_db update
INSERT INTO bok_task
                 ( order_id ...
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 300 page no 5480 n bits 552 index `order_id_un` of table `bok_db`.`bok_task`
    trx id 182335752 lock_mode X insert intention waiting
*** (2) TRANSACTION:
TRANSACTION 182335756, ACTIVE 0 sec inserting
mysql tables in use 1, locked 1
11 lock struct(s), heap size 1184, 2 row lock(s), undo log entries 15
MySQL thread id 12032049, OS thread handle 0x7ff35f5dd700, query id 196418268 10.40.189.132 RW_bok_db update
INSERT INTO bok_task
                 ( order_id ...
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 300 page no 5480 n bits 552 index `order_id_un` of table `bok_db`.`bok_task`
    trx id 182335756 lock_mode X
*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 300 page no 5480 n bits 552 index `order_id_un` of table `bok_db`.`bok_task`
    trx id 182335756 lock_mode X insert intention waiting
*** WE ROLL BACK TRANSACTION (2)

日志中列出了死鎖發生的時間,以及導致死鎖的事務信息(只顯示兩個事務,如果由多個事務導致的死鎖也只顯示兩個),並顯示出每個事務正在執行的 SQL 語句、等待的鎖以及持有的鎖信息等。

看事務一的信息:

* (1) TRANSACTION:
TRANSACTION 182335752, ACTIVE 0 sec inserting
ACTIVE 0 sec 表示事務活動時間,inserting 為事務當前正在運行的狀態,可能的事務狀態有:fetching rows,updating,deleting,inserting 等。

mysql tables in use 1, locked 1
LOCK WAIT 11 lock struct(s), heap size 1184, 2 row lock(s), undo log entries 15
tables in use 1 表示有一個表被使用,locked 1 表示有一個表鎖。LOCK WAIT 表示事務正在等待鎖,11 lock struct(s) 表示該事務的鎖鏈表的長度為 11,每個鏈表節點代表該事務持有的一個鎖結構,包括表鎖,記錄鎖以及 autoinc 鎖等。heap size 1184 為事務分配的鎖堆內存大小。
2 row lock(s) 表示當前事務持有的行鎖個數,通過遍歷上面提到的 11 個鎖結構,找出其中類型為 LOCK_REC 的記錄數。undo log entries 15 表示當前事務有 15 個 undo log 記錄,因為二級索引不記 undo log,說明該事務已經更新了 15 條聚集索引記錄。

* (1) WAITING FOR THIS LOCK TO BE GRANTED:
這里顯示的是正在等待鎖的 SQL 語句,死鎖日志里每個事務都只顯示一條 SQL 語句,這對我們分析死鎖很不方便,我們必須要結合應用程序去具體分析這個 SQL 之前還執行了哪些其他的 SQL 語句,或者根據 binlog 也可以大致找到一個事務執行的 SQL 語句。

RECORD LOCKS space id 300 page no 5480 n bits 552 index `order_id_un` of table `bok_db`.`bok_task` trx id 182335752 lock_mode X insert intention waiting

這里顯示的是事務正在等待什么鎖。RECORD LOCKS 表示記錄鎖(並且可以看出要加鎖的索引為 order_id_un),space id 為 300,page no 為 5480,n bits 552 表示這個記錄鎖結構上留有 552 個 bit 位(該 page 上的記錄數 + 64)。
lock_mode X 表示該記錄鎖為排他鎖,insert intention waiting 表示要加的鎖為插入意向鎖,並處於鎖等待狀態。

在上面有提到 innodb_status_output_locks 這個系統變量可以開啟 InnoDb 的鎖監控,如果開啟了,這個地方還會顯示出鎖的一些額外信息,包括索引記錄的 info bits 和數據信息等:

有四種類型的行鎖:記錄鎖,間隙鎖,Next-key 鎖和插入意向鎖。這四種鎖對應的死鎖日志各不相同,如下:

記錄鎖(LOCK_REC_NOT_GAP): lock_mode X locks rec but not gap
間隙鎖(LOCK_GAP): lock_mode X locks gap before rec
Next-key 鎖(LOCK_ORNIDARY): lock_mode X
插入意向鎖(LOCK_INSERT_INTENTION): lock_mode X locks gap before rec insert intention

* (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 300 page no 5480 n bits 552 index `order_id_un` of table `bok_db`.`bok_task` trx id 182335756 lock_mode X
* (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 300 page no 5480 n bits 552 index `order_id_un` of table `bok_db`.`bok_task` trx id 182335756 lock_mode X insert intention waiting

事務二和事務一的日志基本類似,不過它多了一部分 HOLDS THE LOCK(S),表示事務二持有什么鎖,這個鎖往往就是事務一處於鎖等待的原因。這里可以看到事務二正在等待索引 order_id_un 

事務二和事務一的日志基本類似,不過它多了一部分 HOLDS THE LOCK(S),表示事務二持有什么鎖,這個鎖往往就是事務一處於鎖等待的原因。這里可以看到事務二正在等待索引 order_id_un 上的插入意向鎖,並且它已經持有了一個 X 鎖(Next-key 鎖,也有可能是 supremum 上的間隙鎖)。

到這里為止,我們得到了很多關鍵信息,此時我們可以逆推出死鎖發生的原因嗎?這可能也是每個開發人員和 DBA 最關心的問題,如何通過死鎖日志來診斷死鎖的成因?實際上這是非常困難的。

如果每個事務都只有一條 SQL 語句,這種情況的死鎖成因還算比較好分析,因為我們可以從死鎖日志里找到每個事務執行的 SQL 語句,只要對這兩條 SQL 語句的加鎖過程有一定的了解,死鎖原因一般不難定位。但也有可能死鎖的成因非常隱蔽,這時需要我們對這兩條 SQL 語句的加鎖流程做非常深入的研究才有可能分析出死鎖的根源。

不過大多數情況下,每個事務都不止一條 SQL 語句,譬如上面的死鎖日志里顯示的 undo log entries 15,說明執行 INSERT 語句之前肯定還執行了其他的 SQL 語句,但是具體是什么,我們不得而知,我們只能根據 HOLDS THE LOCK(S) 部分知道有某個 SQL 語句對 order_id_un 索引加了 Next-key 鎖(或間隙鎖)。另外事務二在 WAITING FOR 插入意向鎖,至於它和事務一的哪個鎖沖突也不得而知,因為事務一的死鎖日志里並沒有 HOLDS THE LOCK(S) 部分。

所以,對死鎖的診斷不能僅僅靠死鎖日志,還應該結合應用程序的代碼來進行分析,如果實在接觸不到應用代碼,還可以通過數據庫的 binlog 來分析(只要你的死鎖不是 100% 必現,那么 binlog 日志里肯定能找到一份完整的事務一和事務二的 SQL 語句)。通過應用代碼或 binlog 理出每個事務的 SQL 執行順序,這樣分析死鎖時就會容易很多。


免責聲明!

本站轉載的文章為個人學習借鑒使用,本站對版權不負任何法律責任。如果侵犯了您的隱私權益,請聯系本站郵箱yoyou2525@163.com刪除。



 
粵ICP備18138465號   © 2018-2025 CODEPRJ.COM