Bug #25836 Query execution which timed out not always throws MySQLTimeoutException
Submitted: 24 Jan 2007 18:19 Modified: 22 Feb 2007 15:19
Reporter: Damián Arregui
Status: Closed
Category:Connector/J Severity:S2 (Serious)
Version:5.0.4 OS:
Assigned to: Target Version:

[24 Jan 2007 18:19] Damián Arregui
Description:
Consider a JDBC statement and a query execution method such as Statement.executeUpdate().
If we associate a timeout to the statement via Statement.setQueryTimeout() and if the
query execution does time out, Statement.executeUpdate() should throw a
MySQLTimeoutException. This is not always the case.

The problem comes from a race condition between the client thread calling
Statement.executeUpdate() and the anonymous "cancel thread" in CancelTask.run().

The "cancel thread" successfully executes line 104 of Statement.java:

cancelStmt.execute("KILL QUERY " + connectionId);

This unblocks the client thread in Statement.executeUpdate(), which goes through the
following code:

if (this.wasCancelled) {
    this.wasCancelled = false;
    throw new MySQLTimeoutException();
}

But since the value of wasCancelled is false, it does not throw an exception.

Only then, the "cancel thread" executes line 105 of Statement.java:

wasCancelled = true;

But it's too late!

How to repeat:
Use a Java debugger. Put a break point at line 105 of Statement.java.

Create a statement and set a timeout so that the timeout will be reached.

Execute the statement.

The statement will be cancelled via "KILL QUERY" but the client will not get any
exception.

Suggested fix:
Once a statement is being cancelled, its execution should not return before the outcome
of the cancel operation is known.
[5 Feb 2007 12:55] Tonci Grgin
Hi Damián and thanks for your report. 

I can agree with you on race condition but I'm not sure how this should be treated since
on subsequent access to canceled statement you will get "Query execution was interrupted"
which is descriptive enough. However, I'll set this to "Verified" so that others may take
a look.

Extract from general query log (dnevnik is just a rather large table)
070205 12:24:42	     10 Connect     root@localhost on solusd
		     10 Query       SHOW VARIABLES
		     10 Query       SHOW COLLATION
		     10 Query       SET character_set_results = NULL
		     10 Query       SET autocommit=1
		     10 Query       SET sql_mode='STRICT_TRANS_TABLES'
		     10 Query       SELECT VERSION()
		     10 Query       Select * FROM dnevnik
070205 12:24:47	     11 Connect     root@localhost on solusd
		     11 Query       SHOW VARIABLES
		     11 Query       SHOW COLLATION
		     11 Query       SET character_set_results = NULL
		     11 Query       SET autocommit=1
		     11 Query       SET sql_mode='STRICT_TRANS_TABLES'
		     11 Query       KILL QUERY 10
		     11 Quit       
070205 12:27:44	     10 Quit
[5 Feb 2007 19:45] 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/19333
[22 Feb 2007 15:19] MC Brown
A note has been added to the 5.0.5 changelog.