MySQL Bug剖析之Slave節點並行複製死鎖

此文已由做者溫正湖受權網易雲社區發佈。

歡迎訪問網易雲社區，瞭解更多網易技術產品運營經驗。

有天一早，DBA同窗就找上來了，說有個DDB集羣下的RDS實例Slave節點（從庫）死鎖了，請求支援。說實話，一大早就遇到死鎖這種棘手的問題，個人心裏是奔潰的。不過萬幸的是，DBA說這個實例還未正式上線，處於上線前壓測階段。這麼一來，至少現場能夠一直保持着。方便定位問題。那麼，是什麼問題呢，不賣關子，直接上圖：

這是show processlist的結果。能夠看到有一大坨的鏈接，基本上都是權限操做相關的語句，全都卡在「waiting for table level lock」上。還有幾個複製管理操做，好比stop slave，也卡住了。這密密麻麻一大堆，看得都煩。仍是得從這些鏈接裏面挖掘出少數有用的信息。因此登上實例的mysql客戶端捋下才是王道。先看看有沒有鎖相關的直接信息：

show engine innodb status\G
------------
TRANSACTIONS
------------
Trx id counter 6506046
Purge done for trx's n:o < 6506038 undo n:o < 0 state: running but idle
History list length 2057
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 421794207149728, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421794207150640, not started

裏面根本就沒有持鎖相關的提示，並且事務全都處於not started狀態。再看看InnoDB鎖相關表：

mysql> select * from information_schema.INNODB_LOCK_WAITS;
Empty set (0.00 sec)
mysql>
mysql> select * from  information_schema.INNODB_LOCKS;
Empty set (0.00 sec)

仍是空空如也。既然這樣，那直接看這些鏈接吧。理一理前後順序，發現有3個鏈接是最先同時被卡主的：

|  284480 | system user |           | dbn3               | Connect | 60771 |             0 | Waiting for table level lock                | FLUSH PRIVILEGES                                                                                                                  |
|      28 | rdsadmin    | localhost | NULL               | Query   | 60771 |             0 | Waiting for table level lock                | select count(distinct(User)) from mysql.user where Super_priv = 'Y'                                                               |
|  284481 | system user |           | dbn2               | Connect | 60771 |             0 | Waiting for preceding transaction to commit | GRANT SELECT ON *.* TO 'qs'@'10.122.170.%' IDENTIFIED WITH 'mysql_native_password' AS '*5B9E9DAAD2D1AD00E6D25C667B2E4EFD165CA560' |

有2個鏈接在等table lock，其中一個是用戶鏈接，所作的事情是查詢mysql.user表有super權限的帳號，另外一個鏈接，執行刷權限的操做。剩下的1個鏈接在等待前一個事務提交。其中第一個和第三個爲system user。爲了可以看到更具體的信息，咱們進一步查詢了performance_schema.threads表，獲得以下結果：

mysql> select * from threads where THREAD_ID in (284481, 284480) order by PROCESSLIST_ID desc\G
*************************** 1. row ***************************
THREAD_ID: 284506
NAME: thread/sql/slave_worker
TYPE: FOREGROUND
PROCESSLIST_ID: 284481
PROCESSLIST_USER: rdsadmin
PROCESSLIST_HOST: localhost
PROCESSLIST_DB: NULL
PROCESSLIST_COMMAND: Connect
PROCESSLIST_TIME: 62124
PROCESSLIST_STATE: Waiting for preceding transaction to commit
PROCESSLIST_INFO: GRANT SELECT ON *.* TO 'qs'@'10.122.170.%' IDENTIFIED WITH 'mysql_native_password' AS '*5B9E9DAAD2D1AD00E6D25C667B2E4EFD165CA560'
PARENT_THREAD_ID: 284504
ROLE: NULL
INSTRUMENTED: YES
HISTORY: YES
CONNECTION_TYPE: NULL
THREAD_OS_ID: 7281
*************************** 2. row ***************************
THREAD_ID: 284505
NAME: thread/sql/slave_worker
TYPE: FOREGROUND
PROCESSLIST_ID: 284480
PROCESSLIST_USER: rdsadmin
PROCESSLIST_HOST: localhost
PROCESSLIST_DB: NULL
PROCESSLIST_COMMAND: Connect
PROCESSLIST_TIME: 62124
PROCESSLIST_STATE: Waiting for table level lock
PROCESSLIST_INFO: FLUSH PRIVILEGES
PARENT_THREAD_ID: 284504
ROLE: NULL
INSTRUMENTED: YES
HISTORY: YES
CONNECTION_TYPE: NULL
THREAD_OS_ID: 7280
2 rows in set (0.00 sec)

能夠發現這兩個system user鏈接實際上是MySQL Multi-Threads（多線程，MTS，或並行）複製的worker線程，他們共同的父進程（PARENT_THREAD_ID）是284504。咱們再看下這個父進程在幹嗎：

