天天看點

mysql卡住如何定位_MySQL 5.7中如何定位DDL被阻塞的問題

在配置檔案中設定

[mysqld]performance-schema-instrument='wait/lock/metadata/sql/mdl=ON'

測試場景

下面結合一個簡單的Demo,來看看在MySQL 5.7中如何定位DDL操作的阻塞問題。

session1> begin;

Query OK,0 rows affected (0.00sec)

session1> delete from slowtech.t1 where id=2;

Query OK,1 row affected (0.00sec)

session1> select * fromslowtech.t1;+------+------+

| id | name |

+------+------+

| 1 | a |

+------+------+

1 row in set (0.00sec)

session1> update slowtech.t1 set name='c' where id=1;

Query OK,1 row affected (0.00sec)

Rows matched:1 Changed: 1 Warnings: 0session2> 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.00sec)

session3> select object_type,object_schema,object_name,lock_type,lock_duration,lock_status,owner_thread_id fromperformance_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:27NAME: thread/sql/one_connection

TYPE: FOREGROUND

PROCESSLIST_ID:2PROCESSLIST_USER: root

PROCESSLIST_HOST: localhost

PROCESSLIST_DB:NULLPROCESSLIST_COMMAND: Sleep

PROCESSLIST_TIME:214PROCESSLIST_STATE:NULLPROCESSLIST_INFO:NULLPARENT_THREAD_ID:1ROLE:NULLINSTRUMENTED: YES

HISTORY: YES

CONNECTION_TYPE: Socket

THREAD_OS_ID:9800

*************************** 2. row ***************************THREAD_ID:29NAME: thread/sql/one_connection

TYPE: FOREGROUND

PROCESSLIST_ID:4PROCESSLIST_USER: root

PROCESSLIST_HOST: localhost

PROCESSLIST_DB:NULLPROCESSLIST_COMMAND: Query

PROCESSLIST_TIME:172PROCESSLIST_STATE: Waitingfor tablemetadata lock

PROCESSLIST_INFO:alter table slowtech.t1 add c1 intPARENT_THREAD_ID:1ROLE:NULLINSTRUMENTED: YES

HISTORY: YES

CONNECTION_TYPE: Socket

THREAD_OS_ID:9907

2 rows in set (0.00 sec)

将這兩張表結合,借鑒sys.innodb_lock _waits的輸出,實際上我們也可以直覺地呈現MDL的等待關系。

SELECTa.OBJECT_SCHEMAASlocked_schema,

a.OBJECT_NAME ASlocked_table,

"Metadata Lock"ASlocked_type,

c.PROCESSLIST_IDASwaiting_processlist_id,

c.PROCESSLIST_TIMEASwaiting_age,

c.PROCESSLIST_INFOASwaiting_query,

c.PROCESSLIST_STATEASwaiting_state,

d.PROCESSLIST_IDASblocking_processlist_id,

d.PROCESSLIST_TIMEASblocking_age,

d.PROCESSLIST_INFOASblocking_query,

concat('KILL', d.PROCESSLIST_ID) ASsql_kill_blocking_connectionFROMperformance_schema.metadata_locks aJOIN performance_schema.metadata_locks b ON a.OBJECT_SCHEMA =b.OBJECT_SCHEMAAND a.OBJECT_NAME = b.OBJECT_NAME

AND a.lock_status = 'PENDING'

AND b.lock_status = 'GRANTED'

AND a.OWNER_THREAD_ID <>b.OWNER_THREAD_IDAND a.lock_type = 'EXCLUSIVE'

JOIN performance_schema.threads c ON a.OWNER_THREAD_ID =c.THREAD_IDJOIN 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:4waiting_age:259waiting_query:alter table slowtech.t1 add c1 intwaiting_state: Waitingfor tablemetadata lock

blocking_processlist_id:2blocking_age:301blocking_query:NULLsql_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 * fromsys.schema_table_lock_waits\G*************************** 1. row ***************************object_schema: slowtechobject_name: t1

waiting_thread_id:29waiting_pid:4waiting_account: [email protected]_lock_type: EXCLUSIVE

waiting_lock_duration:TRANSACTIONwaiting_query:alter table slowtech.t1 add c1 intwaiting_query_secs:446waiting_query_rows_affected:0waiting_query_rows_examined:0blocking_thread_id:27blocking_pid:2blocking_account: [email protected]_lock_type: SHARED_READ

blocking_lock_duration:TRANSACTIONsql_kill_blocking_query:KILL QUERY 2sql_kill_blocking_connection:KILL 2

*************************** 2. row ***************************object_schema: slowtechobject_name: t1

waiting_thread_id:29waiting_pid:4waiting_account: [email protected]_lock_type: EXCLUSIVE

waiting_lock_duration:TRANSACTIONwaiting_query:alter table slowtech.t1 add c1 intwaiting_query_secs:446waiting_query_rows_affected:0waiting_query_rows_examined:0blocking_thread_id:29blocking_pid:4blocking_account: [email protected]_lock_type: SHARED_UPGRADABLE

blocking_lock_duration:TRANSACTIONsql_kill_blocking_query:KILL QUERY 4sql_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。

常用的是前面三個。

mysql卡住如何定位_MySQL 5.7中如何定位DDL被阻塞的問題

三者的表結構完全一緻,其中,events_statements_history又包含了events_statements_current的操作,是以我們這裡會使用events_statements_history。

終極SQL如下,

SELECTlocked_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) ASblocking_query,

sql_kill_blocking_connectionFROM(SELECTb.OWNER_THREAD_IDASgranted_thread_id,

a.OBJECT_SCHEMAASlocked_schema,

a.OBJECT_NAME ASlocked_table,

"Metadata Lock"ASlocked_type,

c.PROCESSLIST_IDASwaiting_processlist_id,

c.PROCESSLIST_TIMEASwaiting_age,

c.PROCESSLIST_INFOASwaiting_query,

c.PROCESSLIST_STATEASwaiting_state,

d.PROCESSLIST_IDASblocking_processlist_id,

d.PROCESSLIST_TIMEASblocking_age,

d.PROCESSLIST_INFOASblocking_query,

concat('KILL', d.PROCESSLIST_ID) ASsql_kill_blocking_connectionFROMperformance_schema.metadata_locks aJOIN performance_schema.metadata_locks b ON a.OBJECT_SCHEMA =b.OBJECT_SCHEMAAND a.OBJECT_NAME = b.OBJECT_NAME

AND a.lock_status = 'PENDING'

AND b.lock_status = 'GRANTED'

AND a.OWNER_THREAD_ID <>b.OWNER_THREAD_IDAND a.lock_type = 'EXCLUSIVE'

JOIN performance_schema.threads c ON a.OWNER_THREAD_ID =c.THREAD_IDJOIN performance_schema.threads d ON b.OWNER_THREAD_ID =d.THREAD_ID

) t1,

(SELECTthread_id,

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

) t2WHEREt1.granted_thread_id=t2.thread_id \G*************************** 1. row ***************************locked_schema: slowtech

locked_table: t1

locked_type: Metadata Lock

waiting_processlist_id:4waiting_age:294waiting_query:alter table slowtech.t1 add c1 intwaiting_state: Waitingfor tablemetadata lock

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

1 row in set, 1 warning (0.00 sec)

從上面的輸出可以看到,blocking_query中包含了會話1中目前事務的所有操作,按執行的先後順序輸出。

需要注意的是,預設情況下,events_statements_history隻會保留每個線程最近的10個操作,如果事務中進行的操作較多,實際上也是沒辦法抓全的。

Anyway, it is better than nothing!