Bug report: buggy implementation of setQueryTimeout() in latest JDBC drivers 9.2-100x (AbstractJdbc2Statement.java)

Hey guys,

We have discovered a very weird issues caused by, it turned out, buggy implementation of setQueryTimeout() in latest JDBC drivers 9.2-100x.
Database version is PostgreSQL 9.2.1 (PostgreSQL 9.2.1 on x86_64-unknown-linux-gnu, compiled by gcc (GCC) 4.1.2 20080704 (Red Hat 4.1.2-52), 64-bit.
Application uses Hibernate 3.5.3 and JDBC connection pooling (Apache Tomcat JDBC pool implementation).

The problem:
Random query cancellations with following messages in PostgreSQL log file

.....
2013-01-02 21:00:47 EST xxx xxx localhost.localdomain(51074) localhost.localdomain ERROR: canceling statement due to user request
2013-01-02 21:01:13 EST [unknown] [unknown] localhost.localdomain(46983) localhost.localdomain DEBUG: processing cancel request: sending SIGINT to process 473
2013-01-02 21:01:13 EST xxx xxx localhost.localdomain(51074) localhost.localdomain ERROR: canceling statement due to user request
2013-01-02 21:01:14 EST [unknown] [unknown] localhost.localdomain(46990) localhost.localdomain DEBUG: processing cancel request: sending SIGINT to process 473
2013-01-02 21:01:14 EST xxx xxx localhost.localdomain(51074) localhost.localdomain ERROR: canceling statement due to user request
2013-01-02 21:01:19 EST [unknown] [unknown] localhost.localdomain(47044) localhost.localdomain DEBUG: processing cancel request: sending SIGINT to process 473
....

The consequences:
Random SQL query failures on application side (Java 1.7, postgresql-9.2-1001.jdbc4.jar)

The cause:
We have figured out that issue has been cause by implementation of setQueryTimeout(), specifically when SQL exception is being raised during query execution.
The code in question is AbstractJdbc2Statement.java (line 555):

...
connection.getQueryExecutor().execute(queryToExecute,
queryParameters,
handler,
maxrows,
fetchSize,
flags);
if ( cancelTimer != null )
{
cancelTimer.cancel();
cancelTimer=null;
}
...

Whenever SQL exception is raised, the cancelTimer hasn't been cancelled and stays alive. Because we are using JDBC connection pooling connection behind is not closed but returned to the pool.
Later on, when cancelTimer triggers, it randomly cancels the query currently associated with the connection this timer has been created with. At this moment, it's a totally different query which explains the randomness effect.
The suggested fix for this particular problem is using try / finally construct and cancel timer anyway.

Workaround:
Give up on setQueryTimeout(), use PostgreSQL configuration instead (statement_timeout). It doesn't provide same level of flexibility but at least always works.

The additional notes:
Looking through implementation also showed up another problem with setQueryTimeout(), AbstractJdbc2Statement.java (line 724):

...
cancelTimer = new TimerTask() {
public void run()
{
try {
AbstractJdbc2Statement.this.cancel();
} catch (SQLException e) {
}
}
};

Driver.addTimerTask( cancelTimer, seconds * 1000);
...

What if the prepared statement has been created but never executed (for whatever reasons)? Same issue will happen: timer won't be cancelled and will cause the same random query cancellation later on.
Please feel free to contact in case you need any additional details on that.

Thanks a lot.

Best Regards,
Andriy Redko

*********************************************************************** This e-mail and attachments are confidential, legally privileged, may be subject to copyright and sent solely for the attention of the addressee(s). Any unauthorized use or disclosure is prohibited. Statements and opinions expressed in this e-mail may not represent those of Radialpoint. ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ Le contenu du présent courriel est confidentiel, privilégié et peut être soumis à des droits d'auteur. Il est envoyé à l'intention exclusive de son ou de ses destinataires. Il est interdit de l'utiliser ou de le divulguer sans autorisation. Les opinions exprimées dans le présent courriel peuvent diverger de celles de Radialpoint.