mysql觀測METADATA LOCK(MDL)鎖

背景描述

某天在給一個小表加欄位的時候，一直拿不到鎖，報錯：

ERROR 1205 (HY000): Lock wait timeout exceeded; try restarting transaction

期間show processlist檢視，ddl在等待MDL鎖。MySQL 的 Metadata Lock 機制是為了保護併發訪問資料物件的一致性，並且showps也看不到活動的事務。

如何查到MDL鎖的源頭呢？innodb_locks是看不到MDL鎖的資訊的。performance_schema下面有一張表叫metadata_locks

mysql> desc metadata_locks;


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


| Field                 | Type                | Null | Key | Default | Extra |


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


| OBJECT_TYPE           | varchar(64)         | NO   |     | NULL    |       |


| OBJECT_SCHEMA         | varchar(64)         | YES  |     | NULL    |       |


| OBJECT_NAME           | varchar(64)         | YES  |     | NULL    |       |


| OBJECT_INSTANCE_BEGIN | bigint(20) unsigned | NO   |     | NULL    |       |


| LOCK_TYPE             | varchar(32)         | NO   |     | NULL    |       |


| LOCK_DURATION         | varchar(32)         | NO   |     | NULL    |       |


| LOCK_STATUS           | varchar(32)         | NO   |     | NULL    |       |


| SOURCE                | varchar(64)         | YES  |     | NULL    |       |


| OWNER_THREAD_ID       | bigint(20) unsigned | YES  |     | NULL    |       |


| OWNER_EVENT_ID        | bigint(20) unsigned | YES  |     | NULL    |       |


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


10 rows in set (0.00 sec)

預設需要開啟metadata 的 instrument，才能拿到MDL鎖的資訊。

call sys.ps_setup_enable_instrument('wait/lock/metadata/sql/mdl%')


或者：


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';

開啟後重新執行DDL語句，然後觀測

mysql> select * from performance_schema.metadata_locks where object_name='t'\G


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


          OBJECT_TYPE: TABLE


        OBJECT_SCHEMA: ming


          OBJECT_NAME: t


OBJECT_INSTANCE_BEGIN: 87772208


            LOCK_TYPE: SHARED_READ


        LOCK_DURATION: TRANSACTION


          LOCK_STATUS: GRANTED


               SOURCE: 


      OWNER_THREAD_ID: 29


       OWNER_EVENT_ID: 990


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


          OBJECT_TYPE: TABLE


        OBJECT_SCHEMA: ming


          OBJECT_NAME: t


OBJECT_INSTANCE_BEGIN: 140151695148016


            LOCK_TYPE: SHARED_UPGRADABLE


        LOCK_DURATION: TRANSACTION


          LOCK_STATUS: GRANTED


               SOURCE: 


      OWNER_THREAD_ID: 31


       OWNER_EVENT_ID: 178


*************************** 3. row ***************************


          OBJECT_TYPE: TABLE


        OBJECT_SCHEMA: ming


          OBJECT_NAME: t


OBJECT_INSTANCE_BEGIN: 140151695148992


            LOCK_TYPE: EXCLUSIVE


        LOCK_DURATION: TRANSACTION


          LOCK_STATUS: PENDING


               SOURCE: 


      OWNER_THREAD_ID: 31


       OWNER_EVENT_ID: 237


3 rows in set (0.00 sec)

