Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

DatabaseQueryDelegate retry after throwing exception fails to reestablish connection #258

Open
wwelling opened this issue Sep 19, 2024 · 0 comments

Comments

@wwelling
Copy link

wwelling commented Sep 19, 2024

A database query task fails can fail on timeout or disconnect. It then retries from the previous async checkpoint and is unable to connect.

HikariPool-2 - Connection is not available, request timed out after 30037ms.

Delegate exceptions are handled in an @AfterThrowing point-cut and as of now only send an email.

2024-09-19T13:11:05.523-05:00  INFO 25524 --- [mod-camunda] [nio-8081-exec-3] o.f.rest.camunda.delegate.SetupDelegate  : Setup finished in 9.074899 milliseconds
2024-09-19T13:11:05.655-05:00  INFO 25524 --- [mod-camunda] [aTaskExecutor-1] o.f.r.c.d.DatabaseConnectionDelegate     : Connect LDP [] started
2024-09-19T13:11:05.657-05:00  INFO 25524 --- [mod-camunda] [aTaskExecutor-1] com.zaxxer.hikari.HikariDataSource       : HikariPool-2 - Starting...
2024-09-19T13:11:05.811-05:00  INFO 25524 --- [mod-camunda] [aTaskExecutor-1] com.zaxxer.hikari.pool.HikariPool        : HikariPool-2 - Added connection org.postgresql.jdbc.PgConnection@5c34c347
2024-09-19T13:11:05.813-05:00  INFO 25524 --- [mod-camunda] [aTaskExecutor-1] com.zaxxer.hikari.HikariDataSource       : HikariPool-2 - Start completed.
2024-09-19T13:11:05.815-05:00  INFO 25524 --- [mod-camunda] [aTaskExecutor-1] o.f.r.c.d.DatabaseConnectionDelegate     : Connect LDP finished in 159.9653 milliseconds
2024-09-19T13:11:05.858-05:00  INFO 25524 --- [mod-camunda] [aTaskExecutor-1] o.f.r.c.delegate.DatabaseQueryDelegate   : Find Duplicates [] started
2024-09-19T13:41:05.853-05:00  WARN 25524 --- [mod-camunda] [l-1 housekeeper] com.zaxxer.hikari.pool.ProxyLeakTask     : Connection leak detection triggered for org.postgresql.jdbc.PgConnection@5453b15d on thread camundaTaskExecutor-1, stack trace follows

