Hikari не может обновить соединение, что приводит к утечке соединения - PullRequest
0 голосов
/ 29 апреля 2020

Я использую Hikari Connection Pool и 6 подключений к источникам данных к различным БД MS SQL.

Кажется, что в какой-то момент Hikari не может освободить соединение и добавить новое, а затем мое приложение вылетает.

Журналы:

  :  HikariPool-4 - Pool stats (total=10, active=0, idle=10, waiting=0)
        2020-04-29 12:04:04.710 DEBUG 964 --- [Pool-1 housekeeper] c.z.h.p.HikariPool                           :  HikariPool-1 - Pool stats (total=10, active=0, idle=10, waiting=0)
        2020-04-29 12:04:04.710 DEBUG 964 --- [Pool-5 housekeeper] c.z.h.p.HikariPool                           :  HikariPool-5 - Pool stats (total=10, active=3, idle=7, waiting=0)
        2020-04-29 12:04:04.710 DEBUG 964 --- [Pool-6 housekeeper] c.z.h.p.HikariPool                           :  HikariPool-6 - Pool stats (total=10, active=0, idle=10, waiting=0)
        2020-04-29 12:04:04.710 DEBUG 964 --- [Pool-3 housekeeper] c.z.h.p.HikariPool                           :  HikariPool-3 - Pool stats (total=10, active=0, idle=10, waiting=0)
        2020-04-29 12:04:04.710 DEBUG 964 --- [Pool-2 housekeeper] c.z.h.p.HikariPool                           :  HikariPool-2 - Pool stats (total=9, active=0, idle=9, waiting=0)
        2020-04-29 12:04:04.726 DEBUG 964 --- [ connection closer] c.z.h.p.PoolBase                             :  HikariPool-2 - Closing connection ConnectionID:2580 ClientConnectionId: 4859e8a7-8b9f-4a03-8c57-33bd4f671281: (connection has passed maxLifetime)
        2020-04-29 12:04:04.742 DEBUG 964 --- [2 connection adder] c.z.h.p.HikariPool                           :  HikariPool-2 - Added connection ConnectionID:2637 ClientConnectionId: 20aed2af-eea3-4b87-945e-c6020735e8c4
        2020-04-29 12:04:38.446 DEBUG 964 --- [Pool-6 housekeeper] c.z.h.p.HikariPool                           :  HikariPool-6 - Pool stats (total=10, active=0, idle=10, waiting=0)
        2020-04-29 12:04:38.446 DEBUG 964 --- [Pool-3 housekeeper] c.z.h.p.HikariPool                           :  HikariPool-3 - Pool stats (total=10, active=0, idle=10, waiting=0)
        2020-04-29 12:04:38.446 DEBUG 964 --- [Pool-5 housekeeper] c.z.h.p.HikariPool                           :  HikariPool-5 - Pool stats (total=10, active=3, idle=7, waiting=0)
        2020-04-29 12:04:38.446 DEBUG 964 --- [Pool-4 housekeeper] c.z.h.p.HikariPool                           :  HikariPool-4 - Pool stats (total=10, active=0, idle=10, waiting=0)
        2020-04-29 12:04:38.446 DEBUG 964 --- [Pool-1 housekeeper] c.z.h.p.HikariPool                           :  HikariPool-1 - Pool stats (total=10, active=0, idle=10, waiting=0)
        2020-04-29 12:04:38.446 DEBUG 964 --- [Pool-2 housekeeper] c.z.h.p.HikariPool                           :  HikariPool-2 - Pool stats (total=10, active=0, idle=10, waiting=0)
        2020-04-29 12:05:03.197  WARN 964 --- [Pool-5 housekeeper] c.z.h.p.ProxyLeakTask                        :  Connection leak detection triggered for ConnectionID:2569 ClientConnectionId: 0c2d76e8-bd4b-4de0-b0d7-f36032736671 on thread http-nio-8070-exec-14, stack trace follows
        java.lang.Exception: Apparent connection leak detected
            at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:128)
            at org.springframework.jdbc.datasource.lookup.AbstractRoutingDataSource.getConnection(AbstractRoutingDataSource.java:170)
            at org.hibernate.engine.jdbc.connections.internal.DatasourceConnectionProviderImpl.getConnection(DatasourceConnectionProviderImpl.java:122)
            at org.hibernate.internal.NonContextualJdbcConnectionAccess.obtainConnection(NonContextualJdbcConnectionAccess.java:38)
            at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:104)
            at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getPhysicalConnection(LogicalConnectionManagedImpl.java:134)
            at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.connection(StatementPreparerImpl.java:50)
  ...
            at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
            at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
            at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
            at java.base/java.lang.Thread.run(Thread.java:834)
        2020-04-29 12:05:16.635 DEBUG 964 --- [Pool-6 housekeeper] c.z.h.p.HikariPool                           :  HikariPool-6 - Pool stats (total=10, active=0, idle=10, waiting=0)
        2020-04-29 12:05:16.635 DEBUG 964 --- [Pool-1 housekeeper] c.z.h.p.HikariPool                           :  HikariPool-1 - Pool stats (total=10, active=0, idle=10, waiting=0)
        2020-04-29 12:05:16.635 DEBUG 964 --- [Pool-2 housekeeper] c.z.h.p.HikariPool                           :  HikariPool-2 - Pool stats (total=10, active=0, idle=10, waiting=0)
        2020-04-29 12:05:16.635 DEBUG 964 --- [Pool-3 housekeeper] c.z.h.p.HikariPool                           :  HikariPool-3 - Pool stats (total=10, active=0, idle=10, waiting=0)
        2020-04-29 12:05:16.635 DEBUG 964 --- [Pool-4 housekeeper] c.z.h.p.HikariPool                           :  HikariPool-4 - Pool stats (total=10, active=0, idle=10, waiting=0)
        2020-04-29 12:05:16.635 DEBUG 964 --- [Pool-5 housekeeper] c.z.h.p.HikariPool                           :  HikariPool-5 - Pool stats (total=10, active=3, idle=7, waiting=0)
        2020-04-29 12:05:16.650  WARN 964 --- [Pool-5 housekeeper] c.z.h.p.ProxyLeakTask                        :  Connection leak detection triggered for ConnectionID:2570 ClientConnectionId: 62ff0595-c6ff-47f1-b869-b8e21616638a on thread http-nio-8070-exec-4, stack trace follows
        java.lang.Exception: Apparent connection leak detected
            at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:128)
    .....
            at org.hibernate.loader.Loader.doQuery(Loader.java:953)
            at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:354)
            at org.hibernate.loader.Loader.doList(Loader.java:2838)

