How to solve MySQL innodb "Waiting for table metadata lock" on TRUNCATE TABLE?

Question

Running a test suite with hundreds of application unit tests in a GitLab CI server. After ran 10 tests in, somehow it always gets stuck on Waiting for table metadata lock on TRUNCATE TABLE, which is a tearDown step.

I am aware of the SHOW ENGINE INNODB STATUS command . Here are some diagnostic logs:

mysql> \s -------------- mysql  Ver 14.14 Distrib 5.6.30, for Linux (x86_64) using  EditLine wrapper  Connection id:      190 Current database:    Current user:       root@localhost SSL:            Not in use Current pager:      stdout Using outfile:      '' Using delimiter:    ; Server version:     5.6.30 MySQL Community Server (GPL) Protocol version:   10 Connection:     Localhost via UNIX socket Server characterset:    utf8mb4 Db     characterset:    utf8mb4 Client characterset:    utf8mb4 Conn.  characterset:    utf8mb4 UNIX socket:        /var/run/mysqld/mysqld.sock Uptime:         51 min 28 sec  Threads: 4  Questions: 3859  Slow queries: 0  Opens: 715  Flush tables: 1  Open tables: 131  Queries per second avg: 1.249 --------------  mysql> show processlist; +-----+------+----------------+------------+---------+------+---------------------------------+-----------------------------+ | Id  | User | Host           | db         | Command | Time | State                           | Info                        | +-----+------+----------------+------------+---------+------+---------------------------------+-----------------------------+ |   1 | root | 10.0.2.1:52773 | test_3926  | Query   | 2961 | Waiting for table metadata lock | TRUNCATE TABLE `capability` | | 188 | root | 10.0.2.1:53658 | test_3926  | Sleep   | 2962 |                                 | NULL                        | | 189 | root | 10.0.2.1:53660 | test_3926  | Sleep   | 2962 |                                 | NULL                        | | 190 | root | localhost      | NULL       | Query   |    0 | init                            | show processlist            | +-----+------+----------------+------------+---------+------+---------------------------------+-----------------------------+ 4 rows in set (0.00 sec)   2016-05-18 16:10:37 7f03be9ba700 INNODB MONITOR OUTPUT ===================================== Per second averages calculated from the last 7 seconds ----------------- BACKGROUND THREAD ----------------- srv_master_thread loops: 126 srv_active, 0 srv_shutdown, 3047 srv_idle srv_master_thread log flush and writes: 3173 ---------- SEMAPHORES ---------- OS WAIT ARRAY INFO: reservation count 2408 OS WAIT ARRAY INFO: signal count 2525 Mutex spin waits 988, rounds 24557, OS waits 747 RW-shared spins 1339, rounds 45580, OS waits 1518 RW-excl spins 3, rounds 5283, OS waits 113 Spin rounds per wait: 24.86 mutex, 34.04 RW-shared, 1761.00 RW-excl ------------ TRANSACTIONS ------------ Trx id counter 7574 Purge done for trx's n:o < 7493 undo n:o < 0 state: running but idle History list length 778 LIST OF TRANSACTIONS FOR EACH SESSION: ---TRANSACTION 0, not started MySQL thread id 190, OS thread handle 0x7f03be9ba700, query id 3941 localhost root init SHOW ENGINE INNODB STATUS ---TRANSACTION 7489, not started MySQL thread id 188, OS thread handle 0x7f03bea3c700, query id 3824 10.0.2.1 root cleaning up ---TRANSACTION 7548, not started MySQL thread id 1, OS thread handle 0x7f03bea7d700, query id 3855 10.0.2.1 root Waiting for table metadata lock TRUNCATE TABLE `capability` ---TRANSACTION 7490, ACTIVE 3047 sec MySQL thread id 189, OS thread handle 0x7f03be9fb700, query id 3840 10.0.2.1 root cleaning up Trx read view will not see trx with id >= 7491, sees < 7491 -------- FILE I/O -------- I/O thread 0 state: waiting for completed aio requests (insert buffer thread) I/O thread 1 state: waiting for completed aio requests (log thread) I/O thread 2 state: waiting for completed aio requests (read thread) I/O thread 3 state: waiting for completed aio requests (read thread) I/O thread 4 state: waiting for completed aio requests (read thread) I/O thread 5 state: waiting for completed aio requests (read thread) I/O thread 6 state: waiting for completed aio requests (write thread) I/O thread 7 state: waiting for completed aio requests (write thread) I/O thread 8 state: waiting for completed aio requests (write thread) I/O thread 9 state: waiting for completed aio requests (write thread) Pending normal aio reads: 0 [0, 0, 0, 0] , aio writes: 0 [0, 0, 0, 0] ,  ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0 Pending flushes (fsync) log: 0; buffer pool: 0 173 OS file reads, 6858 OS file writes, 6022 OS fsyncs 0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s ------------------------------------- INSERT BUFFER AND ADAPTIVE HASH INDEX ------------------------------------- Ibuf: size 1, free list len 0, seg size 2, 0 merges merged operations:  insert 0, delete mark 0, delete 0 discarded operations:  insert 0, delete mark 0, delete 0 Hash table size 276671, node heap has 2 buffer(s) 0.00 hash searches/s, 0.00 non-hash searches/s --- LOG --- Log sequence number 10549488 Log flushed up to   10549488 Pages flushed up to 10549488 Last checkpoint at  10549488 0 pending log writes, 0 pending chkp writes 2555 log i/o's done, 0.00 log i/o's/second ---------------------- BUFFER POOL AND MEMORY ---------------------- Total memory allocated 137363456; in additional pool allocated 0 Dictionary memory allocated 545426 Buffer pool size   8191 Free buffers       7354 Database pages     835 Old database pages 288 Modified db pages  0 Pending reads 0 Pending writes: LRU 0, flush list 0, single page 0 Pages made young 4257, not young 0 0.00 youngs/s, 0.00 non-youngs/s Pages read 160, created 4341, written 863 0.00 reads/s, 0.00 creates/s, 0.00 writes/s No buffer pool page gets since the last printout Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s LRU len: 835, unzip_LRU len: 0 I/O sum[0]:cur[0], unzip sum[0]:cur[0] -------------- ROW OPERATIONS -------------- 0 queries inside InnoDB, 0 queries in queue 1 read views open inside InnoDB Main thread process no. 1, id 139654053570304, state: sleeping Number of rows inserted 1187, updated 37, deleted 0, read 650 0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s ---------------------------- END OF INNODB MONITOR OUTPUT 

Now my question is, why TRUNCATE table would get stuck on table metalock? And how can this be resolved?

Answer 1

The problem here seems straightforward enough.

---TRANSACTION 7490, ACTIVE 3047 sec MySQL thread id 189, OS thread handle 0x7f03be9fb700, query id 3840 10.0.2.1 root cleaning up Trx read view will not see trx with id >= 7491, sees < 7491 --- 

Thread 189 (a client connection) is idle, and as been for a while, but it has left a transaction running. This is probably a bug in the code that's using the database, since it doesn't make sense to leave a running transaction going for almost an hour.

mysql> KILL 189; 

That should release the metadata lock... but you need to find out why this is happening. Bad Things™ will happen if an application doesn't behave better than this.

Also... your application should not be connecting as root. Not related to the problem, but not good, if that's what this is.