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

Andriy,

Thanks for the excellent bug report.

Dave

Dave Cramer

dave.cramer(at)credativ(dot)ca
http://www.credativ.ca

On Fri, Jan 4, 2013 at 8:50 AM, Andriy Redko
<Andriy(dot)Redko(at)radialpoint(dot)com>wrote:

> 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.
>