OptimisticLockException when having parallel path

[Yvonne Ye]

Hi, 

We are using jbpm 7.7.0.Final with Runtime Strategy "Per Request" , we have a process as following.

 We observed that node could fail randomly under a stress environment and get following exception trace. 

Caused by: javax.transaction.RollbackException: ARJUNA016053: Could not commit transaction.

at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1301) [narayana-jts-idlj-5.5.30.Final.jar:5.5.30.Final (revision: 9db991)]

at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:126) [narayana-jts-idlj-5.5.30.Final.jar:5.5.30.Final (revision: 9db991)]

at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:89)

at org.wildfly.transaction.client.LocalTransaction.commitAndDissociate(LocalTransaction.java:73) [wildfly-transaction-client-1.0.2.Final.jar:1.0.2.Final]

at org.wildfly.transaction.client.ContextTransactionManager.commit(ContextTransactionManager.java:71) [wildfly-transaction-client-1.0.2.Final.jar:1.0.2.Final]

at org.wildfly.transaction.client.LocalUserTransaction.commit(LocalUserTransaction.java:53) [wildfly-transaction-client-1.0.2.Final.jar:1.0.2.Final]

at com.ec.bpm.infrastructure.sandbox.interceptors.JtaTransactionApplier.onClosed(JtaTransactionApplier.java:55) [ecbpm-core-12.1.0-SNAPSHOT.jar:12.1.0-SNAPSHOT]

... 92 more

Caused by: javax.persistence.OptimisticLockException: Row was updated or deleted by another transaction (or unsaved-value mapping was incorrect) : [org.jbpm.persistence.processinstance.ProcessInstanceInfo#320]

at org.hibernate.jpa.spi.AbstractEntityManagerImpl.wrapStaleStateException(AbstractEntityManagerImpl.java:1717) [hibernate-entitymanager-5.1.10.Final.jar:5.1.10.Final]

at org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1634) [hibernate-entitymanager-5.1.10.Final.jar:5.1.10.Final]

at org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1602) [hibernate-entitymanager-5.1.10.Final.jar:5.1.10.Final]

at org.hibernate.jpa.spi.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1608) [hibernate-entitymanager-5.1.10.Final.jar:5.1.10.Final]

at org.hibernate.jpa.internal.EntityManagerImpl$CallbackExceptionMapperImpl.mapManagedFlushFailure(EntityManagerImpl.java:235) [hibernate-entitymanager-5.1.10.Final.jar:5.1.10.Final]

at org.hibernate.internal.SessionImpl.flushBeforeTransactionCompletion(SessionImpl.java:3163) [hibernate-core-5.1.10.Final.jar:5.1.10.Final]

at org.hibernate.internal.SessionImpl.beforeTransactionCompletion(SessionImpl.java:2352) [hibernate-core-5.1.10.Final.jar:5.1.10.Final]

at org.hibernate.engine.jdbc.internal.JdbcCoordinatorImpl.beforeTransactionCompletion(JdbcCoordinatorImpl.java:491) [hibernate-core-5.1.10.Final.jar:5.1.10.Final]

at org.hibernate.resource.transaction.backend.jta.internal.JtaTransactionCoordinatorImpl.beforeCompletion(JtaTransactionCoordinatorImpl.java:316) [hibernate-core-5.1.10.Final.jar:5.1.10.Final]

at org.hibernate.resource.transaction.backend.jta.internal.synchronization.SynchronizationCallbackCoordinatorNonTrackingImpl.beforeCompletion(SynchronizationCallbackCoordinatorNonTrackingImpl.java:47) [hibernate-core-5.1.10.Final.jar:5.1.10.Final]

at org.hibernate.resource.transaction.backend.jta.internal.synchronization.RegisteredSynchronization.beforeCompletion(RegisteredSynchronization.java:37) [hibernate-core-5.1.10.Final.jar:5.1.10.Final]

