MySQL打印死鎖日志


前言:

在 MySQL 運維過程中,難免會遇到 MySQL 死鎖的情況,一旦線上業務日漸復雜,各種業務操作之間往往會產生鎖沖突,有些會導致死鎖異常。這種死鎖異常一般要在特定時間特定數據和特定業務操作才會復現,有時候處理起來毫無頭緒,一般只能從死鎖日志下手。本篇文章我們一起來看下 MySQL 的死鎖日志。

1.手動打印死鎖日志

當業務發生死鎖時,首先是線上錯誤日志報警發現死鎖異常,也會提示一些堆棧信息,然后會反饋到數據庫層面進行排查。我們一般會在命令行執行 show engine innodb status\G 來輸出死鎖日志,\G 的作用是將查詢到的結果,每行顯示一個字段和字段值,方便查看。

show engine innodb status 是 MySQL 提供的一個用於查看 innodb 引擎系統信息的工具。它會輸出大量的內部信息,內容分為很多小段,每一段對應 innodb 存儲引擎不同部分的信息,其中 LATEST DETECTED DEADLOCK 部分顯示的最近一次的死鎖信息。

下面我們手動制造一次死鎖,來看一下死鎖日志相關信息:

------------------------
LATEST DETECTED DEADLOCK
------------------------
2021-11-10 17:03:10 0x7fb040672700
*** (1) TRANSACTION:
TRANSACTION 46913, ACTIVE 142 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 4 lock struct(s), heap size 1136, 3 row lock(s), undo log entries 1
MySQL thread id 2997198, OS thread handle 140394973071104, query id 9145673 localhost root updating
update test_tb set stu_name = 'lisi' where stu_id = 1006
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 224 page no 4 n bits 80 index uk_stu_id of table `testdb`.`test_tb` trx id 46913 lock_mode X locks rec but not gap waiting
Record lock, heap no 7 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
 0: len 4; hex 800003ee; asc     ;;
 1: len 4; hex 80000006; asc     ;;

*** (2) TRANSACTION:
TRANSACTION 46914, ACTIVE 103 sec starting index read
mysql tables in use 1, locked 1
4 lock struct(s), heap size 1136, 3 row lock(s), undo log entries 1
MySQL thread id 2997201, OS thread handle 140394971473664, query id 9145681 localhost root updating
update test_tb set age = 21  where stu_id = 1005
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 224 page no 4 n bits 80 index uk_stu_id of table `testdb`.`test_tb` trx id 46914 lock_mode X locks rec but not gap
Record lock, heap no 7 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
 0: len 4; hex 800003ee; asc     ;;
 1: len 4; hex 80000006; asc     ;;

*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 224 page no 4 n bits 80 index uk_stu_id of table `testdb`.`test_tb` trx id 46914 lock_mode X locks rec but not gap waiting
Record lock, heap no 6 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
 0: len 4; hex 800003ed; asc     ;;
 1: len 4; hex 80000005; asc     ;;

*** WE ROLL BACK TRANSACTION (2)

# 以上為原文 下面增加個人分析
------------------------
LATEST DETECTED DEADLOCK
------------------------
2021-11-10 17:03:10 0x7fb040672700 #這里顯示了最近一次發生死鎖的日期和時間
*** (1) TRANSACTION: #死鎖相關的第一個事務
TRANSACTION 46913, ACTIVE 142 sec starting index read
#這行表示事務id為46913,事務處於活躍狀態142s,starting index read表示正在使用索引讀取數據行
mysql tables in use 1, locked 1
#這行表示該事務正在使用1個表,且涉及鎖的表有1個
LOCK WAIT 4 lock struct(s), heap size 1136, 3 row lock(s), undo log entries 1
#這行表示在等待4把鎖,占用內存1136字節,涉及3行記錄
MySQL thread id 2997198, OS thread handle 140394973071104, query id 9145673 localhost root updating
#這行表示該事務的線程ID信息,操作系統句柄信息,連接來源、用戶
update test_tb set stu_name = 'lisi' where stu_id = 1006
#這行表示事務執行的最后一條SQL信息
*** (1) WAITING FOR THIS LOCK TO BE GRANTED: #事務1想要獲取的鎖
RECORD LOCKS space id 224 page no 4 n bits 80 index uk_stu_id of table `testdb`.`test_tb` trx id 46913 lock_mode X locks rec but not gap waiting
#這行信息表示等待的鎖是一個record lock,空間id是224,頁編號為4,大概位置在頁的80位處,鎖發生在表testdb.test_tb的uk_stu_id索引上,是一個X鎖,但是不是gap lock,waiting表示正在等待鎖
Record lock, heap no 7 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
 0: len 4; hex 800003ee; asc     ;;
 1: len 4; hex 80000006; asc     ;;

