Bug #22643 | DBCP can't validate ReplicationConnections | ||
---|---|---|---|
Submitted: | 24 Sep 2006 18:44 | Modified: | 12 Oct 2007 13:45 |
Reporter: | Clive Cox | Email Updates: | |
Status: | Closed | Impact on me: | |
Category: | Connector / J | Severity: | S1 (Critical) |
Version: | 3.1.13, 5.0.x | OS: | Linux (linux) |
Assigned to: | CPU Architecture: | Any |
[24 Sep 2006 18:44]
Clive Cox
[24 Sep 2006 18:59]
Clive Cox
The stack trace shown is actually from connector/J 3.1.13 The problem should exist in 5.0.3 as swapConnections looks the same.
[25 Sep 2006 8:26]
Clive Cox
Test showing bug
Attachment: TestDBCPWithRepDriver.java (application/text, text), 4.22 KiB.
[25 Sep 2006 8:32]
Clive Cox
My Test is with a slight modification of the BasicDataSourceExample taken from the DBCP website http://svn.apache.org/viewvc/jakarta/commons/proper/dbcp/trunk/doc/BasicDataSourceExample.... It sets the pool to size 1 and runs some SQL every 5 seconds for 80 seconds with the connection setReadOnly(false). It then runs an SQL query with setReadOnly(true). IMPORTANT: set wait_timeout in the mysql server to 70 The args[0] URI I was using is: "jdbc:mysql://localhost:3306,localhost:3306/mydb?characterEncoding=utf8&useServerPrepStmts=true&logger=com.mysql.jdbc.log.StandardLogger&roundRobinLoadBalance=true&transformedBitIsBoolean=true" So I just connect to the same db for both master and slave. the args[1] SQL was just "select 1" I get a stack trace: Now have run for 85 com.mysql.jdbc.CommunicationsException: Communications link failure due to underlying exception: ** BEGIN NESTED EXCEPTION ** java.net.SocketException MESSAGE: Software caused connection abort: recv failed STACKTRACE: java.net.SocketException: Software caused connection abort: recv failed at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.read(SocketInputStream.java:129) at com.mysql.jdbc.util.ReadAheadInputStream.fill(ReadAheadInputStream.java:113) at com.mysql.jdbc.util.ReadAheadInputStream.readFromUnderlyingStreamIfNecessary(ReadAheadInputStream.java:160) at com.mysql.jdbc.util.ReadAheadInputStream.read(ReadAheadInputStream.java:188) at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:1910) at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:2304) at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:2803) at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1573) at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:1665) at com.mysql.jdbc.Connection.execSQL(Connection.java:3118) at com.mysql.jdbc.Connection.setCatalog(Connection.java:5286) at com.mysql.jdbc.ReplicationConnection.swapConnections(ReplicationConnection.java:493) at com.mysql.jdbc.ReplicationConnection.switchToSlavesConnection(ReplicationConnection.java:472) at com.mysql.jdbc.ReplicationConnection.setReadOnly(ReplicationConnection.java:419) at org.apache.commons.dbcp.DelegatingConnection.setReadOnly(DelegatingConnection.java:239) at net.playtxt.jdbc.TestDBCPWithRepDriver.main(TestDBCPWithRepDriver.java:75) ** END NESTED EXCEPTION ** Last packet sent to the server was 31 ms ago. at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:2515) at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:2803) at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1573) at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:1665) at com.mysql.jdbc.Connection.execSQL(Connection.java:3118) at com.mysql.jdbc.Connection.setCatalog(Connection.java:5286) at com.mysql.jdbc.ReplicationConnection.swapConnections(ReplicationConnection.java:493) at com.mysql.jdbc.ReplicationConnection.switchToSlavesConnection(ReplicationConnection.java:472)Creating connection. Exception:Communications link failure due to underlying exception: ** BEGIN NESTED EXCEPTION ** java.net.SocketException MESSAGE: Software caused connection abort: recv failed STACKTRACE: java.net.SocketException: Software caused connection abort: recv failed at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.read(SocketInputStream.java:129) at com.mysql.jdbc.util.ReadAheadInputStream.fill(ReadAheadInputStream.java:113) at com.mysql.jdbc.util.ReadAheadInputStream.readFromUnderlyingStreamIfNecessary(ReadAheadInputStream.java:160) at com.mysql.jdbc.util.ReadAheadInputStream.read(ReadAheadInputStream.java:188) at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:1910) at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:2304) at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:2803) at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1573) at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:1665) at com.mysql.jdbc.Connection.execSQL(Connection.java:3118) at com.mysql.jdbc.Connection.setCatalog(Connection.java:5286) at com.mysql.jdbc.ReplicationConnection.swapConnections(ReplicationConnection.java:493) at com.mysql.jdbc.ReplicationConnection.switchToSlavesConnection(ReplicationConnection.java:472) at com.mysql.jdbc.ReplicationConnection.setReadOnly(ReplicationConnection.java:419) at org.apache.commons.dbcp.DelegatingConnection.setReadOnly(DelegatingConnection.java:239) at net.playtxt.jdbc.TestDBCPWithRepDriver.main(TestDBCPWithRepDriver.java:75) ** END NESTED EXCEPTION ** Last packet sent to the server was 31 ms ago. at com.mysql.jdbc.ReplicationConnection.setReadOnly(ReplicationConnection.java:419) at org.apache.commons.dbcp.DelegatingConnection.setReadOnly(DelegatingConnection.java:239) at net.playtxt.jdbc.TestDBCPWithRepDriver.main(TestDBCPWithRepDriver.java:75)
[25 Sep 2006 8:36]
Clive Cox
Forgot to say you will need to set databse username and password for your database and you need: Also, as the code say: To compile this example, you'll want: // * commons-pool.jar // * commons-dbcp.jar // * j2ee.jar (for the javax.sql classes) // in your classpath. // // To run this example, you'll want: // * commons-collections.jar // * commons-pool.jar // * commons-dbcp.jar // * j2ee.jar (for the javax.sql classes) // * the classes for your (underlying) JDBC driver // in your classpath.
[22 Oct 2006 11:14]
Valeriy Kravchuk
Thank you for a problem report. Please, try to repeat with the latest versions of Connector/J, 3.1.14 and 5.0.4, and inform about the results.
[1 Nov 2006 11:38]
Clive Cox
Yes the bug still occurs in 5.0.4. If you look at my comments you will see that this is not a bug that will easily disappear without a fundamental change to how the ReplicationDriver works and/or collaboration with DBCP. A simple inspection of the code will make clear that keeping 2 connections open in the ReplicationDriver will mean 1 gets timed-out if not used and DBCP will only test the active connection as it has no idea there is another "hidden" connection.
[9 Nov 2006 12:18]
Tonci Grgin
Hi Clive and thanks for your report. Verified as described with provided test case.
[9 Nov 2006 12:19]
Tonci Grgin
Stack trace
Attachment: 22643STR.zip (application/x-zip-compressed, text), 1.01 KiB.
[7 Dec 2006 21:18]
Mark Matthews
We're looking into ways of fixing this without having to change DBCP.
[6 Sep 2007 14:57]
Fabian Panthen
Is there any idea of when a fix for this can be expected?
[6 Sep 2007 15:04]
Fabian Panthen
We experience the same issue with c3pO
[10 Oct 2007 17:56]
Matt Cohen
Is there any idea when a fix for this will be released?
[12 Oct 2007 13:45]
Mark Matthews
Fixed in 5.0.9, 5.1.5. You have to use a specially-constructed validation query that starts with "/* ping */", here's the entry from the changelog: Specifying a "validation query" in your connection pool that starts with "/* ping */" _exactly_ will cause the driver to instead send a ping to the server and return a fake result set (much lighter weight), and when using a ReplicationConnection or a LoadBalancedConnection, will send the ping across all active connections.
[16 Oct 2007 22:28]
Matt Cohen
Thank you very much. :)