Mysql：從一個USE DB堵塞故障展開的探討

gaopengtttt發表於2017-11-09
MySql

原創水平有限如有誤請指出謝謝！

一、故障描述

今天一個朋友遇到資料庫遇到一個嚴重的故障，故障環境如下：

  • MYSQL 5.6.16
  • RR隔離級別
  • GITD關閉

表現如下：

  • use db不能進入資料庫
  • show table status不能查詢到表資訊
  • schema.processlist來看有大量的 Waiting for table metadata lock

情急之下他殺掉了一大堆執行緒後發現還是不能恢復，最後殺掉了一個沒有及時提交的事物才恢復正常。也僅僅留下了如下圖的一個截圖：


image.png
image.png

二、故障資訊提取

還是回到上圖，我們可以歸納一下語句型別如下：

  • 1、CREATE TABLE A AS SELECT B
    其STATE為sending data
  • 2、DROP TABLE A
    其STATE為Waiting for table metadata lock
  • 3、SELECT * FROM A
    其STATE為Waiting for table metadata lock
  • 4、 SHOW TABLE STATUS[like 'A']
    其STATE為Waiting for table metadata lock

三、資訊分析

要分析出這個案列其實不太容易因為他是MYSQL層MDL LOCK和RR模式innodb row lock的一個綜合案列，並且我們要對schema.processlist的STATE比較敏感才行。
建議先閱讀我的如下文章來學習MDL LOCK：
http://blog.itpub.net/7728585/viewspace-2143093/

本節關於MDL LOCK的驗證使用下面兩種方式：

  • 方式1 筆者在MDL LOCK原始碼加鎖函式處加日誌輸出，但是如果要分析各種語句加MDL LOCK的型別還只能用這種方式，因為MDL LOCK加鎖往往一閃而過，performance_schema.metadata_locks 沒有辦法觀察到

  • 方式2 處於堵塞情況下performance_schema.metadata_locks的輸出
    開啟如下： 

 UPDATE performance_schema.setup_consumers SET ENABLED = 'YES' WHERE NAME ='global_instrumentation';
 UPDATE performance_schema.setup_instruments SET ENABLED = 'YES' WHERE NAME ='wait/lock/metadata/sql/mdl';
 select * from performance_schema.metadata_locks\G
1、關於CREATE TABLE A AS SELECT B 對B表sending data的分析

關於sending data這個狀態其實可以代表很多含義，從我現有的對的瞭解，這是MYSQL上層對SELECT型別語句的這類語句在INNODB層和MYSQL層進行資料互動的時候一個統稱，所以出現它的可能包含:

  • 確實需要訪問資料量特別大，可能需要最佳化
  • 由於INNODB 層的獲取row lock需要等待，比如我們常見的SELECT FOR UPDATE

同時我們還需要注意在RR模式下SELECT B這一部分加鎖方式和INSERT...SELECT是一致的參考不在熬述：
http://blog.itpub.net/7728585/viewspace-2146183/
從他反應的情況因為他在最後殺掉了一個長期的未提交的事物所以他因為是情況2。並且整個CREATE TABLE A AS SELECT B語句由於B表上某些資料庫被上了鎖而不能獲取，導致整個語句處於sending data狀態下。

2、關於SHOW TABLE STATUS[like 'A'] Waiting for table metadata lock的分析

這是本案例中最重要的一環，SHOW TABLE STATUS[like 'A']居然被堵塞其STATE為Waiting for table metadata lock並且注意這裡是table因為MDL LOCK型別分為很多。我在MDL介紹的那篇文章中提到了desc 一個表的時候會上MDL_SHARED_HIGH_PRIO(SH)，其實在SHOW TABLE STATUS的時候也會對本表上MDL_SHARED_HIGH_PRIO(SH)。

  • 方式1： 
mysql> SHOW TABLE STATUS like 'a' \G

