天天看點

[譯文]MySQL發生死鎖腫麼辦?by何金龍

一、導讀

在 mysql 中,當兩個或以上的事務互相持有和請求鎖,并形成一個循環的依賴關系,就會産生死鎖。在一個事務系統中,死鎖是确切存在并且是不能完全避免的。 innodb 會自動檢測事務死鎖,立即復原其中某個事務,并且傳回一個錯誤。它根據某種機制來選擇那個最簡單(代價最小)的事務來進行復原。偶然發生的死鎖不必擔心,但死鎖頻繁出現的時候就要引起注意了。

在 mysql 5.6 之前,隻有最新的死鎖資訊可以使用 show engine innodb status 指令來進行檢視。使用 percona toolkit 工具包中的 pt-deadlock-logger 可以從 show engine innodb status 的結果中得到指定的時間範圍内的死鎖資訊,同時寫入檔案或者表中,等待後面的診斷分析。對于 pt-deadlock-logger 工具的更多資訊可以參考手冊:https://www.percona.com/doc/percona-toolkit/2.2/pt-deadlock-logger.html 。 如果使用的是 mysql 5.6 或以上版本,您可以啟用一個新增的參數 innodb_print_all_deadlocks 把 innodb 中發生的所有死鎖資訊都記錄在錯誤日志裡面。

在開始講診斷之前,得到應用程式捕捉到的死鎖錯誤(mysql error no. 1213),以及通過重試來處理失敗事務是一個重要的做法。

二、如何診斷mysql死鎖

一個 mysql 死鎖可能會涉及到兩個或以上的事務,而 latest detected deadlock 這一節僅僅展示了最後兩個事務,并且隻顯示這兩個事務中最後執行的一條語句和循環依賴中的鎖資訊。而忽略掉了前面執行過的有可能真正申請并持有鎖的語句。下面我會給大家講一些如何收集這些被忽略掉的語句的 tips。

讓我們一起來看兩個例子,看 latest detected deadlock 都給出了什麼資訊。例 1:

1 141013 6:06:22

2 *** (1) transaction:

3 transaction 876726b90, active 7 sec setting auto-inc lock

4 mysql tables in use 1, locked 1

5 lock wait 9 lock struct(s), heap size 1248, 4 row lock(s), undo log entries 4

6 mysql thread id 155118366, os thread handle 0x7f59e638a700, query id87987781416 localhost msandbox update

7 insert into t1 (col1, col2, col3, col4) values (10, 20, 30, 'hello')

8 *** (1) waiting for this lock to be granted:

9 table lock table `mydb`.`t1` trx id 876726b90 lock mode auto-inc waiting

10 *** (2) transaction:

11 transaction 876725b2d, active 9 sec inserting

12 mysql tables in use 1, locked 1

13 876 lock struct(s), heap size 80312, 1022 row lock(s), undo log entries 1002

14 mysql thread id 155097580, os thread handle 0x7f585be79700, query id87987761732 localhost msandbox update

15 insert into t1 (col1, col2, col3, col4) values (7, 86, 62, "a lot of things"),(7, 76, 62, "many more")

16 *** (2) holds the lock(s):

17 table lock table `mydb`.`t1` trx id 876725b2d lock mode auto-inc

18 *** (2) waiting for this lock to be granted:

19 record locks space id 44917 page no 529635 n bits 112 index `primary` of table`mydb`.`t2` trx id 876725b2d lock mode s locks rec but not gap waiting

20 *** we roll back transaction (1)

第 1 行是死鎖發生的時間。如果你的應用程式捕捉和記錄死鎖錯誤到日志中,那麼你可以根據這個時間戳和應用程式日志中的死鎖錯誤的時間戳進行比對。這樣你可以得到已復原的事務,及事務中的所有語句。

第 3 和 11 行,注意事務的序号和活躍時間。如果你定期地把 show engine innodb status 的輸出資訊記錄到日志檔案(這是一個很好的做法),那麼你就可以使用事務編号在之前的輸出日志中查到同一個事務中所希望看到的更多的語句。活躍時間提供了一個線索來判斷這個事務是單個語句的事務,還是包含多個語句的事務。

