ACTIVITI - async serviceTask executed after process end event

Question

We encountered several cases when serviceTasks are executed AFTER reaching process end event.

One example from the ACT_HI_ACTINST table looks like this (line numbers column "L#" added manually):

SELECT
   EXECUTION_ID_,
   PROC_INST_ID_,
   ACT_ID_,
   ACT_TYPE_,
   START_TIME_,
   END_TIME_
FROM ACT_HI_ACTINST
WHERE PROC_INST_ID_ =
  '9841ea77-cee8-11e6-b457-005056aa6e09'
ORDER BY
   START_TIME_;

EXECUTION_ID_                           PROC_INST_ID_                           L#  ACT_ID_                         ACT_TYPE_                   START_TIME_             END_TIME_          
====================================    ====================================    === ============================    ========================    ===================     ===================
9841ea77-cee8-11e6-b457-005056aa6e09    9841ea77-cee8-11e6-b457-005056aa6e09     1. startevent1                     startEvent                  2016-12-31 00:35:06     2016-12-31 00:35:06
9841ea77-cee8-11e6-b457-005056aa6e09    9841ea77-cee8-11e6-b457-005056aa6e09     2. lockOrder                       serviceTask                 2016-12-31 00:35:06     2016-12-31 00:35:06
9841ea77-cee8-11e6-b457-005056aa6e09    9841ea77-cee8-11e6-b457-005056aa6e09     3. processingOrderStatus           serviceTask                 2016-12-31 00:35:06     2016-12-31 00:35:06
989cb4b1-cee8-11e6-b457-005056aa6e09    9841ea77-cee8-11e6-b457-005056aa6e09     4. subprocess1                     subProcess                  2016-12-31 00:35:06     2016-12-31 00:37:18
989e8977-cee8-11e6-b457-005056aa6e09    9841ea77-cee8-11e6-b457-005056aa6e09     5. startevent2                     startEvent                  2016-12-31 00:35:06     2016-12-31 00:35:06
989e8977-cee8-11e6-b457-005056aa6e09    9841ea77-cee8-11e6-b457-005056aa6e09     6. prepareContractContext          serviceTask                 2016-12-31 00:35:07     2016-12-31 00:35:07
989e8977-cee8-11e6-b457-005056aa6e09    9841ea77-cee8-11e6-b457-005056aa6e09     7. processingContractStatus        serviceTask                 2016-12-31 00:35:08     2016-12-31 00:35:09
989e8977-cee8-11e6-b457-005056aa6e09    9841ea77-cee8-11e6-b457-005056aa6e09     8. createSsoAccount                serviceTask                 2016-12-31 00:35:09     2016-12-31 00:35:09
989e8977-cee8-11e6-b457-005056aa6e09    9841ea77-cee8-11e6-b457-005056aa6e09     9. exclusivegateway1               exclusiveGateway            2016-12-31 00:35:09     2016-12-31 00:35:09
989e8977-cee8-11e6-b457-005056aa6e09    9841ea77-cee8-11e6-b457-005056aa6e09    10. exclusivegateway2               exclusiveGateway            2016-12-31 00:35:09     2016-12-31 00:35:09
989e8977-cee8-11e6-b457-005056aa6e09    9841ea77-cee8-11e6-b457-005056aa6e09    11. modifyParty                     serviceTask                 2016-12-31 00:35:10     2016-12-31 00:35:26
a44b1fb0-cee8-11e6-b457-005056aa6e09    9841ea77-cee8-11e6-b457-005056aa6e09    12. timerintermediatecatchevent1    intermediateTimer           2016-12-31 00:35:26     2016-12-31 00:37:30
989e8977-cee8-11e6-b457-005056aa6e09    9841ea77-cee8-11e6-b457-005056aa6e09    13. createNotification              serviceTask                 2016-12-31 00:37:17     2016-12-31 00:37:17
989e8977-cee8-11e6-b457-005056aa6e09    9841ea77-cee8-11e6-b457-005056aa6e09    14. closedContractStatus            serviceTask                 2016-12-31 00:37:18     2016-12-31 00:37:18
989e8977-cee8-11e6-b457-005056aa6e09    9841ea77-cee8-11e6-b457-005056aa6e09    15. endevent1                       endEvent                    2016-12-31 00:37:18     2016-12-31 00:37:18
9841ea77-cee8-11e6-b457-005056aa6e09    9841ea77-cee8-11e6-b457-005056aa6e09    16. registerClosedOrderEvent        serviceTask                 2016-12-31 00:37:19     2016-12-31 00:37:19
9841ea77-cee8-11e6-b457-005056aa6e09    9841ea77-cee8-11e6-b457-005056aa6e09    17. closedOrderStatus               serviceTask                 2016-12-31 00:37:19     2016-12-31 00:37:19
9841ea77-cee8-11e6-b457-005056aa6e09    9841ea77-cee8-11e6-b457-005056aa6e09    18. endevent2                       endEvent                    2016-12-31 00:37:19     2016-12-31 00:37:19
989e8977-cee8-11e6-b457-005056aa6e09    9841ea77-cee8-11e6-b457-005056aa6e09    19. modifyService                   serviceTask                 2016-12-31 00:37:30     2016-12-31 00:37:31
eeec32ad-cee8-11e6-b457-005056aa6e09    9841ea77-cee8-11e6-b457-005056aa6e09    20. waitingForModifyService         intermediateMessageCatch    2016-12-31 00:37:31     2016-12-31 00:37:17

Now endEvent2 (line 18) is a process end event and after its completion another task is executed (this modifyService (line 19) task should be executed right after timerintermediatecatchevent1 (line 12) and in most cases is).

We are using Activiti only as a processing engine of our Spring application. There are 5 instances of application connected to the same DB.

What can cause such behavior? We are observing it regularly and this is very dangerous for our business processes. As a hint - unordered tasks were executed on different machines.

Also we tuned settings of async executor engine - code snippet with its settings below:

asyncExecutor.setDefaultAsyncJobAcquireWaitTimeInMillis(1000);
asyncExecutor.setDefaultTimerJobAcquireWaitTimeInMillis(5 * 1000);
asyncExecutor.setMaxAsyncJobsDuePerAcquisition(10);
asyncExecutor.setMaxTimerJobsPerAcquisition(10);
asyncExecutor.setAsyncJobLockTimeInMillis(10 * 60 * 1000);
asyncExecutor.setTimerLockTimeInMillis(10 * 60 * 1000);

Activiti version: 5.20.0

Any kind of help or hint would be really appreciated.

Further reading

• Crosspost on Alfresco forums: https://community.alfresco.com/message/805537-servicetask-executed-after-process-end-event