Run a test suite with hundreds of application module tests on the CI GitLab server. After running 10 tests, it somehow always gets stuck waiting for the table metadata to be locked on TRUNCATE TABLE, which is a tearDown step.
I know the team SHOW ENGINE INNODB STATUS. 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 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 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 did the TRUNCATE table get stuck on the table? And how can this be solved?