SLEEP thread causing "Waiting for table metadata lock"

SLEEP thread causing "Waiting for table metadata lock"

SLEEP thread causing "Waiting for table metadata lock"

We might have faced some scenarios once our db connection threads are getting locked and we try to find the culprit thread id which is locking the thread, to kill and release the connections. 

Here I am going to focus on one of the scenarios when db connection threads are locked at state "waiting for table metadata lock" and when we see the processlist, we can't find any thread which is running and using the same table, i.e., all threads are in SLEEP state except the locked threads.


Such as : 

mysql [localhost:5726] {msandbox} (world) > show processlist\G
*************************** 1. row ***************************
           Id: 5
         User: rsandbox
         Host: localhost:60624
           db: NULL
      Command: Binlog Dump
         Time: 111519
        State: Master has sent all binlog to slave; waiting for more updates
         Info: NULL
    Rows_sent: 0
Rows_examined: 0
*************************** 2. row ***************************
           Id: 9
         User: msandbox
         Host: localhost
           db: NULL
      Command: Sleep
         Time: 1901
        State:
         Info: NULL
    Rows_sent: 1
Rows_examined: 0
*************************** 3. row ***************************
           Id: 10
         User: msandbox
         Host: localhost
           db: world
      Command: Query
         Time: 282
        State: Waiting for table metadata lock
         Info: alter table city engine=innodb
    Rows_sent: 0
Rows_examined: 0
*************************** 4. row ***************************
           Id: 13
         User: msandbox
         Host: localhost
           db: NULL
      Command: Sleep
         Time: 645
        State:
         Info: NULL
    Rows_sent: 0
Rows_examined: 0
*************************** 5. row ***************************
           Id: 14
         User: msandbox
         Host: localhost
           db: world
      Command: Query
         Time: 0
        State: starting
         Info: show processlist
    Rows_sent: 0
Rows_examined: 0
*************************** 6. row ***************************
           Id: 17
         User: msandbox
         Host: localhost
           db: world
      Command: Sleep
         Time: 285
        State:
         Info: NULL
    Rows_sent: 0
Rows_examined: 4079
6 rows in set (0.00 sec)

mysql [localhost:5726] {msandbox} (world) >
                                                       Below I will explain about how we can troubleshoot this issue, release the locked thread and also get the transaction details of thread which was present in SLEEP state and was causing the "waiting for table metadata lock" to other threads.


Above we can see our thread id 10 is locked at state "waiting for table metadata lock" but on processlist, we can't see any other active thread which is running for table city. All other threads are present in the SLEEP state.

Here We can use below ways to find the culprit thread id which is locking the thread id 10.

A) Using InnoDB Engine Status 

-- Once we will run "show engine innodb status", here we can see there is one active transaction/thread present, and it has "24 lock struct(s), heap size 3520, 4102 row lock(s), undo log entries 1". 

mysql [localhost:5726] {msandbox} (world) > show engine innodb status\G
*
*
*
*
------------
TRANSACTIONS
------------
Trx id counter 1876
Purge done for trx's n:o < 1875 undo n:o < 0 state: running but idle
History list length 24
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 421869282924072, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421869282922944, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 421869282921816, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
---TRANSACTION 1875, ACTIVE 137 sec
24 lock struct(s), heap size 3520, 4102 row lock(s), undo log entries 1
MySQL thread id 17, OS thread handle 140394578265856, query id 5478 localhost msandbox
Trx read view will not see trx with id >= 1875, sees < 1875
*
*
*
mysql [localhost:5726] {msandbox} (world) > 

B) Using the information_schema database tables

-- We can also find the culprit thread id using the INFORMATION_SCHEMA.INNODB_TRX table.

mysql [localhost:5726] {msandbox} (information_schema) > select ps.id,ps.user,ps.host,ps.db,ps.command from information_schema.processlist ps join information_schema.INNODB_TRX itx on itx.trx_mysql_thread_id=ps.id and ps.command='Sleep';
+----+----------+-----------+-------+---------+
| id | user     | host      | db    | command |
+----+----------+-----------+-------+---------+
| 17 | msandbox | localhost | world | Sleep   |
+----+----------+-----------+-------+---------+
1 row in set (0.00 sec) 

By running the above query, we can see we have thread id 17 which is active under the INFORMATION_SCHEMA.INNODB_TRX table and currently present in SLEEP state on processlist.

