Поговорите о провале hikari и tomcat jdbc pool

задняя часть база данных модульный тест Tomcat

последовательность

В этой статье в основном изучается ситуация быстрого отказа пула jdbc hikari и tomcat, когда база данных зависает посередине.

экспериментальный код

	@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);
		}
	}

Разорвите соединение с базой данных после выхода первого цикла, подождите 20-30 секунд перед восстановлением.

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

С этой точки зрения, если база данных отключена посередине, hikari продолжит получать ссылку на базу данных.

Предполагая, что база данных не была восстановлена, все бизнес-потоки, запрашивающие операции с базой данных, будут блокировать время connectionTimeout, которое займет рабочие потоки.

У Hikari есть только функция testOnBorrow, которая представляет собой прямой цикл while, непрерывно заимствовающий соединение в течение времени ожидания, проверяющий соединение и возвращающийся после успешной проверки или вызывающий исключение SQLTransientConnectionException с течением времени. Тайм-аут заимствования — connectionTimeout, который по умолчанию равен 30 секундам.

Исключение для неудачной регистрации проверки

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]

Предполагая, что соединение maxPoolSize вновь установлено перед тестом, тогда база данных прерывается после выполнения, и следующий getConnection будет вынимать эти простаивающие соединения одно за другим, проверять, сбой проверки запишет исключение в журнал, и getConnection продолжает цикл для получения соединений

Исключение, вызванное тайм-аутом getConnection

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

Если в цикле время ожидания соединения истекло, выдается исключение SQLTransientConnectionException.

Асинхронный поток PoolEntryCreator добавляет новые исключения подключения в ведение журнала

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]

Получить исходный код подключения

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 имеет свойства testOnBorrow, testOnReturn, testOnConnect, testWhileIdle для настройки обнаружения соединения. Если это testOnBorrow, при наличии незанятого соединения он будет заимствовать и проверять одновременно. Если время последней проверки находится в пределах интервал проверки, проверка по умолчанию проходит успешно. В противном случае подтвердите, если проверка не пройдена, будет выполнено повторное подключение, а затем повторная проверка. Если снова произойдет сбой, возникнет новое исключение SQLException ("Не удалось проверить вновь установленное соединение"). быть брошенным. Если нет незанятого соединения и пул соединений не заполнен, создать новое; если нет бездействующего соединения и пул соединений заполнен, при опросе очереди бездействия, если соединение не получено, если оно не превышает maxWait , оно продолжится, и если оно превысит, будет выброшено исключение PoolExhaustedException. Если нет незанятых соединений и пул соединений заполнен, время ожидания заимствования равно maxWait, которое по умолчанию равно 30 секундам.

В этом примере программы соединение будет сначала возвращаться, а затем каждый раз переходить в спящий режим, поэтому в пуле соединений всегда есть незанятые соединения, но проверка testOnBorrow не удалась, выполняется повторное соединение, и при повторном соединении выдается исключение.

Исключение, вызванное повторным подключением

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

Получить исходный код подключения

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
    }

резюме

Если нет незанятого соединения и пул соединений заполнен, новое соединение не может быть создано.

  • hikari - это время, которое блокирует connectionTimeout и выдает SQLTransientConnectionException без получения соединения
  • Пул tomcat jdbc заблокирует максимальное время ожидания и выдаст исключение PoolExhaustedException, если соединение не установлено.

Если есть свободное соединение

  • hikari постоянно получает следующее незанятое соединение для проверки в течение времени connectionTimeout и продолжает получать следующее бездействующее соединение, если проверка не удалась, до тех пор, пока тайм-аут не вызовет исключение SQLTransientConnectionException.
  • Пул tomcat jdbc заимствует соединение, а затем проверяет соединение. Если проверка не проходит нормально, он повторно подключается, а затем проверяет. проверка завершится неудачно, будет выброшено исключение SQLException ("Не удалось проверить вновь установленное соединение").

Предполагая, что база данных зависла, но есть незадействованные соединения, testOnBorrow у tomcat=true. Сравнение можно найти

Когда hikari получает соединение, он будет проходить через допустимые соединения одно за другим в течение времени connectionTimeout и, наконец, выдает исключение по тайм-ауту; последующая операция получения соединения блокирует время connectionTimeout, а затем выдает исключение.

Когда пул tomcat jdbc получает соединение, он сначала заимствует соединение, и если обычная проверка не удалась, он переподключится, а затем проверит.Обычно при повторном подключении выдается ConnectException: соединение отклонено, и тогда бизнес-программа быстро выйдет из строя, и последующее соединение также будет установлено.

Видно, что если для hikari установлено слишком большое значение connectionTimeout, легко заблокировать бизнес-поток при зависании базы данных, и пул tomcat jdbc быстро выйдет из строя.

Кроме того, hikari асинхронно устанавливает соединение размера minIdle, в то время как tomcat устанавливает соединение начального размера синхронно.