*** (2) TRANSACTION: #死鎖相關的第一個事務
TRANSACTION 46914, ACTIVE 103 sec starting index read
#這行表示事務2的id為46914,事務處於活躍狀態103s
mysql tables in use 1, locked 1
#正在使用1個表,涉及鎖的表有1個
4 lock struct(s), heap size 1136, 3 row lock(s), undo log entries 1
#涉及4把鎖,3行記錄
MySQL thread id 2997201, OS thread handle 140394971473664, query id 9145681 localhost root updating
#事務2的線程ID信息,操作系統句柄信息,連接來源、用戶
update test_tb set age = 21  where stu_id = 1005
#第二個事務的SQL
*** (2) HOLDS THE LOCK(S): # 事務2持有的鎖 正是事務1想要獲取的鎖
RECORD LOCKS space id 224 page no 4 n bits 80 index uk_stu_id of table `testdb`.`test_tb` trx id 46914 lock_mode X locks rec but not gap
Record lock, heap no 7 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
 0: len 4; hex 800003ee; asc     ;;
 1: len 4; hex 80000006; asc     ;;

*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 224 page no 4 n bits 80 index uk_stu_id of table `testdb`.`test_tb` trx id 46914 lock_mode X locks rec but not gap waiting
Record lock, heap no 6 PHYSICAL RECORD: n_fields 2; compact format; info bits 0
 0: len 4; hex 800003ed; asc     ;;
 1: len 4; hex 80000005; asc     ;;
#上面這部分是事務二正在等待的鎖,從信息上看,等待的是同一個表,同一個索引,同一個page上的record lock X鎖,但是heap no位置不同,即不同的行上的鎖

*** WE ROLL BACK TRANSACTION (2) #表示事務2被回滾

從死鎖日志中可以看到關聯的兩個事務相關信息,當一個事務持有了其他事務需要的鎖,同時又想獲得其他事務持有的鎖時,等待關系上就會產生循環,Innodb 不會顯示所有持有和等待的鎖,但死鎖日志也顯示了相關的信息來幫你確定,排查死鎖發生的索引,這對於你確定能否避免死鎖有較大的價值。

2.自動保存死鎖日志

從上面內容我們知道 MySQL 的死鎖可以通過 show engine innodb status 來查看,但是這個命令需要手動執行並且只能顯示最新的一條死鎖,該方式無法完全捕獲到系統發生的死鎖信息。那有沒有辦法記錄所有的死鎖日志呢,我們來看下 MySQL 的系統參數。

MySQL 系統內部提供一個 innodb_print_all_deadlocks 參數,該參數默認是關閉的,開啟后可以將死鎖信息自動記錄到 MySQL 的錯誤日志中。下面我們來看下這個參數的作用:

# 查看參數是否開啟
mysql> show variables like 'innodb_print_all_deadlocks';
+----------------------------+-------+
| Variable_name              | Value |
+----------------------------+-------+
| innodb_print_all_deadlocks | OFF   |
+----------------------------+-------+

# 開啟innodb_print_all_deadlocks,此參數是全局參數,可以動態調整。記得要加入到配置文件中
mysql> set global innodb_print_all_deadlocks = 1;
Query OK, 0 rows affected (0.00 sec)

mysql> show variables like 'innodb_print_all_deadlocks';
+----------------------------+-------+
| Variable_name              | Value |
+----------------------------+-------+
| innodb_print_all_deadlocks | ON    |
+----------------------------+-------+

建議將 innodb_print_all_deadlocks 參數設置為 1 ,這樣每次發生死鎖后,系統會自動將死鎖信息輸出到錯誤日志中,需要注意的是打開此參數后,只會記錄死鎖部分信息而不會記錄 innodb 其他相關信息,即只會記錄 show engine innodb status 中的 LATEST DETECTED DEADLOCK 部分。

其實 InnoDB 存儲引擎還提供有 InnoDB Monitor 監視器,可以定期將 InnoDB 的狀態信息輸出到錯誤日志中,主要由 innodb_status_output 和 innodb_status_output_locks 參數控制,這兩個系統變量是用來啟用標准 InnoDB 監控和 InnoDB 鎖監控的,開啟后會將監控結果輸出錯誤日志中,大約每隔 15 秒產生一次輸出,輸出內容與 show engine innodb status 一致。不過這會導致錯誤日志暴增,一般不建議開啟這兩個參數。

總結:

本篇文章介紹了 MySQL 死鎖日志的獲取方法,發生死鎖后,可以根據死鎖日志還獲取相關信息。開啟 innodb_print_all_deadlocks 參數可以自動將死鎖信息輸出到錯誤日志中,有助於我們及時發現並處理死鎖異常。


免責聲明!

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



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