MySQL 5.7中如何定位DDL被阻塞的问题

测试场景

下面结合一个简单的Demo，来看看在MySQL 5.7中如何定位DDL操作的阻塞问题。

session1> begin;
Query OK, 0 rows affected (0.00 sec)
session1> delete from slowtech.t1 where id=2;
Query OK, 1 row affected (0.00 sec)
session1> select * from slowtech.t1;
+------+------+
| id   | name |
+------+------+
|    1 | a    |
+------+------+
1 row in set (0.00 sec)
session1> update slowtech.t1 set name='c' where id=1;
Query OK, 1 row affected (0.00 sec)
Rows matched: 1  Changed: 1  Warnings: 0
session2> alter table slowtech.t1 add c1 int; ##被阻塞
session3> show processlist;
+----+------+-----------+------+---------+------+---------------------------------+------------------------------------+
| Id | User | Host      | db   | Command | Time | State                           | Info                               |
+----+------+-----------+------+---------+------+---------------------------------+------------------------------------+
|  2 | root | localhost | NULL | Sleep   |   51 |                                 | NULL                               |
|  3 | root | localhost | NULL | Query   |    0 | starting                        | show processlist                   |
|  4 | root | localhost | NULL | Query   |    9 | Waiting for table metadata lock | alter table slowtech.t1 add c1 int |
+----+------+-----------+------+---------+------+---------------------------------+------------------------------------+
3 rows in set (0.00 sec)
session3> select object_type,object_schema,object_name,lock_type,lock_duration,lock_status,owner_thread_id from performance_schema.metadata_locks;
+-------------+--------------------+----------------+---------------------+---------------+-------------+-----------------+
| object_type | object_schema      | object_name    | lock_type           | lock_duration | lock_status | owner_thread_id |
+-------------+--------------------+----------------+---------------------+---------------+-------------+-----------------+
| TABLE       | slowtech           | t1             | SHARED_WRITE        | TRANSACTION   | GRANTED     |              27 |
| GLOBAL      | NULL               | NULL           | INTENTION_EXCLUSIVE | STATEMENT     | GRANTED     |              29 |
| SCHEMA      | slowtech           | NULL           | INTENTION_EXCLUSIVE | TRANSACTION   | GRANTED     |              29 |
| TABLE       | slowtech           | t1             | SHARED_UPGRADABLE   | TRANSACTION   | GRANTED     |              29 |
| TABLE       | slowtech           | t1             | EXCLUSIVE           | TRANSACTION   | PENDING     |              29 |
| TABLE       | performance_schema | metadata_locks | SHARED_READ         | TRANSACTION   | GRANTED     |              28 |
+-------------+--------------------+----------------+---------------------+---------------+-------------+-----------------+
6 rows in set (0.00 sec)

这里，重点关注lock_status，"PENDING"代表线程在等待MDL，而"GRANTED"则代表线程持有MDL。

如何找出引起阻塞的会话

结合owner_thread_id，可以可到，是29号线程在等待27号线程的MDL，此时，可kill掉52号线程。

但需要注意的是，owner_thread_id给出的只是线程ID，并不是show processlist中的ID。如果要查找线程对应的processlist id，需查询performance_schema.threads表。

session3> select * from performance_schema.threads where thread_id in (27,29)\G

*************************** 1. row ***************************

THREAD_ID: 27

NAME: thread/sql/one_connection

TYPE: FOREGROUND

PROCESSLIST_ID: 2

PROCESSLIST_USER: root

PROCESSLIST_HOST: localhost

PROCESSLIST_DB: NULL

PROCESSLIST_COMMAND: Sleep

PROCESSLIST_TIME: 214

PROCESSLIST_STATE: NULL

PROCESSLIST_INFO: NULL

PARENT_THREAD_ID: 1

ROLE: NULL

INSTRUMENTED: YES

HISTORY: YES

CONNECTION_TYPE: Socket

THREAD_OS_ID: 9800

*************************** 2. row ***************************

THREAD_ID: 29

NAME: thread/sql/one_connection

TYPE: FOREGROUND

PROCESSLIST_ID: 4

PROCESSLIST_USER: root

PROCESSLIST_HOST: localhost

PROCESSLIST_DB: NULL

PROCESSLIST_COMMAND: Query

PROCESSLIST_TIME: 172

