HikariPool-1 - Connection is not available, request timed out after 30000ms.

[frnandu]

After upgrading from 3.12.x to 3.19.x (even tried 3.20.6 - same problem) I am getting the following error (full stack below), which I was not getting in previous versions.
I'm using docker image with embedded postgres, configuration as following:

• name: TOLGEE_AUTHENTICATION_ENABLED
  value: "true"
• name: TOLGEE_AUTHENTICATION_CREATE-INITIAL-USER
  value: "true"
• name: TOLGEE_AUTHENTICATION_REGISTRATIONS_ALLOWED
  value: "true"
• name: TOLGEE_AUTHENTICATION_INITIAL-USERNAME
  value: "admin"
• name: TOLGEE_AUTHENTICATION_NEEDS-EMAIL-VERIFICATION
  value: "true"
• name: TOLGEE_AUTHENTICATION_USER-CAN-CREATE-ORGANIZATIONS
  value: "false"
• name: TOLGEE_CACHE_ENABLED
  value: "true"
• name: TOLGEE_RATE-LIMITS_ENABLED
  value: "false"

Did something change in the way tolgee is using connection pooling to db?
After a few minutes, it will work as normal, but from time to time I get this errors.

org.springframework.transaction.CannotCreateTransactionException: Could not open JPA EntityManager for transaction; nested exception is org.hibernate.exception.JDBCConnectionException: Unable to acquire JDBC Connection
at org.springframework.orm.jpa.JpaTransactionManager.doBegin(JpaTransactionManager.java:467) ~[spring-orm-5.3.27.jar:5.3.27]
at org.springframework.transaction.support.AbstractPlatformTransactionManager.startTransaction(AbstractPlatformTransactionManager.java:400) ~[spring-tx-5.3.27.jar:5.3.27]
at org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:373) ~[spring-tx-5.3.27.jar:5.3.27]
at jdk.internal.reflect.GeneratedMethodAccessor131.invoke(Unknown Source) ~[na:na]
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:na]
at java.base/java.lang.reflect.Method.invoke(Method.java:564) ~[na:na]
at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:344) ~[spring-aop-5.3.27.jar:5.3.27]
at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:198) ~[spring-aop-5.3.27.jar:5.3.27]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163) ~[spring-aop-5.3.27.jar:5.3.27]
at org.springframework.batch.core.configuration.annotation.SimpleBatchConfiguration$PassthruAdvice.invoke(SimpleBatchConfiguration.java:128) ~[spring-batch-core-4.3.8.jar:4.3.8]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.3.27.jar:5.3.27]
at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:220) ~[spring-aop-5.3.27.jar:5.3.27]
at com.sun.proxy.$Proxy248.getTransaction(Unknown Source) ~[na:na]
at org.springframework.transaction.interceptor.TransactionAspectSupport.createTransactionIfNecessary(TransactionAspectSupport.java:595) ~[spring-tx-5.3.27.jar:5.3.27]
at org.springframework.transaction.interceptor.TransactionAspectSupport.invokeWithinTransaction(TransactionAspectSupport.java:382) ~[spring-tx-5.3.27.jar:5.3.27]
at org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:119) ~[spring-tx-5.3.27.jar:5.3.27]
at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.3.27.jar:5.3.27]
at org.springframework.aop.framework.CglibAopProxy$CglibMethodInvocation.proceed(CglibAopProxy.java:763) ~[spring-aop-5.3.27.jar:5.3.27]
at org.springframework.aop.interceptor.AsyncExecutionInterceptor.lambda$invoke$0(AsyncExecutionInterceptor.java:115) ~[spring-aop-5.3.27.jar:5.3.27]
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) ~[na:na]
at io.sentry.spring.SentryTaskDecorator.lambda$decorate$0(SentryTaskDecorator.java:23) ~[sentry-spring-5.7.3.jar:na]
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130) ~[na:na]
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:630) ~[na:na]
at java.base/java.lang.Thread.run(Thread.java:832) ~[na:na]
Caused by: org.hibernate.exception.JDBCConnectionException: Unable to acquire JDBC Connection
at org.hibernate.exception.internal.SQLExceptionTypeDelegate.convert(SQLExceptionTypeDelegate.java:48) ~[hibernate-core-5.6.15.Final.jar:5.6.15.Final]
at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:37) ~[hibernate-core-5.6.15.Final.jar:5.6.15.Final]
at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:113) ~[hibernate-core-5.6.15.Final.jar:5.6.15.Final]
at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:99) ~[hibernate-core-5.6.15.Final.jar:5.6.15.Final]
at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:111) ~[hibernate-core-5.6.15.Final.jar:5.6.15.Final]
at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getPhysicalConnection(LogicalConnectionManagedImpl.java:138) ~[hibernate-core-5.6.15.Final.jar:5.6.15.Final]
at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getConnectionForTransactionManagement(LogicalConnectionManagedImpl.java:276) ~[hibernate-core-5.6.15.Final.jar:5.6.15.Final]
at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.begin(LogicalConnectionManagedImpl.java:284) ~[hibernate-core-5.6.15.Final.jar:5.6.15.Final]
at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.begin(JdbcResourceLocalTransactionCoordinatorImpl.java:246) ~[hibernate-core-5.6.15.Final.jar:5.6.15.Final]
at org.hibernate.engine.transaction.internal.TransactionImpl.begin(TransactionImpl.java:83) ~[hibernate-core-5.6.15.Final.jar:5.6.15.Final]
at org.springframework.orm.jpa.vendor.HibernateJpaDialect.beginTransaction(HibernateJpaDialect.java:164) ~[spring-orm-5.3.27.jar:5.3.27]
at org.springframework.orm.jpa.JpaTransactionManager.doBegin(JpaTransactionManager.java:421) ~[spring-orm-5.3.27.jar:5.3.27]
... 23 common frames omitted
Caused by: java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30000ms.
at com.zaxxer.hikari.pool.HikariPool.createTimeoutException(HikariPool.java:696) ~[HikariCP-4.0.3.jar:na]
at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:197) ~[HikariCP-4.0.3.jar:na]
at com.zaxxer.hikari.pool.HikariPool.getConnection(HikariPool.java:162) ~[HikariCP-4.0.3.jar:na]
at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:128) ~[HikariCP-4.0.3.jar:na]
at org.hibernate.engine.jdbc.connections.internal.DatasourceConnectionProviderImpl.getConnection(DatasourceConnectionProviderImpl.java:122) ~[hibernate-core-5.6.15.Final.jar:5.6.15.Final]
at org.hibernate.internal.NonContextualJdbcConnectionAccess.obtainConnection(NonContextualJdbcConnectionAccess.java:38) ~[hibernate-core-5.6.15.Final.jar:5.6.15.Final]
at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:108) ~[hibernate-core-5.6.15.Final.jar:5.6.15.Final]
... 30 common frames omitted

