【巡檢問題分析與最佳實踐】PolarDB 死鎖問題

往期分享

RDS MySQL

RDS MySQL 執行個體空間問題 RDS MySQL 記憶體使用問題 RDS MySQL 活躍線程數高問題 RDS MySQL 慢SQL問題 RDS MySQL 執行個體IO高問題 RDS MySQL 小版本更新最佳實踐

RDS PostgreSQL

RDS PostgreSQL 執行個體IO高問題 RDS PostgreSQL 慢SQL問題 RDS PostgreSQL CPU高問題

RDS SQL Server

RDS SQL Server 磁盤IO吞吐高問題 RDS SQL Server CPU高問題 RDS SQL Server 空間使用問題

PolarDB

PolarDB MySQL CPU高問題 PolarDB 流量 & 代理問題

Redis

Redis 流控問題 Redis 記憶體高問題 Redis CPU高問題

MongoDB

MongoDB 記憶體高問題 MongoDB 磁盤IO高問題 MongoDB 空間使用問題

背景

死鎖是關系型資料庫系統中最為常見的錯誤，出現在不同僚務中同時對某些資料通路加鎖時都要等待對方請求中的資料而無法擷取鎖，資料庫系統會自動犧牲復原代價最小的事務，進而導緻對應的寫請求失敗，更嚴重的情況是在大量死鎖發生時，會導緻資料庫系統效率低下，堆積程序大量堆積引發性能問題。

一般來說，死鎖都是由于邏輯加鎖的順序導緻的，也就是我們常說的 ABA死鎖，舉例：

tran_A 與 tran_B兩個請求分别持有對方所需要的第二次update的行鎖，就形成了死鎖：

此時業務會收到報錯資訊類似：

Error : Deadlock found when trying to get lock; try restarting transaction      

觀察資料庫内資訊：

show engine innodb status\G;
------------------------
LATEST DETECTED DEADLOCK
------------------------
2020-12-01 16:43:28 0x7fe8a0277700
*** (1) TRANSACTION:
TRANSACTION 370942954, ACTIVE 9 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 3 lock struct(s), heap size 1136, 2 row lock(s), undo log entries 1
MySQL thread id 25713, OS thread handle 140637097146112, query id 237499 106.11.34.226 luhuo_h updating
update sbtest1 set c='tran2_tran1' where id=1
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 354 page no 4 n bits 144 index PRIMARY of table `sbtest`.`sbtest1` trx id 370942954 lock_mode X locks rec but not gap waiting
Record lock, heap no 2 PHYSICAL RECORD: n_fields 6; compact format; info bits 0
 0: len 4; hex 80000001; asc     ;;
 1: len 6; hex 0000161c23e9; asc     # ;;
 2: len 7; hex 23000000151374; asc #     t;;
 3: len 4; hex 80c52f66; asc   /f;;
 4: len 30; hex 7472616e3120202020202020202020202020202020202020202020202020; asc tran1                         ; (total 120 bytes);
 5: len 30; hex 32323139353230373034382d37303131363035323132332d373431343033; asc 22195207048-70116052123-741403; (total 60 bytes);
*** (2) TRANSACTION:
TRANSACTION 370942953, ACTIVE 15 sec starting index read
mysql tables in use 1, locked 1
3 lock struct(s), heap size 1136, 2 row lock(s), undo log entries 1
MySQL thread id 25568, OS thread handle 140637096081152, query id 237597 106.11.34.226 luhuo_h updating
update sbtest1 set c='tran1_tran2' where id=2
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 354 page no 4 n bits 144 index PRIMARY of table `sbtest`.`sbtest1` trx id 370942953 lock_mode X locks rec but not gap
Record lock, heap no 2 PHYSICAL RECORD: n_fields 6; compact format; info bits 0
 0: len 4; hex 80000001; asc     ;;
 1: len 6; hex 0000161c23e9; asc     # ;;
 2: len 7; hex 23000000151374; asc #     t;;
 3: len 4; hex 80c52f66; asc   /f;;
 4: len 30; hex 7472616e3120202020202020202020202020202020202020202020202020; asc tran1                         ; (total 120 bytes);
 5: len 30; hex 32323139353230373034382d37303131363035323132332d373431343033; asc 22195207048-70116052123-741403; (total 60 bytes);
