Bug #63646 Statement#executeUpdate blockant
Submitted: 7 Dec 2011 11:44 Modified: 25 Mar 2013 9:58
Reporter: Francis JUGE-BOIRARD Email Updates:
Status: Can't repeat Impact on me:
None 
Category:Connector / J Severity:S3 (Non-critical)
Version:5.1.18 OS:Any
Assigned to: Alexander Soklakov CPU Architecture:Any
Tags: Thread Dump

[7 Dec 2011 11:44] Francis JUGE-BOIRARD
Description:
Lors de l'exécution de requête au bout d'un certain temps (aléatoire), l'invocation de {@code java.sql.Statement}#executeUpdate(String request) bloque complètement l'application.

Ce problème ne se produit qu'avec la version 5.1.18, j'ai testé toutes les autres versions disponible.

==================================================================================
During the execution of (after a while unpredictable) request, the invocation of {@code java.sql. Statement}#executeUpdate (String request) block(surround) completely the application.

This problem occurs only with the version 5.1.18, I tested all other versions available.

How to repeat:
Open a Statement and make a execution like this :

Statement s = ....;

for (int idx = 0; idx < 1000; idx ++)
{
  s.executeUpdate ("INSERT INTO xxx ....");
  System.console ().printf (idx + "\r");
}
[7 Dec 2011 14:07] Valeriy Kravchuk
Please, provide complete test case, including connection string.
[8 Dec 2011 7:01] Francis JUGE-BOIRARD
TestCase :

    	String urlRezo = "jdbc:mysql://hoteMySQL:portMySQL/databaseName?user=userMySQL&password=passwordMySQL;
    	Connection _connexionRezomatic = DriverManager.getConnection (urlRezo);
    	Statement _statementRezomatic = _connexionRezomatic.createStatement ();

for (int idx = 0; idx < 1000; idx ++)
{
  Statement _s = owner.getStatementRezomatic ();
  try
  {
    _s.executeUpdate ("UPDATE article SET stock=stock");
  }
  catch (SQLException s)
  {
    System.console ().printf (s.getLocalizedMessage ());
  }
  System.console ().printf (idx + "\r");
}

The code below test with :

Connector/J 3.0.17, 3.2.0, 5.0.8, 5.1.18

MySQL Server on windows 5.1.53, MySQL Server 5.1.56 on Linux (Fedora 13), MySQL 5.0.45 on Linux (Fedora 8).

He works fine in all case but HE CRASH if Connector/J 5.1.18 is used.
[8 Dec 2011 7:18] Valeriy Kravchuk
Please, send the output of:

show create table article\G

for that table used and my.cnf file content for any of servers used for testing. I wonder if there is anything suspicious in server's error log for the moment.
[8 Dec 2011 7:37] Francis JUGE-BOIRARD
Config file of MySQL on developement environment.

Attachment: my.ini (application/octet-stream, text), 5.08 KiB.

[8 Dec 2011 7:39] Francis JUGE-BOIRARD
MySQL server config on one production server

Attachment: my.cnf (application/octet-stream, text), 667 bytes.

[8 Dec 2011 7:49] Francis JUGE-BOIRARD
Le blocage peut être reproduit avec une invocation de la forme 
SELECT * FROM brv ORDER BY RAND() LIMIT 1. 
La structure de la table n'est donc pas en cause.
==============================================================
The blocking can be reproduced with an invocation like
SELECT * FROM brv ORDER BY RAND() LIMIT 1. 
The structure of the table article is not the cause.
[8 Dec 2011 7:53] Tonci Grgin
Francis, this is all not very complete...

Now, from what I see, only the deprecated c/J versions work. Does any other c/J 5.1.x work for you?
Next, I'd like to see a *complete* test case attached which produces the "crash" every time it is run. By "complete" I mean I can take it and run it so there must be a connection string, table creation etc in it. Please use bugsdb or c/J sources to check on proper test cases.
Then you say "server crash"... If there was a crash in server, we definitely need a trace of that crash, <your_server_name>.err file, and, if possible, general query log leading to "crash".
Please supply info on JVM settings too.
What is the "crash" stack trace produced by c/J?

Please provide us with as much info as possible because there are zillion installations of c/J out there that have orders of magnitude more updates than shown in your code and all works just fine so we need to dig deeper into what is happening on your side.
[8 Dec 2011 10:55] Francis JUGE-BOIRARD
The lag occurs when other process make a "SELECT" on the same statement !!!

This only true for Connector/J 5.1.18 not for all other release.
[9 Dec 2011 8:53] Francis JUGE-BOIRARD
Switch from critical to serious because the lag occurs when other process send request with de same Statement.

I prepare a complete test case and i post it.
[9 Dec 2011 8:58] Tonci Grgin
Francis, requests are serialized in server upon receiving and dealt with one by one, thus the delay. I see no crash nor anything suspicious so far...
[9 Dec 2011 23:49] Francis JUGE-BOIRARD
TestCase

Attachment: TestConnectorJ.java (application/octet-stream, text), 4.87 KiB.

