Mysql:从一个USE DB堵塞故障展开的探讨

 

感谢lixiaxin200319

http://blog.itpub.net/21582653/viewspace-2149061/

 

原创水平有限如有误请指出谢谢!


一、故障描述

今天一个朋友遇到数据库遇到一个严重的故障,故障环境如下:

  • 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
(请重新连接让参数生效) 

步骤如下:

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

作者微信:

 

 

http://blog.itpub.net/7728585/viewspace-2143093/


----涉及代码:mdl.h mdl.cc

但是笔者通过增加一个TICKET的打印函数让语句的MDL LOCK加锁流程全部打印出来方便学习研究


/*p_ticket in parameter*/
int my_print_ticket(const MDL_ticket* p_ticket)
并且在mdl_ticket类中增加了这个函数原型为友元函数,否则私有成员获取不到,而给出的公有方法比较繁杂
friend int my_print_ticket(const MDL_ticket* p_ticket);


主要获取MDL LOCK的如下信息打印到mysql err日志中:

posted @ 2020-05-15 15:54  feiyun8616  阅读(255)  评论(0编辑  收藏  举报