2017-11-10T03:01:48.142334Z 6 [Note] (acquire_lock)**THIS MDL LOCK acquire WAIT(MDL_LOCK WAIT QUE)!**
2017-11-10T03:01:48.142381Z 6 [Note] (>MDL PRINT) Thread id is 6: 
2017-11-10T03:01:48.142396Z 6 [Note] (->MDL PRINT) DB_name is:test 
2017-11-10T03:01:48.142409Z 6 [Note] (-->MDL PRINT) OBJ_name is:a 
2017-11-10T03:01:48.142421Z 6 [Note] (--->MDL PRINT) Namespace is:TABLE 
2017-11-10T03:01:48.142434Z 6 [Note] (----->MDL PRINT) Mdl type is:MDL_SHARED_HIGH_PRIO(SH) 
2017-11-10T03:01:48.142447Z 6 [Note] (------>MDL PRINT) Mdl  duration is:MDL_TRANSACTION
  • 方式2： 
*************************** 7. row ***************************
         OBJECT_TYPE: TABLE
       OBJECT_SCHEMA: test
         OBJECT_NAME: a
OBJECT_INSTANCE_BEGIN: 140733864665152
           LOCK_TYPE: SHARED_HIGH_PRIO
       LOCK_DURATION: TRANSACTION
         LOCK_STATUS: PENDING
              SOURCE: sql_base.cc:2821
     OWNER_THREAD_ID: 38
      OWNER_EVENT_ID: 1695

兩種方式都能觀察到MDL_SHARED_HIGH_PRIO(SH)的存在並且我模擬的是處於堵塞情況下的。
但是MDL_SHARED_HIGH_PRIO(SH) 是一個優先順序非常高的一個MDL LOCK型別表現如下：

  • 相容性： 
 Request  |  Granted requests for lock                  |
    type    | S  SH  SR  SW  SWLP  SU  SRO  SNW  SNRW  X  |
  ----------+---------------------------------------------+
  SH        | +   +   +   +    +    +   +    +    +    -  |
  • 阻塞佇列優先順序： 
 Request   |  Pending requests for lock      |
      type    | S  SH  SR  SW  SU  SNW  SNRW  X |
    ----------+---------------------------------+
    SH        | +   +   +   +   +   +     +   + |

其被堵塞的條件除了被MDL_EXCLUSIVE(X)堵塞沒有其他的可能。那麼這就是一個非常重要的突破口。

3、關於CREATE TABLE A AS SELECT B 對A表的加MDL LOCK的分析

這一點也是我以前不知道的,也是本案列中花時間最多的地方,前文已經分析過要讓SHOW TABLE STATUS[like 'A']這種只會上MDL_SHARED_HIGH_PRIO(SH) MDL LOCK的語句堵塞在MDL LOCK上只有一種可能那就是A表上了MDL_EXCLUSIVE(X)。那麼我開始
懷疑這個DDL語句在語句結束之前會對A表上MDL_EXCLUSIVE(X) ，然後進行實際測試不出所料確實是這樣的如下：

  • 方式1： 
2017-11-10T05:38:16.824713Z 4 [Note] (acquire_lock)THIS MDL LOCK acquire ok!
2017-11-10T05:38:16.824727Z 4 [Note] (>MDL PRINT) Thread id is 4: 
2017-11-10T05:38:16.824739Z 4 [Note] (->MDL PRINT) DB_name is:test 
2017-11-10T05:38:16.824752Z 4 [Note] (-->MDL PRINT) OBJ_name is:a 
2017-11-10T05:38:16.824764Z 4 [Note] (--->MDL PRINT) Namespace is:TABLE 
2017-11-10T05:38:16.824776Z 4 [Note] (---->MDL PRINT) Fast path is:(Y)
2017-11-10T05:38:16.824788Z 4 [Note] (----->MDL PRINT) Mdl type is:MDL_SHARED(S) 
2017-11-10T05:38:16.824799Z 4 [Note] (------>MDL PRINT) Mdl  duration is:MDL_TRANSACTION 
2017-11-10T05:38:16.825286Z 4 [Note] (upgrade_shared_lock)THIS MDL LOCK  upgrade TO
2017-11-10T05:38:16.825312Z 4 [Note] (>MDL PRINT) Thread id is 4: 
2017-11-10T05:38:16.825332Z 4 [Note] (->MDL PRINT) DB_name is:test 
2017-11-10T05:38:16.825345Z 4 [Note] (-->MDL PRINT) OBJ_name is:a 
2017-11-10T05:38:16.825357Z 4 [Note] (--->MDL PRINT) Namespace is:TABLE 
2017-11-10T05:38:16.825369Z 4 [Note] (----->MDL PRINT) Mdl type is:MDL_EXCLUSIVE(X) 
2017-11-10T05:38:16.825381Z 4 [Note] (------>MDL PRINT) Mdl  duration is:MDL_TRANSACTION
  • 方式2： 