[10 Dec 2011 0:00] Francis JUGE-BOIRARD
With ConnectorJ < 5.1.x the program works but throws NullPointerException.

With ConnectorJ = 5.1.x (18 for the test). The program block completely.

It is thus, in priori, not about a bug but about a change in the management of the synchronization on objects Statement.

Excuse my bad english.
[11 Dec 2011 10:35] Francis JUGE-BOIRARD
Désolé, je pense qu'il ne s'agit donc pas d'un bug, j'ai finalisé les tests et le comportement est le suivant :

Dans une application multi-thread, un Thread obtient un ResultSet, un second Thread obtient un ResultSet aussi.

Si Connector/J < 5.1.x
Lors de la lecture de ces ResultSet l'un des deux lèvera une NullPointerException. C'est là qu'est mon erreur, je n'ai pas vu dans les logs de mon application ces NullPointerException levées de temps en temps.

Si Connector/J = 5.1.x
Lors de la lecture de ces ResultSet le Thread exécutant la première lecture fonctionne, le second bloque. S'il s'agit du Thread qui est au premier plan l'application se plante complètement.
===============================================================================
TRADUCTION FRENCH->ENGLISH MADE WITH reverso.net

Saddened, I think that it is not thus about a bug, I finalized the tests and the behavior is the following one:

In an application multi - thread, Thread obtains ResultSet, the second Thread obtains ResultSet also.

If to Connector / J < 5.1.x
During the reading of these ResultSet the one both will raise NullPointerException. It is there that is my error, I did not see in the logs of my application these NullPointerException raised from time to time.

If to Connector / J = 5.1.x
During the reading of these ResultSet Thread executing the first reading works, the second blocks(surrounds). If it is about Thread which is for the foreground the application gets it all wrong completely.
[12 Dec 2011 15:13] Guilhem Bichot
Bonjour Francis. Les collègues non francophones m'ont appelé au secours. A-t'on bien compris: il n'y a plus aucun bug finalement, "circulez y-a rien à voir"?
[13 Dec 2011 6:49] Francis JUGE-BOIRARD
Je vais essayer d'être le plus clair possible.

Non, il ne s'agit pas d'un bug mais d'un curieux changement de comportement de Connector/J.

Dans mon application deux "Thread" utilisant le même Statement lise un ResultSet (c'est d’ailleurs là que se trouve mon erreur).

Si la version de Connector/J est < 5.1 le programme fonctionne bien qu'une NullPointerException soit levé lors de l'invocation de ResultSet.getXXX ().

Si la version de Connector/J est = 5.1 le programme bloque complètement.

Le bug est donc indiscutablement dans mon application mais le changement de comportement de Connector/J dans ce contexte est surprenant.
[13 Dec 2011 9:08] Guilhem Bichot
To Tonci:
Francis says that he has two threads reading using the same Statement and reading from the same ResultSet (which is a bug in his app).
He notices that the behaviour of Connector/J in this buggy case has changed:
* In connector/j < 5.1 this causes a NullPointerException when calling
ResultSet.getXXX ().
* in connector/j 5.1 this causes a hang (which, I agree, is less friendly than an exception as older versions had).

So if there's a wish here, it would be to have an exception, like older versions, instead of a hang.
[13 Dec 2011 9:19] Tonci Grgin
Thank you Francis & Guilhem, all clear now.
[13 Dec 2011 9:49] Francis JUGE-BOIRARD
Not on the same ResultSet but on the same Statement.

ex : 

Thread th1 = ..., //Runnable
       th2 = ...; //Runnable

th1.start ();
th2.start ();

Statement s = ...;

if th1 and th2 call in run method :
ResultSet r = s.executeQuery ("SELECT xxx FROM ....");
while (r.next ())
  System.out.println (r.getXXX ());

if version of Connector/J < 5.1 th1 or th2 works fine and th1 or th2 throw NullPointerException on r.getXXX ().

if version of Connector/J = 5.1 th1 or th2 works fine and th1 or th2 block completely.
[19 Dec 2011 14:45] Mark Matthews
Would it be possible to get a thread dump at the time of your deadlock? (kill -QUIT the pid of the JVM)
[20 Dec 2011 19:21] Francis JUGE-BOIRARD
My development station is under windows, kill -quit is not supported.

The dump attach to the files tab is made with jvisualvm.
[20 Dec 2011 19:21] Francis JUGE-BOIRARD
Dump Thread from test program made with jvisualvm

Attachment: threaddump-1324408497615.tdump (application/octet-stream, text), 11.23 KiB.

[25 Mar 2013 9:58] Alexander Soklakov
Hi Francis,

I was not able to reproduce deadlock with 5.1.18, 5.1.22 and 5.1.24. Also we implemented several synchronization fixes since 5.1.18, and in 5.1.24 I see the same NullPointerException as you reported for ConnectorJ < 5.1.x.

So, I'm closing this bug report as "Can't repeat". Feel free to reopen it if you find this deadlock in c/j >= 5.1.24.