Bug #11615 Synchronization problem in realClose
Submitted: 28 Jun 2005 17:29 Modified: 2 Aug 2005 18:14
Reporter: Tony Walker Email Updates:
Status: Closed Impact on me:
None 
Category:Connector / J Severity:S3 (Non-critical)
Version:3.1.10 OS:Microsoft Windows (Windows XP)
Assigned to: Mark Matthews CPU Architecture:Any

[28 Jun 2005 17:29] Tony Walker
Description:
Bug in mysql-connector-java-3.1.10:

There appears to be a synchronization bug in com.mysql.jdbc.ServerPreparedStatement at line 870.  

This is a multi-threading bug and appears intermittently when trying to close down the MySQL database using C3P0 connection pooling.

The stack trace is:

Throwable NullPointerException.
java.lang.NullPointerException
	at com.mysql.jdbc.ServerPreparedStatement.realClose(ServerPreparedStatement.java:870)
	at com.mysql.jdbc.ServerPreparedStatement.close(ServerPreparedStatement.java:453)
	at com.mchange.v1.db.sql.StatementUtils.attemptClose(StatementUtils.java:41)
	at com.mchange.v2.c3p0.stmt.GooGooStatementCache$1.run(GooGooStatementCache.java:266)
	at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:366)

The problem appears to be in the realClose method, which has a synchronized
block at line 869.  The relevant code is:

867		if (calledExplicitly) {
868			try {
869				synchronized (this.connection.getMutex()) {
870					MysqlIO mysql = this.connection.getIO();
871
872					Buffer packet = mysql.getSharedSendPacket();
873
874					packet.writeByte((byte) MysqlDefs.COM_CLOSE_STATEMENT);
875					packet.writeLong(this.serverStatementId);
876
877					mysql.sendCommand(MysqlDefs.COM_CLOSE_STATEMENT, null,
878							packet, true, null);
879				}
880			} catch (SQLException sqlEx) {
881				exceptionDuringClose = sqlEx;
882			}
883		}
884
885		clearParametersInternal(false);
886		this.parameterBindings = null;
887
888		this.parameterFields = null;
889		this.resultFields = null;
890
891		super.realClose(calledExplicitly);

A thread obtains the mutex at this.connection.getMutex() (line 869) and then fails at the next line because this.connection is null.  The problem is caused by the fact that the call to super.realClose at line 891 is outside the synchronized block and this call results in the connection being set to null.  Thus, a thread that has  just exited the synchronized block can set the connection to null while the next thread is acquiring the mutex.  Once that thread acquires the mutex, it will fail at the next statement.

How to repeat:
Do until error appears {
  open connection using C3P0 pooling;
  do somenting with connection;
  close C3P0 pooling
}

In my application it appears quite frequently -- somewhere between 1 in 2 and 1 in 3 executions.

Suggested fix:
Put the call to super.realClose inside the synchronized block?  I haven't investigated what other problems this might cause.
[13 Jul 2005 14:24] James Sangroniz
Saw a very similar failure, but on a different line. Here's the top of the stack trace
java.lang.NullPointerException
	at com.mysql.jdbc.ServerPreparedStatement.realClose(ServerPreparedStatement.java:1089)
	at com.mysql.jdbc.Connection.closeAllOpenStatements(Connection.java:2879)
	at com.mysql.jdbc.Connection.realClose(Connection.java:2086)
	at com.mysql.jdbc.Connection.close(Connection.java:1060)
Happens very infrequently, but is bothersom.
[13 Jul 2005 14:56] Mark Matthews
A fix for this has been checked in, and is in the nightly snapshot builds at http://downloads.mysql.com/snapshots.php#connector-j

I'd appreciate it if you could let me know if a binary from the snapshot build shows the same behavior (it shouldn't).

Thanks,

  -Mark
[7 Aug 2005 13:18] Tony Walker
Sorry for the delay in replying -- I've just got back to testing with MySQL.  The bug appears to be gone.  I haven't been able to reproduce it in several tests -- many more than it took previously.

Thanks,

Tony