*************************** 1. row ***************************
          OBJECT_TYPE: TABLE
        OBJECT_SCHEMA: test
          OBJECT_NAME: a
OBJECT_INSTANCE_BEGIN: 140733998842016
            LOCK_TYPE: SHARED
        LOCK_DURATION: TRANSACTION
          LOCK_STATUS: GRANTED
               SOURCE: sql_parse.cc:6314
      OWNER_THREAD_ID: 36
       OWNER_EVENT_ID: 1553

這裡比較遺憾在performance_schema.metadata_locks中並沒有顯示出MDL_EXCLUSIVE(X)，而顯示為MDL_SHARED(S) 但是我們在我輸出的日誌中可以看到這裡做了升級操作將MDL_SHARED(S) 升級為了MDL_EXCLUSIVE(X)。並且由前面的相容性列表來看，只有MDL_EXCLUSIVE(X)會堵塞MDL_SHARED_HIGH_PRIO(SH)。所以我們應該能夠確認這裡確實做了升級操作，否則SHOW TABLE STATUS[like 'A'] 是不會被堵塞的。

4、關於SELECT * FROM A Waiting for table metadata lock的分析

也許大家認為SELECT不會上鎖，但是那是在innodb 層次，在MYSQL層會上MDL_SHARED_READ(SR) 如下：

  • 方式1： 
 select * from a;

2017-11-10T03:31:31.209772Z 6 [Note] (acquire_lock)THIS MDL LOCK acquire WAIT(MDL_LOCK WAIT QUE)!
2017-11-10T03:31:31.209824Z 6 [Note] (>MDL PRINT) Thread id is 6: 
2017-11-10T03:31:31.209851Z 6 [Note] (->MDL PRINT) DB_name is:test 
2017-11-10T03:31:31.209870Z 6 [Note] (-->MDL PRINT) OBJ_name is:a 
2017-11-10T03:31:31.209885Z 6 [Note] (--->MDL PRINT) Namespace is:TABLE 
2017-11-10T03:31:31.209965Z 6 [Note] (----->MDL PRINT) Mdl type is:MDL_SHARED_READ(SR) 
2017-11-10T03:31:31.209985Z 6 [Note] (------>MDL PRINT) Mdl  duration is:MDL_TRANSACTION
  • 方式2： 
 OBJECT_TYPE: TABLE
        OBJECT_SCHEMA: test
          OBJECT_NAME: a
OBJECT_INSTANCE_BEGIN: 140733864625136
            LOCK_TYPE: SHARED_READ
        LOCK_DURATION: TRANSACTION
          LOCK_STATUS: PENDING
               SOURCE: sql_parse.cc:6314
      OWNER_THREAD_ID: 38
       OWNER_EVENT_ID: 1764

可以看到確實有MDL_SHARED_READ(SR)的存在，當前處於堵塞狀態

其相容性如下： 

 Request  |  Granted requests for lock                  |
        type    | S  SH  SR  SW  SWLP  SU  SRO  SNW  SNRW  X  |
      ----------+---------------------------------------------+
      SR        | +   +   +   +    +   +    +    +    -    -  |

顯然MDL_SHARED_READ(SR) 和MDL_SHARED_HIGH_PRIO(SH)是不相容的需要等待。

