Bug #29393 MySQL Server is locked because of a "flush query cache" on heavy load
Submitted: 27 Jun 2007 16:07 Modified: 17 Jul 2007 1:18
Reporter: Frédéric Dhieux Email Updates:
Status: Duplicate Impact on me:
None 
Category:MySQL Server: Locking Severity:S1 (Critical)
Version:5.0.41 OS:Linux (X86_64 binary)
Assigned to: CPU Architecture:Any

[27 Jun 2007 16:07] Frédéric Dhieux
Description:
Hi,

Sometimes when an application runs a "/*!40000 FLUSH QUERY CACHE */" on my MySQL server, this one lock forever. CPU usage goes to 100% occupation for MySQL Server and this situation lead to a "too many connection" situation.

The query never ends and after 8 hours there is no change, it si always running. The only way to resolve the problem is to kill the query in MySQL console as root.

this problem is present since the web application increased is traffic, but there is no change in the queries used by the application.

The problem is present in the version 5.0.27 too.

Thank you for your help, this problem is critical for the web application running on this plateform because of the lock caused by this problem.

Note : with many MySQL server in replication mode, the same query randomly locks some of the servers when the query is played. Slave servers are read only so there only "SELECT" queries on them during the lock.

How to repeat:
- generate an heavy trafic on a 50 GB database with 2000 queries/s on 3000 tables in 60 databases.
- Launch "/*!40000 FLUSH QUERY CACHE */" on MySQL Server during the heavy load until the query lock.

It's difficult to reproduce, because the bug comes randomly ( about 1 time for 6 try on my server ) and need a heavy load context.
[27 Jun 2007 18:55] Sveta Smirnova
Thank you for the report.

Please provide output of statements SHOW GLOBAL VARIABLES LIKE 'query_cache%'; and SHOW GLOBAL STATUS LIKE 'Qcache%';
[28 Jun 2007 10:13] Frédéric Dhieux
mysql1> SHOW GLOBAL VARIABLES LIKE 'query_cache%';
+------------------------------+-----------+
| Variable_name                | Value     |
+------------------------------+-----------+
| query_cache_limit            | 2097152   |
| query_cache_min_res_unit     | 4096      |
| query_cache_size             | 268435456 |
| query_cache_type             | ON        |
| query_cache_wlock_invalidate | OFF       |
+------------------------------+-----------+
5 rows in set (0.00 sec)

mysql1> SHOW GLOBAL STATUS LIKE 'Qcache%';
+-------------------------+-----------+
| Variable_name           | Value     |
+-------------------------+-----------+
| Qcache_free_blocks      | 39679     |
| Qcache_free_memory      | 132175992 |
| Qcache_hits             | 8932226   |
| Qcache_inserts          | 3314332   |
| Qcache_lowmem_prunes    | 772643    |
| Qcache_not_cached       | 1585865   |
| Qcache_queries_in_cache | 90620     |
| Qcache_total_blocks     | 222362    |
+-------------------------+-----------+
8 rows in set (0.00 sec)

I can provide some graphs between 2007-06-26 06:30 and 2007-06-27 21:30 :

http://sly.peer.fr/mysql-bug/graphs/mysql1/day-myext_Qcache_free_blocks.png
http://sly.peer.fr/mysql-bug/graphs/mysql1/day-myext_Qcache_free_memory.png
http://sly.peer.fr/mysql-bug/graphs/mysql1/day-myext_Qcache_hits.png
http://sly.peer.fr/mysql-bug/graphs/mysql1/day-myext_Qcache_inserts.png
http://sly.peer.fr/mysql-bug/graphs/mysql1/day-myext_Qcache_lowmem_prun.png
http://sly.peer.fr/mysql-bug/graphs/mysql1/day-myext_Qcache_not_cached.png
http://sly.peer.fr/mysql-bug/graphs/mysql1/day-myext_Qcache_q_incache.png
http://sly.peer.fr/mysql-bug/graphs/mysql1/day-myext_Qcache_total_blocks.png

Crash at 17:14 the 27th

FLUSH QUERY CACHE query at :
070627  9:18:48
070627  9:33:14
070627  9:55:46
070627 11:06:01
070627 14:27:55
070627 14:36:26
070627 14:47:14
070627 14:53:36
070627 15:51:26
070627 15:56:59
070627 16:04:40
070627 16:09:48
070627 16:15:06
070627 16:24:23
070627 16:34:26
070627 16:39:27
070627 17:14:41 -> Lock

Heavy load begins at about 17:00.
[17 Jul 2007 1:18] Adam Dixon
This bug looks to be a duplicate; http://bugs.mysql.com/bug.php?id=21074