前言
MySQL 死鎖異常是我們經常會遇到的線上異常類别,一旦線上業務日間複雜,各種業務操作之間往往會産生鎖沖突,有些會導緻死鎖異常。這種死鎖異常一般要在特定時間特定資料和特定業務操作才會複現,并且分析解決時還需要了解 MySQL 鎖沖突相關知識,是以一般遇到這些偶爾出現的死鎖異常,往往一時沒有頭緒,不好處理。
本篇文章會講解一下如果線上發生了死鎖異常,如何去排查和處理。除了系列前文講解的有關加鎖和鎖沖突的原理還,還需要對 MySQl 死鎖日志和 binlog 日志進行分析。

正文
日常工作中,應對各類線上異常都要有我們自己的 SOP (标準作業流程) ,這樣不僅能夠提高自己的處理問題效率,也有助于将好的處理流程推廣到團隊,提高團隊的整體處理異常能力。
是以,面對線上偶發的 MySQL 死鎖問題,我的排查處理過程如下:
- 線上錯誤日志報警發現死鎖異常
- 檢視錯誤日志的堆棧資訊
- 檢視 MySQL 死鎖相關的日志
- 根據 binlog 檢視死鎖相關事務的執行内容
- 根據上述資訊找出兩個互相死鎖的事務執行的 SQL 操作,根據本系列介紹的鎖相關理論知識,進行分析推斷死鎖原因
- 修改業務代碼
根據1,2步驟可以找到死鎖異常時進行復原事務的具體業務,也就能夠找到該事務執行的 SQL 語句。然後我們需要通過 3,4步驟找到死鎖異常時另外一個事務,也就是最終獲得鎖的事務所執行的 SQL 語句,然後再進行鎖沖突相關的分析。
第一二步的線上錯誤日志和堆棧資訊一般比較容易獲得,第五步的分析 SQL 鎖沖突原因中涉及的鎖相關的理論在系列文章中都有介紹,沒有了解的同學可以自行去閱讀以下。
下面我們就來重點說一下其中的第三四步驟,也就是如何檢視死鎖日志和 binlog 日志來找到死鎖相關的 SQL 操作。
死鎖日志的擷取
發生死鎖異常後,我們可以直接使用
show engine innodb status
指令擷取死鎖資訊,但是該指令隻能擷取最近一次的死鎖資訊。是以,我們可以通過開啟 InnoDB 的監控機制來擷取實時的死鎖資訊,它會周期性(每隔 15 秒)列印 InnoDb 的運作狀态到 mysqld 服務的錯誤日志檔案中。
InnoDb 的監控較為重要的有标準監控(Standard InnoDB Monitor)和 鎖監控(InnoDB Lock Monitor),通過對應的系統參數可以将其開啟。
-- 開啟标準監控
set GLOBAL innodb_status_output=ON;
-- 關閉标準監控
set GLOBAL innodb_status_output=OFF;
-- 開啟鎖監控
set GLOBAL innodb_status_output_locks=ON;
-- 關閉鎖監控
set GLOBAL innodb_status_output_locks=OFF;
另外,MySQL 提供了一個系統參數
innodb_print_all_deadlocks
專門用于記錄死鎖日志,當發生死鎖時,死鎖日志會記錄到 MySQL 的錯誤日志檔案中。
set GLOBAL innodb_print_all_deadlocks=ON;
死鎖日志的分析
通過上述手段,我們可以拿到死鎖日志,下圖是我做實驗觸發死鎖異常時擷取的日志(省略的部分資訊)。
該日志會列出死鎖發生的時間,死鎖相關的事務,并顯示出兩個事務(可惜,多事務發生死鎖時,也隻顯示兩個事務)在發生死鎖時執行的 SQL 語句、持有或等待的鎖資訊和最終復原的事務。
下面,我們來一段一段的解讀該日志中給出的資訊,我們按照圖中标注的順序來介紹:
TRANSACTION 2078, ACTIVE 74 sec starting index read // -1 事務一的基礎資訊,包括事務ID、活躍時間,目前運作狀态
表示的是 ACTIVE 74 sec 表示事務活動時間,starting index read 為事務目前正在運作的狀态,可能的事務狀态有:fetching rows,updating,deleting,inserting, starting index read 等狀态。
mysql tables in use 1, locked 1 // -2 使用一個table,并且有一個表鎖
LOCK WAIT 3 lock struct(s), heap size 1136, 2 row lock(s), undo log entries 1 // -3 涉及的鎖結構和記憶體大小
tables in use 1 表示有一個表被使用,locked 1 表示有一個表鎖。LOCK WAIT 表示事務正在等待鎖,3 lock struct(s) 表示該事務的鎖連結清單的長度為 3,每個連結清單節點代表該事務持有的一個鎖結構,包括表鎖,記錄鎖或 autoinc 鎖等。heap size 1136 為事務配置設定的鎖堆記憶體大小。
2 row lock(s) 表示目前事務持有的行鎖個數,通過周遊上面提到的 11 個鎖結構,找出其中類型為 LOCK_REC 的記錄數。undo log entries 1 表示目前事務有 1 個 undo log 記錄,說明該事務已經更新了 1條記錄。
下面就是死鎖日志中最為重要的持有或者待擷取鎖資訊,如圖中-5和-6行所示,通過它可以分析鎖的具體類型和涉及的表,這些資訊能輔助你按照系列文章的鎖相關的知識來分析 SQL 的鎖沖突。
RECORD LOCKS space id 2 page no 4 n bits 80 index PRIMARY of table `test`.`t` trx id 2078 lock_mode X locks rec but not gap // -5 具體持有鎖的資訊
RECORD LOCKS space id 2 page no 4 n bits 80 index PRIMARY of table `test`.`t` trx id 2078 lock_mode X locks rec but not gap waiting // -6 等待擷取鎖的資訊
在
《鎖類型和加鎖原理》一文中我們說過,一共有四種類型的行鎖:記錄鎖,間隙鎖,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
是以,按照死鎖日志,我們發現事務一持有了 test.t 表上的記錄鎖,并且等待另一個記錄鎖。
通過死鎖日志,我們可以找到最終獲得鎖事務最後執行的 SQL,但是如果該事務執行了多條 SQL,這些資訊就可能不夠用的啦,我們需要完整的了解該事務所有執行的 SQL語句。這時,我們就需要從 binlog 日志中擷取。
binlog的擷取和分析
binlog 日志會完整記錄事務執行的所有 SQL,借助它,我們就能找到最終擷取鎖事務所執行的全部 SQL。然後再進行具體的鎖沖突分析。
我們可以使用 MySQL 的指令行工具
Mysqlbinlog
遠端擷取線上資料庫的 binlog 日志。具體指令如下所示:
Mysqlbinlog -h127.0.0.1 -u root -p --read-from-remote-server binlog.000001 --base64-output=decode-rows -v
其中
--base64-output=decode-rows
表示 row 模式 binlog日志,是以該方法隻适用于 row 模式的 binlog日志,但是目前主流 MySQL 運維也都是把 binlog 日志設定為 row 模式,是以這點限制也就無傷大雅。
-v
則表示将行事件重構成被注釋掉的僞SQL語句。
我們可以通過死鎖日志中死鎖發生的具體事件和最終擷取鎖事務正在執行的SQL的參數資訊找到 binlog 中該事務的對應資訊,比如我們可以直接通過死鎖日志截圖中的具體的時間 10點57分和 Tom1、Teddy2 等 SQL 的具體資料資訊在 binlog 找到對應的位置,具體如下圖所示。
根據 binlog 的具體資訊,我們可以清晰的找到最終擷取鎖事務所執行的所有 SQL 語句,也就能找到其對應的業務代碼,接下來我們就能進行具體的鎖沖突分析。
小節
死鎖系列終于告一段落,如果大夥有什麼疑問或者文中有什麼錯誤,歡迎在下方留言讨論。也希望大家繼續持續關注。
個人部落格,歡迎來玩