5、關於DROP TABLE A Waiting for table metadata lock的分析

這一點很好分析因為A表上了X鎖而DROP TABLE A必然上MDL_EXCLUSIVE(X)鎖它當然和MDL_EXCLUSIVE(X)不相容。如下：

  • 方式1： 
 drop table a;

2017-11-09T10:58:28.673015Z 3 [Note] (acquire_lock)THIS MDL LOCK acquire ok!
2017-11-09T10:58:28.673030Z 3 [Note] (>MDL PRINT) Thread id is 3: 
2017-11-09T10:58:28.673042Z 3 [Note] (->MDL PRINT) DB_name is:test 
2017-11-09T10:58:28.673054Z 3 [Note] (-->MDL PRINT) OBJ_name is:t10 
2017-11-09T10:58:28.673067Z 3 [Note] (--->MDL PRINT) Namespace is:TABLE 
2017-11-09T10:58:28.673094Z 3 [Note] (----->MDL PRINT) Mdl type is:MDL_EXCLUSIVE(X) 
2017-11-09T10:58:28.673109Z 3 [Note] (------>MDL PRINT) Mdl  duration is:MDL_TRANSACTION
  • 方式2： 
 OBJECT_TYPE: TABLE
        OBJECT_SCHEMA: test
          OBJECT_NAME: a
OBJECT_INSTANCE_BEGIN: 140733864625472
            LOCK_TYPE: EXCLUSIVE
        LOCK_DURATION: TRANSACTION
          LOCK_STATUS: PENDING
               SOURCE: sql_parse.cc:6314
      OWNER_THREAD_ID: 38
       OWNER_EVENT_ID: 1832

其中EXCLUSIVE就是我們說的MDL_EXCLUSIVE(X)它確實存在當前處於堵塞

6、為何use db也會堵塞？

如果使用mysql客戶端不使用-A選項(或者 no-auto-rehash)在USE DB的時候至少要做如下事情：

1、 對db下每個表上MDL (SH) lock如下（呼叫MDL_context::acquire_lock 這裡給出堵塞時候的資訊）：
  • 方式1： 
use test

2017-11-10T03:46:50.223628Z 5 [Note] (acquire_lock)THIS MDL LOCK acquire WAIT(MDL_LOCK WAIT QUE)!
2017-11-10T03:46:50.223666Z 5 [Note] (>MDL PRINT) Thread id is 5: 
2017-11-10T03:46:50.223696Z 5 [Note] (->MDL PRINT) DB_name is:test 
2017-11-10T03:46:50.223714Z 5 [Note] (-->MDL PRINT) OBJ_name is:a 
2017-11-10T03:46:50.223725Z 5 [Note] (--->MDL PRINT) Namespace is:TABLE 
2017-11-10T03:46:50.223735Z 5 [Note] (----->MDL PRINT) Mdl type is:MDL_SHARED_HIGH_PRIO(SH) 
2017-11-10T03:46:50.223755Z 5 [Note] (------>MDL PRINT) Mdl  duration is:MDL_TRANSACTION
  • 方式2： 
*************************** 7. row ***************************
          OBJECT_TYPE: TABLE
        OBJECT_SCHEMA: test
          OBJECT_NAME: a
OBJECT_INSTANCE_BEGIN: 140733797429008
            LOCK_TYPE: SHARED_HIGH_PRIO
        LOCK_DURATION: TRANSACTION
          LOCK_STATUS: PENDING
               SOURCE: sql_base.cc:2821
      OWNER_THREAD_ID: 37
       OWNER_EVENT_ID: 187

可以看到USE DB確實也因為MDL_SHARED_HIGH_PRIO(SH) 發生了堵塞。

2、對每個表加入到table cache，並且開啟表(呼叫open_table_from_share())

那麼這種情況就和SHOW TABLE STATUS[like 'A']被堵塞的情況一模一樣了，也是由於MDL 鎖不相容造成的。

四、分析梳理

