order
This paper mainly studies the fail fast of hikari and tomcat jdbc pool in the case of Midway database hanging.
Experimental code
@Test public void testDatabaseDownAndUp() throws SQLException, InterruptedException { LOGGER.info("begin to wait for database down and up"); for(int c=0;c<10;c++){ LOGGER.info("execute:"+(c+1)); Connection conn = null; String sql = "select 1"; PreparedStatement pstmt = null; try { long start = System.currentTimeMillis(); conn = dataSource.getConnection(); LOGGER.info("{} got connection,cost:{}",(c+1),System.currentTimeMillis() - start); pstmt = (PreparedStatement)conn.prepareStatement(sql); ResultSet rs = pstmt.executeQuery(); int col = rs.getMetaData().getColumnCount(); while (rs.next()) { for (int i = 1; i <= col; i++) { System.out.print(rs.getObject(i)); } System.out.println(""); } LOGGER.info("============================"); } catch (Exception e) { e.printStackTrace(); } finally { //close resources DbUtils.closeQuietly(pstmt); DbUtils.closeQuietly(conn); } TimeUnit.SECONDS.sleep(10); } }
Disconnect the database connection after the first round-robin output and wait for twenty or thirty seconds to recover.
hikari
2018-01-30 15:35:16.668 INFO 5852 --- [ main] c.e.demo.HikariDemoApplicationTests : execute:1 2018-01-30 15:35:26.854 INFO 5852 --- [ main] c.e.demo.HikariDemoApplicationTests : execute:2 2018-01-30 15:36:06.867 INFO 5852 --- [ main] c.e.demo.HikariDemoApplicationTests : execute:3 2018-01-30 15:36:46.878 INFO 5852 --- [ main] c.e.demo.HikariDemoApplicationTests : execute:4
From this point of view, hikari keeps getting database links if the midway database is disconnected Assuming that the database has not been restored, the business threads requesting database operations will block the connection time out, which will occupy the worker threads. hikari only has the function of testOnBorrow, which is a direct while loop. It continuously borrows and validates in time out. Only when validate succeeds, does it return or overtime throw the SQL TransientConnectionException exception. The time-out for borrow is connection time out, which defaults to 30 seconds.
validate unsuccessful log record exception
2018-01-31 16:45:00.653 WARN 6501 --- [ main] org.postgresql.jdbc.PgConnection : Validating connection. org.postgresql.util.PSQLException: FATAL: terminating connection due to administrator command at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2422) ~[postgresql-42.2.1.jar:42.2.1] at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:2167) ~[postgresql-42.2.1.jar:42.2.1] at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:306) ~[postgresql-42.2.1.jar:42.2.1] at org.postgresql.jdbc.PgStatement.executeInternal(PgStatement.java:441) ~[postgresql-42.2.1.jar:42.2.1] at org.postgresql.jdbc.PgStatement.execute(PgStatement.java:365) ~[postgresql-42.2.1.jar:42.2.1] at org.postgresql.jdbc.PgPreparedStatement.executeWithFlags(PgPreparedStatement.java:155) ~[postgresql-42.2.1.jar:42.2.1] at org.postgresql.jdbc.PgPreparedStatement.executeUpdate(PgPreparedStatement.java:132) ~[postgresql-42.2.1.jar:42.2.1] at org.postgresql.jdbc.PgConnection.isValid(PgConnection.java:1364) ~[postgresql-42.2.1.jar:42.2.1] at com.zaxxer.hikari.pool.PoolBase.isConnectionAlive(PoolBase.java:160) [HikariCP-2.7.6.jar:na] at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:171) [HikariCP-2.7.6.jar:na] at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:147) [HikariCP-2.7.6.jar:na] at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:123) [HikariCP-2.7.6.jar:na] at com.example.demo.HikariDemoApplicationTests.testDatabaseDownAndUp(HikariDemoApplicationTests.java:109) [test-classes/:na] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_71] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_71] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_71] at java.lang.reflect.Method.invoke(Method.java:497) ~[na:1.8.0_71] at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50) [junit-4.12.jar:4.12] at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) [junit-4.12.jar:4.12] at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47) [junit-4.12.jar:4.12] at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17) [junit-4.12.jar:4.12] at org.springframework.test.context.junit4.statements.RunBeforeTestExecutionCallbacks.evaluate(RunBeforeTestExecutionCallbacks.java:73) [spring-test-5.0.3.RELEASE.jar:5.0.3.RELEASE] at org.springframework.test.context.junit4.statements.RunAfterTestExecutionCallbacks.evaluate(RunAfterTestExecutionCallbacks.java:83) [spring-test-5.0.3.RELEASE.jar:5.0.3.RELEASE] at org.springframework.test.context.junit4.statements.RunBeforeTestMethodCallbacks.evaluate(RunBeforeTestMethodCallbacks.java:75) [spring-test-5.0.3.RELEASE.jar:5.0.3.RELEASE] at org.springframework.test.context.junit4.statements.RunAfterTestMethodCallbacks.evaluate(RunAfterTestMethodCallbacks.java:86) [spring-test-5.0.3.RELEASE.jar:5.0.3.RELEASE] at org.springframework.test.context.junit4.statements.SpringRepeat.evaluate(SpringRepeat.java:84) [spring-test-5.0.3.RELEASE.jar:5.0.3.RELEASE] at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325) [junit-4.12.jar:4.12] at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.runChild(SpringJUnit4ClassRunner.java:251) [spring-test-5.0.3.RELEASE.jar:5.0.3.RELEASE] at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.runChild(SpringJUnit4ClassRunner.java:97) [spring-test-5.0.3.RELEASE.jar:5.0.3.RELEASE] at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290) [junit-4.12.jar:4.12] at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71) [junit-4.12.jar:4.12] at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288) [junit-4.12.jar:4.12] at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58) [junit-4.12.jar:4.12] at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268) [junit-4.12.jar:4.12] at org.springframework.test.context.junit4.statements.RunBeforeTestClassCallbacks.evaluate(RunBeforeTestClassCallbacks.java:61) [spring-test-5.0.3.RELEASE.jar:5.0.3.RELEASE] at org.springframework.test.context.junit4.statements.RunAfterTestClassCallbacks.evaluate(RunAfterTestClassCallbacks.java:70) [spring-test-5.0.3.RELEASE.jar:5.0.3.RELEASE] at org.junit.runners.ParentRunner.run(ParentRunner.java:363) [junit-4.12.jar:4.12] at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.run(SpringJUnit4ClassRunner.java:190) [spring-test-5.0.3.RELEASE.jar:5.0.3.RELEASE] at org.junit.runner.JUnitCore.run(JUnitCore.java:137) [junit-4.12.jar:4.12] at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:69) [junit-rt.jar:na] at com.intellij.rt.execution.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:234) [junit-rt.jar:na] at com.intellij.rt.execution.junit.JUnitStarter.main(JUnitStarter.java:74) [junit-rt.jar:na] at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_71] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_71] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_71] at java.lang.reflect.Method.invoke(Method.java:497) ~[na:1.8.0_71] at com.intellij.rt.execution.application.AppMain.main(AppMain.java:144) [idea_rt.jar:na]
Assuming that a new maxPoolSize connection is established before the test, then the database is interrupted after execution, the next getConnection will take out these idle connections one by one, validate, validate failures will record exceptions in the log, while getConnection continues to cycle to get connections.
Exceptions thrown by getConnection timeout
java.sql.SQLTransientConnectionException: demo1 - Connection is not available, request timed out after 60007ms. at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:666) at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:182) at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:147) at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:123) at com.example.demo.HikariDemoApplicationTests.testDatabaseDownAndUp(HikariDemoApplicationTests.java:98) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:497) at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50) at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47) at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17) at org.springframework.test.context.junit4.statements.RunBeforeTestExecutionCallbacks.evaluate(RunBeforeTestExecutionCallbacks.java:73) at org.springframework.test.context.junit4.statements.RunAfterTestExecutionCallbacks.evaluate(RunAfterTestExecutionCallbacks.java:83) at org.springframework.test.context.junit4.statements.RunBeforeTestMethodCallbacks.evaluate(RunBeforeTestMethodCallbacks.java:75) at org.springframework.test.context.junit4.statements.RunAfterTestMethodCallbacks.evaluate(RunAfterTestMethodCallbacks.java:86) at org.springframework.test.context.junit4.statements.SpringRepeat.evaluate(SpringRepeat.java:84) at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325) at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.runChild(SpringJUnit4ClassRunner.java:251) at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.runChild(SpringJUnit4ClassRunner.java:97) at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290) at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71) at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288) at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58) at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268) at org.springframework.test.context.junit4.statements.RunBeforeTestClassCallbacks.evaluate(RunBeforeTestClassCallbacks.java:61) at org.springframework.test.context.junit4.statements.RunAfterTestClassCallbacks.evaluate(RunAfterTestClassCallbacks.java:70) at org.junit.runners.ParentRunner.run(ParentRunner.java:363) at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.run(SpringJUnit4ClassRunner.java:190) at org.junit.runner.JUnitCore.run(JUnitCore.java:137) at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:69) at com.intellij.rt.execution.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:234) at com.intellij.rt.execution.junit.JUnitStarter.main(JUnitStarter.java:74) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:497) at com.intellij.rt.execution.application.AppMain.main(AppMain.java:144) Caused by: org.postgresql.util.PSQLException: Connection to 192.168.99.100:5432 refused. Check that the hostname and port are correct and that the postmaster is accepting TCP/IP connections. at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:247) at org.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:49) at org.postgresql.jdbc.PgConnection.<init>(PgConnection.java:195) at org.postgresql.Driver.makeConnection(Driver.java:452) at org.postgresql.Driver.connect(Driver.java:254) at com.zaxxer.hikari.util.DriverDataSource.getConnection(DriverDataSource.java:117) at com.zaxxer.hikari.util.DriverDataSource.getConnection(DriverDataSource.java:123) at com.zaxxer.hikari.pool.PoolBase.newConnection(PoolBase.java:375) at com.zaxxer.hikari.pool.PoolBase.newPoolEntry(PoolBase.java:204) at com.zaxxer.hikari.pool.HikariPool.createPoolEntry(HikariPool.java:459) at com.zaxxer.hikari.pool.HikariPool.access$200(HikariPool.java:70) at com.zaxxer.hikari.pool.HikariPool$PoolEntryCreator.call(HikariPool.java:696) at com.zaxxer.hikari.pool.HikariPool$PoolEntryCreator.call(HikariPool.java:682) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) Caused by: java.net.ConnectException: Connection refused at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350) at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206) at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188) at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) at java.net.Socket.connect(Socket.java:589) at org.postgresql.core.PGStream.<init>(PGStream.java:69) at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:158) ... 16 more
Loop fetch connection timeout throws SQL TransientConnectionException
Asynchronous thread PoolEntry Creator adds exceptions to new connections recorded in the log
2018-01-31 16:45:00.915 WARN 6501 --- [onnection adder] unknown.jul.logger : ConnectException occurred while connecting to 192.168.99.100:5432 java.net.ConnectException: Connection refused at java.net.PlainSocketImpl.socketConnect(Native Method) ~[na:1.8.0_71] at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350) ~[na:1.8.0_71] at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206) ~[na:1.8.0_71] at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188) ~[na:1.8.0_71] at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) ~[na:1.8.0_71] at java.net.Socket.connect(Socket.java:589) ~[na:1.8.0_71] at org.postgresql.core.PGStream.<init>(PGStream.java:69) ~[postgresql-42.2.1.jar:42.2.1] at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:158) ~[postgresql-42.2.1.jar:42.2.1] at org.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:49) [postgresql-42.2.1.jar:42.2.1] at org.postgresql.jdbc.PgConnection.<init>(PgConnection.java:195) [postgresql-42.2.1.jar:42.2.1] at org.postgresql.Driver.makeConnection(Driver.java:452) [postgresql-42.2.1.jar:42.2.1] at org.postgresql.Driver.connect(Driver.java:254) [postgresql-42.2.1.jar:42.2.1] at com.zaxxer.hikari.util.DriverDataSource.getConnection(DriverDataSource.java:117) [HikariCP-2.7.6.jar:na] at com.zaxxer.hikari.util.DriverDataSource.getConnection(DriverDataSource.java:123) [HikariCP-2.7.6.jar:na] at com.zaxxer.hikari.pool.PoolBase.newConnection(PoolBase.java:375) [HikariCP-2.7.6.jar:na] at com.zaxxer.hikari.pool.PoolBase.newPoolEntry(PoolBase.java:204) [HikariCP-2.7.6.jar:na] at com.zaxxer.hikari.pool.HikariPool.createPoolEntry(HikariPool.java:459) [HikariCP-2.7.6.jar:na] at com.zaxxer.hikari.pool.HikariPool.access$200(HikariPool.java:70) [HikariCP-2.7.6.jar:na] at com.zaxxer.hikari.pool.HikariPool$PoolEntryCreator.call(HikariPool.java:696) [HikariCP-2.7.6.jar:na] at com.zaxxer.hikari.pool.HikariPool$PoolEntryCreator.call(HikariPool.java:682) [HikariCP-2.7.6.jar:na] at java.util.concurrent.FutureTask.run(FutureTask.java:266) [na:1.8.0_71] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0_71] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0_71] at java.lang.Thread.run(Thread.java:745) [na:1.8.0_71]
Get the source code for the connection
HikariCP-2.7.6-sources.jar!/com/zaxxer/hikari/pool/HikariPool.java
/** * Get a connection from the pool, or timeout after the specified number of milliseconds. * * @param hardTimeout the maximum time to wait for a connection from the pool * @return a java.sql.Connection instance * @throws SQLException thrown if a timeout occurs trying to obtain a connection */ public Connection getConnection(final long hardTimeout) throws SQLException { suspendResumeLock.acquire(); final long startTime = currentTime(); try { long timeout = hardTimeout; do { PoolEntry poolEntry = connectionBag.borrow(timeout, MILLISECONDS); if (poolEntry == null) { break; // We timed out... break and throw exception } final long now = currentTime(); if (poolEntry.isMarkedEvicted() || (elapsedMillis(poolEntry.lastAccessed, now) > ALIVE_BYPASS_WINDOW_MS && !isConnectionAlive(poolEntry.connection))) { closeConnection(poolEntry, poolEntry.isMarkedEvicted() ? EVICTED_CONNECTION_MESSAGE : DEAD_CONNECTION_MESSAGE); timeout = hardTimeout - elapsedMillis(startTime); } else { metricsTracker.recordBorrowStats(poolEntry, startTime); return poolEntry.createProxyConnection(leakTaskFactory.schedule(poolEntry), now); } } while (timeout > 0L); metricsTracker.recordBorrowTimeoutStats(startTime); throw createTimeoutException(startTime); } catch (InterruptedException e) { Thread.currentThread().interrupt(); throw new SQLException(poolName + " - Interrupted during connection acquisition", e); } finally { suspendResumeLock.release(); } }
tomcat
2018-01-30 15:39:23.913 INFO 5894 --- [ main] com.example.JpaDemoApplicationTests : execute:1 2018-01-30 15:39:33.939 INFO 5894 --- [ main] com.example.JpaDemoApplicationTests : execute:2 2018-01-30 15:39:43.949 INFO 5894 --- [ main] com.example.JpaDemoApplicationTests : execute:3 2018-01-30 15:39:53.955 INFO 5894 --- [ main] com.example.JpaDemoApplicationTests : execute:4 2018-01-30 15:40:03.962 INFO 5894 --- [ main] com.example.JpaDemoApplicationTests : execute:5 2018-01-30 15:40:13.968 INFO 5894 --- [ main] com.example.JpaDemoApplicationTests : execute:6
tomcat jdbc pool has testOnBorrow,testOnReturn,testOnConnect,testWhileIdle attributes to configure when to detect connections. If it is testOnBorrow, idle connections are borrowed and validated at the same time. If the last time of validate is within validation interval, the default validate is successful, otherwise vali is validated. Date, validate fails to reconnect, then validate, and if it fails again, throw a new SQLException("Failed to validate a newly established connection."). If there is no idle connection and the connection pool is not full, create a new one; if there is no idle connection and the connection pool is full, then while polls the idle queue, if the connection is not fetched, if it is not more than maxWait, then continues, and if it is more than maxWait, throws PoolExhaustedException. If there is no idle connection and the connection pool is full, the borrow timeout time is maxWait by default of 30 seconds.
This example program returns the connection first and then sleep s in each loop, so the connection pool always has free connections, but the testOnBorrow check is unsuccessful, reconnected, and throws an exception in reconnect.
The exception thrown by reconnect
org.postgresql.util.PSQLException: Connection to 192.168.99.100:5432 refused. Check that the hostname and port are correct and that the postmaster is accepting TCP/IP connections. at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:262) at org.postgresql.core.ConnectionFactory.openConnection(ConnectionFactory.java:51) at org.postgresql.jdbc.PgConnection.<init>(PgConnection.java:215) at org.postgresql.Driver.makeConnection(Driver.java:404) at org.postgresql.Driver.connect(Driver.java:272) at org.apache.tomcat.jdbc.pool.PooledConnection.connectUsingDriver(PooledConnection.java:310) at org.apache.tomcat.jdbc.pool.PooledConnection.connect(PooledConnection.java:203) at org.apache.tomcat.jdbc.pool.PooledConnection.reconnect(PooledConnection.java:361) at org.apache.tomcat.jdbc.pool.ConnectionPool.borrowConnection(ConnectionPool.java:821) at org.apache.tomcat.jdbc.pool.ConnectionPool.borrowConnection(ConnectionPool.java:651) at org.apache.tomcat.jdbc.pool.ConnectionPool.getConnection(ConnectionPool.java:198) at org.apache.tomcat.jdbc.pool.DataSourceProxy.getConnection(DataSourceProxy.java:132) at com.example.JpaDemoApplicationTests.testDatabaseDownAndUp(JpaDemoApplicationTests.java:296) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:497) at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50) at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47) at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17) at org.springframework.test.context.junit4.statements.RunBeforeTestMethodCallbacks.evaluate(RunBeforeTestMethodCallbacks.java:75) at org.springframework.test.context.junit4.statements.RunAfterTestMethodCallbacks.evaluate(RunAfterTestMethodCallbacks.java:86) at org.springframework.test.context.junit4.statements.SpringRepeat.evaluate(SpringRepeat.java:84) at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325) at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.runChild(SpringJUnit4ClassRunner.java:252) at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.runChild(SpringJUnit4ClassRunner.java:94) at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290) at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71) at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288) at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58) at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268) at org.springframework.test.context.junit4.statements.RunBeforeTestClassCallbacks.evaluate(RunBeforeTestClassCallbacks.java:61) at org.springframework.test.context.junit4.statements.RunAfterTestClassCallbacks.evaluate(RunAfterTestClassCallbacks.java:70) at org.junit.runners.ParentRunner.run(ParentRunner.java:363) at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.run(SpringJUnit4ClassRunner.java:191) at org.junit.runner.JUnitCore.run(JUnitCore.java:137) at com.intellij.junit4.JUnit4IdeaTestRunner.startRunnerWithArgs(JUnit4IdeaTestRunner.java:69) at com.intellij.rt.execution.junit.JUnitStarter.prepareStreamsAndStart(JUnitStarter.java:234) at com.intellij.rt.execution.junit.JUnitStarter.main(JUnitStarter.java:74) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:497) at com.intellij.rt.execution.application.AppMain.main(AppMain.java:144) Caused by: java.net.ConnectException: Connection refused at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350) at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206) at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188) at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) at java.net.Socket.connect(Socket.java:589) at org.postgresql.core.PGStream.<init>(PGStream.java:61) at org.postgresql.core.v3.ConnectionFactoryImpl.openConnectionImpl(ConnectionFactoryImpl.java:144) ... 44 more
Get the source code for the connection
tomcat-jdbc-8.5.23-sources.jar!/org/apache/tomcat/jdbc/pool/ConnectionPool.java
/** * Thread safe way to retrieve a connection from the pool * @param wait - time to wait, overrides the maxWait from the properties, * set to -1 if you wish to use maxWait, 0 if you wish no wait time. * @param username The user name to use for the connection * @param password The password for the connection * @return a connection * @throws SQLException Failed to get a connection */ private PooledConnection borrowConnection(int wait, String username, String password) throws SQLException { if (isClosed()) { throw new SQLException("Connection pool closed."); } //end if //get the current time stamp long now = System.currentTimeMillis(); //see if there is one available immediately PooledConnection con = idle.poll(); while (true) { if (con!=null) { //configure the connection and return it PooledConnection result = borrowConnection(now, con, username, password); borrowedCount.incrementAndGet(); if (result!=null) return result; } //if we get here, see if we need to create one //this is not 100% accurate since it doesn't use a shared //atomic variable - a connection can become idle while we are creating //a new connection if (size.get() < getPoolProperties().getMaxActive()) { //atomic duplicate check if (size.addAndGet(1) > getPoolProperties().getMaxActive()) { //if we got here, two threads passed through the first if size.decrementAndGet(); } else { //create a connection, we're below the limit return createConnection(now, con, username, password); } } //end if //calculate wait time for this iteration long maxWait = wait; //if the passed in wait time is -1, means we should use the pool property value if (wait==-1) { maxWait = (getPoolProperties().getMaxWait()<=0)?Long.MAX_VALUE:getPoolProperties().getMaxWait(); } long timetowait = Math.max(0, maxWait - (System.currentTimeMillis() - now)); waitcount.incrementAndGet(); try { //retrieve an existing connection con = idle.poll(timetowait, TimeUnit.MILLISECONDS); } catch (InterruptedException ex) { if (getPoolProperties().getPropagateInterruptState()) { Thread.currentThread().interrupt(); } SQLException sx = new SQLException("Pool wait interrupted."); sx.initCause(ex); throw sx; } finally { waitcount.decrementAndGet(); } if (maxWait==0 && con == null) { //no wait, return one if we have one if (jmxPool!=null) { jmxPool.notify(org.apache.tomcat.jdbc.pool.jmx.ConnectionPool.POOL_EMPTY, "Pool empty - no wait."); } throw new PoolExhaustedException("[" + Thread.currentThread().getName()+"] " + "NoWait: Pool empty. Unable to fetch a connection, none available["+busy.size()+" in use]."); } //we didn't get a connection, lets see if we timed out if (con == null) { if ((System.currentTimeMillis() - now) >= maxWait) { if (jmxPool!=null) { jmxPool.notify(org.apache.tomcat.jdbc.pool.jmx.ConnectionPool.POOL_EMPTY, "Pool empty - timeout."); } throw new PoolExhaustedException("[" + Thread.currentThread().getName()+"] " + "Timeout: Pool empty. Unable to fetch a connection in " + (maxWait / 1000) + " seconds, none available[size:"+size.get() +"; busy:"+busy.size()+"; idle:"+idle.size()+"; lastwait:"+timetowait+"]."); } else { //no timeout, lets try again continue; } } } //while }
Summary
If there is no idle connection and the connection pool is full, no new connection can be created.
- hikari is the time when connection Timeout is blocked and the SQL Transient Connection Exception is thrown without a connection.
- tomcat jdbc pool blocks max-wait time and throws PoolExhaustedException if it is not connected
If there is an idle connection
- hikari iterates through the connection time to get the next free connection for validation. The validation failure continues to get the next free connection until the SQL Transient Connection Exception is thrown out overtime.
- tomcat jdbc pool will borrow connection and then validate connection, normal validate failure will reconnect, then validate, if reconnect is not successful then throw ConnectException: Connection refused, if reconnect succeeds but validate fails, throw SQLException("Failed to validate a newly established connection").
Assuming that the database is hanging, but there is still an idle connection, tomcat's testOnBorrow=true. Contrast can be found
When hikari retrieves a connection, it iterates the idle connections to validate one by one in connection time, and finally throws an exception in time out; after that, it blocks connection time and then throws an exception. tomcat jdbc pool is to get a connection, borrow out the connection first, normal validate failure will reconnect, then validate, usually reconnect when throwing ConnectException: Connection refused, then business program will fail fast, and then the access connection is also fail fast.
Thus, if hikari connectionTimeout is set too large, it is easy to block business threads when the database hangs, while tomcat jdbc pool fails fast.
In addition, hikari asynchronously establishes a minIdle-sized connection, while tomcat synchronously establishes an initial-size connection.