[case5] talk about fail fast between hikari and tomcat jdbc pool.

  jdbc

Order

This paper mainly studies the fail fast of hikari and tomcat jdbc pool when the database is hung halfway.

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 after the first round of output and wait 20 to 30 seconds before resuming.

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 will continue to obtain database links if the database is disconnected in the middle.

Assuming that the database has not been restored, the business thread requesting the database operation will block the connectionTimeout, which will occupy the work thread.

Hikari only has testOnBorrow function, which is a direct while loop. It continuously connects with Row and validate during timeout time, and validate returns successfully or throws SQLTransientConnectionException exception over time. Borrow’s timeout is connectionTimeout, which defaults to 30 seconds.

Validate unsuccessful logging 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 the maxPoolSize connection is newly established before the test, then if the database is interrupted after the execution, the next getConnection will fetch these idle connections one by one, validate, validate failure will record an exception in the log, and getConnection will continue to loop to obtain the connection.

Exception 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 timed out, SqlTransientConnectionException is thrown.

Asynchronous thread PoolEntryCreator supplements the newly connected exception in logging

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, TestonConnecte, TestwHileidle attributes to configure when to detect connections. If it is TestonBorrow, if there is an idle connection, then Borrow and validate are performed at the same time. If the time of the last validation is within the validation interval, the default validation succeeds; otherwise, validation will be performed. if validation fails, reconnect and validate will be performed. if it fails again, a new sqlexception (“failed to validate a newly established connection.”) will be thrown. If there is no free connection and the connection pool is not full, create a new one; If there is no idle connection and the connection pool is full, while polls the idle queue; if no connection is obtained, if maxWait is not exceeded, continue; if not, PoolExhaustedException is thrown. If there are no idle connections and the connection pool is full, the borrow timeout is maxWait default of 30 seconds.

In this sample program, the connection will be returned before sleep every cycle, so the connection pool always has free connections, but testOnBorrow verification was unsuccessful, reconnection was performed, and an exception was thrown at reconnection.

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 the connectionTimeout is blocked and no connection throws a SQLTransientConnectionException.
  • Tomcat jdbc pool will block max-wait time and throw PoolExhaustedException if no connection is obtained.

If there is an idle connection

  • Hikari is to repeatedly acquire the next idle connection for verification within the connectionTimeout time. If verification fails, the next idle connection will be acquired until SQLTransientConnectionException is thrown out over time.
  • Tomcat jdbc pool will connect borrow and then validate the connection. If normal validation fails, it will reconnect and validate again. If reconnection fails at this time, it will throw CONNECT EXCEPTION: CONNECT REFUSED. If reconnect succeeds but validate fails, sqlexception (“failed to validate a newlyestablished connection.”)

Assuming that the database is hung, but there are still free connections, tomcat’s testOnBorrow=true. The comparison shows that

Hikari, when acquiring a connection, will validate the idle connections one by one in the connectionTimeout time, and finally timeout throws an exception. After the get connection operation, the connectionTimeout time is blocked and an exception is thrown.

Tomcat jdbc pool is to obtain a connection by borrow first. normal validations fail and reconnect, and then validate. normally reconnect throws a connectedexception: connectedreused, then the business program fails fast, and the subsequent connections are also fail fast.

Thus, hikari, if the connectionTimeout is set too large, will easily block the business thread when the database is hung, while tomcat jdbc pool will fail fast.

In addition, hikari establishes minIdle-sized connections asynchronously, while tomcat establishes initial-size connections synchronously.