Event registry exception spam

Hello.

This problem is a bit annoying. I’m trying to get “fix” a specific event registry exception, however whatever I do, the result is the same: each minute there is an exception printed in the log file.

Information:

  • Spring Boot application with embedded Tomcat
  • Application is using Flowable Spring Boot Maven dependencies
  • Application has two datasources which are properly configured and assigned where needed
  • Everything regarding Flowable dependencies work, except the stuff in below exception
  • I do not get this exception locally using the exact same configuration
  • I get this exception only on company’s Linux virtual machine where we host the application

I’ve tried:

  • Injecting custom SpringEventRegistryEngineConfiguration bean
  • “Editing” existing/default SpringEventRegistryEngineConfiguration bean
  • Adding “flowable.eventregistry.enabled=false” to “application.properties”
  • Adding “flowable.eventregistry.enable-change-detection=false” to “application.properties”
  • Adding “flowable.eventregistry.change-detection-delay=1000000000000000000” to “application.properties”

Nothing works. Whatever I do

11-05-2020 15:21:54.898 [main] INFO  o.f.app.engine.impl.AppEngineImpl.<init> - AppEngine default created
11-05-2020 15:21:55.984 [main] INFO  o.f.j.s.i.a.AbstractAsyncExecutor.start - Starting up the async job executor [org.flowable.spring.job.service.SpringAsyncExecutor].
11-05-2020 15:21:55.985 [Thread-4] INFO  o.f.j.s.i.a.AcquireTimerJobsRunnable.run - starting to acquire async jobs due
11-05-2020 15:21:55.986 [Thread-5] INFO  o.f.j.s.i.a.ResetExpiredJobsRunnable.run - starting to reset expired jobs for engine cmmn
11-05-2020 15:21:55.986 [main] INFO  o.f.j.s.i.a.AbstractAsyncExecutor.start - Starting up the async job executor [org.flowable.spring.job.service.SpringAsyncExecutor].
11-05-2020 15:21:55.985 [Thread-3] INFO  o.f.j.s.i.a.AcquireAsyncJobsDueRunnable.run - starting to acquire async jobs due
11-05-2020 15:21:55.991 [Thread-6] INFO  o.f.j.s.i.a.AcquireAsyncJobsDueRunnable.run - starting to acquire async jobs due
11-05-2020 15:21:55.994 [Thread-8] INFO  o.f.j.s.i.a.ResetExpiredJobsRunnable.run - starting to reset expired jobs for engine bpmn
11-05-2020 15:21:55.995 [Thread-7] INFO  o.f.j.s.i.a.AcquireTimerJobsRunnable.run - starting to acquire async jobs due
11-05-2020 15:21:56.044 [main] INFO  h.f.d.p.DigipopPortalApplication.logStarted - Started DigipopPortalApplication in 18.426 seconds (JVM running for 19.111)
11-05-2020 15:22:04.378 [flowable-event-change-detector-1] ERROR o.f.e.i.m.EventRegistryChangeDetectionRunnable.run - Exception while detecting event registry changes
org.springframework.transaction.CannotCreateTransactionException: Could not open JDBC Connection for transaction; nested exception is java.sql.SQLException: HikariDataSource HikariDataSource (HikariPool-2) has been closed.
        at org.springframework.jdbc.datasource.DataSourceTransactionManager.doBegin(DataSourceTransactionManager.java:307)
        at org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:376)
        at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:137)
        at org.flowable.common.spring.SpringTransactionInterceptor.execute(SpringTransactionInterceptor.java:56)
        at org.flowable.common.engine.impl.interceptor.LogInterceptor.execute(LogInterceptor.java:30)
        at org.flowable.common.engine.impl.cfg.CommandExecutorImpl.execute(CommandExecutorImpl.java:56)
        at org.flowable.common.engine.impl.cfg.CommandExecutorImpl.execute(CommandExecutorImpl.java:51)
        at org.flowable.common.engine.impl.query.AbstractQuery.list(AbstractQuery.java:117)
        at org.flowable.eventregistry.impl.management.DefaultEventRegistryChangeDetectionManager.detectChanges(DefaultEventRegistryChangeDetectionManager.java:50)
        at org.flowable.eventregistry.impl.management.EventRegistryChangeDetectionRunnable.run(EventRegistryChangeDetectionRunnable.java:35)
        at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        at java.lang.Thread.run(Thread.java:748)
Caused by: java.sql.SQLException: HikariDataSource HikariDataSource (HikariPool-2) has been closed.
        at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:96)
        at org.springframework.jdbc.datasource.DataSourceTransactionManager.doBegin(DataSourceTransactionManager.java:263)
        ... 17 common frames omitted
