Details
Critical Description
When running RHPAM / kie-server on multiple nodes, concurrent taskComplete operations related to the same process instance will cause an OptimisticLockException on one of the nodes. This exception should cause all operations to be rolled back, however the update on the Task table is still getting committed:
// taskComplete call through REST
2021-03-01 03:24:06,561 DEBUG [org.kie.server.services.jbpm.UserTaskServiceBase] (default task-11) About to complete task with id '2448237' as user 'xyz' with data {...}
// update statement
2021-03-01 03:24:06,668 DEBUG [org.hibernate.SQL] (default task-11) update Task set archived=?, allowedToDelegate=?, description=?, formName=?, name=?, taskInitiator_id=?, priority=?, subTaskStrategy=?, subject=?, activationTime=?, actualOwner_id=?, createdBy_id=?, createdOn=?, deploymentId=?, documentAccessType=?, documentContentId=?, documentType=?, expirationTime=?, faultAccessType=?, faultContentId=?, faultName=?, faultType=?, outputAccessType=?, outputContentId=?, outputType=?, parentId=?, previousStatus=?, processId=?, processInstanceId=?, processSessionId=?, skipable=?, status=?, workItemId=?, taskType=?, OPTLOCK=? where id=? and OPTLOCK=?
// parameters status and id
2021-03-01 03:24:06,679 TRACE [org.hibernate.metamodel.model.convert.internal.NamedEnumValueConverter] (default task-11) Binding [Completed] to parameter: [32]
2021-03-01 03:24:06,679 TRACE [org.hibernate.type.descriptor.sql.BasicBinder] (default task-11) binding parameter [36] as [BIGINT] - [2448237]
// OptimisticLockException (due to concurrent update of the process instance on another node)
2021-03-01 03:24:06,684 WARN [org.jbpm.services.task.persistence.TaskTransactionInterceptor] (default task-11) Could not commit session: javax.persistence.OptimisticLockException: Row was updated or deleted by another transaction (or unsaved-value mapping was incorrect) : [org.jbpm.persistence.processinstance.ProcessInstanceInfo#639156]
at org.hibernate.internal.ExceptionConverterImpl.wrapStaleStateException(ExceptionConverterImpl.java:226)
at org.hibernate.internal.ExceptionConverterImpl.convert(ExceptionConverterImpl.java:93)
at org.hibernate.internal.ExceptionConverterImpl.convert(ExceptionConverterImpl.java:181)
at org.hibernate.query.internal.AbstractProducedQuery.list(AbstractProducedQuery.java:1514)
at org.hibernate.query.Query.getResultList(Query.java:135)
at org.jbpm.services.task.persistence.JPATaskPersistenceContext.queryStringWithParameters(JPATaskPersistenceContext.java:665)
at org.jbpm.services.task.persistence.JPATaskPersistenceContext.queryWithParametersInTransaction(JPATaskPersistenceContext.java:488)
at org.jbpm.services.task.audit.JPATaskLifeCycleEventListener.getAuditTask(JPATaskLifeCycleEventListener.java:468)
at org.jbpm.services.task.audit.JPATaskLifeCycleEventListener.afterTaskCompletedEvent(JPATaskLifeCycleEventListener.java:189)
at org.jbpm.services.task.events.TaskEventSupport.fireAfterTaskCompleted(TaskEventSupport.java:347)
at org.jbpm.services.task.internals.lifecycle.MVELLifeCycleManager.taskOperation(MVELLifeCycleManager.java:411)
at org.jbpm.services.task.impl.TaskInstanceServiceImpl.complete(TaskInstanceServiceImpl.java:191)
// After the OptimisticLockExcpetion, there is another Task update statement that sets the Task instance to completed:
2021-03-01 03:24:06,765 DEBUG [org.hibernate.SQL] (default task-11) update Task set archived=?, allowedToDelegate=?, description=?, formName=?, name=?, taskInitiator_id=?, priority=?, subTaskStrategy=?, subject=?, activationTime=?, actualOwner_id=?, createdBy_id=?, createdOn=?, deploymentId=?, documentAccessType=?, documentContentId=?, documentType=?, expirationTime=?, faultAccessType=?, faultContentId=?, faultName=?, faultType=?, outputAccessType=?, outputContentId=?, outputType=?, parentId=?, previousStatus=?, processId=?, processInstanceId=?, processSessionId=?, skipable=?, status=?, workItemId=?, taskType=?, OPTLOCK=? where id=? and OPTLOCK=?
2021-03-01 03:24:06,769 TRACE [org.hibernate.metamodel.model.convert.internal.NamedEnumValueConverter] (default task-11) Binding [Completed] to parameter: [32]
2021-03-01 03:24:06,769 TRACE [org.hibernate.type.descriptor.sql.BasicBinder] (default task-11) binding parameter [36] as [BIGINT] - [2448237]
In the database, we see an inconsistent state of the Task entity as a result:
| Table | Task status |
| AuditTaskImpl | InProgress |
| TaskEvent | ADDED, STARTED |
| Task | Completed |
Further debugging shows that the OptimisticLockRetryInterceptor retries the operation once, which in turn calls the TaskTransactionInterceptor.execute method, which then results in the status update of the Task entity through the TaskSynchronizationImpl.afterCompletion method. If I disable the logic in OptimisticLockRetryInterceptor by setting retries=0 for a test, then the outcome is expected (all updates rolled back), and even the client is getting the error message.
Attachments
Issue Links
- is related to
-
JBPM-9633 Task instance marked as Completed despite OptimisticLockException
-
- Resolved
-
- relates to
-
RHPAM-3490 Provide configuration parameters for OptimisticLockRetryInterceptor
-
- Closed
-
