cancel
Showing results for 
Search instead for 
Did you mean: 

using asyncExecutor but ActivitiOptimisticLockingException on activiti 5.21.0

gavin_huang
Champ in-the-making
Champ in-the-making
Hi,

In my workflow,
1. there is a Multi-instance sub-process
2. the task on Subprocess are service task
3. all "service task" set activiti:async="true" activiti:exclusive="false"
the image as attachement

the config as follow:
<bean id="asyncExecutor"
      class="org.activiti.engine.impl.asyncexecutor.DefaultAsyncJobExecutor">
      <property name="corePoolSize" value="10" />
      <property name="maxPoolSize" value="50" />
      <property name="keepAliveTime" value="3000000" />
      <property name="queueSize" value="200" />
      <property name="maxTimerJobsPerAcquisition" value="2" />
      <property name="maxAsyncJobsDuePerAcquisition" value="2" />
      <property name="defaultAsyncJobAcquireWaitTimeInMillis"
         value="6000000" />
      <property name="defaultTimerJobAcquireWaitTimeInMillis"
         value="6000000" />
      <property name="timerLockTimeInMillis" value="1800000" />
      <property name="asyncJobLockTimeInMillis" value="1800000" />
   </bean>

when run , the exception as follow:

02:23:43,793 [pool-1-thread-6] DEBUG org.activiti.engine.impl.interceptor.CommandContext  - Optimistic locking exception : org.activiti.engine.ActivitiOptimisticLockingException: VariableInstanceEntity[id=904513d7-968d-11e6-b78c-507b9d5d39ec, name=nrOfActiveInstances, type=integer, longValue=20, textValue=20] was updated by another transaction concurrently
}02:23:43,886 [pool-1-thread-6] DEBUG org.activiti.engine.impl.interceptor.LogInterceptor  - — ExecuteAsyncJobCmd finished ——————————————————–
}02:23:43,886 [pool-1-thread-6] DEBUG org.activiti.engine.impl.interceptor.LogInterceptor  -

…….

02:23:43,908 [pool-1-thread-6] DEBUG org.activiti.engine.impl.persistence.entity.JobEntity.updateMessage  - ==> Parameters: 2(Integer), null, null, 2(Integer), c01cd949-968d-11e6-b78c-507b9d5d39ec(String), VariableInstanceEntity[id=904513d7-968d-11e6-b78c-507b9d5d39ec, name=nrOfActiveInstances, type=integer, longValue=20, textValue=20] was updated by another transaction concurrently(String), 2016-10-20 14:23:53.905(Timestamp), 907e9ad4-968d-11e6-b78c-507b9d5d39ec(String), 1(Integer)
}02:23:43,909 [pool-1-thread-6] DEBUG org.activiti.engine.impl.persistence.entity.JobEntity.updateMessage  - <==    Updates: 1
}02:23:43,948 [pool-1-thread-6] DEBUG org.activiti.engine.impl.interceptor.LogInterceptor  - — JobRetryCmd finished ——————————————————–
}02:23:43,948 [pool-1-thread-6] DEBUG org.activiti.engine.impl.interceptor.LogInterceptor  -

}02:23:43,949 [pool-1-thread-6] DEBUG org.activiti.engine.impl.interceptor.LogInterceptor  - —  finished ——————————————————–
}02:23:43,949 [pool-1-thread-6] DEBUG org.activiti.engine.impl.interceptor.LogInterceptor  -

}02:23:43,949 [pool-1-thread-6] DEBUG org.activiti.engine.impl.asyncexecutor.ExecuteAsyncRunnable  - Optimistic locking exception during job execution. If you have multiple async executors running against the same database, this exception means that this thread tried to acquire an exclusive job, which already was changed by another async executor thread.This is expected behavior in a clustered environment. You can ignore this message if you indeed have multiple job executor threads running against the same database. Exception message: VariableInstanceEntity[id=904513d7-968d-11e6-b78c-507b9d5d39ec, name=nrOfActiveInstances, type=integer, longValue=20, textValue=20] was updated by another transaction concurrently
}02:23:43,950 [pool-1-thread-6] DEBUG org.activiti.engine.impl.interceptor.LogInterceptor  -
6 REPLIES 6

gavin_huang
Champ in-the-making
Champ in-the-making
<bean id="asyncExecutor" class="org.activiti.engine.impl.asyncexecutor.DefaultAsyncJobExecutor">
  <property name="corePoolSize" value="10" />
  <property name="maxPoolSize" value="50" />
  <property name="keepAliveTime" value="3000000" />
  <property name="queueSize" value="200" />
  <property name="maxTimerJobsPerAcquisition" value="2" />
  <property name="maxAsyncJobsDuePerAcquisition" value="2" />
  <property name="defaultAsyncJobAcquireWaitTimeInMillis"
   value="6000000" />
  <property name="defaultTimerJobAcquireWaitTimeInMillis"
   value="6000000" />
  <property name="timerLockTimeInMillis" value="1800000" />
  <property name="asyncJobLockTimeInMillis" value="1800000" />
</bean>

cjose
Elite Collaborator
Elite Collaborator
Looks like you are spinning off multiple parallel sub-processes and from those sub-processes you are trying to update a common variable nrOfActiveInstances. Hence this optimistic locking exception to prevent concurrent updates on a variable.

gavin_huang
Champ in-the-making
Champ in-the-making
Yes, I am spinning off multiple parallel sub-processes and know this optimistic locking exception to prevent concurrent updates on a variable. But how to solve this exception when using multiple parallel sub-processes?
My code do not try to update this common variable nrOfActiveInstances, is the multiple parallel sub-processes. So I do not know how to use multiple parallel sub-processes without optimistic locking exception.

