MySQLDeadLock故障排查全過程記錄

來源：懂視網(wǎng) 責編：小采時間：2020-11-09 20:20:57

MySQLDeadLock故障排查全過程記錄

MySQLDeadLock故障排查全過程記錄:【作者】劉博：攜程技術保障中心數(shù)據(jù)庫高級經(jīng)理，主要關注Sql server和Mysql的運維和故障處理。【環(huán)境】版本號：5.6.21 隔離級別：REPEATABLE READ 【問題描述】接到監(jiān)控報警，有一個線上的應用DeadLock報錯，每15分鐘會準時出現(xiàn)，報錯統(tǒng)計如

推薦度：

點擊下載本文 文檔為doc格式

導讀MySQLDeadLock故障排查全過程記錄:【作者】劉博：攜程技術保障中心數(shù)據(jù)庫高級經(jīng)理，主要關注Sql server和Mysql的運維和故障處理。【環(huán)境】版本號：5.6.21 隔離級別：REPEATABLE READ 【問題描述】接到監(jiān)控報警，有一個線上的應用DeadLock報錯，每15分鐘會準時出現(xiàn)，報錯統(tǒng)計如

可以看到 EXTRA 列：

Using intersect(column5_index,idxColumn6)

從5.1開始，引入了 index merge 優(yōu)化技術，對同一個表可以使用多個索引分別進行條件掃描。

相關文檔：http://dev.mysql.com/doc/refman/5.7/en/index-merge-optimization.html

The Index Merge method is used to retrieve rows with several range scans and to merge their results into one. The merge can produce unions, intersections, or unions-of-intersections of its underlying scans. This access method merges index scans from a single table; it does not merge scans across multiple tables.

【模擬與驗證】

根據(jù)以上初步分析，猜測應該就是intersect造成的，于是在測試環(huán)境模擬驗證，開啟2個session模擬死鎖：

時間序列	Session1	Session2
1	Begin；
2	UPDATE TestTable SET Column2 = sysdate() Column4 = 0 AND Column5 = 47 AND Column6 = 'SEK 執(zhí)行成功，影響7行
3		Begin；
4		UPDATE TestTable SET Column2 = sysdate(),Column4 = 0 AND Column5 = 485 AND Column6 = 'SEK'；被Blocking
5	UPDATE TestTable SET Column2 = sysdate(),Column4 = 0 AND Column5 = 485 AND Column6 = 'SEK'；執(zhí)行成功	ERROR 1213 (40001): Deadlock found when trying to get lock; try restarting transaction

依據(jù)以上信息可以發(fā)現(xiàn)Session2雖然被Block了，但也獲取了一些Session1在時間序列5時所需資源的X鎖，可以再開啟一個查詢select count(Column5) from TestTable where Column5 = 485，設置SET TRANSACTION ISOLATION LEVEL SERIALIZABLE，去查詢Column5 = 485的行，觀察鎖等待的信息：
mysql> SELECT r.trx_id waiting_trx_id, r.trx_mysql_thread_id waiting_thread, r.trx_query waiting_query, b.trx_id

mysql> SELECT r.trx_id waiting_trx_id, r.trx_mysql_thread_id waiting_thread, r.trx_query waiting_query, b.trx_id blocking_trx_id, b.trx_mysql_thread_id blocking_thread, b.trx_query blocking_query FROM information_schema.innodb_lock_waits w INNER JOIN information_schema.innodb_trx b ON b.trx_id = w.blocking_trx_id INNER JOIN information_schema.innodb_trx r ON r.trx_id = w.requesting_trx_id \G;

*************************** 1. row ***************************

waiting_trx_id: 103006

waiting_thread: 36

waiting_query: UPDATE TestTable SET Column1 = 1, Column2 = sysdate(), Column3 = '026' Column4 = 0 AND Column5 = 485 AND Column6 = 'SEK'

blocking_trx_id: 103003

blocking_thread: 37

blocking_query: NULL

*************************** 2. row ***************************

waiting_trx_id: 421500433538672

waiting_thread: 39

waiting_query: select count(Column5) from TestTable where Column5 = 485

blocking_trx_id: 103006

blocking_thread: 36

blocking_query: UPDATE TestTable SET Column1 = 1, Column2 = sysdate(), Column3 = '026' Column4 = 0 AND Column5 = 485 AND Column6 = 'SEK'

2 rows in set, 1 warning (0.00 sec)

mysql> select * from information_schema.innodb_lock_waits \G;

*************************** 1. row ***************************

requesting_trx_id: 103006

requested_lock_id: 103006:417:1493:859

blocking_trx_id: 103003

blocking_lock_id: 103003:417:1493:859

*************************** 2. row ***************************

requesting_trx_id: 421500433538672

requested_lock_id: 421500433538672:417:749:2

blocking_trx_id: 103006

blocking_lock_id: 103006:417:749:2

2 rows in set, 1 warning (0.00 sec)

mysql> select * from INNODB_LOCKS \G;

*************************** 1. row ***************************

lock_id: 103006:417:1493:859

lock_trx_id: 103006

lock_mode: X

lock_type: RECORD

lock_table: test.TestTable

lock_index: idxColumn6

lock_space: 417

lock_page: 1493

lock_rec: 859

lock_data: 'SEK', 8262738

*************************** 2. row ***************************

lock_id: 103003:417:1493:859

lock_trx_id: 103003

lock_mode: X

lock_type: RECORD

lock_table:test.TestTable

lock_index: idxColumn6

lock_space: 417

lock_page: 1493

lock_rec: 859

lock_data: 'SEK', 8262738

*************************** 3. row ***************************

lock_id: 421500433538672:417:749:2

lock_trx_id: 421500433538672

lock_mode: S

lock_type: RECORD

lock_table: test.TestTable

lock_index: column5_index

lock_space: 417

lock_page: 749

lock_rec: 2

lock_data: 485, 8317620

*************************** 4. row ***************************

lock_id: 103006:417:749:2

lock_trx_id: 103006

lock_mode: X

lock_type: RECORD

lock_table: test.TestTable

lock_index: column5_index

lock_space: 417

lock_page: 749

lock_rec: 2

lock_data: 485, 8317620

4 rows in set, 1 warning (0.00 sec)

可以看到Session2，trx_id 103006阻塞了trx_id 421500433538672，而trx_id 421500433538672 requested_lock也正好是lock_data: 485, 8317620。由此可見Session2雖然別block了，但是還是獲取到了Index column5_index相關的鎖。被Block是因為intersect的原因，還需要idxColumn6的鎖，至此思路已經(jīng)清晰，對整個分配鎖的信息簡化一下，如下表格（請求到的鎖用青色表示，需獲取但未獲取到的鎖用紅色表示）：