2016-05-18 39 views
4

在GitLab CI服务器中运行包含数百个应用程序单元测试的测试套件。在运行10次测试之后,不知何故,它始终停留在等待TRUNCATE TABLE上的表元数据锁定,这是一个tearDown步骤。如何在TRUNCATE TABLE上解决MySQL innodb“等待表元数据锁定”问题?

我知道SHOW ENGINE INNODB STATUS命令。这里有一些诊断日志:

mysql> \s 
-------------- 
mysql Ver 14.14 Distrib 5.6.30, for Linux (x86_64) using EditLine wrapper 

Connection id:  190 
Current database: 
Current user:  [email protected] 
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 

现在我的问题是,为什么TRUNCATE表会卡在表metalock?如何解决这个问题?

+1

它看起来非常类似于报告的错误[这里](https://bugs.mysql.com/bug.php?id=61935)。试试'FLUSH TABLES;'看看它是否有帮助。 – alvits

+0

@alvits感谢您提供一些额外的提示!我在截断表之前尝试了'FLUSH TABLES',但它似乎没有删除表metalock :( – Devy

+0

对于那些想知道的,上面的事务列表是由SHOW ENGINE INNODB STATUS输出的(发布的内容是剪切和粘贴错过这个命令) – Luca

回答

9

这里的问题看起来很简单。

---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 

线程189(一个客户端连接)是空闲的,并且已经有一段时间了,但它已经让事务运行了。这可能是使用数据库的代码中的一个错误,因为将正在运行的事务保留近一个小时没有任何意义。

mysql> KILL 189; 

这应该释放元数据锁定......但您需要找出原因。如果应用程序的行为并不比这更好,将会发生坏事™。

另外...您的应用程序不应该连接为root。与问题无关,但不好,如果这就是这样。

+0

谢谢@ michael-sqlbot!虽然你说的很多东西都有道理,但我不知道你怎么能明确地告诉Tread 189是罪魁祸首现在只是活动时间:'ACTIVE 3047 sec'?另外,我正在使用root,因为它是一个单元测试码头容器,除了单元测试运行器外没有别的东西,所以我不太担心使用'root'(同样的原因,docker run/exec默认给你'root') – Devy

+2

它是唯一一个有正在运行的事务和已建立快照的线程,'ACTIVE'和'Trx读取视图不会看到t rx的id> = 7491,看到<7491'意味着这个连接有一个活动的读取快照,如果允许'TRUNCATE'操作继续进行,它将被销毁,所以[它不能](http://dev.mysql的.com/DOC/refman/5.7/EN /元数据locking.html)。如果有多个线程看起来像这样,我就无法分辨出哪一个线程。你没有提到你的服务器版本,但是从5.7.3开始,还有一个'performance_schema.metadata_locks'表。 –

+0

再次感谢您分享您的推理。我确实与'\ s'输出分享了我的服务器版本。它是'5.6.30 MySQL社区服务器(GPL)'。是的,我知道5.7.3中有新的'performance_schema.metadata_locks'表,但不知道它提供了多少信息。另外,为什么读取快照需要锁定?我已阅读https://bugs.mysql.com/bug.php?id=61935礼貌@alvits,但仍然没有线索为什么FLUSH TABLES在我的情况下没有工作。 – Devy