cancel
Showing results for 
Search instead for 
Did you mean: 

Async job executed twice after optimisticLockException

rzr1
Champ in-the-making
Champ in-the-making
Hey,

we observed some strange situation during processing. We are using your engine in multi-clustered environment connected to one db. Our process definition contains serviceTask given below:


<serviceTask id="transferService" name="Transfer service" activiti:async="true" activiti:delegateExpression="${transferServiceDelegate}">
   <extensionElements> <activiti:failedJobRetryTimeCycle>R3/PT60M</activiti:failedJobRetryTimeCycle> </extensionElements>
</serviceTask>


Task is preceded by timerEvent waiting for start of the new month. In this month we spotted several situations like below (these are logs from one of application nodes - situation took place on one machine):


INFO [2016-09-01 00:11:20.949] [D004635001,o.a.c.s.S.S.ServiceManagement           ,provideAsyncJobExecutor-7,,,,1087641058] Outbound Message
INFO [2016-09-01 00:11:37.860] [D004635001,o.a.c.s.S.S.ServiceManagement           ,provideAsyncJobExecutor-7,,,,1087641058] Inbound Message
WARN [2016-09-01 00:11:37.947] [D004635001,.e.DispatcherLoggingExecuteAsyncRunnable,provideAsyncJobExecutor-7,,,,1087641058] Optimistic locking exception during job execution: 836c28ab-6fc6-11e6-80e5-005056aa1dfc
INFO [2016-09-01 00:11:59.582] [D004635001,o.a.c.s.S.S.ServiceManagement           ,provideAsyncJobExecutor-7,,,,1087641058] Outbound Message
INFO [2016-09-01 00:11:59.824] [D004635001,o.a.c.s.S.S.ServiceManagement           ,provideAsyncJobExecutor-7,,,,1087641058] Inbound Message
ERROR [2016-09-01 00:11:59.844] [D004635001,.e.DispatcherLoggingExecuteAsyncRunnable,provideAsyncJobExecutor-7,,,,1087641058] Job 836c28ab-6fc6-11e6-80e5-005056aa1dfc failed


Description of steps:
#1 First Outbound Message / Inbound Message -> WS call ended with success.
#2 Optimistic locking exception during job execution: 836c28ab-6fc6-11e6-80e5-005056aa1dfc
#3 Outbound Message / Inbound Message -> same as #1, but ended with fail (because it has already been done)

My first concern - what could cause ActivitiOptimisticLockingException after first WS call?  I couldn't find any logs showing, that this job was handled by another node in the same time.
And the second - what could cause second WS call in such short period of time, executed by the same thread? Do you have any suggestions, what could go wrong or where can we look for potential problems?

Activiti version: 5.19.0.2
1 REPLY 1

rzr1
Champ in-the-making
Champ in-the-making
Any hints or suggestions?