第 4 和 12 行,使用到的表和鎖隻是針對于目前的語句。是以,使用到一張表,并不意味着事務僅僅涉及到一張表。

第 5 和 13 行,這裡的資訊需要重點關注,因為它告訴我們事務做了多少的改變,也就是 "undo log entries";"row lock(s)" 則告訴我們持有多少行鎖。這些資訊都會提示我們這個事務的複雜程度。

第 6 和 14 行,留意線程 id、連接配接主機和使用者。如果你在不同的應用程式中使用不同的 mysql 使用者,這将是另外一個好的習慣,這樣你就可以根據連接配接主機和使用者來定位到事務來自于哪個應用程式。

第 9 行,對于第一個事務,它隻是顯示了處于鎖等待狀态,在這個例子中,是表 t1 的 auto_inc 鎖。其他的可能:共享鎖(s),有間隙鎖(gap lock)的排他鎖(x),及沒有間隙鎖(gap lock)的排他鎖(x)。

第 16 和 17 行,對于第二個事務,顯示了它持有的鎖,在本示例中,是事務1 (transaction (1)) 所請求并等待中的 auto-inc 鎖。

第 18 和 19 行,顯示了事務2 (transaction (2)) 所等待的鎖的資訊。在本例中,是一個在另一個表 t2 的主鍵上面共享的沒有間隙的記錄鎖。在 innodb 中隻有少數情況會産生 共享記錄鎖:

1) 使用了 select … lock in share mode 的語句

2) 外鍵引用記錄

3) 源表上的共享鎖,使用了 insert into… select 的語句

事務2 的目前語句是一個簡單的 insert to t1,是以 1 和 3 被排除了。通過檢查 show create table t1,你可以确定共享鎖(s) 是由于父表t2 的外鍵一緻性限制。

例 2:使用 mysql 社群版,每個記錄鎖的記錄内容都會被列印出來。

1 2014-10-11 10:41:12 7f6f912d7700

3 transaction 2164000, active 27 sec starting index read

5 lock wait 3 lock struct(s), heap size 360, 2 row lock(s), undo log entries 1

6 mysql thread id 9, os thread handle 0x7f6f91296700, query id 87 localhost ro otupdating

7 update t1 set name = 'b' where id = 3

9 record locks space id 1704 page no 3 n bits 72 index `primary` of table `test`.`t1`trx id 2164000 lock_mode x locks rec but not gap waiting

10 record lock, heap no 4 physical record: n_fields 5; compact format; info bit s0

11 0: len 4; hex 80000003; asc ;;

12 1: len 6; hex 000000210521; asc ! !;;

13 2: len 7; hex 180000122117cb; asc ! ;;

14 3: len 4; hex 80000008; asc ;;

15 4: len 1; hex 63; asc c;;

16

17 *** (2) transaction:

18 transaction 2164001, active 18 sec starting index read

19 mysql tables in use 1, locked 1

20 3 lock struct(s), heap size 360, 2 row lock(s), undo log entries 1

21 mysql thread id 10, os thread handle 0x7f6f912d7700, query id 88 localhost root updating

22 update t1 set name = 'c' where id = 2

23 *** (2) holds the lock(s):

24 record locks space id 1704 page no 3 n bits 72 index `primary` of table `test`.`t1`trx id 2164001 lock_mode x locks rec but not gap

25 record lock, heap no 4 physical record: n_fields 5; compact format; info bit s0

26 0: len 4; hex 80000003; asc ;;

27 1: len 6; hex 000000210521; asc ! !;;

28 2: len 7; hex 180000122117cb; asc ! ;;

29 3: len 4; hex 80000008; asc ;;

30 4: len 1; hex 63; asc c;;

31

32 *** (2) waiting for this lock to be granted:

33 record locks space id 1704 page no 3 n bits 72 index `primary` of table `test`.`t1`trx id 2164001 lock_mode x locks rec but not gap waiting

34 record lock, heap no 3 physical record: n_fields 5; compact format; info bit s0

35 0: len 4; hex 80000002; asc ;;

36 1: len 6; hex 000000210520; asc ! ;;

37 2: len 7; hex 17000001c510f5; asc ;;

