| Bug #1955 | deadlock in LogicalConnection and MySqlPooledConnection | ||
|---|---|---|---|
| Submitted: | 25 Nov 2003 16:12 | Modified: | 28 Mar 2014 13:36 |
| Reporter: | Quartz 12h | Email Updates: | |
| Status: | Can't repeat | Impact on me: | |
| Category: | Connector / J | Severity: | S1 (Critical) |
| Version: | 3.0.9, 3.0.8, ...? | OS: | Any |
| Assigned to: | Alexander Soklakov | CPU Architecture: | Any |
[26 Nov 2003 14:37]
Quartz 12h
also experienced with 3.0.8
[26 Nov 2003 15:25]
Mark Matthews
Are you using the same PooledConnectionDataSource from two different threads, and calling getConnection() from each thread? I need a way to repeat the behavior, so either a testcase, or a complete explanation of what your code is doing would help, here.
[28 Nov 2003 7:27]
Quartz 12h
(I though I did explain the code... anyway)
the single piece of code is very simple. Given a single PooledConnection shared between threads, the code calls getConnection() to grab a logical connection.
Then it work with it, some statement etc... then call the logical connection .close().
Connection c = null
try {
c = this.sharedpooledConn.getConnection();
//work with c
} finally {
c.close();
}
Put a sleep if you want to increase time separation between getConnection and close(). You got the 2 thread stack to proove how the deadlock happen. I cannot be more precise.
[2 Dec 2003 9:19]
Mark Matthews
Please the latest nightly snapshot build of 3.0 from http://downloads.mysql.com/snapshots.php as the synchronization has been re-worked to (hopefully) avoid this problem.
[29 Jul 2009 13:01]
Ingo Siebert
We encountered the same problem several times with MySQL driver 5.1.6. That's quite critical, I wonder why this bug is still open. I'm quite sure it also exists in newer releases. We fixed it now and I upload a test case which reproduces the problem within seconds and I upload the fix as diff file. I hope you apply the patch to your trunk. First fix part: the synchronized keywords for methods of MysqlPooledConnection are removed and replaces by a synchronized block with a new lock object. Second fix part: The second fix part is that the ConnectionEventListeners are called outside the of the sychronization with the help of a snapshot copy of all listeners. Stacktraces of our deadlock: Name: Timer-3 State: BLOCKED on com.mysql.jdbc.jdbc2.optional.MysqlPooledConnection@51acd5cc owned by: pool-1-thread-1 Total blocked: 38 Total waited: 120.774 Stack trace: com.mysql.jdbc.jdbc2.optional.MysqlPooledConnection.getConnection(MysqlPooledConnection.java:153) org.apache.commons.dbcp.datasources.KeyedCPDSConnectionFactory.validateObject(KeyedCPDSConnectionFactory.java:195) org.apache.commons.pool.impl.GenericKeyedObjectPool.evict(GenericKeyedObjectPool.java:1489) org.apache.commons.pool.impl.GenericKeyedObjectPool$Evictor.run(GenericKeyedObjectPool.java:1750) java.util.TimerThread.mainLoop(Timer.java:512) java.util.TimerThread.run(Timer.java:462) name: pool-1-thread-1 State: BLOCKED on org.apache.commons.pool.impl.GenericKeyedObjectPool@46244cd7 owned by: Timer-3 Total blocked: 1.784.777 Total waited: 85.536 Stack trace: org.apache.commons.pool.impl.GenericKeyedObjectPool.addObjectToPool(GenericKeyedObjectPool.java:1237) org.apache.commons.pool.impl.GenericKeyedObjectPool.returnObject(GenericKeyedObjectPool.java:1199) org.apache.commons.dbcp.datasources.KeyedCPDSConnectionFactory.connectionClosed(KeyedCPDSConnectionFactory.java:268) com.mysql.jdbc.jdbc2.optional.MysqlPooledConnection.callConnectionEventListeners(MysqlPooledConnection.java:243) com.mysql.jdbc.jdbc2.optional.ConnectionWrapper.close(ConnectionWrapper.java:854) com.mysql.jdbc.jdbc2.optional.ConnectionWrapper.close(ConnectionWrapper.java:477) org.springframework.jdbc.datasource.DataSourceUtils.doReleaseConnection(DataSourceUtils.java:313) org.springframework.jdbc.datasource.DataSourceUtils.releaseConnection(DataSourceUtils.java:274) org.springframework.jdbc.core.JdbcTemplate.execute(JdbcTemplate.java:411)
[29 Jul 2009 13:03]
Ingo Siebert
Testcase to reproduce the bug
Attachment: PoolDeadlockTest.java (application/octet-stream, text), 2.85 KiB.
[29 Jul 2009 13:03]
Ingo Siebert
Bug fix as diff file
Attachment: mysql_deadlock_patch.diff (application/octet-stream, text), 4.50 KiB.
[28 Mar 2014 13:36]
Alexander Soklakov
I close this report as "Can't repeat" because there is no feedback for a long time and codebase is too old. Please, feel free to reopen it if the problem still exists in current driver.
Description: After waiting foever, I dump a stack: [...] Found one Java-level deadlock: ============================= "t-2000": waiting to lock monitor 0x0091ea4c (object 0x10bcf290, a com.mysql.jdbc.jdbc2.optional.MysqlPooledConnection), which is held by "t-3000" "t-3000": waiting to lock monitor 0x0091eaac (object 0x11c82298, a com.mysql.jdbc.jdbc2.optional.LogicalHandle), which is held by "t-2000" Java stack information for the threads listed above: =================================================== "t-2000": at com.mysql.jdbc.jdbc2.optional.MysqlPooledConnection.callListener(MysqlPooledConnection.java:159) - waiting to lock <0x10bcf290> (a com.mysql.jdbc.jdbc2.optional.MysqlPooledConnection) at com.mysql.jdbc.jdbc2.optional.LogicalHandle.close(LogicalHandle.java:769) - locked <0x11c82298> (a com.mysql.jdbc.jdbc2.optional.LogicalHandle) at com.mysql.jdbc.jdbc2.optional.LogicalHandle.close(LogicalHandle.java:431) - locked <0x11c82298> (a com.mysql.jdbc.jdbc2.optional.LogicalHandle) at (our destroy code) "t-3000": at com.mysql.jdbc.jdbc2.optional.LogicalHandle.close(LogicalHandle.java:764) - waiting to lock <0x11c82298> (a com.mysql.jdbc.jdbc2.optional.LogicalHandle) at com.mysql.jdbc.jdbc2.optional.MysqlPooledConnection.getConnection(MysqlPooledConnection.java:123) - locked <0x10bcf290> (a com.mysql.jdbc.jdbc2.optional.MysqlPooledConnection) at (our init code) Found 1 deadlock. How to repeat: A piece of code gets a (logical) connection from the pooledConnection, then work with it and finally close the (logical) connection. At least 2 threads are running the same code. We don't add any explicit listener, although the callListener seams invoked. Sometimes, a logical connection gets closed by the wron thread, leaing to an java.sql.SQLException: Logical handle no longer valid at com.mysql.jdbc.jdbc2.optional.LogicalHandle.createStatement(LogicalHandle.java:462) But sometimes, the threads collide and deadlock as described above. Suggested fix: Tryied once with 3.0.8 and it didn't deadlock. (we run about 30 thousands of iterations like these for each threads, 4 threads), over about 5 minutes.