MySQL Bugs: #64700: Deadlock during Connection.close()

Bug #64700	Deadlock during Connection.close()
Submitted:	20 Mar 2012 3:25	Modified:	24 Jul 2012 15:48
Reporter:	Przemek Bruski	Email Updates:
Status:	Won't fix	Impact on me:	None
Category:	Connector / J	Severity:	S2 (Serious)
Version:	5.1.18	OS:	Any
Assigned to:	Alexander Soklakov	CPU Architecture:	Any

Description:
We've encountered the following deadlock:

Found one Java-level deadlock:
=============================
"com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2":
  waiting to lock monitor 0x0000000051fc80e8 (object 0x0000000630b58a98, a com.mysql.jdbc.JDBC4Connection),
  which is held by "com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1"
"com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1":
  waiting to lock monitor 0x0000000050bdc548 (object 0x0000000630b70490, a com.mysql.jdbc.JDBC4ResultSet),
  which is held by "com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2"

Java stack information for the threads listed above:
===================================================
"com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2":
        at com.mysql.jdbc.ConnectionImpl.getCharacterSetMetadata(ConnectionImpl.java:2798)
        - waiting to lock <0x0000000630b58a98> (a com.mysql.jdbc.JDBC4Connection)
        at com.mysql.jdbc.Field.getStringFromBytes(Field.java:710)
        at com.mysql.jdbc.Field.getOriginalName(Field.java:652)
        at com.mysql.jdbc.ResultSetImpl.buildIndexMapping(ResultSetImpl.java:749)
        at com.mysql.jdbc.ResultSetImpl.findColumn(ResultSetImpl.java:1108)
        - locked <0x0000000630b70490> (a com.mysql.jdbc.JDBC4ResultSet)
        at com.mysql.jdbc.DatabaseMetaData$9.forEach(DatabaseMetaData.java:5030)
        at com.mysql.jdbc.IterateBlock.doForAll(IterateBlock.java:51)
        at com.mysql.jdbc.DatabaseMetaData.getTables(DatabaseMetaData.java:4962)
        at com.mchange.v2.c3p0.impl.DefaultConnectionTester.activeCheckConnectionNoQuery(DefaultConnectionTester.java:185)
        at com.mchange.v2.c3p0.impl.DefaultConnectionTester.activeCheckConnection(DefaultConnectionTester.java:62)
        at com.mchange.v2.c3p0.AbstractConnectionTester.activeCheckConnection(AbstractConnectionTester.java:67)
        at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.testPooledConnection(C3P0PooledConnectionPool.java:368)
        at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.refurbishIdleResource(C3P0PooledConnectionPool.java:310)
        at com.mchange.v2.resourcepool.BasicResourcePool$AsyncTestIdleResourceTask.run(BasicResourcePool.java:1999)
        at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:547)
"com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1":
        at com.mysql.jdbc.ResultSetImpl.realClose(ResultSetImpl.java:7477)
        - waiting to lock <0x0000000630b70490> (a com.mysql.jdbc.JDBC4ResultSet)
        at com.mysql.jdbc.ResultSetImpl.close(ResultSetImpl.java:907)
        at com.mysql.jdbc.StatementImpl.realClose(StatementImpl.java:2478)
        - locked <0x0000000630b70540> (a com.mysql.jdbc.StatementImpl)
        at com.mysql.jdbc.ConnectionImpl.closeAllOpenStatements(ConnectionImpl.java:1584)
        at com.mysql.jdbc.ConnectionImpl.realClose(ConnectionImpl.java:4364)
        at com.mysql.jdbc.ConnectionImpl.close(ConnectionImpl.java:1556)
        - locked <0x0000000630b58a98> (a com.mysql.jdbc.JDBC4Connection)
        at com.mchange.v2.c3p0.impl.NewPooledConnection.close(NewPooledConnection.java:549)
        at com.mchange.v2.c3p0.impl.NewPooledConnection.close(NewPooledConnection.java:234)
        - locked <0x0000000630b5a0f0> (a com.mchange.v2.c3p0.impl.NewPooledConnection)
        at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.destroyResource(C3P0PooledConnectionPool.java:470)
        at com.mchange.v2.resourcepool.BasicResourcePool$1DestroyResourceTask.run(BasicResourcePool.java:964)
        at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:547)

How to repeat:
You could probably stress test it out. But the stack traces look pretty much self-explanatory.

Suggested fix:
Maybe making sure that a Connection is always locked when a ResultSet is locked?

The driver used to do just that, and c3p0 would deadlock itself too then. Getting database metadata, and grabbing a table list isn't the best "live" check in the world, it can be very expensive. You can probably get better performance from "preferredTestQuery=/* ping */ SELECT 1" in your C3p0 configuration.

If you still must use c3p0's getTables() connection test method, I'd suggest adding "useDynamicCharsetInfo=false" to your JDBC url to see if it clears up this problem? (it will prevent the driver from having to issue a query to produce this result set).

You may also consider talking to the c3p0 maintainers, and have them handle tear-down of connections when the pool is closing down or expiring them by using the abort() method on Connection. It was put there just for this purpose.

Viable workaround.

I am using c3p0-0.9.1 and/or MySQL Connector/J 5.1.22 and getting the exact same issue. Following is the details of jstack from my tomcat:

Found one Java-level deadlock:
=============================

"com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2":
  waiting to lock Monitor@0x00000000075a8e60 (Object@0x00000000c2604040, a com/mysql/jdbc/JDBC4Connection),
  which is held by "com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0"
"com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0":
  waiting to lock Monitor@0x00000000075a8488 (Object@0x00000000c2616238, a com/mysql/jdbc/JDBC4ResultSet),
  which is held by "com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2"

This causes my application to break, is there a way to resolve this? Status says Won't fix?

Thanks
Triguna

I am not sure if this deadlock is during Connection.close as jstack did not give me any such information.

Mark Matthews, there's no abort on java.sql.Connection (only in JDBC4). Also since MySQL connector implementation does synchronization, it would be nice if the order of obtaining locks was fixed, just like Przemek Bruski recommended. For other deadlock cases, which you mentioned, there need to be separate tickets.