*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 354 page no 4 n bits 144 index PRIMARY of table `sbtest`.`sbtest1` trx id 370942953 lock_mode X locks rec but not gap waiting
Record lock, heap no 3 PHYSICAL RECORD: n_fields 6; compact format; info bits 0
 0: len 4; hex 80000002; asc     ;;
 1: len 6; hex 0000161c23ea; asc     # ;;
 2: len 7; hex 24000000191844; asc $     D;;
 3: len 4; hex 8021f170; asc  ! p;;
 4: len 30; hex 7472616e3220202020202020202020202020202020202020202020202020; asc tran2                         ; (total 120 bytes);
 5: len 30; hex 32383733333830323932332d31303534383839343634312d313138363735; asc 28733802923-10548894641-118675; (total 60 bytes);
*** WE ROLL BACK TRANSACTION (2)      

但是引擎層列印出的太過于晦澀，難以定位問題，本文主要描述以雲上已有工具進行業務邏輯的定位方法

另外，本文說的死鎖是指deadlock，而非事務鎖造成的阻塞(block)，要區分排查。

定位

基礎分析

通過執行個體控制台->一鍵診斷->鎖分析入口進入，選擇立即診斷，如果執行個體存在死鎖，會在【發現死鎖】列出現 【是】。

需要說明的是，目前診斷功能隻能拉取最後一次死鎖，同樣是從innodb status中擷取的，如果執行個體不重新開機，死鎖資訊會一直保留最後一組日志，是以需要确認診斷後的日志是不是存量死鎖問題，也就是說發現死鎖不一定是新出現的死鎖。

目前DMS平台正在排期全量死鎖記錄的功能，到時會有真實的全量死鎖資訊。

發現死鎖後，點選查詢詳情頁，會顯示格式化後的死鎖資訊：

• Thread id : 線程ID，和洞察中的線程ID對應
• 涉及表：死鎖出現的表，有時可能左右表不一緻，是因為事務中請求的表不緻的問題
• 等待鎖索引名： DML語句會将鎖加在索引行上，是以擷取不到的鎖一定是在某個索引上
• 事務SQL ： 引發死鎖的語句

以上資訊是一個簡單死鎖的基本情況，但是由于MySQL的死鎖資訊相對簡單，如果是一組事務中的幾個語句導緻加鎖順序不對，在死鎖資訊中無法定位，如果是簡單業務，可以将【事務SQL】給到研發人員進行語句級别的定位，但是由于有些業務邏輯過于複雜，開發也無法确認事務流，此時就需要進一步将整個事務進行定位。

事務流定位

事務流定位的前提條件是在死鎖發生前，開啟了sql洞察功能，才能對執行過的語句進行定位。

首先可以擷取的資訊是：

1. 1. 復原的事務
   2. 發生死鎖的語句
   3. thread_id 

• 錯誤線程定位

犧牲事務thread_id 為 1622，成功thread id 為1746，先對犧牲事務進行定位：

狀态中顯示 【失敗(1213)】,error 1213就是死鎖復原的code，是以可以定位發生復原的事務：

預設傳回是秒級排序，如果要擷取時序的事務流，需要通過 【執行時間(毫秒)】進行排序，注意如果傳回語句太多，将無法進行【執行時間(毫秒)】排序，需要繼續縮小時間短，減小傳回審計資料。

同時知道執行成功的thread id 為1746 ，可以再次進行定位：

分析日志可擷取事務時間線：

至此死鎖鍊的事務流已經分析出來，可以交由業務人員進行代碼定位了。

注意事項

• 在查找SQL審計内容時，有可能出現大量的語句導緻無法分析，需要不斷的縮短時間範圍以定位準确區間
• 需要明确出現的報錯語句為error 1213錯誤才是死鎖退出的語句
• 如果業務無沒有開啟事務，有可能是在架構中配置的，一般開始語句都是set autocommit=0,有begin開始事務的情況不是很多。