[JanCizmar]

This might happen when some queries occupy the connection pool. Sometimes it happens due to some deadlocks or transaction serialization. Increasing of the connection pool size might help.

The bad think about increasing the pool size is that it's currently not possible, if you use Embedded Postgres. Otherwise, you can increase it.

[JanCizmar]

Hey! Have you somehow resolved this or do you need more assistance?

[frnandu]

Nope, still seeing this regularly on production, specially when using:
/v2/projects/translations?filterKeyName={filterKeyName}&filterNamespace={filterNamespace}&languages={languages}

We use this endpoint to find a key ID by keyName/namespace/language in order to use next

/v2/projects/suggest/machine-translations which requires it.

I assume since this endpoint uses a cursor (for paging) it keeps connections open somehow for some time (can we configure this time amount somehow)?!

We would much more like to use an endpoint which given an exact combination of keyName+namespace+language would return the exact key ID without needing for search/pagging/etc....

We were using /v2/projects/keys/search but it has some bug on a specific combination of keyName (we'll report it in a separate issue with a reproducible minimal test case).

[JanCizmar]

And do you use the embedded Postgres or do you have separate deployment. Increasing the pool size might help.

config.yaml

spring:
  datasource:
    hikari:
      maximum-pool-size: 100

However, this doesn't work for embedded Postgres, since there is a bug, so the pool size is not configurable there. It will be fixed in #911. But if it's issue for you I can fix it now.

[frnandu]

Am currently migrating to a non-embedded postgres, will let you know if it helps. Thanks.

[github-actions]

This issue is stale because it has been open for 30 days with no activity.