enterprise-support team mailing list archive

[Valerii Kravchuk <valerii.kravchuk@xxxxxxxxxxx>]

This was easy enough to verify with PS 5.6.24. While sysbench was
running, I tried:

[openxs@centos ~]$ mysql -uroot test
Reading table information for completion of table and column names
You can turn off this feature to get a quicker startup with -A

Welcome to the MySQL monitor.  Commands end with ; or \g.
Your MySQL connection id is 1
Server version: 5.6.24-72.2-log Percona Server (GPL), Release 72.2, Revision 8d0f85b

Copyright (c) 2009-2015 Percona LLC and/or its affiliates
Copyright (c) 2000, 2015, Oracle and/or its affiliates. All rights reserved.

Oracle is a registered trademark of Oracle Corporation and/or its
affiliates. Other names may be trademarks of their respective
owners.

Type 'help;' or '\h' for help. Type '\c' to clear the current input
statement.

mysql> create table app(id int primary key);
Query OK, 0 rows affected (0.97 sec)

mysql> flush tables app for export;
Query OK, 0 rows affected (0.01 sec)

mysql> flush tables app for export;
ERROR 1192 (HY000): Can't execute the given command because you have active locked tables or an active transaction
mysql> unlock tables;
Query OK, 0 rows affected (0.00 sec)

mysql> flush tables app for export;
Query OK, 0 rows affected (0.00 sec)

mysql> unlock tables;
Query OK, 0 rows affected (0.00 sec)

mysql> flush tables app for export;

... and now it hanged. In other session we can see:

mysql> show processlist;
+----+------+-----------+------+---------+------+-------------+------------------------------------------------------------------------------------------------------+-----------+---------------+
| Id | User | Host      | db   | Command | Time | State       | Info                                                                                                 | Rows_sent | Rows_examined |
+----+------+-----------+------+---------+------+-------------+------------------------------------------------------------------------------------------------------+-----------+---------------+
|  1 | root | localhost | test | Query   |   76 | System lock | flush tables app for export                                                                          |         0 |             0 |
|  2 | root | localhost | test | Query   |    2 | update      | INSERT INTO sbtest1(k, c, pad) VALUES(2513807, '05488995274-59078070332-49503422272-20145529088-7820 |         0 |             0 |
|  3 | root | localhost | test | Query   |    0 | init        | show processlist                                                                                     |         0 |             0 |
+----+------+-----------+------+---------+------+-------------+------------------------------------------------------------------------------------------------------+-----------+---------------+
3 rows in set (0.01 sec)

and, indeed, at this time change buffer is used:

mysql> show engine innodb status\G
*************************** 1. row ***************************
  Type: InnoDB
  Name:
Status:
=====================================
2015-05-25 19:50:21 7f345b658700 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 37 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 166 srv_active, 0 srv_shutdown, 146 srv_idle
srv_master_thread log flush and writes: 312
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 4144
--Thread 139862099334912 has waited at buf0flu.cc line 1858 for 1.0000 seconds the semaphore:
Mutex at 0x7f3457badbe8 '&buf_pool->flush_state_mutex', lock var 1
waiters flag 1
--Thread 139862848673536 has waited at buf0buf.cc line 1886 for 1.0000 seconds the semaphore:
Mutex at 0x7f3457badaa8 '&buf_pool->LRU_list_mutex', lock var 1
waiters flag 1
OS WAIT ARRAY INFO: signal count 3827
Mutex spin waits 1340, rounds 40736, OS waits 1137
RW-shared spins 1759, rounds 54488, OS waits 760
RW-excl spins 200, rounds 67536, OS waits 2164
Spin rounds per wait: 30.40 mutex, 30.98 RW-shared, 337.68 RW-excl
------------
TRANSACTIONS
------------
Trx id counter 123819
Purge done for trx's n:o < 123752 undo n:o < 0 state: stopped
History list length 215
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0, not started
MySQL thread id 3, OS thread handle 0x7f345b658700, query id 138 localhost root init
show engine innodb status
---TRANSACTION 0, not started
MySQL thread id 1, OS thread handle 0x7f345b6da700, query id 81 localhost root System lock
flush tables app for export
---TRANSACTION 123818, ACTIVE 1 sec inserting
mysql tables in use 1, locked 1
1 lock struct(s), heap size 360, 0 row lock(s), undo log entries 1081
MySQL thread id 2, OS thread handle 0x7f345b699700, query id 137 localhost root update
INSERT INTO sbtest1(k, c, pad) VALUES(2520188, '23265171360-40256758300-76422825425-13580470856-20610876655-51059683997-20531291710-60899682120-24328394273-84119137420', '53620872615-59974842661-44683850061-54412224416-74849613198'),(2476861, '86696909084-02479793694-51170576190-45122155285-89858238887-68479987794-32082721316-60674682103-56050409979-52868593074', '09988394520-20659103006-21980839252-20858888383-30008858837'),(2488714, '66342712639-57030167917-87404020530-99067237210-80875833843-84157380906-03751940334-97032191790-84280038367-03049564210', '79326798778-33162785414-08336700839-4
--------
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: complete io for buf page (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: 1
2565 OS file reads, 11860 OS file writes, 1368 OS fsyncs
11.81 reads/s, 16384 avg bytes/read, 74.11 writes/s, 8.19 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 6, free list len 99, seg size 106, 1109 merges
merged operations:
 insert 21452, delete mark 0, delete 0
discarded operations:
 insert 0, delete mark 0, delete 0
843.33 hash searches/s, 53876.54 non-hash searches/s
...

see "size 6" above.

** Also affects: percona-server/5.6
   Importance: Undecided
       Status: New

** Changed in: percona-server/5.6
       Status: New => Confirmed

-- 
You received this bug notification because you are a member of Ubuntu
Server/Client Support Team, which is subscribed to MySQL.
Matching subscriptions: Ubuntu Server/Client Support Team
https://bugs.launchpad.net/bugs/1454441

Title:
  Hanging "System Lock" when executing "flush table ... for export"

To manage notifications about this bug go to:
https://bugs.launchpad.net/mysql-server/+bug/1454441/+subscriptions