После поступления любого запроса я вижу:

2020-04-29 12:09:02.876  WARN 964 --- [Pool-3 housekeeper] c.z.h.p.HikariPool                           :  HikariPool-3 - Thread starvation or clock leap detected (housekeeper delta=52s578ms651µs700ns).
2020-04-29 12:09:02.876  WARN 964 --- [Pool-6 housekeeper] c.z.h.p.HikariPool                           :  HikariPool-6 - Thread starvation or clock leap detected (housekeeper delta=52s578ms472µs500ns)

.

Есть ли какое-либо решение для этого?

Моя конфигурация для HIkari:

2020-04-29 12:43:07.142 DEBUG 6672 --- [              main] c.z.h.HikariConfig                           :  HikariPool-2 - configuration:
2020-04-29 12:43:07.142 DEBUG 6672 --- [              main] c.z.h.HikariConfig                           :  allowPoolSuspension.............false
2020-04-29 12:43:07.142 DEBUG 6672 --- [              main] c.z.h.HikariConfig                           :  autoCommit......................true
2020-04-29 12:43:07.142 DEBUG 6672 --- [              main] c.z.h.HikariConfig                           :  catalog.........................none
2020-04-29 12:43:07.142 DEBUG 6672 --- [              main] c.z.h.HikariConfig                           :  connectionInitSql...............none
2020-04-29 12:43:07.158 DEBUG 6672 --- [              main] c.z.h.HikariConfig                           :  connectionTestQuery............."SELECT 1"
2020-04-29 12:43:07.158 DEBUG 6672 --- [              main] c.z.h.HikariConfig                           :  connectionTimeout...............30000
2020-04-29 12:43:07.158 DEBUG 6672 --- [              main] c.z.h.HikariConfig                           :  dataSource......................none
2020-04-29 12:43:07.158 DEBUG 6672 --- [              main] c.z.h.HikariConfig                           :  dataSourceClassName.............none
2020-04-29 12:43:07.158 DEBUG 6672 --- [              main] c.z.h.HikariConfig                           :  dataSourceJNDI..................none
2020-04-29 12:43:07.158 DEBUG 6672 --- [              main] c.z.h.HikariConfig                           :  dataSourceProperties............{password=<masked>}
2020-04-29 12:43:07.158 DEBUG 6672 --- [              main] c.z.h.HikariConfig                           :  driverClassName................."com.microsoft.sqlserver.jdbc.SQLServerDriver"
2020-04-29 12:43:07.158 DEBUG 6672 --- [              main] c.z.h.HikariConfig                           :  healthCheckProperties...........{}
2020-04-29 12:43:07.158 DEBUG 6672 --- [              main] c.z.h.HikariConfig                           :  healthCheckRegistry.............none
2020-04-29 12:43:07.158 DEBUG 6672 --- [              main] c.z.h.HikariConfig                           :  idleTimeout.....................600000
2020-04-29 12:43:07.158 DEBUG 6672 --- [              main] c.z.h.HikariConfig                           :  initializationFailTimeout.......1
2020-04-29 12:43:07.158 DEBUG 6672 --- [              main] c.z.h.HikariConfig                           :  isolateInternalQueries..........false
2020-04-29 12:43:07.158 DEBUG 6672 --- [              main] c.z.h.HikariConfig                           :  jdbcUrl.........................
2020-04-29 12:43:07.158 DEBUG 6672 --- [              main] c.z.h.HikariConfig                           :  leakDetectionThreshold..........300000
2020-04-29 12:43:07.158 DEBUG 6672 --- [              main] c.z.h.HikariConfig                           :  maxLifetime.....................1800000
2020-04-29 12:43:07.158 DEBUG 6672 --- [              main] c.z.h.HikariConfig                           :  maximumPoolSize.................10
2020-04-29 12:43:07.158 DEBUG 6672 --- [              main] c.z.h.HikariConfig                           :  metricRegistry..................none
2020-04-29 12:43:07.158 DEBUG 6672 --- [              main] c.z.h.HikariConfig                           :  metricsTrackerFactory...........none
2020-04-29 12:43:07.158 DEBUG 6672 --- [              main] c.z.h.HikariConfig                           :  minimumIdle.....................10
2020-04-29 12:43:07.158 DEBUG 6672 --- [              main] c.z.h.HikariConfig                           :  password........................<masked>
2020-04-29 12:43:07.158 DEBUG 6672 --- [              main] c.z.h.HikariConfig                           :  poolName........................"HikariPool-2"
2020-04-29 12:43:07.158 DEBUG 6672 --- [              main] c.z.h.HikariConfig                           :  readOnly........................false
2020-04-29 12:43:07.158 DEBUG 6672 --- [              main] c.z.h.HikariConfig                           :  registerMbeans..................false
2020-04-29 12:43:07.158 DEBUG 6672 --- [              main] c.z.h.HikariConfig                           :  scheduledExecutor...............none
2020-04-29 12:43:07.158 DEBUG 6672 --- [              main] c.z.h.HikariConfig                           :  schema..........................none
2020-04-29 12:43:07.158 DEBUG 6672 --- [              main] c.z.h.HikariConfig                           :  threadFactory...................internal
2020-04-29 12:43:07.158 DEBUG 6672 --- [              main] c.z.h.HikariConfig                           :  transactionIsolation............default
2020-04-29 12:43:07.158 DEBUG 6672 --- [              main] c.z.h.HikariConfig                           :  username........................""
2020-04-29 12:43:07.158 DEBUG 6672 --- [              main] c.z.h.HikariConfig  

                     :  validationTimeout...............5000

Может быть, мне нужно как-то настроить соединение? Или тайм-ауты?

...