mysql> select * from threads where THREAD_ID in (284504) order by PROCESSLIST_ID desc\G
*************************** 1. row ***************************
THREAD_ID: 284504
NAME: thread/sql/slave_sql
TYPE: FOREGROUND
PROCESSLIST_ID: 284479
PROCESSLIST_USER: rdsadmin
PROCESSLIST_HOST: localhost
PROCESSLIST_DB: NULL
PROCESSLIST_COMMAND: Connect
PROCESSLIST_TIME: 62124
PROCESSLIST_STATE: Waiting for dependent transaction to commit
PROCESSLIST_INFO: NULL
PARENT_THREAD_ID: 282714
ROLE: NULL
INSTRUMENTED: YES
HISTORY: YES
CONNECTION_TYPE: NULL
THREAD_OS_ID: 7279
1 rows in set (0.00 sec)

該父進程即爲多線程複製的sql線程，其所處的狀態爲"Waiting for dependent transaction to commit"，看代碼能夠發現，這個狀態的意思是等待當前的Group提交後才能並行執行一下個Group的事務。咱們知道InnoDB表是沒有表鎖的，而本例大量的鏈接在等表鎖，根據其操做內容，能夠基本肯定是在等待mysql.user表的鎖，該表是MyISAM表。grant to語句跟"FLUSH PRIVILEGES"語句確定是互斥的。而flush語句狀態爲"Waiting for preceding transaction to commit"，這狀態的意思是等待同一個Group中靠前的事務先完成提交。那麼它的前一個事務是什麼呢？其實很差判斷。

google一直是定位問題的好幫手，在分析這個案例的同時，也沒忘去google一把，發現了一個有點相似的案例http://dbaplus.cn/news-11-1874-1.html。但咱們的案例中並無Flush tables with read lock。僅有的用戶鏈接是"select count(distinct(User)) from mysql.user where Super_priv = 'Y'  ",這個鏈接沒法起到FTWRL的做用。那麼會不會是"FLUSH PRIVILEGES"呢？其實有必定的可能性。但倘若真是如此，那麼就是MySQL自己的一個Bug了，由於沒有用戶鏈接的參與，2個mysqld自身的worker線程就致使了死鎖。那麼如何肯定就是這個"FLUSH PRIVILEGES"阻塞了grant to呢。根據從庫執行到的Master Binlog位置，看下對應的Binlog信息便可。查詢到的結果以下：

從圖中咱們能夠發現，last_commited同爲734263的Group有2個事務，分別是"FLUSH PRIVILEGES"和" GRANT SELECT ON *.* TO 'qs'@'10.122.170.%' IDENTIFIED WITH 'mysql_native_password' AS '*5B9E9DAAD2D1AD00E6D25C667B2E4EFD165CA560'"。其中sequence_number爲734264的"FLUSH PRIVILEGES"在前，sequence_number爲734265的grant語句在後。在開啓並行（或多線程）複製的從庫上。734265語句先獲得執行，到了commit階段，因爲設置了slave_preserve_commit_order參數，致使734265須要等待734264先提交後才能提交。但因爲這兩個事務都須要更新mysql.user，且該表爲MyISAM表，加鎖粒度爲表級（table level），這就使得734265須要等待734264先提交後才能提交，但734264須要等待734265提交後纔會釋放的mysql.user表鎖，因而last_commited爲734263的這個Group的2個事務沒法正常完成。進一步致使做爲並行複製的事務分發線程的sql線程一直沒法給worker線程派發下一個Group（last_commited爲734265）的事務。這就把整個Slave的複製鎖死了。

到這裏，須要交代一個DBA提供的背景："一開始是在ddb層,,去改用戶密碼,,來來回回改了幾回,,,而後其中一個節點的內部從就出現了Waiting for table level lock ,,, 都是跟權限相關的"。咱們結合Binlog信息能夠進一步發現，上層至少在數據庫dbn二、dbn3上分別同時執行了" GRANT SELECT ON *.* TO 'qs'@'10.122.170.%' IDENTIFIED WITH 'mysql_native_password' AS '*5B9E9DAAD2D1AD00E6D25C667B2E4EFD165CA560'"和"FLUSH PRIVILEGES"。因爲這兩個操做是都須要加mysql.user的表鎖，因此實際執行時是互斥的，不存在並行提交的Group概念，或者說按照Group Commit機制，這兩個操做是不會出如今同一個Group中的。

但爲何實際上卻出現了呢，這是因爲MySQL 5.7.3開始對group commit作了進一步優化，這裏不作詳細解釋，感興趣的同窗能夠看下這個參考文獻（http://mysql.taobao.org/monthly/2016/08/01/）。

將該Bug上報給MySQL官方，獲得了官方的開發同窗的確認，並建了個bug（https://bugs.mysql.com/bug.php?id=89229）。該Bug對實際業務的影響很小，線上通常不會在多個數據庫上併發執行賦權語句，而是因爲是在從庫上發生，即便出現了，也能夠經過kill掉mysqld從新拉起解決該問題。此外，其實在執行" GRANT SELECT ON *.* TO 'qs'@'10.122.170.%' IDENTIFIED WITH 'mysql_native_password' AS '*5B9E9DAAD2D1AD00E6D25C667B2E4EFD165CA560'"後，並不須要執行"FLUSH PRIVILEGES"。grant to語句自己就會刷新權限信息。

網易雲免費體驗館，0成本體驗20+款雲產品！ 

更多網易技術、產品、運營經驗分享請點擊。

相關文章：
【推薦】 當咱們在談論multidex65535時，咱們在談論什麼
【推薦】 Vuex實踐
【推薦】 機器學習、深度學習、和AI算法能夠在網絡安全中作什麼？