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