Performance issue with sequential multi-instance subprocesses (10k iterations)

Flowable Engine
1

Setup:
Flowable version: 7.0.1
Database: [MySQL]
History level: NONE
Execution: Using sequential multi-instance subProcess (isSequential=“true”)
Loop cardinality : 10000.

BPMN of Subprocess:

<subProcess id="Loop__ws__forecast__ws__internal__ws__fetch-loopSubProcess" name="CreateUpdate_Facility_Item_Vendor_Forecast_External_V001">
	<multiInstanceLoopCharacteristics isSequential="true" flowable:collection="docUriListToLoop" flowable:elementVariable="docUri">
		<extensionElements>
			<flowable:variableAggregation target="resultBeanList" flowable:transient="true">
				<flowable:variable source="resultOutputMap" target="resultOutputMap"/>
			</flowable:variableAggregation>
		</extensionElements>
	</multiInstanceLoopCharacteristics>
	<startEvent id="Start_Sub"/>
	<serviceTask id="CheckRule" flowable:delegateExpression="${ruleDelegate}">
		<extensionElements>
			<flowable:field name="ruleName" stringValue="Vendor Check Publish Vendor Forecast Is True"/>
			<flowable:field name="ruleResultField" stringValue="rs_Rule_Publish"/>
		</extensionElements>
	</serviceTask>
	<exclusiveGateway id="Gateway_PublishCheck"/>
	<serviceTask id="FCPU_Forecast_External" flowable:delegateExpression="${baseFunctionDelegate}">
		<extensionElements>
			<flowable:field name="baseFunction" stringValue="fcpu"/>
			<flowable:field name="paramSet" stringValue="CreateUpdate Forecast Internal TO External"/>
		</extensionElements>
	</serviceTask>
	<endEvent id="End_Sub"/>
	<sequenceFlow sourceRef="Start_Sub" targetRef="CheckRule"/>
	<sequenceFlow sourceRef="CheckRule" targetRef="Gateway_PublishCheck"/>
	<sequenceFlow sourceRef="Gateway_PublishCheck" targetRef="FCPU_Forecast_External">
		<conditionExpression xsi:type="tFormalExpression">${rs_Rule_Publish}</conditionExpression>
	</sequenceFlow>
	<sequenceFlow sourceRef="Gateway_PublishCheck" targetRef="End_Sub">
		<conditionExpression xsi:type="tFormalExpression">${!rs_Rule_Publish}</conditionExpression>
	</sequenceFlow>
	<sequenceFlow sourceRef="FCPU_Forecast_External" targetRef="End_Sub"/>
</subProcess>

Observed Behavior

  1. At the start of the sequential multi-instance subprocess, the delay between one subprocess iteration finishing and the next iteration starting is around 20 ms.

    • Please refer to FlowableEngineLog1 (which mainly shows DEBUG-level internal Flowable engine logs captured after one subprocess iteration finishes and before the next iteration begins. The delay between these log blocks grows as the number of iterations increases.)

  2. As the loop progresses toward higher iteration counts (e.g., 8,000–10,000 items), the delay increases to ~300 ms per iteration.

    • Please refer to FlowableEngineLog2.

  3. This slowdown is consistent both in the multi-instance subprocess and when using a call activity.

  4. Variable aggregation is implemented to collect subprocess results into the parent process.

Question

  1. How can we address or mitigate this performance problem when dealing with 10k+ sequential iterations?

Thanks in advance for your guidance!

FlowableEngineLog1