at org.wildfly.transaction.client.AbstractTransaction.performConsumer(AbstractTransaction.java:209) [wildfly-transaction-client-1.0.2.Final.jar:1.0.2.Final]

at org.wildfly.transaction.client.AbstractTransaction.performConsumer(AbstractTransaction.java:220) [wildfly-transaction-client-1.0.2.Final.jar:1.0.2.Final]

at org.wildfly.transaction.client.AbstractTransaction$AssociatingSynchronization.beforeCompletion(AbstractTransaction.java:265) [wildfly-transaction-client-1.0.2.Final.jar:1.0.2.Final]

at com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple.beforeCompletion(SynchronizationImple.java:76) [narayana-jts-idlj-5.5.30.Final.jar:5.5.30.Final (revision: 9db991)]

at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.beforeCompletion(TwoPhaseCoordinator.java:368) [narayana-jts-idlj-5.5.30.Final.jar:5.5.30.Final (revision: 9db991)]

at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:91) [narayana-jts-idlj-5.5.30.Final.jar:5.5.30.Final (revision: 9db991)]

at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:162) [narayana-jts-idlj-5.5.30.Final.jar:5.5.30.Final (revision: 9db991)]

at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1289) [narayana-jts-idlj-5.5.30.Final.jar:5.5.30.Final (revision: 9db991)]

... 98 more

Caused by: org.hibernate.StaleObjectStateException: Row was updated or deleted by another transaction (or unsaved-value mapping was incorrect) : [org.jbpm.persistence.processinstance.ProcessInstanceInfo#320]

at org.hibernate.persister.entity.AbstractEntityPersister.check(AbstractEntityPersister.java:2396) [hibernate-core-5.1.10.Final.jar:5.1.10.Final]

at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:3188) [hibernate-core-5.1.10.Final.jar:5.1.10.Final]

at org.hibernate.persister.entity.AbstractEntityPersister.updateOrInsert(AbstractEntityPersister.java:3063) [hibernate-core-5.1.10.Final.jar:5.1.10.Final]

at org.hibernate.persister.entity.AbstractEntityPersister.update(AbstractEntityPersister.java:3443) [hibernate-core-5.1.10.Final.jar:5.1.10.Final]

at org.hibernate.action.internal.EntityUpdateAction.execute(EntityUpdateAction.java:145) [hibernate-core-5.1.10.Final.jar:5.1.10.Final]

at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:589) [hibernate-core-5.1.10.Final.jar:5.1.10.Final]

at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:463) [hibernate-core-5.1.10.Final.jar:5.1.10.Final]

at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:337) [hibernate-core-5.1.10.Final.jar:5.1.10.Final]

at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:39) [hibernate-core-5.1.10.Final.jar:5.1.10.Final]

at org.hibernate.internal.SessionImpl.flush(SessionImpl.java:1295) [hibernate-core-5.1.10.Final.jar:5.1.10.Final]

at org.hibernate.internal.SessionImpl.managedFlush(SessionImpl.java:468) [hibernate-core-5.1.10.Final.jar:5.1.10.Final]

at org.hibernate.internal.SessionImpl.flushBeforeTransactionCompletion(SessionImpl.java:3159) [hibernate-core-5.1.10.Final.jar:5.1.10.Final]

... 111 more

My thinking is that this error could due to there are two nodes finish at the same time and try to persist the status to ProcessInstanceInfo. I have seen answers from other post that enabling pessimistic locking strategy could help to resolve this, but I tried and it seems the performance has a significant downgrade. So I am asking if there is any other solution? Thanks a lot!

Best regards,

Yvonne

[Maciej Swiderski]

That is correct, its usual cause is the concurrent update to process instance. Although the action should be automatically retried so the process should still finish its executuion. Per process instance strategy has a lock on runtime maanger engine so you could switch to that which should resolve this issue.

Maciej

