Bug #40264 Aborted cached query causes query to hang indefinitely on next cache hit
Submitted: 22 Oct 2008 18:53 Modified: 13 Feb 2009 20:02
Reporter: Lucas Madar Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server: Query Cache Severity:S2 (Serious)
Version:5.0.67, 5.0 bzr OS:Any (FreeBSD 7.0-STABLE, MP; Linux)
Assigned to: Davi Arnaut CPU Architecture:Any
Triage: Triaged: D1 (Critical)

[22 Oct 2008 18:53] Lucas Madar
Description:
When query caching is enabled, large amounts of queries are sent to the server in succession, and a query is aborted, the query cache is put into a state which hangs indefinitely the next time that query is executed.

The hanging thread is identified in 'sleep' mode in the processlist; all other queries proceed normally.

Unfortunately, I am unable to test this in mysql debug mode as mysqld with debugging enabled crashes on startup on my platform.

I have made a test case which reliably causes the bug to manifest.

How to repeat:
** Step 1: Generate a table with random data. 
sql:
CREATE TABLE qc(idx integer, a integer, b integer, value float);

perl:
---------------
for($i = 0; $i < 1200000; $i++) {
   my $r1 = int(rand(2000));
   my $r2 = int(rand(1000000));
   my $r3 = int(rand(1000000));
   my $r4 = rand(100000000);

   printf "insert into qc values (%d, %d, %d, %d);\n", $r1, $r2, $r3, $r4;
}
---------------

Redirect the output of the perl script to a file and execute that sql file so you now have a junk table with random data. We don't use indexes because we want these queries to be slow.

** Step 2: Perform a bunch of queries in succession, aborting
perl:
---------------
use DBI;

# connect to mysql
my $sql = DBI->connect('DBI:mysql:database', 'username', 'password'
                   ) || die "Could not connect to database: $DBI::errstr";

srand(1234) # start out at the same state so we always make the same numbers

for($i = 0; $i < 100; $i++) {
   my $min = rand(1000);
   my $max = 1000 + rand(99000);

   my $query = sprintf "SELECT idx,val FROM qc WHERE a BETWEEN %d and %d ORDER BY b", $min, $max;
   print "Executing: $query\n";

   my $statement = $sql->prepare($query);
   $statement->execute();

   while($statement->fetch()) {
      # do nothing with results
   }

   print "... query complete\n\n";

   $statement->finish();
}

$sql->disconnect();
---------------

Repeatedly execute the program and press control-C at a similar point (~5 seconds in) to abort it. After about 5-10 tries, the program will hang on a particular query. If you abort and try again, the program hangs on the same query. Entering this query into a mysql command line client now also hangs the query.

This test seems very contrived, but the actual bug manifested itself in a server which terminated child processes executing queries if the results of the queries were no longer needed.

Suggested fix:
A temporary workaround is to disable the query cache, but this is undesirable.
[22 Oct 2008 18:54] Lucas Madar
There is a semicolon missing in the second perl script after srand(1234).
[23 Oct 2008 17:54] Sveta Smirnova
Thank you for the report.

Verified as described. 256 MB query cache is enough to repeat. Only version 5.0 is affected.
[28 Nov 2008 4:23] Svend Andersen
Could someone please clarify -- is this a problem that was introduced in 5.0.67, or does it occur in *all* versions of 5.0?
[3 Dec 2008 4:17] Svend Andersen
We've just confirmed that it seems to have been introduced around 5.0.51 -- my colleague suggested that they might be as a result of the fix for bug #30269 (removing statements that column-level access control apply to from the query cache) or bug #30201 (where KILL CONNECTION or KILL QUERY could crash the server).

(Of course, these are just guesses based on the release notes for 5.0.51.)
[29 Dec 2008 22:23] Heiko Weber
Hey Luscas, 

have you tried if frequently FLUSH TABLES or RESET QUERY CACHE can help ?
[19 Jan 2009 23:49] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/63579

2734 Davi Arnaut	2009-01-19
      Bug#40264: Aborted cached query causes query to hang indefinitely on next cache hit
      
      The problem is that the query cache was storing partial results
      if the statement failed when sending the results to the client.
      This could cause clients to hang when trying to read the results
      from the cache as they would, for example, wait indefinitely for
      a eof packet that wasn't saved.
      
      The solution is to always discard the caching of a query that
      failed to send its results to the associated client.
[22 Jan 2009 10:28] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/63797

2734 Davi Arnaut	2009-01-22
      Bug#40264: Aborted cached query causes query to hang indefinitely on next cache hit
      
      The problem is that the query cache was storing partial results
      if the statement failed when sending the results to the client.
      This could cause clients to hang when trying to read the results
      from the cache as they would, for example, wait indefinitely for
      a eof packet that wasn't saved.
      
      The solution is to always discard the caching of a query that
      failed to send its results to the associated client.
[22 Jan 2009 10:46] Davi Arnaut
Queued to 5.0-bugteam
[22 Jan 2009 11:24] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/63800

2750 Davi Arnaut	2009-01-22 [merge]
      Merge test case of Bug#40264 to mysql-5.1-bugteam
[3 Feb 2009 9:11] Bugs System
Pushed into 5.0.78 (revid:joro@sun.com-20090203090422-v91rh3gmx2ulhbu9) (version source revid:chad@mysql.com-20090126173455-ia9503yxdqi30guh) (merge vers: 5.0.77) (pib:6)
[3 Feb 2009 9:39] Bugs System
Pushed into 5.1.32 (revid:joro@sun.com-20090203090549-gos3v4320vimrzg6) (version source revid:horst@mysql.com-20090123182108-2efo5zwexcrf0h3o) (merge vers: 5.1.32) (pib:6)
[4 Feb 2009 11:14] Bugs System
Pushed into 6.0.10-alpha (revid:kostja@sun.com-20090204104420-mw1i2u9lum4bxjo6) (version source revid:davi.arnaut@sun.com-20090122122216-12ugma6vbjtschx4) (merge vers: 6.0.10-alpha) (pib:6)
[13 Feb 2009 20:02] Paul Dubois
Noted in 5.0.78, 5.1.32, 6.0.10 changelogs.

The query cache stored only partial query results if a statement
failed while the results were being sent to the client. This could
cause other clients to hang when trying to read the cached result.
Now if a statement fails, the result is not cached.
[17 Feb 2009 14:58] Bugs System
Pushed into 5.1.32-ndb-6.3.23 (revid:tomas.ulin@sun.com-20090217131017-6u8qz1edkjfiobef) (version source revid:tomas.ulin@sun.com-20090203133556-9rclp06ol19bmzs4) (merge vers: 5.1.32-ndb-6.3.22) (pib:6)
[17 Feb 2009 16:46] Bugs System
Pushed into 5.1.32-ndb-6.4.3 (revid:tomas.ulin@sun.com-20090217134419-5ha6xg4dpedrbmau) (version source revid:tomas.ulin@sun.com-20090203133556-9rclp06ol19bmzs4) (merge vers: 5.1.32-ndb-6.3.22) (pib:6)
[17 Feb 2009 18:22] Bugs System
Pushed into 5.1.32-ndb-6.2.17 (revid:tomas.ulin@sun.com-20090217134216-5699eq74ws4oxa0j) (version source revid:tomas.ulin@sun.com-20090202111723-1zzwax187rtls913) (merge vers: 5.1.32-ndb-6.2.17) (pib:6)