06:25:15.143  DEBUG PERF1 o.f.e.i.a.ContinueProcessOperation.executeActivityBehavior 267 -  Executing activityBehavior class org.flowable.engine.impl.bpmn.behavior.ServiceTaskDelegateExpressionActivityBehavior on activity 'Loop__ws__forecast__ws__internal__ws__fetch-loopSubProcess_Start' with execution 94f51bb8-8c7c-11f0-9763-1acb0952e19b
06:25:15.143  DEBUG PERF1 o.f.e.i.h.DefaultHistoryConfigurationSettings.isHistoryEnabledForActivity 160 -  Current history level: NONE, level required: ACTIVITY
06:25:15.142  DEBUG PERF1 o.f.e.i.interceptor.CommandInvoker.executeOperation 163 -  Executing operation class org.flowable.engine.impl.agenda.ContinueProcessOperation
06:25:15.142  DEBUG PERF1 o.f.e.i.a.DefaultFlowableEngineAgenda.planOperation 54 -  Operation class org.flowable.engine.impl.agenda.ContinueProcessOperation added to agenda
06:25:15.142  DEBUG PERF1 o.f.e.i.a.ContinueProcessOperation.continueThroughSequenceFlow 351 -  Sequence flow 'null' encountered. Continuing process by following it using execution 94f51bb8-8c7c-11f0-9763-1acb0952e19b
06:25:15.142  DEBUG PERF1 o.f.e.i.h.DefaultHistoryConfigurationSettings.isHistoryEnabledForActivity 160 -  Current history level: NONE, level required: ACTIVITY
06:25:15.142  DEBUG PERF1 o.f.e.i.interceptor.CommandInvoker.executeOperation 163 -  Executing operation class org.flowable.engine.impl.agenda.ContinueProcessOperation
06:25:15.142  DEBUG PERF1 o.f.e.i.a.DefaultFlowableEngineAgenda.planOperation 54 -  Operation class org.flowable.engine.impl.agenda.ContinueProcessOperation added to agenda
06:25:15.142  DEBUG PERF1 o.f.e.i.a.TakeOutgoingSequenceFlowsOperation.leaveFlowNode 201 -  Leaving flow node class org.flowable.bpmn.model.StartEvent with id 'Loop__ws__forecast__ws__internal__ws__fetch-loopSubProcess_Start_Default' by following it's 1 outgoing sequenceflow
06:25:15.142  DEBUG PERF1 o.f.e.i.h.DefaultHistoryConfigurationSettings.isHistoryEnabledForActivity 160 -  Current history level: NONE, level required: ACTIVITY
06:25:15.142  DEBUG PERF1 o.f.e.i.interceptor.CommandInvoker.executeOperation 163 -  Executing operation class org.flowable.engine.impl.agenda.TakeOutgoingSequenceFlowsOperation
06:25:15.142  DEBUG PERF1 o.f.e.i.a.DefaultFlowableEngineAgenda.planOperation 54 -  Operation class org.flowable.engine.impl.agenda.TakeOutgoingSequenceFlowsOperation added to agenda
06:25:15.142  DEBUG PERF1 o.f.e.i.a.ContinueProcessOperation.executeActivityBehavior 267 -  Executing activityBehavior class org.flowable.engine.impl.bpmn.behavior.NoneStartEventActivityBehavior on activity 'Loop__ws__forecast__ws__internal__ws__fetch-loopSubProcess_Start_Default' with execution 94f51bb8-8c7c-11f0-9763-1acb0952e19b
06:25:15.141  DEBUG PERF1 o.f.e.i.h.DefaultHistoryConfigurationSettings.isHistoryEnabledForActivity 160 -  Current history level: NONE, level required: ACTIVITY
06:25:15.141  DEBUG PERF1 o.f.e.i.interceptor.CommandInvoker.executeOperation 163 -  Executing operation class org.flowable.engine.impl.agenda.ContinueProcessOperation
06:25:15.141  DEBUG PERF1 o.f.e.i.a.DefaultFlowableEngineAgenda.planOperation 54 -  Operation class org.flowable.engine.impl.agenda.ContinueProcessOperation added to agenda
06:25:15.141  DEBUG PERF1 o.f.e.i.p.e.ExecutionEntityManagerImpl.createChildExecution 340 -  Child execution Execution[ id '94f51bb8-8c7c-11f0-9763-1acb0952e19b' ] - definition '8fe87f77-8c70-11f0-b889-6659b34e6d0e' - parent '94f39514-8c7c-11f0-9763-1acb0952e19b' - tenantId 'PERF1' created with parent 94f39514-8c7c-11f0-9763-1acb0952e19b
06:25:15.141  DEBUG PERF1 o.f.e.i.a.ContinueMultiInstanceOperation.executeSynchronous 92 -  Executing activityBehavior class org.flowable.engine.impl.bpmn.behavior.SequentialMultiInstanceBehavior on activity 'Loop__ws__forecast__ws__internal__ws__fetch-loopSubProcess' with execution 94f39514-8c7c-11f0-9763-1acb0952e19b
06:25:15.141  DEBUG PERF1 o.f.e.i.h.DefaultHistoryConfigurationSettings.isHistoryEnabledForActivity 160 -  Current history level: NONE, level required: ACTIVITY
06:25:15.140  DEBUG PERF1 o.f.e.i.h.DefaultHistoryConfigurationSettings.isHistoryLevelAtLeast 123 -  Current history level: NONE, level required: ACTIVITY
06:25:15.140  DEBUG PERF1 o.f.e.i.h.DefaultHistoryConfigurationSettings.isHistoryLevelAtLeast 135 -  Current history level: NONE, level required: FULL
06:25:15.140  DEBUG PERF1 o.f.e.i.h.DefaultHistoryConfigurationSettings.isHistoryLevelAtLeast 123 -  Current history level: NONE, level required: ACTIVITY
06:25:15.140  DEBUG PERF1 o.f.e.i.interceptor.CommandInvoker.executeOperation 163 -  Executing operation class org.flowable.engine.impl.agenda.ContinueMultiInstanceOperation
06:25:15.139  DEBUG PERF1 o.a.i.logging.jdbc.BaseJdbcLogger.debug 137 - MYBATIS <==      Total: 0
06:25:15.138  DEBUG PERF1 o.a.i.logging.jdbc.BaseJdbcLogger.debug 137 - MYBATIS ==> Parameters: 94bc0a3f-8c7c-11f0-9763-1acb0952e19b(String), bpmnExternalWorker(String), bpmnVariableAggregation(String)
06:25:15.137  DEBUG PERF1 o.a.i.logging.jdbc.BaseJdbcLogger.debug 137 - MYBATIS ==>  Preparing: select * from ACT_RU_VARIABLE WHERE SUB_SCOPE_ID_ = ? AND SCOPE_TYPE_ in ( ? , ? )
06:25:15.136  DEBUG PERF1 o.f.e.i.p.e.ExecutionEntityManagerImpl.deleteRelatedDataForExecution 826 -  Ending and deleting execution Scoped execution[ id '94bc0a3f-8c7c-11f0-9763-1acb0952e19b' ] - definition '8fe87f77-8c70-11f0-b889-6659b34e6d0e' - activity 'Loop__ws__forecast__ws__internal__ws__fetch-loopSubProcess' - parent '911e98db-8c7c-11f0-9763-1acb0952e19b' - tenantId 'PERF1' Reason: null
06:25:15.136  DEBUG PERF1 o.f.e.i.h.DefaultHistoryConfigurationSettings.isHistoryEnabledForActivity 160 -  Current history level: NONE, level required: ACTIVITY
06:25:15.136  DEBUG PERF1 o.a.i.logging.jdbc.BaseJdbcLogger.debug 137 - MYBATIS <==      Total: 0
06:25:15.134  DEBUG PERF1 o.a.i.logging.jdbc.BaseJdbcLogger.debug 137 - MYBATIS ==> Parameters: 94bc0a3f-8c7c-11f0-9763-1acb0952e19b(String)
06:25:15.134  DEBUG PERF1 o.a.i.logging.jdbc.BaseJdbcLogger.debug 137 - MYBATIS ==>  Preparing: select * from ACT_RU_EXECUTION where SUPER_EXEC_ = ?
06:25:15.134  DEBUG PERF1 o.a.i.logging.jdbc.BaseJdbcLogger.debug 137 - MYBATIS <==      Total: 0
06:25:15.132  DEBUG PERF1 o.a.i.logging.jdbc.BaseJdbcLogger.debug 137 - MYBATIS ==> Parameters: 94be2d23-8c7c-11f0-9763-1acb0952e19b(String)
06:25:15.132  DEBUG PERF1 o.a.i.logging.jdbc.BaseJdbcLogger.debug 137 - MYBATIS ==>  Preparing: select * from ACT_RU_EXECUTION where SUPER_EXEC_ = ?
06:25:15.132  DEBUG PERF1 o.f.e.i.interceptor.CommandInvoker.executeOperation 163 -  Executing operation class org.flowable.engine.impl.agenda.DestroyScopeOperation
06:25:15.132  DEBUG PERF1 o.f.e.i.a.DefaultFlowableEngineAgenda.planOperation 54 -  Operation class org.flowable.engine.impl.agenda.ContinueMultiInstanceOperation added to agenda
06:25:15.132  DEBUG PERF1 o.f.e.i.h.DefaultHistoryConfigurationSettings.isHistoryLevelAtLeast 123 -  Current history level: NONE, level required: ACTIVITY
06:25:15.131  DEBUG PERF1 o.f.e.i.h.DefaultHistoryConfigurationSettings.isHistoryLevelAtLeast 135 -  Current history level: NONE, level required: FULL
06:25:15.131  DEBUG PERF1 o.f.e.i.h.DefaultHistoryConfigurationSettings.isHistoryLevelAtLeast 123 -  Current history level: NONE, level required: ACTIVITY
06:25:15.131  DEBUG PERF1 o.f.e.i.p.e.ExecutionEntityManagerImpl.createChildExecution 340 -  Child execution Execution[ id '94f39514-8c7c-11f0-9763-1acb0952e19b' ] - definition '8fe87f77-8c70-11f0-b889-6659b34e6d0e' - parent '911e98db-8c7c-11f0-9763-1acb0952e19b' - tenantId 'PERF1' created with parent 911e98db-8c7c-11f0-9763-1acb0952e19b
06:25:15.131  DEBUG PERF1 o.f.e.i.b.b.MultiInstanceActivityBehavior.logLoopDetails 595 -  Multi-instance 'Loop__ws__forecast__ws__internal__ws__fetch-loopSubProcess' instance completed. Details: loopCounter=17, nrOrCompletedInstances=17,nrOfActiveInstances=1,nrOfInstances=9394
06:25:15.130  DEBUG PERF1 o.f.e.i.h.DefaultHistoryConfigurationSettings.isHistoryLevelAtLeast 123 -  Current history level: NONE, level required: ACTIVITY
06:25:15.130  DEBUG PERF1 o.f.e.i.h.DefaultHistoryConfigurationSettings.isHistoryLevelAtLeast 123 -  Current history level: NONE, level required: ACTIVITY
06:25:15.130  DEBUG PERF1 o.f.e.i.h.DefaultHistoryConfigurationSettings.isHistoryLevelAtLeast 135 -  Current history level: NONE, level required: FULL
06:25:15.130  DEBUG PERF1 o.f.e.i.a.DefaultFlowableEngineAgenda.planOperation 54 -  Operation class org.flowable.engine.impl.agenda.DestroyScopeOperation added to agenda
06:25:15.130  DEBUG PERF1 o.a.i.logging.jdbc.BaseJdbcLogger.debug 137 - MYBATIS <==      Total: 0
06:25:15.128  DEBUG PERF1 o.a.i.logging.jdbc.BaseJdbcLogger.debug 137 - MYBATIS ==> Parameters: compensate(String), 94bc0a3f-8c7c-11f0-9763-1acb0952e19b(String)
06:25:15.128  DEBUG PERF1 o.a.i.logging.jdbc.BaseJdbcLogger.debug 137 - MYBATIS ==>  Preparing: select * from ACT_RU_EVENT_SUBSCR where (EVENT_TYPE_ = ?) and (EXECUTION_ID_ = ?)
06:25:15.128  DEBUG PERF1 o.a.i.logging.jdbc.BaseJdbcLogger.debug 137 - MYBATIS <==      Total: 0
06:25:15.126  DEBUG PERF1 o.a.i.logging.jdbc.BaseJdbcLogger.debug 137 - MYBATIS ==> Parameters: 94bc0a3f-8c7c-11f0-9763-1acb0952e19b(String)
06:25:15.126  DEBUG PERF1 o.a.i.logging.jdbc.BaseJdbcLogger.debug 137 - MYBATIS ==>  Preparing: select * from ACT_RU_EXECUTION where PARENT_ID_ = ?
06:25:15.125  DEBUG PERF1 o.f.e.i.agenda.EndExecutionOperation.handleRegularExecution 198 -  Parent execution found. Continuing process using execution 94bc0a3f-8c7c-11f0-9763-1acb0952e19b
06:25:15.125  DEBUG PERF1 o.f.e.i.p.e.ExecutionEntityManagerImpl.deleteRelatedDataForExecution 826 -  Ending and deleting execution Execution[ id '94be2d23-8c7c-11f0-9763-1acb0952e19b' ] - definition '8fe87f77-8c70-11f0-b889-6659b34e6d0e' - activity 'Loop__ws__forecast__ws__internal__ws__fetch-loopSubProcess_End_Default' - parent '94bc0a3f-8c7c-11f0-9763-1acb0952e19b' - tenantId 'PERF1' Reason: null
06:25:15.125  DEBUG PERF1 o.f.e.i.h.DefaultHistoryConfigurationSettings.isHistoryEnabledForActivity 160 -  Current history level: NONE, level required: ACTIVITY
06:25:15.125  DEBUG PERF1 o.f.e.i.agenda.EndExecutionOperation.handleRegularExecution 195 -  Ending execution 94be2d23-8c7c-11f0-9763-1acb0952e19b
06:25:15.125  DEBUG PERF1 o.f.e.i.interceptor.CommandInvoker.executeOperation 163 -  Executing operation class org.flowable.engine.impl.agenda.EndExecutionOperation
06:25:15.125  DEBUG PERF1 o.f.e.i.a.DefaultFlowableEngineAgenda.planOperation 54 -  Operation class org.flowable.engine.impl.agenda.EndExecutionOperation added to agenda
06:25:15.125  DEBUG PERF1 o.f.e.i.a.TakeOutgoingSequenceFlowsOperation.leaveFlowNode 247 -  No outgoing sequence flow found for flow node 'Loop__ws__forecast__ws__internal__ws__fetch-loopSubProcess_End_Default'.
06:25:15.125  DEBUG PERF1 o.f.e.i.a.TakeOutgoingSequenceFlowsOperation.leaveFlowNode 201 -  Leaving flow node class org.flowable.bpmn.model.EndEvent with id 'Loop__ws__forecast__ws__internal__ws__fetch-loopSubProcess_End_Default' by following it's 0 outgoing sequenceflow
06:25:15.124  DEBUG PERF1 o.f.e.i.interceptor.CommandInvoker.executeOperation 163 -  Executing operation class org.flowable.engine.impl.agenda.TakeOutgoingSequenceFlowsOperation
06:25:15.124  DEBUG PERF1 o.f.e.i.a.DefaultFlowableEngineAgenda.planOperation 54 -  Operation class org.flowable.engine.impl.agenda.TakeOutgoingSequenceFlowsOperation added to agenda
06:25:15.124  DEBUG PERF1 o.f.e.i.a.ContinueProcessOperation.executeActivityBehavior 267 -  Executing activityBehavior class org.flowable.engine.impl.bpmn.behavior.NoneEndEventActivityBehavior on activity 'Loop__ws__forecast__ws__internal__ws__fetch-loopSubProcess_End_Default' with execution 94be2d23-8c7c-11f0-9763-1acb0952e19b
06:25:15.124  DEBUG PERF1 o.f.e.i.h.DefaultHistoryConfigurationSettings.isHistoryEnabledForActivity 160 -  Current history level: NONE, level required: ACTIVITY
06:25:15.124  DEBUG PERF1 o.f.e.i.interceptor.CommandInvoker.executeOperation 163 -  Executing operation class org.flowable.engine.impl.agenda.ContinueProcessOperation
06:25:15.124  DEBUG PERF1 o.f.e.i.a.DefaultFlowableEngineAgenda.planOperation 54 -  Operation class org.flowable.engine.impl.agenda.ContinueProcessOperation added to agenda
06:25:15.124  DEBUG PERF1 o.f.e.i.a.ContinueProcessOperation.continueThroughSequenceFlow 351 -  Sequence flow 'null' encountered. Continuing process by following it using execution 94be2d23-8c7c-11f0-9763-1acb0952e19b
06:25:15.124  DEBUG PERF1 o.f.e.i.h.DefaultHistoryConfigurationSettings.isHistoryEnabledForActivity 160 -  Current history level: NONE, level required: ACTIVITY
06:25:15.124  DEBUG PERF1 o.f.e.i.interceptor.CommandInvoker.executeOperation 163 -  Executing operation class org.flowable.engine.impl.agenda.ContinueProcessOperation
06:25:15.124  DEBUG PERF1 o.f.e.i.a.DefaultFlowableEngineAgenda.planOperation 54 -  Operation class org.flowable.engine.impl.agenda.ContinueProcessOperation added to agenda
06:25:15.124  DEBUG PERF1 o.f.e.i.a.TakeOutgoingSequenceFlowsOperation.leaveFlowNode 201 -  Leaving flow node class org.flowable.bpmn.model.ServiceTask with id 'Loop__ws__forecast__ws__internal__ws__fetch-loopSubProcess_End' by following it's 1 outgoing sequenceflow
06:25:15.124  DEBUG PERF1 o.f.e.i.h.DefaultHistoryConfigurationSettings.isHistoryEnabledForActivity 160 -  Current history level: NONE, level required: ACTIVITY
06:25:15.123  DEBUG PERF1 o.f.e.i.interceptor.CommandInvoker.executeOperation 163 -  Executing operation class org.flowable.engine.impl.agenda.TakeOutgoingSequenceFlowsOperation
06:25:15.123  DEBUG PERF1 o.f.e.i.a.DefaultFlowableEngineAgenda.planOperation 54 -  Operation class org.flowable.engine.impl.agenda.TakeOutgoingSequenceFlowsOperation added to agenda


