Seeing issue with latest version of 5.17

[ganeshr]

We are seeing one odd behavior after upgrading from 5.15 to 5.17.
We have a business process with multiple human tasks. When the first task is completed then the process should create a second task, here second task is getting created however three create events are getting triggered with three different task id's for the same second task and with same business process id. And finally out of three only one row is getting created in ACT_RU_TASK table and seems two task id's are getting rollbacked. Not able to figure out why it is generating three task create events for the same task with different task id's instead of one.

Activiti engine is running in cluster mode(4 clusters)
Here is the log from three clusters:

Cluster 1:
15-Jan-2015[13:06:05.415]:EBUG:ool-1-thread-202:rg.activiti.engine.impl.pvm.runtime.AtomicOperationTransitionCreateScope:42 - create scope: parent ProcessInstance[65cbde96-9ce9-11e4-bc2d-020030001d4b] continues as execution ScopeExecution[8e259cce-9ce9-11e4-90d0-020030001d69]
15-Jan-2015[13:06:05.416]:EBUG:ool-1-thread-202:rg.activiti.engine.impl.pvm.runtime.AtomicOperationActivityExecute:45 - ScopeExecution[8e259cce-9ce9-11e4-90d0-020030001d69] executes Activity(CustomerAcceptanceHumanTask): org.activiti.engine.impl.bpmn.behavior.UserTaskActivityBehavior
15-Jan-2015[13:06:16.302]:EBUG:ool-1-thread-205:rg.activiti.engine.impl.pvm.runtime.AtomicOperationTransitionDestroyScope:50 - moving concurrent ConcurrentExecution[94a2af3a-9ce9-11e4-90d0-020030001d69] one scope up under ProcessInstance[65cbde96-9ce9-11e4-bc2d-020030001d4b]


Cluster 2:
15-Jan-2015[13:05:57.160]:EBUG:ool-1-thread-107:rg.activiti.engine.impl.pvm.runtime.AtomicOperationActivityExecute:45 - ProcessInstance[5d78c652-9c20-11e4-85d7-020030001b9b] executes Activity(endevent1): org.activiti.engine.impl.bpmn.behavior.NoneEndEventActivityBehavior
15-Jan-2015[13:06:06.131]:EBUG:ool-1-thread-151:rg.activiti.engine.impl.pvm.runtime.AtomicOperationTransitionCreateScope:42 - create scope: parent ProcessInstance[65cbde96-9ce9-11e4-bc2d-020030001d4b] continues as execution ScopeExecution[8e935254-9ce9-11e4-87d8-020030001d4c]
15-Jan-2015[13:06:06.132]:EBUG:ool-1-thread-151:rg.activiti.engine.impl.pvm.runtime.AtomicOperationActivityExecute:45 - ScopeExecution[8e935254-9ce9-11e4-87d8-020030001d4c] executes Activity(CustomerAcceptanceHumanTask): org.activiti.engine.impl.bpmn.behavior.UserTaskActivityBehavior
15-Jan-2015[13:06:43.815]:EBUG:ool-1-thread-144:rg.activiti.engine.impl.pvm.runtime.AtomicOperationTransitionDestroyScope:99 - destroy scope: scoped ScopeExecution[7a9cf252-9c20-11e4-9668-020030001bb0] continues as parent scope ProcessInstance[7a9ca50a-9c20-11e4-9668-020030001bb0]


cluster 3:
15-Jan-2015[13:05:11.286]:EBUG:ool-1-thread-138:rg.activiti.engine.impl.pvm.runtime.AtomicOperationTransitionDestroyScope:50 - moving concurrent ConcurrentExecution[6de27d12-9ce9-11e4-bc2d-020030001d4b] one scope up under ProcessInstance[65cbde96-9ce9-11e4-bc2d-020030001d4b]
15-Jan-2015[13:05:11.287]:EBUG:ool-1-thread-138:rg.activiti.engine.impl.pvm.runtime.AtomicOperationTransitionDestroyScope:75 - merging last concurrent ConcurrentExecution[6de207e1-9ce9-11e4-bc2d-020030001d4b] into concurrent root ConcurrentScopeExecution[6741dd16-9ce9-11e4-bc2d-020030001d4b]
15-Jan-2015[13:05:12.229]:EBUG:ool-1-thread-138:rg.activiti.engine.impl.pvm.runtime.AtomicOperationTransitionNotifyListenerTake:62 -


Process instance id - 65cbde96-9ce9-11e4-bc2d-020030001d4b

Can any help me in resolving this..

Thanks.

[jbarrez]

ok, thx for the xml. Dont see anything wrong straight away.

Why are you making the user tasks async? Is there any particular reason why you'd want that?
What could be happening is that the task listeners are failing, rolling back the original transaction and then other nodes take over the work (and hence recreating the task). How many times is the task created?

[ganeshr]

> Why are you making the user tasks async? Is there any particular reason why you'd want that?
     Yes we ant to do in a seperate transaction, first we want to  compelete the task before the next task is either created/not created.

   Task listener is not failing, events are firing in all nodes and task is creating in all nodes and out of which only one is committed finally in database.  As we are running in 4 nodes, we are ending up with 3 tasks events with 3 different task id's. This is happening only for asynchronous task and for synchronous this is firing only one task event and creating only one task.

   

[trademak]

In the async executor logic a job is only retrieved from the database when it's timed out, so it's really strange that you are experiencing this. It looks like a rollback is done in a couple of cases but the event is being thrown anyway. We'll examine the behaviour and come back to you.

Best regards,

[ganeshr]

Do we have any improvement in latest release of 5.18 for this issue ?

[jbarrez]

There's but one way to know for sure and that is trying it …

I'm not aware of any specific fixes that went in around the issue described here (as we could not reproduce it), but of course many things have changed in the code so it always could be it is fixed for you.