38 3: len 4; hex 80000009; asc ;;

39 4: len 1; hex 62; asc b;;

第 9 和 10 行:"space id" 是表空間 id,"page no" 指出了這個表空間裡面記錄鎖所在的資料頁,"n bits" 不是資料頁偏移量,而是鎖位圖裡面的 bits 數。在第 10 行記錄的 "heap no" 是資料頁偏移量。

第 11 到 15 行:顯示了記錄資料的十六進制編碼。字段 0 表示聚集索引(即主鍵),忽略最高位,值為 3。字段 1 表示最後修改這條記錄的事務的id号,上面執行個體中的十進制值是 2164001,即是 transaction (2)。字段 2 表示復原指針。從字段 3 開始,表示的是餘下的行資料:字段 3 表示一個整型列,值為 8,字段 4 表示一個字元串列,值為 'c'。通過閱讀這些資訊,我們可以準确知道哪一行被鎖了,哪些是目前值。

三、我們還可以從分析中學到什麼

既然大多數 mysql 死鎖是發生在兩個事務之間,那麼我們可以基于這個假設來進行分析。在例1 中,事務2 (trx(2)) 在等待一個共享鎖,是以事務1 (trx(1)) 在表 t2 的主鍵記錄上,要麼持有一個共享鎖,要麼持有一個排他鎖。假設 col2 是一個外鍵列,通過檢查 trx(1) 的目前語句,我們可以知道它不需要相同的記錄鎖,因而它肯定是一些在 trx(1) 之前就已經申請了在 t2 主鍵索引上的 s 或者 x 鎖的語句。trx(1) 在 7 秒鐘裡面僅改變了 4 行資料。

是以,我們可以得到 trx(1) 的一些特征:它做了很多處理,卻做了很少變化;變化涉及到 t1 和 t2,單個記錄插入到 t2。這些資訊結合着其他資料可以幫助開發人員定位到那個事務。

四、我們還可以從哪裡找到事物之前的語句

除了應用程式日志和之前的 show engine innodb status 的輸出資訊外,還可以利用 binlog、low log,甚至是 general log。

通過 binlog,如果 binlog_format = statement,binlog 中的每個 event 都會擁有一個 thread_id。隻有已送出的事務會被記錄到 binlog 中,是以,我們隻能在 binlog 中查找 trx(2) 的細資訊。在例1 中,我們知道死鎖發生的時間,還有 trx(2) 是在 9 秒前開始的。我們可以執行 mysqlbinlog 指令來解析對應的 binlog 檔案,并且尋找帶有 thread_id = 155097580 的語句。使用應用程式代碼來進行交叉确認也是很好的。

$ mysqlbinlog -vvv --start-datetime=“2014-10-13 6:06:12” --stop-datatime=“2014-10-136:06:22” mysql-bin.000010 > binlog_1013_0606.out

在 percona server 5.5 或者更早版本,可以通過設定 log_slow_verbosity 選項來把 事務 id 記錄在 slow log 中。如果你設定了 long_query_time = 0,你可以捕獲到包括那些復原到 slow log 裡面的所有語句。通過 general log,可以用 thread id 來查找相關的語句。

五、如何避免死鎖

在了解死鎖之後,我們可以做一些事情來避免它。

對應用程式進行調整/修改。在某些情況下,你可以通過把大事務分解成多個小事務,使得鎖能夠更快被釋放,進而極大程度地降低死鎖發生的頻率。在其他情況下,死鎖的發生是因為兩個事務采用不同的順序操作了一個或多個表的相同的資料集。需要改成以相同順序讀寫這些資料集,換言之,就是對這些資料集的通路采用串行化方式。這樣在并發事務時,就讓死鎖變成了鎖等待。

修改表的 schema,例如删除外鍵限制來分離兩張表,或者添加索引來減少掃描和鎖定的行。

如果發生了間隙鎖,你可以把會話或者事務的事務隔離級别更改為 rc(read committed)級别來避免,但此時需要把 binlog_format 設定成 row 或者 mixed 格式。

<b>本文來自雲栖社群合作夥伴“dbgeek”</b>

繼續閱讀