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 :
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) >
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.
Very well explained in simple words, really helps!
ReplyDeleteThanks!
Rohan
Thanks Rohan!
DeleteExcellent answer ..saved my day..
ReplyDeleteGreat answer but how can we prevent this from occuring?
ReplyDelete