20ms

FlowableEngineLog2

07:51:55.206  DEBUG PERF1 o.f.e.i.a.ContinueProcessOperation.executeActivityBehavior 267 -  Executing activityBehavior class org.flowable.engine.impl.bpmn.behavior.ServiceTaskDelegateExpressionActivityBehavior on activity 'Loop__ws__forecast__ws__internal__ws__fetch-loopSubProcess_Start' with execution b05e5ba8-8c88-11f0-9763-1acb0952e19b
07:51:55.206  DEBUG PERF1 o.f.e.i.h.DefaultHistoryConfigurationSettings.isHistoryEnabledForActivity 160 -  Current history level: NONE, level required: ACTIVITY
07:51:55.163  DEBUG PERF1 o.f.e.i.interceptor.CommandInvoker.executeOperation 163 -  Executing operation class org.flowable.engine.impl.agenda.ContinueProcessOperation
07:51:55.163  DEBUG PERF1 o.f.e.i.a.DefaultFlowableEngineAgenda.planOperation 54 -  Operation class org.flowable.engine.impl.agenda.ContinueProcessOperation added to agenda
07:51:55.163  DEBUG PERF1 o.f.e.i.a.ContinueProcessOperation.continueThroughSequenceFlow 351 -  Sequence flow 'null' encountered. Continuing process by following it using execution b05e5ba8-8c88-11f0-9763-1acb0952e19b
07:51:55.163  DEBUG PERF1 o.f.e.i.h.DefaultHistoryConfigurationSettings.isHistoryEnabledForActivity 160 -  Current history level: NONE, level required: ACTIVITY
07:51:55.148  DEBUG PERF1 o.f.e.i.interceptor.CommandInvoker.executeOperation 163 -  Executing operation class org.flowable.engine.impl.agenda.ContinueProcessOperation
07:51:55.148  DEBUG PERF1 o.f.e.i.a.DefaultFlowableEngineAgenda.planOperation 54 -  Operation class org.flowable.engine.impl.agenda.ContinueProcessOperation added to agenda
07:51:55.148  DEBUG PERF1 o.f.e.i.a.TakeOutgoingSequenceFlowsOperation.leaveFlowNode 201 -  Leaving flow node class org.flowable.bpmn.model.StartEvent with id 'Loop__ws__forecast__ws__internal__ws__fetch-loopSubProcess_Start_Default' by following it's 1 outgoing sequenceflow
07:51:55.148  DEBUG PERF1 o.f.e.i.h.DefaultHistoryConfigurationSettings.isHistoryEnabledForActivity 160 -  Current history level: NONE, level required: ACTIVITY
07:51:55.134  DEBUG PERF1 o.f.e.i.interceptor.CommandInvoker.executeOperation 163 -  Executing operation class org.flowable.engine.impl.agenda.TakeOutgoingSequenceFlowsOperation
07:51:55.134  DEBUG PERF1 o.f.e.i.a.DefaultFlowableEngineAgenda.planOperation 54 -  Operation class org.flowable.engine.impl.agenda.TakeOutgoingSequenceFlowsOperation added to agenda
07:51:55.134  DEBUG PERF1 o.f.e.i.a.ContinueProcessOperation.executeActivityBehavior 267 -  Executing activityBehavior class org.flowable.engine.impl.bpmn.behavior.NoneStartEventActivityBehavior on activity 'Loop__ws__forecast__ws__internal__ws__fetch-loopSubProcess_Start_Default' with execution b05e5ba8-8c88-11f0-9763-1acb0952e19b
07:51:55.133  DEBUG PERF1 o.f.e.i.h.DefaultHistoryConfigurationSettings.isHistoryEnabledForActivity 160 -  Current history level: NONE, level required: ACTIVITY
07:51:55.090  DEBUG PERF1 o.f.e.i.interceptor.CommandInvoker.executeOperation 163 -  Executing operation class org.flowable.engine.impl.agenda.ContinueProcessOperation
07:51:55.090  DEBUG PERF1 o.f.e.i.a.DefaultFlowableEngineAgenda.planOperation 54 -  Operation class org.flowable.engine.impl.agenda.ContinueProcessOperation added to agenda
07:51:55.090  DEBUG PERF1 o.f.e.i.p.e.ExecutionEntityManagerImpl.createChildExecution 340 -  Child execution Execution[ id 'b05e5ba8-8c88-11f0-9763-1acb0952e19b' ] - definition '8fe87f77-8c70-11f0-b889-6659b34e6d0e' - parent 'b0518a64-8c88-11f0-9763-1acb0952e19b' - tenantId 'PERF1' created with parent b0518a64-8c88-11f0-9763-1acb0952e19b
07:51:55.090  DEBUG PERF1 o.f.e.i.a.ContinueMultiInstanceOperation.executeSynchronous 92 -  Executing activityBehavior class org.flowable.engine.impl.bpmn.behavior.SequentialMultiInstanceBehavior on activity 'Loop__ws__forecast__ws__internal__ws__fetch-loopSubProcess' with execution b0518a64-8c88-11f0-9763-1acb0952e19b
07:51:55.090  DEBUG PERF1 o.f.e.i.h.DefaultHistoryConfigurationSettings.isHistoryEnabledForActivity 160 -  Current history level: NONE, level required: ACTIVITY
07:51:55.046  DEBUG PERF1 o.f.e.i.h.DefaultHistoryConfigurationSettings.isHistoryLevelAtLeast 123 -  Current history level: NONE, level required: ACTIVITY
07:51:55.046  DEBUG PERF1 o.f.e.i.h.DefaultHistoryConfigurationSettings.isHistoryLevelAtLeast 135 -  Current history level: NONE, level required: FULL
07:51:55.046  DEBUG PERF1 o.f.e.i.h.DefaultHistoryConfigurationSettings.isHistoryLevelAtLeast 123 -  Current history level: NONE, level required: ACTIVITY
07:51:55.046  DEBUG PERF1 o.f.e.i.interceptor.CommandInvoker.executeOperation 163 -  Executing operation class org.flowable.engine.impl.agenda.ContinueMultiInstanceOperation
07:51:55.036  DEBUG PERF1 o.a.i.logging.jdbc.BaseJdbcLogger.debug 137 - MYBATIS <==      Total: 0
07:51:55.035  DEBUG PERF1 o.a.i.logging.jdbc.BaseJdbcLogger.debug 137 - MYBATIS ==> Parameters: afd4921f-8c88-11f0-9763-1acb0952e19b(String), bpmnExternalWorker(String), bpmnVariableAggregation(String)
07:51:55.034  DEBUG PERF1 o.a.i.logging.jdbc.BaseJdbcLogger.debug 137 - MYBATIS ==>  Preparing: select * from ACT_RU_VARIABLE WHERE SUB_SCOPE_ID_ = ? AND SCOPE_TYPE_ in ( ? , ? )
07:51:55.024  DEBUG PERF1 o.f.e.i.p.e.ExecutionEntityManagerImpl.deleteRelatedDataForExecution 826 -  Ending and deleting execution Scoped execution[ id 'afd4921f-8c88-11f0-9763-1acb0952e19b' ] - definition '8fe87f77-8c70-11f0-b889-6659b34e6d0e' - activity 'Loop__ws__forecast__ws__internal__ws__fetch-loopSubProcess' - parent '911e98db-8c7c-11f0-9763-1acb0952e19b' - tenantId 'PERF1' Reason: null
07:51:55.023  DEBUG PERF1 o.f.e.i.h.DefaultHistoryConfigurationSettings.isHistoryEnabledForActivity 160 -  Current history level: NONE, level required: ACTIVITY
07:51:55.013  DEBUG PERF1 o.a.i.logging.jdbc.BaseJdbcLogger.debug 137 - MYBATIS <==      Total: 0
07:51:55.012  DEBUG PERF1 o.a.i.logging.jdbc.BaseJdbcLogger.debug 137 - MYBATIS ==> Parameters: afd4921f-8c88-11f0-9763-1acb0952e19b(String)
07:51:55.012  DEBUG PERF1 o.a.i.logging.jdbc.BaseJdbcLogger.debug 137 - MYBATIS ==>  Preparing: select * from ACT_RU_EXECUTION where SUPER_EXEC_ = ?
07:51:55.010  DEBUG PERF1 o.a.i.logging.jdbc.BaseJdbcLogger.debug 137 - MYBATIS <==      Total: 0
07:51:55.009  DEBUG PERF1 o.a.i.logging.jdbc.BaseJdbcLogger.debug 137 - MYBATIS ==> Parameters: afe1d893-8c88-11f0-9763-1acb0952e19b(String)
07:51:55.009  DEBUG PERF1 o.a.i.logging.jdbc.BaseJdbcLogger.debug 137 - MYBATIS ==>  Preparing: select * from ACT_RU_EXECUTION where SUPER_EXEC_ = ?
07:51:55.007  DEBUG PERF1 o.f.e.i.interceptor.CommandInvoker.executeOperation 163 -  Executing operation class org.flowable.engine.impl.agenda.DestroyScopeOperation
07:51:55.007  DEBUG PERF1 o.f.e.i.a.DefaultFlowableEngineAgenda.planOperation 54 -  Operation class org.flowable.engine.impl.agenda.ContinueMultiInstanceOperation added to agenda
07:51:55.006  DEBUG PERF1 o.f.e.i.h.DefaultHistoryConfigurationSettings.isHistoryLevelAtLeast 123 -  Current history level: NONE, level required: ACTIVITY
07:51:55.006  DEBUG PERF1 o.f.e.i.h.DefaultHistoryConfigurationSettings.isHistoryLevelAtLeast 135 -  Current history level: NONE, level required: FULL
07:51:55.006  DEBUG PERF1 o.f.e.i.h.DefaultHistoryConfigurationSettings.isHistoryLevelAtLeast 123 -  Current history level: NONE, level required: ACTIVITY
07:51:55.006  DEBUG PERF1 o.f.e.i.p.e.ExecutionEntityManagerImpl.createChildExecution 340 -  Child execution Execution[ id 'b0518a64-8c88-11f0-9763-1acb0952e19b' ] - definition '8fe87f77-8c70-11f0-b889-6659b34e6d0e' - parent '911e98db-8c7c-11f0-9763-1acb0952e19b' - tenantId 'PERF1' created with parent 911e98db-8c7c-11f0-9763-1acb0952e19b
07:51:55.006  DEBUG PERF1 o.f.e.i.b.b.MultiInstanceActivityBehavior.logLoopDetails 595 -  Multi-instance 'Loop__ws__forecast__ws__internal__ws__fetch-loopSubProcess' instance completed. Details: loopCounter=9393, nrOrCompletedInstances=9393,nrOfActiveInstances=1,nrOfInstances=9394
07:51:55.005  DEBUG PERF1 o.f.e.i.h.DefaultHistoryConfigurationSettings.isHistoryLevelAtLeast 123 -  Current history level: NONE, level required: ACTIVITY
07:51:55.005  DEBUG PERF1 o.f.e.i.h.DefaultHistoryConfigurationSettings.isHistoryLevelAtLeast 123 -  Current history level: NONE, level required: ACTIVITY
07:51:55.005  DEBUG PERF1 o.f.e.i.h.DefaultHistoryConfigurationSettings.isHistoryLevelAtLeast 135 -  Current history level: NONE, level required: FULL
07:51:55.005  DEBUG PERF1 o.f.e.i.a.DefaultFlowableEngineAgenda.planOperation 54 -  Operation class org.flowable.engine.impl.agenda.DestroyScopeOperation added to agenda
07:51:55.005  DEBUG PERF1 o.a.i.logging.jdbc.BaseJdbcLogger.debug 137 - MYBATIS <==      Total: 0
07:51:55.004  DEBUG PERF1 o.a.i.logging.jdbc.BaseJdbcLogger.debug 137 - MYBATIS ==> Parameters: compensate(String), afd4921f-8c88-11f0-9763-1acb0952e19b(String)
07:51:55.003  DEBUG PERF1 o.a.i.logging.jdbc.BaseJdbcLogger.debug 137 - MYBATIS ==>  Preparing: select * from ACT_RU_EVENT_SUBSCR where (EVENT_TYPE_ = ?) and (EXECUTION_ID_ = ?)
07:51:54.999  DEBUG PERF1 o.a.i.logging.jdbc.BaseJdbcLogger.debug 137 - MYBATIS <==      Total: 0
07:51:54.998  DEBUG PERF1 o.a.i.logging.jdbc.BaseJdbcLogger.debug 137 - MYBATIS ==> Parameters: afd4921f-8c88-11f0-9763-1acb0952e19b(String)
07:51:54.998  DEBUG PERF1 o.a.i.logging.jdbc.BaseJdbcLogger.debug 137 - MYBATIS ==>  Preparing: select * from ACT_RU_EXECUTION where PARENT_ID_ = ?
07:51:54.997  DEBUG PERF1 o.f.e.i.agenda.EndExecutionOperation.handleRegularExecution 198 -  Parent execution found. Continuing process using execution afd4921f-8c88-11f0-9763-1acb0952e19b
07:51:54.997  DEBUG PERF1 o.f.e.i.p.e.ExecutionEntityManagerImpl.deleteRelatedDataForExecution 826 -  Ending and deleting execution Execution[ id 'afe1d893-8c88-11f0-9763-1acb0952e19b' ] - definition '8fe87f77-8c70-11f0-b889-6659b34e6d0e' - activity 'Loop__ws__forecast__ws__internal__ws__fetch-loopSubProcess_End_Default' - parent 'afd4921f-8c88-11f0-9763-1acb0952e19b' - tenantId 'PERF1' Reason: null
07:51:54.997  DEBUG PERF1 o.f.e.i.h.DefaultHistoryConfigurationSettings.isHistoryEnabledForActivity 160 -  Current history level: NONE, level required: ACTIVITY
07:51:54.985  DEBUG PERF1 o.f.e.i.agenda.EndExecutionOperation.handleRegularExecution 195 -  Ending execution afe1d893-8c88-11f0-9763-1acb0952e19b
07:51:54.985  DEBUG PERF1 o.f.e.i.interceptor.CommandInvoker.executeOperation 163 -  Executing operation class org.flowable.engine.impl.agenda.EndExecutionOperation
07:51:54.985  DEBUG PERF1 o.f.e.i.a.DefaultFlowableEngineAgenda.planOperation 54 -  Operation class org.flowable.engine.impl.agenda.EndExecutionOperation added to agenda
07:51:54.984  DEBUG PERF1 o.f.e.i.a.TakeOutgoingSequenceFlowsOperation.leaveFlowNode 247 -  No outgoing sequence flow found for flow node 'Loop__ws__forecast__ws__internal__ws__fetch-loopSubProcess_End_Default'.
07:51:54.984  DEBUG PERF1 o.f.e.i.a.TakeOutgoingSequenceFlowsOperation.leaveFlowNode 201 -  Leaving flow node class org.flowable.bpmn.model.EndEvent with id 'Loop__ws__forecast__ws__internal__ws__fetch-loopSubProcess_End_Default' by following it's 0 outgoing sequenceflow
07:51:54.984  DEBUG PERF1 o.f.e.i.interceptor.CommandInvoker.executeOperation 163 -  Executing operation class org.flowable.engine.impl.agenda.TakeOutgoingSequenceFlowsOperation
07:51:54.984  DEBUG PERF1 o.f.e.i.a.DefaultFlowableEngineAgenda.planOperation 54 -  Operation class org.flowable.engine.impl.agenda.TakeOutgoingSequenceFlowsOperation added to agenda
07:51:54.984  DEBUG PERF1 o.f.e.i.a.ContinueProcessOperation.executeActivityBehavior 267 -  Executing activityBehavior class org.flowable.engine.impl.bpmn.behavior.NoneEndEventActivityBehavior on activity 'Loop__ws__forecast__ws__internal__ws__fetch-loopSubProcess_End_Default' with execution afe1d893-8c88-11f0-9763-1acb0952e19b
07:51:54.984  DEBUG PERF1 o.f.e.i.h.DefaultHistoryConfigurationSettings.isHistoryEnabledForActivity 160 -  Current history level: NONE, level required: ACTIVITY
07:51:54.941  DEBUG PERF1 o.f.e.i.interceptor.CommandInvoker.executeOperation 163 -  Executing operation class org.flowable.engine.impl.agenda.ContinueProcessOperation
07:51:54.941  DEBUG PERF1 o.f.e.i.a.DefaultFlowableEngineAgenda.planOperation 54 -  Operation class org.flowable.engine.impl.agenda.ContinueProcessOperation added to agenda
07:51:54.941  DEBUG PERF1 o.f.e.i.a.ContinueProcessOperation.continueThroughSequenceFlow 351 -  Sequence flow 'null' encountered. Continuing process by following it using execution afe1d893-8c88-11f0-9763-1acb0952e19b
07:51:54.941  DEBUG PERF1 o.f.e.i.h.DefaultHistoryConfigurationSettings.isHistoryEnabledForActivity 160 -  Current history level: NONE, level required: ACTIVITY
07:51:54.927  DEBUG PERF1 o.f.e.i.interceptor.CommandInvoker.executeOperation 163 -  Executing operation class org.flowable.engine.impl.agenda.ContinueProcessOperation
07:51:54.927  DEBUG PERF1 o.f.e.i.a.DefaultFlowableEngineAgenda.planOperation 54 -  Operation class org.flowable.engine.impl.agenda.ContinueProcessOperation added to agenda
07:51:54.927  DEBUG PERF1 o.f.e.i.a.TakeOutgoingSequenceFlowsOperation.leaveFlowNode 201 -  Leaving flow node class org.flowable.bpmn.model.ServiceTask with id 'Loop__ws__forecast__ws__internal__ws__fetch-loopSubProcess_End' by following it's 1 outgoing sequenceflow
07:51:54.927  DEBUG PERF1 o.f.e.i.h.DefaultHistoryConfigurationSettings.isHistoryEnabledForActivity 160 -  Current history level: NONE, level required: ACTIVITY
07:51:54.914  DEBUG PERF1 o.f.e.i.interceptor.CommandInvoker.executeOperation 163 -  Executing operation class org.flowable.engine.impl.agenda.TakeOutgoingSequenceFlowsOperation
07:51:54.914  DEBUG PERF1 o.f.e.i.a.DefaultFlowableEngineAgenda.planOperation 54 -  Operation class org.flowable.engine.impl.agenda.TakeOutgoingSequenceFlowsOperation added to agenda


