閱讀364 返回首頁    go 技術社區[雲棲]


USE DB導致MySQL大堵塞故障?

一、故障描述

今天一個朋友遇到數據庫遇到一個嚴重的故障,故障環境如下:

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

表現如下:

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


情急之下他殺掉了一大堆線程後發現還是不能恢複,最後殺掉了一個沒有及時提交的事物才恢複正常。也僅僅留下了如下圖的一個截圖:

2dca64667fdf354f0bebb057f2c536812fb5c7f8

二、故障信息提取

還是回到上圖,我們可以歸納一下語句類型如下:

  • 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:
https://blog.itpub.net/7728585/viewspace-2143093/

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

方式1,筆者在MDL LOCK源碼加鎖函數處加日誌輸出,如果要分析各種語句加MDL LOCK的類型還隻能用這種方式,因為MDL LOCK加鎖往往一閃而過,performance_schema.metadata_locks 沒有辦法觀察到。
方式2,處於堵塞情況下使用5.7版本的performance_schema.metadata_locks觀察。

在P_S中打開mdl監測方法如下:


mysql> UPDATE performance_schema.setup_consumers SET ENABLED = 'YES' WHERE NAME ='global_instrumentation';
mysql> UPDATE performance_schema.setup_instruments SET ENABLED = 'YES' WHERE NAME ='wait/lock/metadata/sql/mdl';
mysql> 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是一致的參考不再贅述:
https://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
(請重新連接讓參數生效)


步驟如下:

5a1e3556dbe3125bdd497ebc543b2272af619ec6

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表也會處於MDL_EXCLUSIVE(X)保護下,因此也會觸發USE DB\SHOW TABLE STATUS等待的情況。
  • 如果打開GTID不能使用CREATE TABLE A SELECT B這樣的語句。
  • 對於DML/DDL混用的係統一定要注意並發,就像本例中如果注意到高並發下的情況可以想辦法避免。
  • 這個案列再次說明了長期不提交的事物可能引發悲劇,所以建議監控超過N秒沒結束的事務。
  • 使用MySQL Cli客戶端連接時,記得加上 -A(no-auto-rehash)選項,或者用gui客戶端連接時,也關閉自動獲取meta data選項,避免造成MDL鎖。(葉師傅補充)



七、附錄

  • 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         | +   +   +   +    +    +   +    +     +   + |

原文發布時間為:2017-11-11
本文作者:高鵬(重慶八怪)
本文來自雲棲社區合作夥伴“老葉茶館”,了解相關信息可以關注“老葉茶館”微信公眾號


最後更新:2017-11-13 16:34:12

  上一篇:go  阿裏雲推出應用配置管理新工具 助力企業效能幾何式提升
  下一篇:go  ICCV2017 論文解讀:基於圖像檢索的行人重識別 | PaperDaily #13