有了前面的分析那麼我們可以梳理這個故障發生的原因如下：

  • 1、有一個在B表上長期未提交的DML
    語句會在innodb層對B表某些資料加innodb row lock。
  • 2、由步驟1引起了CREATE TABLE A AS SELECT B的堵塞
    因為RR模式下SELECT B必然對B表上滿足的資料上鎖，因為步驟1已經加鎖所以觸發等待，STATE為sending data。
  • 3、由步驟2引起了其他語句的堵塞
    因為CRATE TABLE A AS SELECT B在A表建立完成之前會上MDL_EXCLUSIVE(X),這把鎖會堵塞其他全部的關於A表的語句，包括DESC/SHOW TABLE STATUS/USE DB(非-A) 這種只上MDL_SHARED_HIGH_PRIO(SH)MDL LOCK 的語句。STATE統一為Waiting for table metadata lock。

五、模擬測試

測試環境：

  • 5.7.14
  • GITD關閉
  • RR隔離級別
  • 使用指令碼： 
create table b (id int);
insert into b values(1);
set global innodb_lock_wait_timeout=1000;
UPDATE performance_schema.setup_consumers SET ENABLED = 'YES' WHERE NAME ='global_instrumentation';
UPDATE performance_schema.setup_instruments SET ENABLED = 'YES' WHERE NAME ='wait/lock/metadata/sql/mdl';
select * from performance_schema.metadata_locks\G
(請重新連線讓引數生效)

步驟如下：

session1 session2 session3 session4
--- --- use test; ---
use test;begin; delete from b; --- --- ---
--- use test;create table a asselect * from b;(由於b表innodb row lock堵塞) --- ---
--- --- show table status like 'a';(由於a表MDL LOCK堵塞) ---
--- --- --- use test(由於a表MDL LOCK堵塞)

最後我們看到的等待狀態如下： 

mysql> select id,COMMAND,STATE, INFO,TIME from information_schema.processlist;
+----+------------+---------------------------------+------------------------------------------------------------------------+------+
| id | COMMAND    | STATE                           | INFO                                                                   | TIME |
+----+------------+---------------------------------+------------------------------------------------------------------------+------+
|  9 | Query      | executing                       | select id,COMMAND,STATE, INFO,TIME from information_schema.processlist |    0 |
|  7 | Query      | Sending data                    | create table a as                                  select * from b     |   20 |
| 10 | Field List | Waiting for table metadata lock |                                                                        |   12 |
|  5 | Sleep      |                                 | NULL                                                                   |  171 |
|  6 | Query      | Waiting for table metadata lock | show table status  like 'a'                                            |   18 |
+----+------------+---------------------------------+------------------------------------------------------------------------+------+

這樣我們就完美的模擬出線上的狀態，如果我們殺掉session1中的事物，自然就全部解鎖了，同事我們看一下performance_schema.metadata_locks中的輸出： 

mysql> SELECT * FROM performance_schema.metadata_locks where object_name='a' \G
*************************** 1. row ***************************
          OBJECT_TYPE: TABLE
        OBJECT_SCHEMA: test
          OBJECT_NAME: a
OBJECT_INSTANCE_BEGIN: 140733999179328
            LOCK_TYPE: SHARED
        LOCK_DURATION: TRANSACTION
          LOCK_STATUS: GRANTED
               SOURCE: sql_parse.cc:6314
      OWNER_THREAD_ID: 40
       OWNER_EVENT_ID: 1615
*************************** 2. row ***************************
          OBJECT_TYPE: TABLE
        OBJECT_SCHEMA: test
          OBJECT_NAME: a
OBJECT_INSTANCE_BEGIN: 140733663338832
            LOCK_TYPE: SHARED_HIGH_PRIO
        LOCK_DURATION: TRANSACTION
          LOCK_STATUS: PENDING
               SOURCE: sql_base.cc:2821
      OWNER_THREAD_ID: 41
       OWNER_EVENT_ID: 1613
*************************** 3. row ***************************
          OBJECT_TYPE: TABLE
        OBJECT_SCHEMA: test
          OBJECT_NAME: a