292ms
2

Did you perform any profiling?

Martin

3

Doing this in 1 transaction means minimally 10k rows in the database that will be inserted in one jdbc transaction. That on itself will be problematic.

You can model this differently by introducing async, but the whole execution tree in the db will still be huge.

Looking at this model and the multi-instance - is this a passthrough, i.e. all automatic steps? Or are there wait states involved?

4

Thanks for the explanation.

Could you help clarify why we can’t simply mark the subprocess or callActivity as async to address the slowdown? I’d like to understand the detailed technical reasons behind this.

In our model, the multi-instance loop is essentially a passthrough with only automatic steps. It contains service tasks and variable aggregation, but no human tasks, timers, or other wait states. This means the engine has to execute all iterations back-to-back without any natural pauses, which puts additional load on both the database and the runtime engine.

5

If you mark it as async you would have 10K jobs, which is OK. The async would become a wait state. That can actually address the slow down.

In any case, we want to make the passthrough with only automatic steps also perform well. We actually have a branch (GitHub - flowable/flowable-engine at multi-instance-large-collection) that has not been implemented yet for this.

Cheers,
Filip

6

Hi @martin.grofcik ,

Thanks for the suggestion. I ran profiling on the sequential multi-instance subprocess (Loop cardinality : 10000) with a simplified delegate.