PROCESSLIST_STATE: Waiting for table metadata lock

PROCESSLIST_INFO: alter table slowtech.t1 add c1 int

PARENT_THREAD_ID: 1

ROLE: NULL

INSTRUMENTED: YES

HISTORY: YES

CONNECTION_TYPE: Socket

THREAD_OS_ID: 9907

2 rows in set (0.00 sec)

将这两张表结合，借鉴sys.innodb_lock _waits的输出，实际上我们也可以直观地呈现MDL的等待关系。

SELECT

a.OBJECT_SCHEMA AS locked_schema,

a.OBJECT_NAME AS locked_table,

"Metadata Lock" AS locked_type,

c.PROCESSLIST_ID AS waiting_processlist_id,

c.PROCESSLIST_TIME AS waiting_age,

c.PROCESSLIST_INFO AS waiting_query,

c.PROCESSLIST_STATE AS waiting_state,

d.PROCESSLIST_ID AS blocking_processlist_id,

d.PROCESSLIST_TIME AS blocking_age,

d.PROCESSLIST_INFO AS blocking_query,

concat('KILL ', d.PROCESSLIST_ID) AS sql_kill_blocking_connection

FROM

performance_schema.metadata_locks a

JOIN performance_schema.metadata_locks b ON a.OBJECT_SCHEMA = b.OBJECT_SCHEMA

AND a.OBJECT_NAME = b.OBJECT_NAME

AND a.lock_status = 'PENDING'

AND b.lock_status = 'GRANTED'

AND a.OWNER_THREAD_ID <> b.OWNER_THREAD_ID

AND a.lock_type = 'EXCLUSIVE'

JOIN performance_schema.threads c ON a.OWNER_THREAD_ID = c.THREAD_ID

JOIN performance_schema.threads d ON b.OWNER_THREAD_ID = d.THREAD_ID\G

*************************** 1. row ***************************

locked_schema: slowtech

locked_table: t1

locked_type: Metadata Lock

waiting_processlist_id: 4

waiting_age: 259

waiting_query: alter table slowtech.t1 add c1 int

waiting_state: Waiting for table metadata lock

blocking_processlist_id: 2

blocking_age: 301

blocking_query: NULL

sql_kill_blocking_connection: KILL 2

1 row in set (0.00 sec)

输出一目了然，DDL操作如果要获得MDL，执行kill 2即可。

官方的sys.schematablelock_waits

实际上，MySQL 5.7在sys库中也集成了类似功能，同样的场景，其输出如下，

mysql> select * from sys.schema_table_lock_waits\G
*************************** 1. row ***************************
               object_schema: slowtech
                 object_name: t1
           waiting_thread_id: 29
                 waiting_pid: 4
             waiting_account: root@localhost
           waiting_lock_type: EXCLUSIVE
       waiting_lock_duration: TRANSACTION
               waiting_query: alter table slowtech.t1 add c1 int
          waiting_query_secs: 446
 waiting_query_rows_affected: 0
 waiting_query_rows_examined: 0
          blocking_thread_id: 27
                blocking_pid: 2
            blocking_account: root@localhost
          blocking_lock_type: SHARED_READ
      blocking_lock_duration: TRANSACTION
     sql_kill_blocking_query: KILL QUERY 2
sql_kill_blocking_connection: KILL 2
*************************** 2. row ***************************
               object_schema: slowtech
                 object_name: t1
           waiting_thread_id: 29
                 waiting_pid: 4
             waiting_account: root@localhost
           waiting_lock_type: EXCLUSIVE
       waiting_lock_duration: TRANSACTION
               waiting_query: alter table slowtech.t1 add c1 int
          waiting_query_secs: 446
 waiting_query_rows_affected: 0
 waiting_query_rows_examined: 0
          blocking_thread_id: 29
                blocking_pid: 4
            blocking_account: root@localhost
          blocking_lock_type: SHARED_UPGRADABLE
      blocking_lock_duration: TRANSACTION
     sql_kill_blocking_query: KILL QUERY 4
sql_kill_blocking_connection: KILL 4
2 rows in set (0.00 sec)

具体分析下官方的输出，

只有一个alter table操作，却产生了两条记录，而且两条记录的kill对象竟然还不一样，对表结构不熟悉及不仔细看记录内容的话，难免会kill错对象。