warper
Star Contributor
Star Contributor
Hi Gavin!

>all "service task" set activiti:async="true" activiti:exclusive="false"
You can start instances in different executions if you set async=true, exclusive=false and sequential=false in multi-instance settings. Why do you want to add more async points in subprocesses?

cjose
Elite Collaborator
Elite Collaborator
Since your subprocesses contains just a two service tasks, the chances of these subprocesses ending at the same time is more and hence the variable update happening at the same time. Since I'm not across your complete use-case, it's very difficult to give a solution with the current available information. Since all your tasks inside the subprocess are set to async, setting  maxAsyncJobsDuePerAcquisition=1 in your config might help complete the subprocess, one at a time.

Ciju.

thuynh
Star Contributor
Star Contributor
Hi Gavin,
Your process definition xml seems fine. For your information, here are the Activiti user guides on Multi-Instance (http://www.activiti.org/userguide/#bpmnMultiInstance) and Async Executor (http://www.activiti.org/userguide/#jobExecutorConfiguration).
So I believe the following settings should be enough to get you going with Activiti Multi-Instance and Async. It worked for me.
  • Enable Multi-Instance for the subprocess by defining multi-instance sequential to false and the carnality.
  • Enable SyncExecutor in activiti-cfg.xml (see my attached cfg,xml)
  • For the service tasks to be executed asynchronously, check 'Asynchronous' (see my attached process definition xml)
  • Leave the 'Exclusive' checkbox default (checked) (see my attached process definition xml and documentation why you should leave it default, http://www.activiti.org/userguide/#exclusiveJobs). 
Testing this in a unit test can be troublesome as you are testing async jobs which can complete or not complete by the time the Junit test completes. 
Here is a snippet of my unit test log showing that the service tasks were executed asynchronously in the multi-instance loop.
Multi-Instance
-------------------------------------------------------
 T E S T S
-------------------------------------------------------
Running org.activiti.designer.test.MultiInstanceTest
Dec 19, 2016 12:18:34 PM org.springframework.beans.factory.xml.XmlBeanDefinitionReader loadBeanDefinitions
INFO: Loading XML bean definitions from class path resource [activiti.cfg.xml]
Dec 19, 2016 12:18:36 PM org.activiti.engine.impl.db.DbSqlSession executeSchemaResource
INFO: performing create on engine with resource org/activiti/db/create/activiti.h2.create.engine.sql
Dec 19, 2016 12:18:37 PM org.activiti.engine.impl.db.DbSqlSession executeSchemaResource
INFO: performing create on history with resource org/activiti/db/create/activiti.h2.create.history.sql
Dec 19, 2016 12:18:37 PM org.activiti.engine.impl.db.DbSqlSession executeSchemaResource
INFO: performing create on identity with resource org/activiti/db/create/activiti.h2.create.identity.sql
Dec 19, 2016 12:18:37 PM org.activiti.engine.impl.ProcessEngineImpl <init>
INFO: ProcessEngine default created
Dec 19, 2016 12:18:37 PM org.activiti.engine.impl.asyncexecutor.DefaultAsyncJobExecutor start
INFO: Starting up the default async job executor [org.activiti.engine.impl.asyncexecutor.DefaultAsyncJobExecutor].
Dec 19, 2016 12:18:37 PM org.activiti.engine.impl.asyncexecutor.DefaultAsyncJobExecutor startExecutingAsyncJobs
INFO: Creating thread pool queue of size 100
Dec 19, 2016 12:18:37 PM org.activiti.engine.impl.asyncexecutor.DefaultAsyncJobExecutor startExecutingAsyncJobs
INFO: Creating executor service with corePoolSize 2, maxPoolSize 10 and keepAliveTime 5000
Dec 19, 2016 12:18:37 PM org.activiti.engine.impl.asyncexecutor.AcquireTimerJobsRunnable run
INFO: {} starting to acquire async jobs due
Dec 19, 2016 12:18:37 PM org.activiti.engine.impl.asyncexecutor.AcquireAsyncJobsDueRunnable run
INFO: {} starting to acquire async jobs due
Dec 19, 2016 12:18:37 PM org.activiti.engine.impl.bpmn.deployer.BpmnDeployer deploy
INFO: Processing resource multiInstanceProcess.bpmn20.xml
Dec 19, 2016 12:18:38 PM java.util.logging.LogManager$RootLogger log
INFO: Instance started, id 5 multiInstanceProcess:1:4
Dec 19, 2016 12:18:38 PM java.util.logging.LogManager$RootLogger log
INFO: Execute create service task for execution id 14
Dec 19, 2016 12:18:38 PM java.util.logging.LogManager$RootLogger log
INFO: Execute create service task for execution id 18
Dec 19, 2016 12:18:38 PM java.util.logging.LogManager$RootLogger log
INFO: Running processes: 0
Dec 19, 2016 12:18:38 PM java.util.logging.LogManager$RootLogger log
INFO: Execute create service task for execution id 20
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 4.707 sec
Results :
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0
[INFO] ------------------------------------------------------------------------
[INFO] BUILD SUCCESS
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 7.308s
[INFO] Finished at: Mon Dec 19 12:18:38 ICT 2016
[INFO] Final Memory: 10M/167M
[INFO] ------------------------------------------------------------------------
Hope this helps,
Thanks,
Thong Huynh