Profiling results:

  • 60% of time → com.hazelcast.internal.util.executor.StripedExecutor$Worker.run (executor overhead).
    30% of time → org.flowable.engine.impl.RuntimeServiceImpl.startProcessInstanceByKeyAndTenantId() (process instantiation + execution tree persistence).

  • Only a very small fraction (<5%) is spent on external calls (MarkLogic reads/evals) and JAXB unmarshalling.

image
image1920×1141 170 KB

Observed:

  • At low iteration counts (~1–500), delay between iterations is ~20 ms.

  • At higher iteration counts (8k–10k), delay grows to ~300 ms per iteration.

  • The profiling confirms that the slowdown is caused mainly by Flowable engine overhead in creating and persisting the execution tree during each iteration, not by external database calls.

7

@joram @martin.grofcik @filiphr
This is a follow-up to my earlier post about performance degradation with sequential multi-instance subprocesses (10k+ iterations).

To overcome the per-iteration delay, I optimized the design by introducing batching and making the outer subprocess asynchronous.

Updated design (simplified):

<subProcess id="Loop__ws__forecast__ws__internal__ws__fetch-loopSubProcess" name="CreateUpdate_Facility_Item_Vendor_Forecast_External_V001" flowable:async="true">
	<multiInstanceLoopCharacteristics isSequential="true" flowable:collection="docUriBatches" flowable:elementVariable="currentBatch">
		<extensionElements>
			<flowable:variableAggregation target="resultBeanList" transient="true">
				<flowable:variable source="batchResultList" target="batchResultList"/>
			</flowable:variableAggregation>
		</extensionElements>
	</multiInstanceLoopCharacteristics>
	<startEvent id="outerStart"/>
	<serviceTask id="logBatchInfo" name="Log Batch Info" flowable:delegateExpression="${batchLoggerDelegate}"/>
	<callActivity id="innerLoop" calledElement="CreateUpdate_Facility_Item_Vendor_Forecast_External_V001" flowable:useLocalScopeForOutParameters="true" flowable:fallbackToDefaultTenant="true">
		<multiInstanceLoopCharacteristics isSequential="true" flowable:collection="currentBatch" flowable:elementVariable="currentDocUri"/>
	</callActivity>
	<endEvent id="outerEnd"/>
