24

I am using Spring Boot (1.5.6), Hibernate, Postgres, Hikari (2.7.8) . My configuration is :

spring.datasource.hikari.minimumIdle=1
spring.datasource.hikari.maximumPoolSize=20
spring.datasource.hikari.idleTimeout=30000
spring.datasource.hikari.poolName=SpringBootJPAHikariCP
spring.datasource.hikari.maxLifetime=50000
spring.datasource.hikari.connectionTimeout=30000

What I expect is, Idle connections should be released after 30000 ms/ 30 sec of idleness.
The problem is with every request new connection being made leaving all the idle connection as it is. So after some times I end up with 20 idle connection and with a new request Hikari try to gain a new connection and get SpringBootJPAHikariCP - Connection is not available, request timed out after 30001ms.

So, What I am doing wrong.? Or Have the misunderstood the configuration?

Hikari initialization Log:

SpringBootJPAHikariCP - configuration:
 allowPoolSuspension.............false
 autoCommit......................true
 catalog.........................none
 connectionInitSql...............none
 connectionTestQuery.............none
 connectionTimeout...............30000
 dataSource......................none
 dataSourceClassName.............none
 dataSourceJNDI..................none
 dataSourceProperties............{password=<masked>}
 driverClassName................."org.postgresql.Driver"
 healthCheckProperties...........{}
 healthCheckRegistry.............none
 idleTimeout.....................30000
 initializationFailFast..........true
 initializationFailTimeout.......1
 isolateInternalQueries..........false
 jdbc4ConnectionTest.............false
 jdbcUrl.........................jdbc:postgresql://localhost:5432/dbname
 leakDetectionThreshold..........0
 maxLifetime.....................50000
 maximumPoolSize.................20
 metricRegistry..................none
 metricsTrackerFactory...........none
 minimumIdle.....................1
 password........................<masked>
 poolName........................"SpringBootJPAHikariCP"
 readOnly........................false
 registerMbeans..................false
 scheduledExecutor...............none
 scheduledExecutorService........internal
 schema..........................none
 threadFactory...................internal
 transactionIsolation............default
 username........................"postgres"
 validationTimeout...............5000

Update: In last 24 hour I have tried several solution from different thread and none of them fixed my issue. So here is the observations that might be important.

  1. SpringBootJPAHikariCP - Reset (autoCommit) on connection org.postgresql.jdbc.PgConnection@1344bbf1 found this log. studied Reset (autoCommit) on connection in HikariCP this thread. tried to set auto commit same (true) at both side (hibernate and Hikari) and tried with false at both side also. still no luck.
  2. Enables leakDetectionThreshold, got leak detection exception. So tried to understand if hibernate/spring transaction manager releasing connections. From bellow Logs it looks like hibernate working fine.

    28 22:19:35- DEBUG - o.s.orm.jpa.JpaTransactionManager-371 ::  Opened new EntityManager [org.hibernate.jpa.internal.EntityManagerImpl@4212be39] for JPA transaction
    28 22:19:35- DEBUG - o.h.e.t.internal.TransactionImpl-51 ::  begin
    28 22:19:35- DEBUG - o.s.orm.jpa.JpaTransactionManager-403 ::  Exposing JPA transaction as JDBC transaction [org.springframework.orm.jpa.vendor.HibernateJpaDialect$HibernateConnectionHandle@243e942]
    2com.someentity.MyEntity#ac918eed-345f-4a6c-8539-fe14e7fc41e2
    28 22:19:35- DEBUG - o.h.r.j.i.LogicalConnectionManagedImpl-137 ::  Initiating JDBC connection release from afterTransaction
    28 22:19:35- DEBUG - c.zaxxer.hikari.pool.ProxyConnection-242 ::  SpringBootJPAHikariCP - Executed rollback on connection org.postgresql.jdbc.PgConnection@1344bbf1 due to dirty commit state on close().
    28 22:19:35- DEBUG - o.h.e.i.AbstractFlushingEventListener-132 ::  Processing flush-time cascades
    28 22:19:35- DEBUG - o.h.e.i.AbstractFlushingEventListener-174 ::  Dirty checking collections
    
    28 22:19:35- DEBUG - org.hibernate.internal.SessionImpl-508 ::  Disconnecting session
    28 22:19:35- DEBUG - o.s.orm.jpa.JpaTransactionManager-759 ::  Initiating transaction commit
    28 22:19:35- DEBUG - o.s.orm.jpa.JpaTransactionManager-512 ::  Committing JPA transaction on EntityManager [org.hibernate.jpa.internal.EntityManagerImpl@4212be39]
    28 22:19:35- DEBUG - o.h.e.t.internal.TransactionImpl-62 ::  committing
    28 22:19:35- DEBUG - o.h.r.j.i.LogicalConnectionManagedImpl-137 ::  Initiating JDBC connection release from afterTransaction
    28 22:19:35- DEBUG - o.h.r.j.i.LogicalConnectionManagedImpl-137 ::  Initiating JDBC connection release from afterTransaction
    28 22:19:35- DEBUG - o.s.orm.jpa.JpaTransactionManager-600 ::  Closing JPA EntityManager [org.hibernate.jpa.internal.EntityManagerImpl@4212be39] after transaction
    28 22:19:35- DEBUG - o.s.o.jpa.EntityManagerFactoryUtils-435 ::  Closing JPA EntityManager
    
  3. All the idle connectiona are idle form postgres point of view and active form Hikari point of view. So when there are 5 idle connection from database, there are toatal = 5, active=4, idle = ,waiting=0 in Hikari log.

