Hello everybody!
We have problems under heavy load (8 requests per second) with our setup. Currently we don't know, what is the cause of the problem, but I will describe our observations. We are using Activiti 5.21.
1. NullPointerExceptions in logfile
2017-05-08T10:40:34.255 ERROR [pool-4-thread-9] Job 46568299 failed
java.lang.NullPointerException: null
at org.activiti.engine.impl.interceptor.CommandContext.performOperation(CommandContext.java:96)
at org.activiti.engine.impl.jobexecutor.AsyncContinuationJobHandler.execute(AsyncContinuationJobHandler.java:35)
at org.activiti.engine.impl.persistence.entity.JobEntity.execute(JobEntity.java:85)
at org.activiti.engine.impl.persistence.entity.MessageEntity.execute(MessageEntity.java:34)
at org.activiti.engine.impl.cmd.ExecuteAsyncJobCmd.execute(ExecuteAsyncJobCmd.java:52)
at org.activiti.engine.impl.interceptor.CommandInvoker.execute(CommandInvoker.java:24)
at org.activiti.engine.impl.interceptor.CommandContextInterceptor.execute(CommandContextInterceptor.java:57)
at org.activiti.engine.impl.interceptor.LogInterceptor.execute(LogInterceptor.java:31)
at org.activiti.engine.impl.cfg.CommandExecutorImpl.execute(CommandExecutorImpl.java:40)
at org.activiti.engine.impl.cfg.CommandExecutorImpl.execute(CommandExecutorImpl.java:35)
at org.activiti.engine.impl.asyncexecutor.ExecuteAsyncRunnable.executeJob(ExecuteAsyncRunnable.java:95)
at org.activiti.engine.impl.asyncexecutor.ExecuteAsyncRunnable.run(ExecuteAsyncRunnable.java:50)
at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Unknown Source)
2. Jobs in act_ru_job table with less than 0 retries_ (down to -8)
3. These jobs contain the message "JobEntity [id=4431434] was updated by another transaction concurrently"
Exception Stacktrance found in DB:
org.activiti.engine.ActivitiOptimisticLockingException: JobEntity [id=4431434] was updated by another transaction concurrently
at org.activiti.engine.impl.db.DbSqlSession$CheckedDeleteOperation.execute(DbSqlSession.java:298)
at org.activiti.engine.impl.db.DbSqlSession.flushRegularDeletes(DbSqlSession.java:929)
at org.activiti.engine.impl.db.DbSqlSession.flushDeletes(DbSqlSession.java:895)
at org.activiti.engine.impl.db.DbSqlSession.flush(DbSqlSession.java:620)
at org.activiti.engine.impl.interceptor.CommandContext.flushSessions(CommandContext.java:212)
at org.activiti.engine.impl.interceptor.CommandContext.close(CommandContext.java:138)
at org.activiti.engine.impl.interceptor.CommandContextInterceptor.execute(CommandContextInterceptor.java:66)
at org.activiti.engine.impl.interceptor.LogInterceptor.execute(LogInterceptor.java:31)
at org.activiti.engine.impl.cfg.CommandExecutorImpl.execute(CommandExecutorImpl.java:40)
at org.activiti.engine.impl.cfg.CommandExecutorImpl.execute(CommandExecutorImpl.java:35)
at org.activiti.engine.impl.asyncexecutor.ExecuteAsyncRunnable.executeJob(ExecuteAsyncRunnable.java:95)
at org.activiti.engine.impl.asyncexecutor.ExecuteAsyncRunnable.run(ExecuteAsyncRunnable.java:50)
at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Unknown Source)
We have one Activiti engine running, with a configured AsyncJobExecutor. The process itself looks as following:
3 parallel subprocesses, each of them contains a JavaServiceTask and UserTask. The ServiceTasks are all configured as async = true.
Before and after these parallel processes we have parallel gateways to fork/join. The first parallel gateway is also set to async = true.
All elements are also exclusive.
I have the feeling, that our configuration is not well set, because 99,9 % of the failing jobs are on the first parallel gateway. But currently I simply don't understand why this happens. I read the section about AsyncJobExecutor as well as the one about Exclusive Jobs. With the knowledge I gained there, I would expect, that such concurrency cannot happen.
Any hint is appreciated.
Best wishes,
Steffi