</subProcess>

Batching drastically reduced iteration time and improved throughput compared to the original pure sequential 10k-loop setup

New Issue — Duplicate Job Creation / Execution

After enabling flowable:async="true" on the subprocess, I observed that:

  • For every batch, two entries are created in ACT_RU_JOB.

  • Both jobs get executed (by different executor threads), resulting in the same batch being processed twice.

  • Logs clearly show two separate async-continuation threads (e.g., task-2 and task-3) executing the same logical batch.

  • Each job references the same execution_id_, but separate id_ and timestamps.

It appears Flowable internally creates two async-continuations for the same outer iteration (one for the async subprocess boundary and another for the inner multi-instance callActivity continuation). This leads to duplicate batch execution, even though it’s a sequential setup.

Is this a known behavior in Flowable 7.0.1 — where both the async subprocess boundary and the inner sequential multi-instance continuation produce separate jobs?
If so, what’s the recommended approach to:

  • prevent duplicate execution per batch, without losing the performance gain from async batching?

Would appreciate any guidance on correct modeling or configuration to avoid duplicate job creation in this scenario.

Thanks,
Rahul

8

Hey @RahulDravid1702,

There should be no duplicate job creation. Can you provide a minimal reproducible example showing that when using sequential multi instance you have parallel execution?