Note:

  1. may be I am having this exact issue https://github.com/brettwooldridge/HikariCP/issues/109 in my case active connection increasing with every transaction.

  2. HikariCP - connection is not available this is also a same issue. but nobody provide clear solution to this. btw I was using @Transactional from the begging as suggested by the accepted answer.

brettw
  • 10,664
  • 2
  • 42
  • 59
Saif
  • 6,804
  • 8
  • 40
  • 61
  • 1
    Your code is not returning connections to the pool. This has nothing to do with idleTimeout configuration setting. – Okas May 27 '18 at 17:24
  • 1
    how do i resolve this then. any suggestion or resource to read.? btw i am pretty new in connection pool matter. – Saif May 27 '18 at 17:41
  • 1
    Enable the ``leakDetectionThreshold`` and watch the log for leak stacktraces. – brettw May 28 '18 at 06:36
  • after enabling `leakDetectionThreshold` got several leak detection exception. so possibly it is not the pool it self, may be my application doing something wrong. still open to suggestions – Saif May 28 '18 at 06:51
  • @brettw can you please check my update on the question. still stuck with the issue. – Saif May 28 '18 at 16:53
  • Is your configuration opening and closing EntityManagers constantly? Your log kind of implies that it does, eg. ``Opened new EntityManager [org.hibernate.jpa.internal.EntityManagerImpl@4212be39] for JPA transaction 28 22:19:35- DEBUG - o.h.e.t.internal.TransactionImpl-51``. Also, ``autoCommit`` should definintely be ``false``. – brettw May 29 '18 at 18:51
  • @Saif pls create an issue / comment your details at `HikariCP` github repository , hope the `HikariCP` community will be able to solve this Or guide you to a solution – Aminul Jun 01 '18 at 08:17
  • thank you @brettw for the suggestion. Solved this problem afterwards, could not post because of missing details. Thanks anyway. – Saif Oct 30 '18 at 13:37

1 Answers1

7

This was not any Hikari issue, there was a mistake in my end. Still posting the details of how this occurred, in case it helps someone.

I was using spring boot 1.5.6 (This was the latest version when I start working). This version included spring-orm 4.3.1. This version of spring-orm included support for three versions of hibernate, Hibernate5, Hibernate4 and Hibernate3.

So I configured spring boot with bellow configuration for current_session_context_class.

spring.jpa.properties.hibernate.current_session_context_class=org.springframework.orm.hibernate4.SpringSessionContext

Everything was working fine until it comes to connection management of Hikari. What happened is spring-boot-starter-jpa for 1.5.6 included Hibernate5 (I mean hibernate core) .

So, After performing any DB operation spring loosing control of that connection (most possibility for this version mismatch). Hence the problem.

After changing

org.springframework.orm.hibernate4.SpringSessionContext

to

org.springframework.orm.hibernate5.SpringSessionContext

the problem was solved immediately.

My current configuration is

spring.jpa.properties.hibernate.current_session_context_class=org.springframework.orm.hibernate5.SpringSessionContext
spring.jpa.properties.hibernate.dialect=org.hibernate.dialect.PostgreSQL95Dialect

FYI, after solving the problem is switched to Spring Boot 2.

Saif
  • 6,804
  • 8
  • 40
  • 61
  • 1
    Hello @saif can you suggest configuration for me because after reading your post also i am not able to fix my hikari pool issue – Nikhil Sharma Jan 21 '20 at 07:53
  • Try adding maxLifeTime parameter to your hikariPool – veritas May 13 '22 at 18:59
  • @saif We have similar issue and we are using `spring-boot-starter-parent` version `2.3.8.RELEASE`. How do we identify if there is mismatch of Hibernate version? Please guide – Ankur Raiyani Sep 06 '22 at 09:34