可以看到已經會話被授予（GRANTED）了SHARED_READ型別的MDL鎖。DDL會話先被授予了SHARED_UPGRADABLE，然後需要被授予EXCLUSIVE的鎖，但是拿不到，所以處於PENDING狀態。所以只要找到GRANTED的會話是哪個，然後殺掉就可以了。

   MDL_SHARED_READ,


  /*


    A shared metadata lock for cases when there is an intention to modify


    (and not just read) data in the table.


    A connection holding SW lock can read table metadata and modify or read


    table data (after acquiring appropriate table and row-level locks).


    To be used for tables to be modified by INSERT, UPDATE, DELETE


    statements, but not LOCK TABLE ... WRITE or DDL). Also taken by


    SELECT ... FOR UPDATE.


  */


 MDL_SHARED_UPGRADABLE,


  /*


    A shared metadata lock for cases when we need to read data from table


    and block all concurrent modifications to it (for both data and metadata).


    Used by LOCK TABLES READ statement.

通過perforamnce_schema.threads查詢：

mysql> select * from performance_schema.threads where thread_id=29\G 


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


          THREAD_ID: 29


               NAME: thread/sql/one_connection


               TYPE: FOREGROUND


     PROCESSLIST_ID: 2


   PROCESSLIST_USER: root


   PROCESSLIST_HOST: localhost


     PROCESSLIST_DB: ming


PROCESSLIST_COMMAND: Sleep


   PROCESSLIST_TIME: 107


  PROCESSLIST_STATE: NULL


   PROCESSLIST_INFO: NULL


   PARENT_THREAD_ID: 1


               ROLE: NULL


       INSTRUMENTED: YES


            HISTORY: YES


    CONNECTION_TYPE: Socket


       THREAD_OS_ID: 2822


1 row in set (0.00 sec)

取processlist_id，kill掉該會話即可。

mysql> kill 2;


Query OK, 0 rows affected (0.00 sec)





mysql> alter table t add c4 int;


Query OK, 0 rows affected (3 min 58.00 sec)


Records: 0  Duplicates: 0  Warnings: 0

檢視pstack： 阻塞源頭

Thread 9 (Thread 0x7f77c3043700 (LWP 2822)):


#0  0x00007f77f1debf0d in poll () from /lib64/libc.so.6


#1  0x00000000012c48df in vio_io_wait (vio=<optimized out>, event=<optimized out>, timeout=28800000) at /export/home/pb2/build/sb_0-32013917-1545390211.74/mysql-5.7.25/vio/viosocket.c:786


#2  0x00000000012c49d3 in vio_socket_io_wait (vio=<optimized out>, event=<optimized out>) at /export/home/pb2/build/sb_0-32013917-1545390211.74/mysql-5.7.25/vio/viosocket.c:77


#3  0x00000000012c5008 in vio_read (vio=0x505ab10, buf=0x5372800 "\001", size=4) at /export/home/pb2/build/sb_0-32013917-1545390211.74/mysql-5.7.25/vio/viosocket.c:132


#4  0x0000000000c6e4a3 in net_read_raw_loop (net=0x50683f8, count=4) at /export/home/pb2/build/sb_0-32013917-1545390211.74/mysql-5.7.25/sql/net_serv.cc:672


#5  0x0000000000c6ed3b in net_read_packet_header (net=0x50683f8) at /export/home/pb2/build/sb_0-32013917-1545390211.74/mysql-5.7.25/sql/net_serv.cc:756


#6  net_read_packet (net=<optimized out>, complen=0x7f77c3042cf8) at /export/home/pb2/build/sb_0-32013917-1545390211.74/mysql-5.7.25/sql/net_serv.cc:822


#7  0x0000000000c6efec in my_net_read (net=0x50683f8) at /export/home/pb2/build/sb_0-32013917-1545390211.74/mysql-5.7.25/sql/net_serv.cc:899


#8  0x0000000000c7c88c in Protocol_classic::read_packet (this=0x5067c98) at /export/home/pb2/build/sb_0-32013917-1545390211.74/mysql-5.7.25/sql/protocol_classic.cc:808


#9  0x0000000000c7b622 in Protocol_classic::get_command (this=0x5067c98, com_data=0x7f77c3042da0, cmd=0x7f77c3042dcc) at /export/home/pb2/build/sb_0-32013917-1545390211.74/mysql-5.7.25/sql/protocol_classic.cc:965


#10 0x0000000000d1e3d7 in do_command (thd=0x5066c40) at /export/home/pb2/build/sb_0-32013917-1545390211.74/mysql-5.7.25/sql/sql_parse.cc:964


#11 0x0000000000defb14 in handle_connection (arg=<optimized out>) at /export/home/pb2/build/sb_0-32013917-1545390211.74/mysql-5.7.25/sql/conn_handler/connection_handler_per_thread.cc:306


#12 0x000000000125d3f4 in pfs_spawn_thread (arg=0x50008f0) at /export/home/pb2/build/sb_0-32013917-1545390211.74/mysql-5.7.25/storage/perfschema/pfs.cc:2190


#13 0x00007f77f333ce25 in start_thread () from /lib64/libpthread.so.0


#14 0x00007f77f1df6bad in clone () from /lib64/libc.so.6

被阻塞者：

Thread 7 (Thread 0x7f77c2fdf700 (LWP 2869)):
#0  0x00007f77f3340d42 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1  0x0000000000c67d40 in native_cond_timedwait (abstime=0x7f77c2fda790, mutex=0x7f779c000b78, cond=0x7f779c000ba8) at /export/home/pb2/build/sb_0-32013917-1545390211.74/mysql-5.7.25/include/thr_cond.h:129
#2  my_cond_timedwait (abstime=0x7f77c2fda790, mp=0x7f779c000b78, cond=0x7f779c000ba8) at /export/home/pb2/build/sb_0-32013917-1545390211.74/mysql-5.7.25/include/thr_cond.h:182
#3  inline_mysql_cond_timedwait (src_line=1861, src_file=0x140f5d0 "/export/home/pb2/build/sb_0-32013917-1545390211.74/mysql-5.7.25/sql/mdl.cc", abstime=0x7f77c2fda790, mutex=0x7f779c000b78, that=0x7f779c000ba8) at /export/home/pb2/build/sb_0-32013917-1545390211.74/mysql-5.7.25/include/mysql/psi/mysql_thread.h:1229
#4  MDL_wait::timed_wait (this=0x7f779c000b78, owner=0x7f779c000ae0, abs_timeout=0x7f77c2fda790, set_status_on_timeout=false, wait_state_name=<optimized out>) at /export/home/pb2/build/sb_0-32013917-1545390211.74/mysql-5.7.25/sql/mdl.cc:1861
#5  0x0000000000c6a917 in MDL_context::acquire_lock (this=0x7f779c000b78, mdl_request=0x7f77c2fda810, lock_wait_timeout=<optimized out>) at /export/home/pb2/build/sb_0-32013917-1545390211.74/mysql-5.7.25/sql/mdl.cc:3655
#6  0x0000000000c6b68f in MDL_context::upgrade_shared_lock (this=0x7f779c000b78, mdl_ticket=0x7f779c0103f0, new_type=MDL_EXCLUSIVE, lock_wait_timeout=31536000) at /export/home/pb2/build/sb_0-32013917-1545390211.74/mysql-5.7.25/sql/mdl.cc:3919
#7  0x0000000000d82ad7 in mysql_inplace_alter_table (thd=0x7f779c000ae0, table_list=0x7f779c005fe0, table=0x7f779c01af60, altered_table=0x7f779c068980, ha_alter_info=0x7f77c2fdc1e0, inplace_supported=HA_ALTER_INPLACE_NO_LOCK_AFTER_PREPARE, target_mdl_request=0x7f77c2fdc9a0, alter_ctx=0x7f77c2fdac40) at /export/home/pb2/build/sb_0-32013917-1545390211.74/mysql-5.7.25/sql/sql_table.cc:7449
#8  0x0000000000d8550e in mysql_alter_table (thd=0x7f779c000ae0, new_db=0x7f779c068980 "\360\222\006\234w\177", new_name=0x7f77c2fdc1e0 "\300\323\375\302w\177", create_info=0x7f77c2fdd3c0, table_list=0x7f779c005fe0, alter_info=0x7f77c2fdd4c0) at /export/home/pb2/build/sb_0-32013917-1545390211.74/mysql-5.7.25/sql/sql_table.cc:9798
#9  0x0000000000e8de2c in Sql_cmd_alter_table::execute (this=<optimized out>, thd=0x7f779c000ae0) at /export/home/pb2/build/sb_0-32013917-1545390211.74/mysql-5.7.25/sql/sql_alter.cc:327
#10 0x0000000000d17f2a in mysql_execute_command (thd=0x7f779c000ae0, first_level=true) at /export/home/pb2/build/sb_0-32013917-1545390211.74/mysql-5.7.25/sql/sql_parse.cc:4835
#11 0x0000000000d1c3fd in mysql_parse (thd=0x7f779c000ae0, parser_state=<optimized out>) at /export/home/pb2/build/sb_0-32013917-1545390211.74/mysql-5.7.25/sql/sql_parse.cc:5570
#12 0x0000000000d1d625 in dispatch_command (thd=0x7f779c000ae0, com_data=0x7f77c2fdeda0, command=COM_QUERY) at /export/home/pb2/build/sb_0-32013917-1545390211.74/mysql-5.7.25/sql/sql_parse.cc:1484
#13 0x0000000000d1e4d4 in do_command (thd=0x7f779c000ae0) at /export/home/pb2/build/sb_0-32013917-1545390211.74/mysql-5.7.25/sql/sql_parse.cc:1025
#14 0x0000000000defb14 in handle_connection (arg=<optimized out>) at /export/home/pb2/build/sb_0-32013917-1545390211.74/mysql-5.7.25/sql/conn_handler/connection_handler_per_thread.cc:306
#15 0x000000000125d3f4 in pfs_spawn_thread (arg=0x5d629c0) at /export/home/pb2/build/sb_0-32013917-1545390211.74/mysql-5.7.25/storage/perfschema/pfs.cc:2190
#16 0x00007f77f333ce25 in start_thread () from /lib64/libpthread.so.0

來自 “ ITPUB部落格 ” ，連結：http://blog.itpub.net/31480688/viewspace-2700737/，如需轉載，請註明出處，否則將追究法律責任。