--
You received this message because you are subscribed to the Google Groups "jBPM Usage" group.
To unsubscribe from this group and stop receiving emails from it, send an email to jbpm-usage+...@googlegroups.com.
To post to this group, send email to jbpm-...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/jbpm-usage/42b7dcef-c52f-4d1d-b105-4fc7351e5692%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[Yvonne Ye]

Thanks Maciej for your reply, 

I have been spending days to try out different solutions, here is my experiment results:

1. Use pessimistic locking strategy:

    This did help to get rid of the StaleObjectStateException,  but the bottle necks transferred to the Database, I encountered "ORA-00054: resource busy and acquire with NOWAIT specified or timeout expired", which is should due to two threads trying to acquire lock. So the solution with pessimistic locking strategy does not help to solve the problem. 

2. User Per_Process_Instance Runtime strategy

    From the experiment, we still see the same problem. Besides, we are calling external service through rest, not sure if per_process_instance strategy will be suitable with this especially in a cluster environment. 

3. Mark ProcessInstanceInfo lastReadDate transient. 

    This is a work-around suggested in the https://issues.jboss.org/browse/JBPM-3902, but maybe due to jbpm 5 and jbpm 6 engine difference, this work-around does not work anymore. 

Digging in the code has following finding:

The completeWorkitem command is accessing the ProcessInstanceInfo with JPAProcessInstanceManager.getProcessInstance()  which will calls processInstanceInfo.updateLastReadDate(), this produces a lot of DB update traffic and result in the StaleObjectException. 

Is there ways to enforce the completeWorkitem command to call ProcessInstance getProcessInstance(long id, boolean readOnly)? 

I am open to any suggestions to solve the concurrent access to ProcessInstanceInfo entity issue. 

Best regards,

Yvonne

在 2018年7月19日星期四 UTC+2上午2:13:34，Maciej Swiderski写道：

[Maciej Swiderski]

looks like you’re on a version that does not have this locking feature implemented. What version are you using? I’d actually recommend to upgrade to version 7 anyway 

On 23 Jul 2018, at 15:09, Yvonne Ye <blsnc...@gmail.com> wrote:

Thanks Maciej for your reply, 

I have been spending days to try out different solutions, here is my experiment results:

1. Use pessimistic locking strategy:

    This did help to get rid of the StaleObjectStateException,  but the bottle necks transferred to the Database, I encountered "ORA-00054: resource busy and acquire with NOWAIT specified or timeout expired", which is should due to two threads trying to acquire lock. So the solution with pessimistic locking strategy does not help to solve the problem. 

2. User Per_Process_Instance Runtime strategy

    From the experiment, we still see the same problem. Besides, we are calling external service through rest, not sure if per_process_instance strategy will be suitable with this especially in a cluster environment. 

yes, it is a good fit, though you need to be on the version that has the feature https://issues.jboss.org/browse/JBPM-5305

3. Mark ProcessInstanceInfo lastReadDate transient. 

    This is a work-around suggested in the https://issues.jboss.org/browse/JBPM-3902, but maybe due to jbpm 5 and jbpm 6 engine difference, this work-around does not work anymore. 

process instance needs to be loaded and updated as it actually moves forward

Digging in the code has following finding:

The completeWorkitem command is accessing the ProcessInstanceInfo with JPAProcessInstanceManager.getProcessInstance()  which will calls processInstanceInfo.updateLastReadDate(), this produces a lot of DB update traffic and result in the StaleObjectException. 

Is there ways to enforce the completeWorkitem command to call ProcessInstance getProcessInstance(long id, boolean readOnly)? 

it’s not possible to make it read only as then you would lose the updates

Maciej

To view this discussion on the web visit https://groups.google.com/d/msgid/jbpm-usage/b8bbce36-7e22-41cb-bdcd-c08dc7b726c5%40googlegroups.com.

[Zadon]

All i am getting the similar issue in JBPM 7 with per request strategy, 

Do we have any recommended solution for this issue?

Thanks