HistoricVariableInstanceEntity was updated by another transaction

[texens]

I'm getting the following error when I submit form data.

URL : /service/form/form-data
Method : POST
Payload : {"taskId":"124104","properties":[{"id":"businessName","value":"10123"}, <a lot of other variables go here>]}

Response :
{
errorMessage: "HistoricVariableInstanceEntity[id=124016, name=testUrl, revision=29, type=string, textValue=] was updated by another transaction concurrently"
statusCode: 409
}

I'm not running any other queries on the db at this point of time. All the tasks are sync tasks.
A (user task) —> B (Service Task) —> C (User Task)
This post is for user task A. Service Task B is also executed, and then we come across the aforementioned error.

When I explicitly set the max active connections to 1, I get the following error : Cannot get a connection, pool error Timeout waiting for idle object.

So, it looks like within the same for submit call, a transaction is initiated which is locking the row containing testUrl, then another transaction is initiated which is trying to modify the same row.

Has anybody come across this before ? Any pointers on how to resolve this issue ?

Log trace :
22:15:07.498 [http-8080-1] DEBUG o.a.e.i.p.e.H.updateHistoricVariableInstance - <==    Updates: 0
22:15:07.502 [http-8080-1] DEBUG o.a.e.i.interceptor.CommandContext - Optimistic locking exception : org.activiti.engine.ActivitiOptimisticLockingException: HistoricVariableInstanceEntity[id=124016, name=testUrl, revision=29, type=string, textValue=] was updated by another transaction concurrently
22:15:07.502 [http-8080-1] DEBUG o.s.j.d.DataSourceTransactionManager - Participating in existing transaction
22:15:07.502 [http-8080-1] DEBUG o.a.i.t.managed.ManagedTransaction - Closing JDBC Connection [Transaction-aware proxy for target Connection [com.mysql.jdbc.JDBC4Connection@122db4af]]
22:15:07.519 [http-8080-1] DEBUG o.s.t.support.TransactionTemplate - Initiating transaction rollback on application exception
org.activiti.engine.ActivitiOptimisticLockingException: HistoricVariableInstanceEntity[id=124016, name=testUrl, revision=29, type=string, textValue=] was updated by another transaction concurrently
   at org.activiti.engine.impl.db.DbSqlSession.flushUpdates(DbSqlSession.java:620) ~[activiti-engine-5.15.1.jar:5.15.1]
   at org.activiti.engine.impl.db.DbSqlSession.flush(DbSqlSession.java:502) ~[activiti-engine-5.15.1.jar:5.15.1]
   at org.activiti.engine.impl.interceptor.CommandContext.flushSessions(CommandContext.java:175) ~[activiti-engine-5.15.1.jar:5.15.1]
   at org.activiti.engine.impl.interceptor.CommandContext.close(CommandContext.java:122) ~[activiti-engine-5.15.1.jar:5.15.1]
   at org.activiti.engine.impl.interceptor.CommandContextInterceptor.execute(CommandContextInterceptor.java:66) ~[activiti-engine-5.15.1.jar:5.15.1]
   at org.activiti.spring.SpringTransactionInterceptor$1.doInTransaction(SpringTransactionInterceptor.java:47) ~[activiti-spring-5.15.1.jar:5.15.1]
   at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:131) ~[spring-tx-3.2.7.RELEASE.jar:3.2.7.RELEASE]
   at org.activiti.spring.SpringTransactionInterceptor.execute(SpringTransactionInterceptor.java:45) [activiti-spring-5.15.1.jar:5.15.1]
   at org.activiti.engine.impl.interceptor.LogInterceptor.execute(LogInterceptor.java:37) [activiti-engine-5.15.1.jar:5.15.1]
   at org.activiti.engine.impl.cfg.CommandExecutorImpl.execute(CommandExecutorImpl.java:40) [activiti-engine-5.15.1.jar:5.15.1]
   at org.activiti.engine.impl.cfg.CommandExecutorImpl.execute(CommandExecutorImpl.java:35) [activiti-engine-5.15.1.jar:5.15.1]
   at org.activiti.engine.impl.FormServiceImpl.submitTaskFormData(FormServiceImpl.java:70) [activiti-engine-5.15.1.jar:5.15.1]
   at org.activiti.rest.service.api.form.FormDataResource.submitForm(FormDataResource.java:97) [activiti-rest-5.15.1.jar:5.15.1]
   at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.7.0_51]
   at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) ~[na:1.7.0_51]
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.7.0_51]
   at java.lang.reflect.Method.invoke(Method.java:606) ~[na:1.7.0_51]
   at org.restlet.resource.ServerResource.doHandle(ServerResource.java:503) [org.restlet-2.1.4.jar:na]
   at org.restlet.resource.ServerResource.post(ServerResource.java:1216) [org.restlet-2.1.4.jar:na]
   at org.restlet.resource.ServerResource.doHandle(ServerResource.java:592) [org.restlet-2.1.4.jar:na]
   at org.restlet.resource.ServerResource.doNegotiatedHandle(ServerResource.java:649) [org.restlet-2.1.4.jar:na]
   at org.restlet.resource.ServerResource.doConditionalHandle(ServerResource.java:348) [org.restlet-2.1.4.jar:na]
   at org.restlet.resource.ServerResource.handle(ServerResource.java:952) [org.restlet-2.1.4.jar:na]
   at org.restlet.resource.Finder.handle(Finder.java:246) [org.restlet-2.1.4.jar:na]
   at org.restlet.routing.Filter.doHandle(Filter.java:159) [org.restlet-2.1.4.jar:na]
   at org.restlet.routing.Filter.handle(Filter.java:206) [org.restlet-2.1.4.jar:na]
   at org.restlet.routing.Router.doHandle(Router.java:431) [org.restlet-2.1.4.jar:na]
   at org.restlet.routing.Router.handle(Router.java:648) [org.restlet-2.1.4.jar:na]
   at org.restlet.routing.Filter.doHandle(Filter.java:159) [org.restlet-2.1.4.jar:na]
   at org.restlet.routing.Filter.handle(Filter.java:206) [org.restlet-2.1.4.jar:na]
   at org.restlet.routing.Filter.doHandle(Filter.java:159) [org.restlet-2.1.4.jar:na]
   at org.restlet.routing.Filter.handle(Filter.java:206) [org.restlet-2.1.4.jar:na]
   at org.restlet.routing.Filter.doHandle(Filter.java:159) [org.restlet-2.1.4.jar:na]
   at org.restlet.routing.Filter.handle(Filter.java:206) [org.restlet-2.1.4.jar:na]
   at org.restlet.routing.Filter.doHandle(Filter.java:159) [org.restlet-2.1.4.jar:na]
   at org.restlet.routing.Filter.handle(Filter.java:206) [org.restlet-2.1.4.jar:na]
   at org.restlet.routing.Filter.doHandle(Filter.java:159) [org.restlet-2.1.4.jar:na]
   at org.restlet.engine.application.StatusFilter.doHandle(StatusFilter.java:155) [org.restlet-2.1.4.jar:na]
   at org.restlet.routing.Filter.handle(Filter.java:206) [org.restlet-2.1.4.jar:na]
   at org.restlet.routing.Filter.doHandle(Filter.java:159) [org.restlet-2.1.4.jar:na]
   at org.restlet.routing.Filter.handle(Filter.java:206) [org.restlet-2.1.4.jar:na]
   at org.restlet.engine.CompositeHelper.handle(CompositeHelper.java:211) [org.restlet-2.1.4.jar:na]
   at org.restlet.engine.application.ApplicationHelper.handle(ApplicationHelper.java:84) [org.restlet-2.1.4.jar:na]
   at org.restlet.Application.handle(Application.java:381) [org.restlet-2.1.4.jar:na]
   at org.restlet.routing.Filter.doHandle(Filter.java:159) [org.restlet-2.1.4.jar:na]
   at org.restlet.routing.Filter.handle(Filter.java:206) [org.restlet-2.1.4.jar:na]
   at org.restlet.routing.Router.doHandle(Router.java:431) [org.restlet-2.1.4.jar:na]
   at org.restlet.routing.Router.handle(Router.java:648) [org.restlet-2.1.4.jar:na]
   at org.restlet.routing.Filter.doHandle(Filter.java:159) [org.restlet-2.1.4.jar:na]
   at org.restlet.routing.Filter.handle(Filter.java:206) [org.restlet-2.1.4.jar:na]
   at org.restlet.routing.Router.doHandle(Router.java:431) [org.restlet-2.1.4.jar:na]
   at org.restlet.routing.Router.handle(Router.java:648) [org.restlet-2.1.4.jar:na]
   at org.restlet.routing.Filter.doHandle(Filter.java:159) [org.restlet-2.1.4.jar:na]
   at org.restlet.routing.Filter.handle(Filter.java:206) [org.restlet-2.1.4.jar:na]
   at org.restlet.engine.CompositeHelper.handle(CompositeHelper.java:211) [org.restlet-2.1.4.jar:na]
   at org.restlet.Component.handle(Component.java:392) [org.restlet-2.1.4.jar:na]
   at org.restlet.Server.handle(Server.java:516) [org.restlet-2.1.4.jar:na]
   at org.restlet.engine.ServerHelper.handle(ServerHelper.java:72) [org.restlet-2.1.4.jar:na]
   at org.restlet.engine.adapter.HttpServerHelper.handle(HttpServerHelper.java:152) [org.restlet-2.1.4.jar:na]
   at org.restlet.ext.servlet.ServerServlet.service(ServerServlet.java:1089) [org.restlet.ext.servlet-2.1.4.jar:na]
   at javax.servlet.http.HttpServlet.service(HttpServlet.java:717) [servlet-api.jar:na]
   at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290) [catalina.jar:6.0.32]
   at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206) [catalina.jar:6.0.32]
   at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233) [catalina.jar:6.0.32]
   at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191) [catalina.jar:6.0.32]
   at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127) [catalina.jar:6.0.32]
   at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102) [catalina.jar:6.0.32]
   at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) [catalina.jar:6.0.32]
   at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:298) [catalina.jar:6.0.32]
   at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:859) [tomcat-coyote.jar:6.0.32]
   at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:588) [tomcat-coyote.jar:6.0.32]
   at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:489) [tomcat-coyote.jar:6.0.32]
   at java.lang.Thread.run(Thread.java:744) [na:1.7.0_51]