Cheers,
Filip

9

Hi @filiphr

Thanks for the quick response.

I am using a sequential multi-instance subprocess with flowable:async="true" enabled on the subprocess level to improve performance for large batch volumes (~10k records).

Simplified BPMN snippet:

<subProcess id="Loop_SubProcess" name="Forecast_External" flowable:async="true">
    <multiInstanceLoopCharacteristics isSequential="true"
        flowable:collection="docUriBatches"
        flowable:elementVariable="currentBatch">
        <extensionElements>
            <flowable:variableAggregation target="resultBeanList" transient="true">
                <flowable:variable source="batchResultList" target="batchResultList"/>
            </flowable:variableAggregation>
        </extensionElements>
    </multiInstanceLoopCharacteristics>

    <startEvent id="Start_Sub"/>
    <serviceTask id="BatchLogger" flowable:delegateExpression="${batchLoggerDelegate}"/>
    <callActivity id="InnerLoop" calledElement="CreateUpdate_Facility_Item_Vendor_Forecast_External_V001"/>
    <endEvent id="End_Sub"/>
</subProcess>

Even though the multi-instance is defined as isSequential="true", it seems the async behavior allows multiple job executors to pick up the same job simultaneously.

Thanks,
Rahul

10

Hey @RahulDravid1702,

That is not a minimal reproducible example. How does your batchLoggerDelegate look like? How does the docUriBatches look like.

Cheers,
Filip

11

Hi @filiphr,

Thanks for the response. Sure — here are more details:

Delegate Implementation:

@Component
@Scope("prototype")
public class BatchLoggerDelegate implements JavaDelegate {

    private static final Logger log = LoggerFactory.getLogger(BatchLoggerDelegate.class);

    @Override
    public void execute(DelegateExecution execution) {
        Integer batchIndex = (Integer) execution.getVariable("loopCounter");
        List<?> currentBatch = (List<?>) execution.getVariable("currentBatch");

        log.info(">>> Processing Batch #{} with {} docURIs",
                (batchIndex != null ? batchIndex + 1 : 0),
                (currentBatch != null ? currentBatch.size() : 0));
    }
}

docUriBatches Structure:
docUriBatches is a List<List<String>> prepared before the subprocess starts.
Each inner list represents one batch of document URIs (example: 100 items per batch).

For example:

List<List<String>> docUriBatches = new ArrayList<>();
// e.g., 10,000 total URIs → 100 batches of 100 items each
// Each URI looks like: /integration/Facility+Item+Vendor+Forecast+Internal/US01_0020_KS01_9419_647274_2025_October
execution.setVariable("docUriBatches", docUriBatches);

BPMN Definition (Minimal Reproducible Example):

<?xml version="1.0" encoding="UTF-8"?>
<definitions xmlns="http://www.omg.org/spec/BPMN/20100524/MODEL" xmlns:flowable="http://flowable.org/bpmn" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" targetNamespace="Examples">
	<process id="Forecast_Batch_Processing" name="Forecast Batch Processing" isExecutable="true">
		<startEvent id="Start_Main"/>
		<subProcess id="Loop__ws__forecast__ws__internal__ws__fetch-loopSubProcess" name="CreateUpdate_Facility_Item_Vendor_Forecast_External_V001" flowable:async="true">
			<multiInstanceLoopCharacteristics isSequential="true" flowable:collection="docUriBatches" flowable:elementVariable="currentBatch">
				<extensionElements>
					<flowable:variableAggregation target="resultBeanList" transient="true">
						<flowable:variable source="batchResultList" target="batchResultList"/>
					</flowable:variableAggregation>
				</extensionElements>
			</multiInstanceLoopCharacteristics>
			<startEvent id="outerStart"/>
			<serviceTask id="logBatchInfo" name="Log Batch Info" flowable:delegateExpression="${batchLoggerDelegate}"/>
			<callActivity id="innerLoopSubProcess" name="Forecast Inner Processor" calledElement="CreateUpdate_Facility_Item_Vendor_Forecast_External_V001" flowable:useLocalScopeForOutParameters="true" flowable:fallbackToDefaultTenant="true">
				<extensionElements>
					<flowable:in source="currentDocUriToLoop_Loop__ws__forecast__ws__internal__ws__fetch" target="docUri"/>
					<flowable:out source="resultOutputMap" target="resultOutputMap"/>
				</extensionElements>
				<multiInstanceLoopCharacteristics isSequential="true" flowable:collection="currentBatch" flowable:elementVariable="currentDocUriToLoop_Loop__ws__forecast__ws__internal__ws__fetch">
					<extensionElements>
						<flowable:variableAggregation target="batchResultList" transient="true">
							<flowable:variable source="resultOutputMap" target="resultOutputMap"/>
						</flowable:variableAggregation>
					</extensionElements>
				</multiInstanceLoopCharacteristics>
			</callActivity>
			<endEvent id="outerEnd"/>
			<sequenceFlow sourceRef="outerStart" targetRef="logBatchInfo"/>
			<sequenceFlow sourceRef="logBatchInfo" targetRef="innerLoopSubProcess"/>
			<sequenceFlow sourceRef="innerLoopSubProcess" targetRef="outerEnd"/>
		</subProcess>
		<sequenceFlow sourceRef="Start_Main" targetRef="Loop__ws__forecast__ws__internal__ws__fetch-loopSubProcess"/>
		<endEvent id="End_Main"/>
		<sequenceFlow sourceRef="Loop__ws__forecast__ws__internal__ws__fetch-loopSubProcess" targetRef="End_Main"/>
	</process>
</definitions>

Thanks,
Rahul

12

I can’t run this since the innerLoopSubProcess definition is missing.

Can you also share the debug logs?

13

Could you create a jUnit test?

Regards

Martin

14

Hi @filiphr

Here are the details

BPMN Definition (Minimal Reproducible Example):

