原创水平有限如有误请指出谢谢!
今天一个朋友遇到数据库遇到一个严重的故障,故障环境如下:
表现如下:
情急之下他杀掉了一大堆线程后发现还是不能恢复,最后杀掉了一个没有及时提交的事物才恢复正常。也仅仅留下了如下图的一个截图:
还是回到上图,我们可以归纳一下语句类型如下:
要分析出这个案列其实不太容易因为他是MYSQL层MDL LOCK和RR模式innodb row lock的一个综合案列,并且我们要对schema.processlist的STATE比较敏感才行。
本节关于MDL LOCK的验证使用下面两种方式:
方式1 笔者在MDL LOCK源码加锁函数处加日志输出,但是如果要分析各种语句加MDL LOCK的类型还只能用这种方式,因为MDL LOCK加锁往往一闪而过,performance_schema.metadata_locks 没有办法观察到
方式2 处于堵塞情况下performance_schema.metadata_locks的输出
关于sending data这个状态其实可以代表很多含义,从我现有的对的了解,这是MYSQL上层对SELECT类型语句的这类语句在INNODB层和MYSQL层进行数据交互的时候一个统称,所以出现它的可能包含:
同时我们还需要注意在RR模式下SELECT B这一部分加锁方式和INSERT...SELECT是一致的参考不在熬述:
这是本案例中最重要的一环,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)。
两种方式都能观察到MDL_SHARED_HIGH_PRIO(SH)的存在并且我模拟的是处于堵塞情况下的。
其被堵塞的条件除了被MDL_EXCLUSIVE(X)堵塞没有其他的可能。那么这就是一个非常重要的突破口。
这一点也是我以前不知道的,也是本案列中花时间最多的地方,前文已经分析过要让SHOW TABLE STATUS[like 'A']这种只会上MDL_SHARED_HIGH_PRIO(SH) MDL LOCK的语句堵塞在MDL LOCK上只有一种可能那就是A表上了MDL_EXCLUSIVE(X)。那么我开始
这里比较遗憾在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'] 是不会被堵塞的。
也许大家认为SELECT不会上锁,但是那是在innodb 层次,在MYSQL层会上MDL_SHARED_READ(SR) 如下:
可以看到确实有MDL_SHARED_READ(SR)的存在,当前处于堵塞状态
其兼容性如下:
显然MDL_SHARED_READ(SR) 和MDL_SHARED_HIGH_PRIO(SH)是不兼容的需要等待。
这一点很好分析因为A表上了X锁而DROP TABLE A必然上MDL_EXCLUSIVE(X)锁它当然和MDL_EXCLUSIVE(X)不兼容。如下:
其中EXCLUSIVE就是我们说的MDL_EXCLUSIVE(X)它确实存在当前处于堵塞
如果使用mysql客户端不使用-A选项(或者 no-auto-rehash)在USE DB的时候至少要做如下事情:
可以看到USE DB确实也因为MDL_SHARED_HIGH_PRIO(SH) 发生了堵塞。
那么这种情况就和SHOW TABLE STATUS[like 'A']被堵塞的情况一模一样了,也是由于MDL 锁不兼容造成的。
有了前面的分析那么我们可以梳理这个故障发生的原因如下:
测试环境:
步骤如下:
最后我们看到的等待状态如下:
这样我们就完美的模拟出线上的状态,如果我们杀掉session1中的事物,自然就全部解锁了,同事我们看一下performance_schema.metadata_locks中的输出:
我们可以看到如上的输出,但是需要注意LOCK_TYPE: SHARED它不可能堵塞LOCK_TYPE: SHARED_HIGH_PRIO(可以参考附录或者我以前写的MDL LOCK分析的文章)如上文分析这里实际上是做了升级操作升级为了MDL_EXCLUSIVE(X)。
作者微信:
一、故障描述
二、故障信息提取
其STATE为sending data
其STATE为Waiting for table metadata lock
其STATE为Waiting for table metadata lock
其STATE为Waiting for table metadata lock
三、信息分析
建议先阅读我的如下文章来学习MDL LOCK:
http://blog.itpub.net/7728585/viewspace-2143093/
打开如下:
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的分析
http://blog.itpub.net/7728585/viewspace-2146183/
从他反应的情况因为他在最后杀掉了一个长期的未提交的事物所以他因为是情况2。并且整个CREATE TABLE A AS SELECT B语句由于B表上某些数据库被上了锁而不能获取,导致整个语句处于sending data状态下。
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
*************************** 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 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 | + + + + + + + + |
怀疑这个DDL语句在语句结束之前会对A表上MDL_EXCLUSIVE(X) ,然后进行实际测试不出所料确实是这样的如下:
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
*************************** 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
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
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
Request | Granted requests for lock |
type | S SH SR SW SWLP SU SRO SNW SNRW X |
----------+---------------------------------------------+
SR | + + + + + + + + - - |
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
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
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
*************************** 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
四、分析梳理
语句会在innodb层对B表某些数据加innodb row lock。
因为RR模式下SELECT B必然对B表上满足的数据上锁,因为步骤1已经加锁所以触发等待,STATE为sending data。
因为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。
五、模拟测试
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 |
+----+------------+---------------------------------+------------------------------------------------------------------------+------+
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
六、结语
七、附录
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 | + + + + + + + + + + |