SOLVED
Ultimately the solution noted in the similar ticket noted below worked for us. When we tried it initially our configuration parser was mangling the URL and removing &connectTimeout=15000&socketTimeout=60000 from it, which invalidated that test.
I'm having trouble getting a tomcat jdbc connection pool to fail-over to a new DB server using Amazon RDS' mutli-az feature. When fail-over occurs the application server gets hung up trying to borrow a connection from the pool. It's similar to this question, however the solution to this users problem did not help me, so I suspect it's not quite the same: Configure GlassFish JDBC connection pool to handle Amazon RDS Multi-AZ failover The sequence goes a bit like this:
- Succesful request is made, log output as expected
- fail-over initiated (via reboot with failover in RDS)
- Request made that times out, log messages from request appear as expected up until a connection is borrowed from the pool.
- Subsequent requests generate no log messages, they time out as well.
- After some amount of time, the daemon will eventually start printing more log messages as if it succesfully connected to the database and performing operations. This can take just over 16 minutes to occur, the client has long since timed out.
- If I wait about 50 minutes and try again eventually the system will finally accept connections again.
Notes
If I tell tomcat to shut down there are exceptions in the logs about it being unable to clean up resources, and about my servlet still processing a request. Most notable (In my opinion) is the following stack trace indicating at least one thing is stuck waiting for communication over a socket from mysql.
java.net.SocketInputStream.socketRead0(Native Method) java.net.SocketInputStream.socketRead(SocketInputStream.java:116) java.net.SocketInputStream.read(SocketInputStream.java:171) java.net.SocketInputStream.read(SocketInputStream.java:141) com.mysql.jdbc.util.ReadAheadInputStream.fill(ReadAheadInputStream.java:114) com.mysql.jdbc.util.ReadAheadInputStream.readFromUnderlyingStreamIfNecessary(ReadAheadInputStream.java:161) com.mysql.jdbc.util.ReadAheadInputStream.read(ReadAheadInputStream.java:189) com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:3116) com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3573) com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3562) com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4113) com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2570) com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2731) com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2812) com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2761) com.mysql.jdbc.StatementImpl.execute(StatementImpl.java:894) com.mysql.jdbc.StatementImpl.execute(StatementImpl.java:732) org.apache.tomcat.jdbc.pool.PooledConnection.validate(PooledConnection.java:441) org.apache.tomcat.jdbc.pool.PooledConnection.validate(PooledConnection.java:384) org.apache.tomcat.jdbc.pool.ConnectionPool.borrowConnection(ConnectionPool.java:716) org.apache.tomcat.jdbc.pool.ConnectionPool.borrowConnection(ConnectionPool.java:579) org.apache.tomcat.jdbc.pool.ConnectionPool.getConnection(ConnectionPool.java:174) org.apache.tomcat.jdbc.pool.DataSourceProxy.getConnection(DataSourceProxy.java:111) <...>If I restart tomcat things return to normal as soon as it comes back. Obviously long term this is probably not a workable solution for maintaining uptime.
Environment Details
- Database: MySQL (using mysql-connector-java 5.1.26) (server 5.5.53)
- Tomcat 8.0.45
I've gone through several changes to my configuration while trying to solve this issue. At the time of this writing the following related settings are in place:
- jre/lib/security/java.security -- I'm under the impression that the default value for Oracle Java 1.8 is 30s with no security manager. I set these to zero just to be positive this isn't the issue.
- networkaddress.cache.ttl: 0
- networkaddress.cache.negative.ttl: 0
- connection pool settings
- testOnBorrow: true
- testOnConnect: true
- testOnReturn: true
- jdbc url parameters
- connectTimeout:60000
- socketTimeout:60000
- autoReconnect:true
Update
Still no solution found.
Added in logging to confirm that this was not a DNS caching issue. IP address logged immediately before timeout matches up with IP address of 'new' master RDS host.
For reference the following block represents the properties I'm using to initialize my data source. I’m configuring the pool in code rather than JNDI, with some elements pulled out of our app's config file. I’ve pasted the code below along with comments indicating what the config values are for the tests I’ve been running.
PoolProperties p = new PoolProperties();
p.setUrl(config.get("JDBC_URL")); // jdbc:mysql://host:3306/dbname
p.setDriverClassName("com.mysql.jdbc.Driver");
p.setUsername(config.get("JDBC_USER"));
p.setPassword(config.get("JDBC_PASSWORD"));
p.setJmxEnabled(true);
p.setTestWhileIdle(false);
p.setTestOnBorrow(true);
p.setValidationQuery("SELECT 1");
p.setValidationInterval(30000);
p.setTimeBetweenEvictionRunsMillis(30000);
p.setMaxActive(Integer.parseInt(config.get("MAX_ACTIVE"))); //45
p.setInitialSize(10);
p.setMaxWait(5);
p.setRemoveAbandonedTimeout(Integer.parseInt(config.get("REMOVE_ABANDONED_TIMEOUT"))); //600
p.setMinEvictableIdleTimeMillis(Integer.parseInt(config.get("DB_EVICTION_TIMEOUT"))); //60000
p.setMinIdle(Integer.parseInt(config.get("DB_MIN_IDLE"))); //50
p.setLogAbandoned(Boolean.parseBoolean(config.get("LOG_ABANDONED"))); //true
p.setRemoveAbandoned(true);
p.setJdbcInterceptors(
"org.apache.tomcat.jdbc.pool.interceptor.ConnectionState;"+
"org.apache.tomcat.jdbc.pool.interceptor.StatementFinalizer;"+
"org.apache.tomcat.jdbc.pool.interceptor.ResetAbandonedTimer");
// make sure new connections have auto commit true
p.setDefaultAutoCommit(true);