OBJECT_INSTANCE_BEGIN: 140733797433200
            LOCK_TYPE: SHARED_HIGH_PRIO
        LOCK_DURATION: TRANSACTION
          LOCK_STATUS: PENDING
               SOURCE: sql_base.cc:2821
      OWNER_THREAD_ID: 42
       OWNER_EVENT_ID: 184

我們可以看到如上的輸出，但是需要注意LOCK_TYPE: SHARED它不可能堵塞LOCK_TYPE: SHARED_HIGH_PRIO(可以參考附錄或者我以前寫的MDL LOCK分析的文章)如上文分析這裡實際上是做了升級操作升級為了MDL_EXCLUSIVE(X)。

六、結語

  • RC模式下雖然CREATE TABLE A SELECT B中B表不會上任何INNODB ROW LOCK但是如果B表非常大那麼A表也會處於(X)保護下，因此也會觸發USE DB\SHOW TABLE STATUS等待的情況。
  • 如果開啟GTID不能使用CREATE TABLE A SELECT B這樣的語句。
  • 對於DML/DDL混用的系統一定要注意併發，就像本例中如果注意到高併發下的情況可以想辦法避免。
  • 這個案列再次說明了長期不提交的事物可能引發悲劇，所以建議監控超過N秒沒結束的事務。

七、附錄

  • MDL LOCK TYPE 
MDL_INTENTION_EXCLUSIVE(IX)
MDL_SHARED(S)
MDL_SHARED_HIGH_PRIO(SH)
MDL_SHARED_READ(SR)
MDL_SHARED_WRITE(SW)
MDL_SHARED_WRITE_LOW_PRIO(SWL)
MDL_SHARED_UPGRADABLE(SU)
MDL_SHARED_READ_ONLY(SRO)
MDL_SHARED_NO_WRITE(SNW)
MDL_SHARED_NO_READ_WRITE(SNRW)
MDL_EXCLUSIVE(X)
  • 相容性矩陣 
 Request  |  Granted requests for lock                   |
        type    | S  SH  SR  SW  SWLP  SU  SRO  SNW  SNRW  X  |
      ----------+---------------------------------------------+
      S         | +   +   +   +    +    +   +    +    +    -  |
      SH        | +   +   +   +    +    +   +    +    +    -  |
      SR        | +   +   +   +    +    +   +    +    -    -  |
      SW        | +   +   +   +    +    +   -    -    -    -  |
      SWLP      | +   +   +   +    +    +   -    -    -    -  |
      SU        | +   +   +   +    +    -   +    -    -    -  |
      SRO       | +   +   +   -    -    +   +    +    -    -  |
      SNW       | +   +   +   -    -    -   +    -    -    -  |
      SNRW      | +   +   -   -    -    -   -    -    -    -  |
      X         | -   -   -   -    -    -   -    -    -    -  |
  • 等待佇列優先順序矩陣 
 A priority matrice specified by it looks like:

       Request  |         Pending requests for lock          |
        type    | S  SH  SR  SW  SWLP  SU  SRO  SNW  SNRW  X |
      ----------+--------------------------------------------+
      S         | +   +   +   +    +    +   +    +     +   - |
      SH        | +   +   +   +    +    +   +    +     +   + |
      SR        | +   +   +   +    +    +   +    +     -   - |
      SW        | +   +   +   +    +    +   +    -     -   - |
      SWLP      | +   +   +   +    +    +   -    -     -   - |
      SU        | +   +   +   +    +    +   +    +     +   - |
      SRO       | +   +   +   -    +    +   +    +     -   - |
      SNW       | +   +   +   +    +    +   +    +     +   - |
      SNRW      | +   +   +   +    +    +   +    +     +   - |
      X         | +   +   +   +    +    +   +    +     +   + |

作者微信：


微信.jpg


來自 “ ITPUB部落格 ” ，連結：http://blog.itpub.net/7728585/viewspace-2147057/，如需轉載，請註明出處，否則將追究法律責任。

相關文章