[frederikherema1]

Can you share the service-task code you're using?

[sathish1]

Not sure why are you doing this code.,
<code>
@Override
public void execute(DelegateExecution execution) {

// loginMobileNumber is taken as input in the preceding user task
execution.setVariable(process(execution.getVariable("loginMobileNumber")));

}
</code>

But if you are trying to set a variable you already have the variable in the execution object?? But this still does not prove the theory of why you get an optimistic lock exception I guess.

Cheers.

[texens]

HI frederikheremans,


Thanks for the reply.

The service task code is as mentioned below. I might have found the issue, currently I'm trying to validate my hypothesis.

In my user task, I take an input "loginMobileNumber" from the user. In the service task that follows this user task  (user task `Registration User Task` –> Service Task `RegistrationValidator`) , I do some processing on this variable - "loginMobileNumber" and set it to this new modified value in the service task.
The flow is something like this :

User Task `Registration` –> take input "loginMobileNumber" from user (via REST API) –> `RegistrationValidator` Service Task (get the variable value from loginMobileNumber, process it, and then update the variable using - execution.setVariable()

I'm guessing, when I try to update the same variable twice - once as part of user task form submission, and then as part of the service task variable update, I'm running into the optimistic locking exception because the revision of the variable - loginMobileNumber is different for the two of them. Now, on commit, the user task writes to disk first and updates the revision number. Next, the service task is trying to write to disk, but the revision has already been updated by the user task (increased by 1). So, this results in the optimistic locking exception.

Could you please confirm or refute this hypothesis.

— USER TASK —

<userTask id="Registration" name="Registration">
      <extensionElements>
        <activiti:formProperty id="loginMobileNumber" name="Login Mobile Number" type="string" required="true"></activiti:formProperty>
      </extensionElements>
</userTask>


— SERVICE TASK —

public class RegistrationValidator implements JavaDelegate {

  @Override
  public void execute(DelegateExecution execution) {

    // loginMobileNumber is taken as input in the preceding user task
    execution.setVariable("loginMobileNumber", process(execution.getVariable("loginMobileNumber")));

  }

  public String process(String loginMobileNumber) {
    // process mobile number
    return processedMobileNumber;
  }

EDIT : fixed the setVariable line
-    execution.setVariable(process(execution.getVariable("loginMobileNumber")));
+    execution.setVariable("loginMobileNumber", process(execution.getVariable("loginMobileNumber")));

[texens]

Hi Sathish,

There was a typo in my earlier post.
- execution.setVariable(process(execution.getVariable("loginMobileNumber")));
+ execution.setVariable("loginMobileNumber", process(execution.getVariable("loginMobileNumber")));

I'm taking the loginMobileNumber as input, and then have a function that processes it (say, to remove country code or preceding 0s) and then I save it to the variable. We can look at it as validation of user input.