java.lang.Exception: Apparent connection leak detected
        at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:128) ~[HikariCP-5.0.1.jar:na]
        at org.folio.spring.tenant.hibernate.HibernateMultiTenantConnectionProvider.getAnyConnection(HibernateMultiTenantConnectionProvider.java:36) ~[spring-tenant-2.1.0-SNAPSHOT.jar:2.1.0-SNAPSHOT]
        at org.folio.spring.tenant.hibernate.HibernateMultiTenantConnectionProvider.getConnection(HibernateMultiTenantConnectionProvider.java:47) ~[spring-tenant-2.1.0-SNAPSHOT.jar:2.1.0-SNAPSHOT]
        at org.folio.spring.tenant.hibernate.HibernateMultiTenantConnectionProvider.getConnection(HibernateMultiTenantConnectionProvider.java:17) ~[spring-tenant-2.1.0-SNAPSHOT.jar:2.1.0-SNAPSHOT]
        at org.hibernate.internal.ContextualJdbcConnectionAccess.obtainConnection(ContextualJdbcConnectionAccess.java:52) ~[hibernate-core-6.4.4.Final.jar:6.4.4.Final]
        at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:113) ~[hibernate-core-6.4.4.Final.jar:6.4.4.Final]
        at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getPhysicalConnection(LogicalConnectionManagedImpl.java:143) ~[hibernate-core-6.4.4.Final.jar:6.4.4.Final]
        at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getConnectionForTransactionManagement(LogicalConnectionManagedImpl.java:273) ~[hibernate-core-6.4.4.Final.jar:6.4.4.Final]
        at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.begin(LogicalConnectionManagedImpl.java:281) ~[hibernate-core-6.4.4.Final.jar:6.4.4.Final]
        at org.hibernate.resource.transaction.backend.jdbc.internal.JdbcResourceLocalTransactionCoordinatorImpl$TransactionDriverControlImpl.begin(JdbcResourceLocalTransactionCoordinatorImpl.java:232) ~[hibernate-core-6.4.4.Final.jar:6.4.4.Final]
        at org.hibernate.engine.transaction.internal.TransactionImpl.begin(TransactionImpl.java:83) ~[hibernate-core-6.4.4.Final.jar:6.4.4.Final]
        at org.springframework.orm.jpa.vendor.HibernateJpaDialect.beginTransaction(HibernateJpaDialect.java:176) ~[spring-orm-6.1.4.jar:6.1.4]
        at org.springframework.orm.jpa.JpaTransactionManager.doBegin(JpaTransactionManager.java:420) ~[spring-orm-6.1.4.jar:6.1.4]
        at org.springframework.transaction.support.AbstractPlatformTransactionManager.startTransaction(AbstractPlatformTransactionManager.java:531) ~[spring-tx-6.1.4.jar:6.1.4]
        at org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:405) ~[spring-tx-6.1.4.jar:6.1.4]
        at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:137) ~[spring-tx-6.1.4.jar:6.1.4]
        at org.camunda.bpm.engine.spring.SpringTransactionInterceptor.execute(SpringTransactionInterceptor.java:72) ~[camunda-engine-spring-6-7.21.0-alpha2.jar:7.21.0-alpha2]
        at org.camunda.bpm.engine.impl.interceptor.ProcessApplicationContextInterceptor.execute(ProcessApplicationContextInterceptor.java:70) ~[camunda-engine-7.21.0-alpha2.jar:7.21.0-alpha2]
        at org.camunda.bpm.engine.impl.interceptor.CommandCounterInterceptor.execute(CommandCounterInterceptor.java:35) ~[camunda-engine-7.21.0-alpha2.jar:7.21.0-alpha2]
        at org.camunda.bpm.engine.impl.interceptor.LogInterceptor.execute(LogInterceptor.java:33) ~[camunda-engine-7.21.0-alpha2.jar:7.21.0-alpha2]
        at org.camunda.bpm.engine.impl.interceptor.ExceptionCodeInterceptor.execute(ExceptionCodeInterceptor.java:55) ~[camunda-engine-7.21.0-alpha2.jar:7.21.0-alpha2]
        at org.camunda.bpm.engine.impl.jobexecutor.ExecuteJobHelper.executeJob(ExecuteJobHelper.java:57) ~[camunda-engine-7.21.0-alpha2.jar:7.21.0-alpha2]
        at org.camunda.bpm.engine.impl.jobexecutor.ExecuteJobsRunnable.executeJob(ExecuteJobsRunnable.java:110) ~[camunda-engine-7.21.0-alpha2.jar:7.21.0-alpha2]
        at org.camunda.bpm.engine.impl.jobexecutor.ExecuteJobsRunnable.run(ExecuteJobsRunnable.java:71) ~[camunda-engine-7.21.0-alpha2.jar:7.21.0-alpha2]
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144) ~[na:na]
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642) ~[na:na]
        at java.base/java.lang.Thread.run(Thread.java:1583) ~[na:na]

2024-09-19T14:11:50.750-05:00  INFO 25524 --- [mod-camunda] [aTaskExecutor-2] o.f.r.c.delegate.DatabaseQueryDelegate   : Find Duplicates [] started
2024-09-19T14:11:55.767-05:00  WARN 25524 --- [mod-camunda] [aTaskExecutor-2] com.zaxxer.hikari.pool.PoolBase          : HikariPool-2 - Failed to validate connection org.postgresql.jdbc.PgConnection@782059f2 (This connection has been closed.). Possibly consider using a shorter maxLifetime value.
2024-09-19T14:12:00.769-05:00 
@wwelling wwelling added this to FOLIO Sep 19, 2024
@wwelling wwelling converted this from a draft issue Sep 19, 2024
@wwelling wwelling assigned wwelling and unassigned wwelling Sep 19, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
Status: 📋 Backlog
Development

No branches or pull requests

1 participant