1. 程式人生 > 其它 >死鎖日誌分析

死鎖日誌分析

------------------------
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 執行順序,這樣分析死鎖時就會容易很多。

轉自:MySQL 死鎖日誌分析 - __Yoon - 部落格園 (cnblogs.com)