C) Using information_schema and performance_schema database tables

Here it is assumed we have performance_schema enabled. 

-- By running the below query we can check the current active/open transaction as well as the list of queries executed by the current active/open transaction which will help the developer to troubleshoot the application effectively once they have the culprit thread detail with the list of queries executed by the open transaction. 

mysql [localhost:5726] {msandbox} ((none)) > SELECT   pslst.id 'PROCESS ID'  ,itrx.trx_id 'TRX_ID'     ,pesh.event_name 'EVENT NAME'     ,pesh.sql_text 'SQL'     ,th.processlist_user 'USER'     ,th.processlist_host 'HOST' FROM   information_schema.innodb_trx itrx JOIN information_schema.processlist pslst ON   itrx.trx_mysql_thread_id = pslst.id JOIN performance_schema.threads th ON   th.processlist_id = itrx.trx_mysql_thread_id JOIN performance_schema.events_statements_history pesh ON   pesh.thread_id = th.thread_id WHERE   itrx.trx_started < CURRENT_TIME - INTERVAL 100 SECOND  AND pslst.USER != 'SYSTEM_USER' GROUP BY  pesh.sql_text ORDER BY   pesh.EVENT_ID\G
*************************** 1. row ***************************
PROCESS ID: 17
    TRX_ID: 1875
EVENT NAME: statement/sql/select
       SQL: SELECT DATABASE()
      USER: msandbox
      HOST: localhost
*************************** 2. row ***************************
PROCESS ID: 17
    TRX_ID: 1875
EVENT NAME: statement/com/Init DB
       SQL: NULL
      USER: msandbox
      HOST: localhost
*************************** 3. row ***************************
PROCESS ID: 17
    TRX_ID: 1875
EVENT NAME: statement/sql/show_databases
       SQL: show databases
      USER: msandbox
      HOST: localhost
*************************** 4. row ***************************
PROCESS ID: 17
    TRX_ID: 1875
EVENT NAME: statement/sql/show_tables
       SQL: show tables
      USER: msandbox
      HOST: localhost
*************************** 5. row ***************************
PROCESS ID: 17
    TRX_ID: 1875
EVENT NAME: statement/sql/begin
       SQL: start transaction
      USER: msandbox
      HOST: localhost
*************************** 6. row ***************************
PROCESS ID: 17
    TRX_ID: 1875
EVENT NAME: statement/sql/select
       SQL: select * from city limit 2
      USER: msandbox
      HOST: localhost
*************************** 7. row ***************************
PROCESS ID: 17
    TRX_ID: 1875
EVENT NAME: statement/sql/update
       SQL: update city set Population=1780001 where Name='Kabul'
      USER: msandbox
      HOST: localhost
7 rows in set (0.01 sec)


mysql [localhost:5726] {msandbox} ((none)) > 






Above we can see we have active/open transaction id 17 which have started the transaction but not yet committed, and currently, we can see this thread is present in SLEEP state on processlist.


                                       So above we saw a couple of ways where we can find and confirm the culprit thread id which is causing for the "waiting for table metadata lock" issue.


Now once we have culprit thread id details from above, We can now KILL the culprit thread id and we can release the locked thread id.
mysql [localhost:5726] {msandbox} ((none)) > kill 17;
Query OK, 0 rows affected (0.01 sec)
mysql [localhost:5726] {msandbox} (world) > alter table city engine=innodb;
Query OK, 0 rows affected (26 min 8.17 sec)
Records: 0  Duplicates: 0  Warnings: 0
Hope this blog post will help to troubleshoot the "waiting for table metadata lock" issue once we have all other threads present in SLEEP state on processlist. 


Photo by drmakete lab on Unsplash

Comments

  1. Very well explained in simple words, really helps!
    Thanks!
    Rohan

    ReplyDelete
  2. Excellent answer ..saved my day..

    ReplyDelete
  3. Great answer but how can we prevent this from occuring?

    ReplyDelete

Post a Comment

Popular

MySQL Memory Calculator

errno: 24 - Too many open files

How to properly shutdown MySQL before any maintenance activity

How to create CentOS VM using Vagrant

set --server-id to enable either a master or a slave

ERROR 1040 (HY000): Too many connections

GTID Replication (Skip Transaction using empty transaction)

Master has purged binary logs containing GTIDs that the slave requires

How to Prepare for MySQL Certification Exam