11-05-2020 15:23:04.379 [flowable-event-change-detector-1] ERROR o.f.e.i.m.EventRegistryChangeDetectionRunnable.run - Exception while detecting event registry changes
org.springframework.transaction.CannotCreateTransactionException: Could not open JDBC Connection for transaction; nested exception is java.sql.SQLException: HikariDataSource HikariDataSource (HikariPool-2) has been closed.
        at org.springframework.jdbc.datasource.DataSourceTransactionManager.doBegin(DataSourceTransactionManager.java:307)
        at org.springframework.transaction.support.AbstractPlatformTransactionManager.getTransaction(AbstractPlatformTransactionManager.java:376)
        at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:137)
        at org.flowable.common.spring.SpringTransactionInterceptor.execute(SpringTransactionInterceptor.java:56)
        at org.flowable.common.engine.impl.interceptor.LogInterceptor.execute(LogInterceptor.java:30)
        at org.flowable.common.engine.impl.cfg.CommandExecutorImpl.execute(CommandExecutorImpl.java:56)
        at org.flowable.common.engine.impl.cfg.CommandExecutorImpl.execute(CommandExecutorImpl.java:51)
        at org.flowable.common.engine.impl.query.AbstractQuery.list(AbstractQuery.java:117)
        at org.flowable.eventregistry.impl.management.DefaultEventRegistryChangeDetectionManager.detectChanges(DefaultEventRegistryChangeDetectionManager.java:50)
        at org.flowable.eventregistry.impl.management.EventRegistryChangeDetectionRunnable.run(EventRegistryChangeDetectionRunnable.java:35)
        at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        at java.lang.Thread.run(Thread.java:748)
Caused by: java.sql.SQLException: HikariDataSource HikariDataSource (HikariPool-2) has been closed.
        at com.zaxxer.hikari.HikariDataSource.getConnection(HikariDataSource.java:96)
        at org.springframework.jdbc.datasource.DataSourceTransactionManager.doBegin(DataSourceTransactionManager.java:263)
        ... 17 common frames omitted

I’m out of ideas. Bottom line, I just need the Event Registry or the thread that checks this changes disabled completely, for now.

Hey @fiki574,

If you have

flowable.eventregistry.enable-change-detection=false

then the thread should not run. Can you debug and check when DefaultEventRegistryChangeDetectionExecutor is created and when DefaultEventRegistryChangeDetectionExecutor#initialize is invoked?

Cheers,
Filip

Hey.

Having the following three properties (including the one you suggested) in the application.properties file has no impact whatsoever, after the application restart I can still see the thread running as per usual once every minute.

flowable.eventregistry.enabled=false
flowable.eventregistry.enable-change-detection=false
flowable.eventregistry.change-detection-delay=1000000000000000000

However, I’ve added the following bean to my Spring Boot application, and for past hour there is no exception in the log, though it sometimes takes several hours for that exception to show up so I’m kind of suspicious that this solves it.

@Bean
public EngineConfigurationConfigurer<SpringEventRegistryEngineConfiguration> eventRegistryEngineConfiguration() {
  return configuration -> {
    configuration.setDataSource(dataSource);
    configuration.setTransactionManager(transactionManager);
    configuration.setDatabaseSchemaUpdate("false");
  };
}

Hey @fiki574,

Can you do the debugging that I mentioned?

It doesn’t make sense for the code snippet you shared to disable the thread.

Cheers,
Filip

Hey.

It didn’t disable the thread obviously (neither I aimed at that), it might have fixed that exception that was getting spammed in the log by explicitly providing a data source in this way.

I’ll let it run like this for now, if the exception happens again, I’ll do the debugging and post further replies.

The properties entry you’re talking about makes no sense because of this:

It is already set to false, so by default it shouldn’t even run.

Okay, so I’ve debugged it.

After the following line, the creation and initialization of event registry starts.

2020-05-12 10:12:36.158 INFO 824 --- [ restartedMain] o.f.a.s.SpringAppEngineConfiguration : Executing configure() of class org.flowable.eventregistry.spring.configurator.SpringEventRegistryConfigurator (priority:100000)

And from the picture we can see that the property gets ignored:

And from your source code, I can see you don’t use that variable in any check whatsoever.

1 Like

That’s what I suspected. This is fixed on master. It was done in https://github.com/flowable/flowable-engine/commit/a6a71428ec90006d4855b558bd644287b86d1e16

1 Like

Okay, right. So is that fix available in a downloadable version? Or do I have to compile it on my own?

That fix is not yet released. You’ll need to compile it on your own.

1 Like

Okay so, I had two instances of my application running from the same directory, pointing to the same database, and one of them was deleted from the file system but was still normally running.

Force killing the deleted application and restarting my proper one “fixed” the exception occurences, so this was mostly an error from my side.

But the fix you posted still stands and I have it in mind, just wanted to clear up why this exception happened.

Thanks a lot for clarifying this with us. We were really surprised from the exception as well.

1 Like