<?xml version="1.0" encoding="UTF-8"?>
<definitions xmlns="http://www.omg.org/spec/BPMN/20100524/MODEL" xmlns:flowable="http://flowable.org/bpmn" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" targetNamespace="Examples">
	<process id="Forecast_Batch_Processing" name="Forecast Batch Processing" isExecutable="true">
		<startEvent id="Start_Main"/>
		<subProcess id="Loop__ws__forecast__ws__internal__ws__fetch-loopSubProcess" name="CreateUpdate_Facility_Item_Vendor_Forecast_External_V001" flowable:async="true">
			<multiInstanceLoopCharacteristics isSequential="true" flowable:collection="docUriBatches" flowable:elementVariable="currentBatch">
				<extensionElements>
					<flowable:variableAggregation target="resultBeanList" transient="true">
						<flowable:variable source="batchResultList" target="batchResultList"/>
					</flowable:variableAggregation>
				</extensionElements>
			</multiInstanceLoopCharacteristics>
			<startEvent id="outerStart"/>
			<serviceTask id="logBatchInfo" name="Log Batch Info" flowable:delegateExpression="${batchLoggerDelegate}"/>
			<callActivity id="innerLoopSubProcess" name="Forecast Inner Processor" calledElement="CreateUpdate_Facility_Item_Vendor_Forecast_External_V001" flowable:useLocalScopeForOutParameters="true" flowable:fallbackToDefaultTenant="true">
				<extensionElements>
					<flowable:in source="currentDocUriToLoop_Loop__ws__forecast__ws__internal__ws__fetch" target="docUri"/>
					<flowable:out source="resultOutputMap" target="resultOutputMap"/>
				</extensionElements>
				<multiInstanceLoopCharacteristics isSequential="true" flowable:collection="currentBatch" flowable:elementVariable="currentDocUriToLoop_Loop__ws__forecast__ws__internal__ws__fetch">
					<extensionElements>
						<flowable:variableAggregation target="batchResultList" transient="true">
							<flowable:variable source="resultOutputMap" target="resultOutputMap"/>
						</flowable:variableAggregation>
					</extensionElements>
				</multiInstanceLoopCharacteristics>
			</callActivity>
			<endEvent id="outerEnd"/>
			<sequenceFlow sourceRef="outerStart" targetRef="logBatchInfo"/>
			<sequenceFlow sourceRef="logBatchInfo" targetRef="innerLoopSubProcess"/>
			<sequenceFlow sourceRef="innerLoopSubProcess" targetRef="outerEnd"/>
		</subProcess>
		<sequenceFlow sourceRef="Start_Main" targetRef="Loop__ws__forecast__ws__internal__ws__fetch-loopSubProcess"/>
		<endEvent id="End_Main"/>
		<sequenceFlow sourceRef="Loop__ws__forecast__ws__internal__ws__fetch-loopSubProcess" targetRef="End_Main"/>
	</process>
</definitions>
  1. Inner Subprocess Definition (CreateUpdate_Facility_Item_Vendor_Forecast_External_V001)

This is the minimal version of the called inner subprocess — it just logs the docUri (same variable used in the parent):

<process id="CreateUpdate_Facility_Item_Vendor_Forecast_External_V001" name="Forecast Inner Processor" isExecutable="true">
  <startEvent id="Start_Inner" />
  <serviceTask id="LogDocUri"
               name="Log Doc URI"
               flowable:delegateExpression="${logDocUriDelegate}" />
  <endEvent id="End_Inner" />
  <sequenceFlow sourceRef="Start_Inner" targetRef="LogDocUri" />
  <sequenceFlow sourceRef="LogDocUri" targetRef="End_Inner" />
</process>
  1. Delegate Classes

BatchLoggerDelegate.java

@Component
@Scope("prototype")
public class BatchLoggerDelegate implements JavaDelegate {
    private static final Logger log = LoggerFactory.getLogger(BatchLoggerDelegate.class);
    @Override
    public void execute(DelegateExecution execution) {
        Integer batchIndex = (Integer) execution.getVariable("loopCounter");
        List<?> currentBatch = (List<?>) execution.getVariable("currentBatch");
        log.info(">>> Processing Batch #{} with {} docURIs",
                (batchIndex != null ? batchIndex + 1 : 0),
                (currentBatch != null ? currentBatch.size() : 0));
    }
}

LogDocUriDelegate.java

@Component
@Scope("prototype")
public class LogDocUriDelegate implements JavaDelegate {
    private static final Logger log = LoggerFactory.getLogger(LogDocUriDelegate.class);
    @Override
    public void execute(DelegateExecution execution) {
        String docUri = (String) execution.getVariable("docUri");
        log.info(">>> Executing for docUri: {}", docUri);
    }
}
  1. Engine Configuration (Spring Boot / Flowable Config)
@Configuration
@EnableConfigurationProperties(FlowableProperties.class)
@PropertySource("classpath:application.properties")
@AutoConfigureBefore({ SpringProcessEngineConfiguration.class })
@AutoConfigureAfter(DataSourceAutoConfiguration.class)
public class UcbosProcessEngineConfigurationForFlowable
        implements EngineConfigurationConfigurer<SpringProcessEngineConfiguration> {

    private static final Logger log = LoggerFactory.getLogger(UcbosProcessEngineConfigurationForFlowable.class);

    @Value("classpath*:**.bpmn20.xml")
    private Resource[] flowableResources;

    @Autowired
    private DataSource dataSource;

    @Autowired
    private EntityManagerFactory entityManagerFactory;

    @Autowired
    private PlatformTransactionManager transactionManager;

    @Override
    public void configure(SpringProcessEngineConfiguration processEngineConfiguration) {

        processEngineConfiguration.setDeploymentResources(this.getFlowableResources());
        processEngineConfiguration.setDataSource(dataSource);
        processEngineConfiguration.setJpaEntityManagerFactory(entityManagerFactory);
        processEngineConfiguration.setTransactionManager(transactionManager);
        processEngineConfiguration.setJpaHandleTransaction(false);
        processEngineConfiguration.setJpaCloseEntityManager(false);
        processEngineConfiguration.setHistoryLevel(HistoryLevel.NONE);
    }

    private Resource[] getFlowableResources() {
        return getFlowableResourcesAsList().toArray(new Resource[0]);
    }

    protected List<Resource> getFlowableResourcesAsList() {
        return new ArrayList<>(Arrays.asList(flowableResources));
    }
}
  1. Sample Input

docUriBatches is a list of 100 batches, each with 100 strings:

List<List<String>> batches = new ArrayList<>();
for (int i = 0; i < 100; i++) {
    List<String> inner = new ArrayList<>();
    for (int j = 0; j < 100; j++) {
        inner.add("/integration/Forecast/Internal/Doc_" + i + "_" + j);
    }
    batches.add(inner);
}
runtimeService.startProcessInstanceByKey("Forecast_Batch_Processing",
        Map.of("docUriBatches", batches));

Thanks
Rahul

15

Thanks @RahulDravid1702,

I’ve taken your beans and processes and run them with an in memory H2 database using Spring Boot 3.5.6 and the flowable-spring-boot-starter version 7.0.1 and everything runs properly, there are no batches processed synchronously.

Please provide a Git repo with steps and a test case explaining how we can reproduce what you are seeing.

Cheers,
Filip

16

Hi @filiphr
Thanks for your help earlier.

I’ve identified the root cause of the duplicate execution issue — it was due to an extra sequence flow immediately after the subprocess.
Example:
<sequenceFlow sourceRef="logBatchInfo" targetRef="innerLoopSubProcess"/>

This caused the subprocess to be triggered twice, leading to duplicate processing.
After removing the redundant sequence flow, the issue is resolved.

I have one follow-up question related to performance optimization.

Originally, I was facing performance issues when handling 10K+ sequential iterations in a single process instance.

To improve throughput, I introduced batching and made the outer subprocess asynchronous (flowable:async="true") so that each batch is handled as a separate async job, while maintaining sequential execution within the multi-instance loop (isSequential="true").

Is this the recommended approach to handle large-scale sequential workloads in Flowable — i.e., by batching the data and marking the outer subprocess as asynchronous for better scheduling and throughput?

Thanks again for your guidance!
Rahul