flowable / flowable/flowable-engine

Bad behavior using Event Gateway with 2 timers

Open
#3,562 6 comments 0 reactions 0 assignees View on GitHub
Dominant language
Java
Stars
9.5k
Forks
2.9k
Avg merge
7h 8m
Merged PRs (30d)
2

Description

**Describe the bug**
I have designed a loop with an event gateway waiting for either a timer for intermediate loops or another timer for the end (to avoid endless loops).
Unfortunately, I have an unexpected behavior stopping the workflow in some cases (and nothing in Dead Letter).
In some other cases where the end timer succeeds (sometimes after optimistic exception), its theoric end time is far exceeded.

I have tested with the Event Gateway synchronous, asynchronous, and asynchronous exclusive, still with error.

**Expected behavior**
Each workflow started should reach the end event after the end timer duration.

**Code**
[Test_actinst_table.zip](https://github.com/flowable/flowable-engine/files/10270802/Test_actinst_table.zip)

**Screenshots:**
Model of the loop (only the PENDING branch is used):
![image](https://user-images.githubusercontent.com/43992260/208729378-c43e1020-0261-4535-ac6f-c821b81b0ca9.png)
3 processes started:
![image](https://user-images.githubusercontent.com/43992260/208729425-5ea8c822-9375-495f-a434-2d727b2389db.png)
After full execution (no more log in console), we have several end results:
[SUCCESS] Process successfully ended:
![image](https://user-images.githubusercontent.com/43992260/208729445-603e3df4-b7be-4709-9e32-8a03774e7908.png)
[BUG] Process ended but with the intermediate loop timer in green...(??):
![image](https://user-images.githubusercontent.com/43992260/208729465-59b24de6-a96d-427c-a6ca-2bda3c04b1f7.png)
[BUG] Process NOT ended BUT stuck (ACT_RU_ACTINST history not deleted, but no activity with NULL END_TIME...):
![image](https://user-images.githubusercontent.com/43992260/208729496-d446275b-dc4f-4fd9-9644-af7128988c53.png)

**Additional context**
6.7.2 with H2 (default config) in Tomcat 8

**Console log:**
> step1
> step2.1
> step3.0 - init endLoopDate
> max end date for the loop: 12/20/2022 17:59:20
> step3
> 12/20/2022 17:58:50
> step1
> step2.1
> step3.0 - init endLoopDate
> max end date for the loop: 12/20/2022 17:59:23
> step3
> 12/20/2022 17:58:53
> step1
> step2.1
> step3.0 - init endLoopDate
> max end date for the loop: 12/20/2022 17:59:25
> step3
> 12/20/2022 17:58:55
> step3
> 12/20/2022 17:59:00
> step3
> 12/20/2022 17:59:05
> step3
> 12/20/2022 17:59:05
> step3
> 12/20/2022 17:59:10
> step3
> 12/20/2022 17:59:15
> step3
> 12/20/2022 17:59:15
> step3
> 12/20/2022 17:59:25
> 2022-12-20 17:59:25.135 ERROR 15356 --- [ask-Executor-13] ltAsyncRunnableExecutionExceptionHandler : Job a55e3bbe-8087-11ed-9077-6a545a21dcb1 failed
>
> org.flowable.common.engine.api.FlowableOptimisticLockingException: JobEntity [id=a55e3bc1-8087-11ed-9077-6a545a21dcb1] was updated by another transaction concurrently
> at org.flowable.common.engine.impl.db.DbSqlSession.flushDeleteEntities(DbSqlSession.java:643) ~[flowable-engine-common-6.7.2.jar:6.7.2]
> at org.flowable.common.engine.impl.db.DbSqlSession.flushDeletes(DbSqlSession.java:598) ~[flowable-engine-common-6.7.2.jar:6.7.2]
> at org.flowable.common.engine.impl.db.DbSqlSession.flush(DbSqlSession.java:365) ~[flowable-engine-common-6.7.2.jar:6.7.2]
> at org.flowable.common.engine.impl.interceptor.CommandContext.flushSessions(CommandContext.java:212) ~[flowable-engine-common-6.7.2.jar:6.7.2]
> at org.flowable.common.engine.impl.interceptor.CommandContext.close(CommandContext.java:70) ~[flowable-engine-common-6.7.2.jar:6.7.2]
> at org.flowable.common.engine.impl.interceptor.CommandContextInterceptor.execute(CommandContextInterceptor.java:114) ~[flowable-engine-common-6.7.2.jar:6.7.2]
> at org.flowable.common.spring.SpringTransactionInterceptor.lambda$execute$0(SpringTransactionInterceptor.java:57) ~[flowable-spring-common-6.7.2.jar:6.7.2]
> at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:140) ~[spring-tx-5.3.14.jar:5.3.14]
> at org.flowable.common.spring.SpringTransactionInterceptor.execute(SpringTransactionInterceptor.java:57) ~[flowable-spring-common-6.7.2.jar:6.7.2]
> at org.flowable.common.engine.impl.interceptor.LogInterceptor.execute(LogInterceptor.java:30) ~[flowable-engine-common-6.7.2.jar:6.7.2]
> at org.flowable.common.engine.impl.cfg.CommandExecutorImpl.execute(CommandExecutorImpl.java:56) ~[flowable-engine-common-6.7.2.jar:6.7.2]
> at org.flowable.common.engine.impl.cfg.CommandExecutorImpl.execute(CommandExecutorImpl.java:51) ~[flowable-engine-common-6.7.2.jar:6.7.2]
> at org.flowable.job.service.impl.asyncexecutor.ExecuteAsyncRunnable.executeJob(ExecuteAsyncRunnable.java:127) ~[flowable-job-service-6.7.2.jar:6.7.2]
> at org.flowable.job.service.impl.asyncexecutor.ExecuteAsyncRunnable.run(ExecuteAsyncRunnable.java:115) ~[flowable-job-service-6.7.2.jar:6.7.2]
> at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) ~[na:na]
> at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) ~[na:na]
> at java.base/java.lang.Thread.run(Thread.java:829) ~[na:na]
>
> step3
> 12/20/2022 17:59:25
> step4.1
> step3
> step3
> 12/20/2022 17:59:35
> 12/20/2022 17:59:35
> step3
> step3
> 12/20/2022 17:59:45
> 12/20/2022 17:59:45
> step3
> step3
> 12/20/2022 17:59:55
> 12/20/2022 17:59:55
> step3
>
> step3
> 12/20/2022 18:01:05
> 12/20/2022 18:01:05
> step3
> step3
> 12/20/2022 18:01:15
> 12/20/2022 18:01:15
> step3
> step3
> 12/20/2022 18:01:25
> 12/20/2022 18:01:25
> step3
> step3
> 12/20/2022 18:01:35
> 12/20/2022 18:01:35
> step3
> 12/20/2022 18:01:45
> step3
> 12/20/2022 18:01:45
> step3
> step3
> 12/20/2022 18:01:55
> 12/20/2022 18:01:55
> step3
> step3
> 12/20/2022 18:02:05
> 12/20/2022 18:02:05
> step3
> 12/20/2022 18:02:15
> step3
> 12/20/2022 18:02:15
> step3
> step3
> 12/20/2022 18:02:25
> 12/20/2022 18:02:25
> step3
> step3
> 12/20/2022 18:02:35
> 12/20/2022 18:02:35
> step3
> 12/20/2022 18:02:45
> step3
> 12/20/2022 18:02:45
> step3
> step3
> 12/20/2022 18:02:55
> 12/20/2022 18:02:55
> step3
> step3
> 12/20/2022 18:03:05
> 12/20/2022 18:03:05
> step3
> step3
> 12/20/2022 18:03:15
> 12/20/2022 18:03:15
> step3
> step3
> 12/20/2022 18:03:25
> 12/20/2022 18:03:25
> step4.1

ACT_RU_ACTINST:
[issue_eventgtw_actinst.docx](https://github.com/flowable/flowable-engine/files/10270941/issue_eventgtw_actinst.docx)

Contributor guide

No contributing guide indexed for this repository

Research direction

Start by reproducing the two-timer Event Gateway workflow from Test_actinst_table.zip on Flowable 6.7.2 with H2, then inspect the async job execution path shown in the optimistic-locking stack trace. Compare ACT_RU_ACTINST and timer outcomes; done means each workflow reaches its end event on schedule without stuck activity history or repeated timer execution.

Written by the indexing model from the issue text.

Assessment

Tech stack
java
Domain
backend, distributed-systems
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Mostly clear
Newbie friendliness
35/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.