不仅如此，如果有N个查询被DDL操作堵塞，则会产生N*2条记录。在阻塞操作较多的情况下，这N*2条记录完全是个噪音。

而之前的SQL，无论有多少操作被阻塞，一个alter table操作，就只会输出一条记录。

如何查看阻塞会话已经执行过的操作

但上面这个 SQL 也有遗憾，其blocking_query为NULL，而在会话1中，其明明已经执行了三个SQL。

这个与performance_schema.threads（类似于show processlist）有关，其只会输出当前正在运行的SQL，对于已经执行过的，实际上是没办法看到。

但在线上，kill是一个需要谨慎的操作，毕竟你很难知道kill的是不是业务关键操作？又或者，是个批量update操作？那么，有没有办法抓到该事务之前的操作呢？

答案，有。

即Performance Schema中记录Statement Event（操作事件）的表，具体包括events_statements_current,events_statements_history,events_statements_history_long,prepared_statements_instances。

常用的是前面三个。

三者的表结构完全一致，其中，events_statements_history又包含了events_statements_current的操作，所以我们这里会使用events_statements_history。

终极SQL如下，

SELECT

locked_schema,

locked_table,

locked_type,

waiting_processlist_id,

waiting_age,

waiting_query,

waiting_state,

blocking_processlist_id,

blocking_age,

substring_index(sql_text,"transaction_begin;" ,-1) AS blocking_query,

sql_kill_blocking_connection

FROM

(

SELECT

b.OWNER_THREAD_ID AS granted_thread_id,

a.OBJECT_SCHEMA AS locked_schema,

a.OBJECT_NAME AS locked_table,

"Metadata Lock" AS locked_type,

c.PROCESSLIST_ID AS waiting_processlist_id,

c.PROCESSLIST_TIME AS waiting_age,

c.PROCESSLIST_INFO AS waiting_query,

c.PROCESSLIST_STATE AS waiting_state,

d.PROCESSLIST_ID AS blocking_processlist_id,

d.PROCESSLIST_TIME AS blocking_age,

d.PROCESSLIST_INFO AS blocking_query,

concat('KILL ', d.PROCESSLIST_ID) AS sql_kill_blocking_connection

FROM

performance_schema.metadata_locks a

JOIN performance_schema.metadata_locks b ON a.OBJECT_SCHEMA = b.OBJECT_SCHEMA

AND a.OBJECT_NAME = b.OBJECT_NAME        AND a.lock_status = 'PENDING'

AND b.lock_status = 'GRANTED'        AND a.OWNER_THREAD_ID <> b.OWNER_THREAD_ID

AND a.lock_type = 'EXCLUSIVE'        JOIN performance_schema.threads c ON a.OWNER_THREAD_ID = c.THREAD_ID

JOIN performance_schema.threads d ON b.OWNER_THREAD_ID = d.THREAD_ID

) t1,

(

SELECT

thread_id,

group_concat(  CASE WHEN EVENT_NAME = 'statement/sql/begin' THEN "transaction_begin" ELSE sql_text END ORDER BY event_id SEPARATOR ";" ) AS sql_text

FROM

performance_schema.events_statements_history

GROUP BY thread_id

) t2

WHERE

t1.granted_thread_id = t2.thread_id \G

*************************** 1. row ***************************

locked_schema: slowtech

locked_table: t1

locked_type: Metadata Lock

waiting_processlist_id: 4

waiting_age: 294

waiting_query: alter table slowtech.t1 add c1 int

waiting_state: Waiting for table metadata lock

blocking_processlist_id: 2

blocking_age: 336

blocking_query: delete from slowtech.t1 where id=2;select * from slowtech.t1;update slowtech.t1 set name='c' where id=1

sql_kill_blocking_connection: KILL 21 row in set, 1 warning (0.00 sec)

从上面的输出可以看到，blocking_query中包含了会话1中当前事务的所有操作，按执行的先后顺序输出。

需要注意的是，默认情况下，events_statements_history只会保留每个线程最近的10个操作，如果事务中进行的操作较多，实际上也是没办法抓全的。

Anyway, it is better than nothing！

Linux公社的RSS地址： https://www.linuxidc.com/rssFeed.aspx

本文永久更新链接地址： https://www.linuxidc.com/Linux/2018-09/154059.htm