Open danielchapman-impactteam opened 2 years ago
It has to do to the terminateWorkflowOnDelegation=true
option.
It used to work in older versions of AEM, however in AEM 6.5.12 and Cloud SDK 2022.6.7904.20220629T070041Z-220600 it triggers 10 additional workflows, i.e. something in the AEM workflow implementation loops ten times trying to resurrect the terminated workflow. That is, in modern versions of AEM a workflow cannot programmatically terminate itself.
A workaround is to reduce the starter workflow to just the Delegation step
and set the terminateWorkflowOnDelegation
option to false
:
this way the starter workflow will naturally die after delegation.
I think you can allow self termination via the OSGi toggle:
FWIW i havent tested it, but i assume based on the description this would allow self termination of WF without re-spawning.
If you add DEBUG logging on com.adobe.granite.workflow.core.job.JobHandler
you should see a log message like: Workflow with id {} was terminated by a workflow process {}. Processing has stopped
when this flag is enabled.
You can also check your ERROR log and you should see
an error message from the JobHandler that reads: Error executing workflow step. <exception>
..
Few other things...
it looks like you can try setting on the Workflow Model itself (however this requires feature toggle: ft-cq-4343693 to be enabled, not sure if/when that we turned on generally):
noRetryOnException
= true... or in the workflow instance's metadata map a property (does not require a feature toggle).
noretry
= trueI think you can allow self termination via the OSGi toggle:
FWIW i havent tested it, but i assume based on the description this would allow self termination of WF without re-spawning.
If you add DEBUG logging on
com.adobe.granite.workflow.core.job.JobHandler
you should see a log message like:
Workflow with id {} was terminated by a workflow process {}. Processing has stopped
when this flag is enabled.
Before SP11 and SP12+ the OSGi configuration for com.adobe.granite.workflow.core.job.JobHandler is the same. Allow self process termination is ticked, and job.topics.name:
com/adobe/granite/workflow/job/ com/adobe/granite/workflow/job com/adobe/granite/workflow/transient/job/
This is only breaking since SP12.
Sample error.log:
08.07.2022 09:36:42.604 *ERROR* [JobHandler: /var/workflow/instances/server0/2022-07-08/request_for_activation_1:/content/mysite/us/en/test] com.adobe.granite.workflow.core.job.JobHandler Error executing workflow step
java.lang.NullPointerException: null
at com.adobe.granite.workflow.core.job.JobHandler.process(JobHandler.java:402)
at org.apache.sling.event.impl.jobs.JobConsumerManager$JobConsumerWrapper.process(JobConsumerManager.java:502)
at org.apache.sling.event.impl.jobs.queues.JobQueueImpl.startJob(JobQueueImpl.java:351)
at org.apache.sling.event.impl.jobs.queues.JobQueueImpl.access$100(JobQueueImpl.java:60)
at org.apache.sling.event.impl.jobs.queues.JobQueueImpl$1.run(JobQueueImpl.java:287)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
08.07.2022 09:36:42.604 *ERROR* [JobHandler: /var/workflow/instances/server0/2022-07-08/request_for_activation_1:/content/mysite/us/en/test] com.adobe.granite.workflow.core.job.JobHandler Error processing workflow job
java.lang.NullPointerException: null
at com.adobe.granite.workflow.core.jcr.WorkflowManager.setWaitingToAdvance(WorkflowManager.java:562)
at com.adobe.granite.workflow.core.job.JobHandler.process(JobHandler.java:430)
at org.apache.sling.event.impl.jobs.JobConsumerManager$JobConsumerWrapper.process(JobConsumerManager.java:502)
at org.apache.sling.event.impl.jobs.queues.JobQueueImpl.startJob(JobQueueImpl.java:351)
at org.apache.sling.event.impl.jobs.queues.JobQueueImpl.access$100(JobQueueImpl.java:60)
at org.apache.sling.event.impl.jobs.queues.JobQueueImpl$1.run(JobQueueImpl.java:287)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
08.07.2022 09:36:42.604 *WARN* [sling-threadpool-fe608215-52b7-4533-9e28-8d13292fc433-(apache-sling-job-thread-pool)-25-Granite Workflow Queue(com/adobe/granite/workflow/job/var/workflow/models/request_for_activation)] org.apache.sling.event.impl.jobs.queues.JobQueueImpl.Granite Workflow Queue Failed job Sling Job [topic=com/adobe/granite/workflow/job/var/workflow/models/request_for_activation, id=2022/7/8/9/36/320a3470-3e33-4ef0-834a-26ebd8f9c954_14, properties=slingevent:application=320a3470-3e33-4ef0-834a-26ebd8f9c954,jcr:created=java.util.GregorianCalendar(Fri Jul 08 09:36:42 UTC 2022),slingevent:created=java.util.GregorianCalendar(Fri Jul 08 09:36:42 UTC 2022),event.job.queuename=Granite Workflow Queue,event.job.queued.time=java.util.GregorianCalendar(Fri Jul 08 09:36:42 UTC 2022),jcr:createdBy=sling-event,sling:resourceType=slingevent:Job,event.job.application=320a3470-3e33-4ef0-834a-26ebd8f9c954,event.job.retries=10,jcr:primaryType=slingevent:Job,event.job.retrycount=1,:sling:jobs:asynchandler=org.apache.sling.event.impl.jobs.JobConsumerManager$JobConsumerWrapper$1@329de2ce,com.adobe.granite.workflow.job=com.adobe.granite.workflow.job.WorkflowJob@8994ccb,com.adobe.granite.workflow.jobid=VolatileWorkItem_node1_var_workflow_instances_server0_2022-07-08_request_for_activation_1], will retry 9 more time(s), retryCount=1
08.07.2022 09:36:44.871 *INFO* [JobHandler: /var/workflow/instances/server0/2022-07-08/request_for_activation_1:/content/mysite/us/en/test] com.adobe.acs.commons.workflow.process.impl.WorkflowDelegationStep Delegating payload [ /content/mysite/us/en/test ] to Workflow Model [ /var/workflow/models/delegated-workflow ]
08.07.2022 09:36:44.871 *INFO* [JobHandler: /var/workflow/instances/server0/2022-07-08/request_for_activation_1:/content/mysite/us/en/test] com.adobe.acs.commons.workflow.process.impl.WorkflowDelegationStep Terminating current workflow due to PROCESS_ARGS[ terminateWorkflowOnDelegation ] = [ true ]
08.07.2022 09:36:44.872 *ERROR* [JobHandler: /var/workflow/instances/server0/2022-07-08/request_for_activation_1:/content/mysite/us/en/test] com.adobe.granite.workflow.core.job.JobHandler Error executing workflow step
com.adobe.granite.workflow.WorkflowException: Process execution resulted in an error
at com.adobe.granite.workflow.core.job.HandlerBase.executeProcess(HandlerBase.java:204)
at com.adobe.granite.workflow.core.job.JobHandler.process(JobHandler.java:275)
at org.apache.sling.event.impl.jobs.JobConsumerManager$JobConsumerWrapper.process(JobConsumerManager.java:502)
at org.apache.sling.event.impl.jobs.queues.JobQueueImpl.startJob(JobQueueImpl.java:351)
at org.apache.sling.event.impl.jobs.queues.JobQueueImpl.access$100(JobQueueImpl.java:60)
at org.apache.sling.event.impl.jobs.queues.JobQueueImpl$1.run(JobQueueImpl.java:287)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.IllegalStateException: Workflow is already finished.
at com.adobe.granite.workflow.core.WorkflowSessionImpl.terminateWorkflow(WorkflowSessionImpl.java:546)
at com.adobe.acs.commons.workflow.process.impl.WorkflowDelegationStep.execute(WorkflowDelegationStep.java:162) [com.adobe.acs.acs-aem-commons-bundle:5.3.2]
at com.adobe.granite.workflow.core.job.HandlerBase.executeProcess(HandlerBase.java:198)
... 8 common frames omitted
08.07.2022 09:36:44.873 *WARN* [sling-threadpool-fe608215-52b7-4533-9e28-8d13292fc433-(apache-sling-job-thread-pool)-27-Granite Workflow Queue(com/adobe/granite/workflow/job/var/workflow/models/request_for_activation)] org.apache.sling.event.impl.jobs.queues.JobQueueImpl.Granite Workflow Queue Failed job Sling Job [topic=com/adobe/granite/workflow/job/var/workflow/models/request_for_activation, id=2022/7/8/9/36/320a3470-3e33-4ef0-834a-26ebd8f9c954_14, properties=slingevent:application=320a3470-3e33-4ef0-834a-26ebd8f9c954,jcr:created=java.util.GregorianCalendar(Fri Jul 08 09:36:42 UTC 2022),slingevent:created=java.util.GregorianCalendar(Fri Jul 08 09:36:42 UTC 2022),event.job.queuename=Granite Workflow Queue,event.job.queued.time=java.util.GregorianCalendar(Fri Jul 08 09:36:42 UTC 2022),jcr:createdBy=sling-event,sling:resourceType=slingevent:Job,event.job.application=320a3470-3e33-4ef0-834a-26ebd8f9c954,event.job.retries=10,jcr:primaryType=slingevent:Job,event.job.retrycount=2,:sling:jobs:asynchandler=org.apache.sling.event.impl.jobs.JobConsumerManager$JobConsumerWrapper$1@3d766093,com.adobe.granite.workflow.job=com.adobe.granite.workflow.job.WorkflowJob@8994ccb,com.adobe.granite.workflow.jobid=VolatileWorkItem_node1_var_workflow_instances_server0_2022-07-08_request_for_activation_1], will retry 8 more time(s), retryCount=2
08.07.2022 09:36:46.928 *INFO* [JobHandler: /var/workflow/instances/server0/2022-07-08/request_for_activation_1:/content/mysite/us/en/test] com.adobe.acs.commons.workflow.process.impl.WorkflowDelegationStep Delegating payload [ /content/mysite/us/en/test ] to Workflow Model [ /var/workflow/models/delegated-workflow ]
08.07.2022 09:36:46.929 *INFO* [JobHandler: /var/workflow/instances/server0/2022-07-08/request_for_activation_1:/content/mysite/us/en/test] com.adobe.acs.commons.workflow.process.impl.WorkflowDelegationStep Terminating current workflow due to PROCESS_ARGS[ terminateWorkflowOnDelegation ] = [ true ]
08.07.2022 09:36:46.929 *ERROR* [JobHandler: /var/workflow/instances/server0/2022-07-08/request_for_activation_1:/content/mysite/us/en/test] com.adobe.granite.workflow.core.job.JobHandler Error executing workflow step
com.adobe.granite.workflow.WorkflowException: Process execution resulted in an error
at com.adobe.granite.workflow.core.job.HandlerBase.executeProcess(HandlerBase.java:204)
at com.adobe.granite.workflow.core.job.JobHandler.process(JobHandler.java:275)
at org.apache.sling.event.impl.jobs.JobConsumerManager$JobConsumerWrapper.process(JobConsumerManager.java:502)
at org.apache.sling.event.impl.jobs.queues.JobQueueImpl.startJob(JobQueueImpl.java:351)
at org.apache.sling.event.impl.jobs.queues.JobQueueImpl.access$100(JobQueueImpl.java:60)
at org.apache.sling.event.impl.jobs.queues.JobQueueImpl$1.run(JobQueueImpl.java:287)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.IllegalStateException: Workflow is already finished.
at com.adobe.granite.workflow.core.WorkflowSessionImpl.terminateWorkflow(WorkflowSessionImpl.java:546)
at com.adobe.acs.commons.workflow.process.impl.WorkflowDelegationStep.execute(WorkflowDelegationStep.java:162) [com.adobe.acs.acs-aem-commons-bundle:5.3.2]
at com.adobe.granite.workflow.core.job.HandlerBase.executeProcess(HandlerBase.java:198)
... 8 common frames omitted
08.07.2022 09:36:46.932 *WARN* [sling-threadpool-fe608215-52b7-4533-9e28-8d13292fc433-(apache-sling-job-thread-pool)-29-Granite Workflow Queue(com/adobe/granite/workflow/job/var/workflow/models/request_for_activation)] org.apache.sling.event.impl.jobs.queues.JobQueueImpl.Granite Workflow Queue Failed job Sling Job [topic=com/adobe/granite/workflow/job/var/workflow/models/request_for_activation, id=2022/7/8/9/36/320a3470-3e33-4ef0-834a-26ebd8f9c954_14, properties=slingevent:application=320a3470-3e33-4ef0-834a-26ebd8f9c954,jcr:created=java.util.GregorianCalendar(Fri Jul 08 09:36:42 UTC 2022),slingevent:created=java.util.GregorianCalendar(Fri Jul 08 09:36:42 UTC 2022),event.job.queuename=Granite Workflow Queue,event.job.queued.time=java.util.GregorianCalendar(Fri Jul 08 09:36:42 UTC 2022),jcr:createdBy=sling-event,sling:resourceType=slingevent:Job,event.job.application=320a3470-3e33-4ef0-834a-26ebd8f9c954,event.job.retries=10,jcr:primaryType=slingevent:Job,event.job.retrycount=3,:sling:jobs:asynchandler=org.apache.sling.event.impl.jobs.JobConsumerManager$JobConsumerWrapper$1@60d32e93,com.adobe.granite.workflow.job=com.adobe.granite.workflow.job.WorkflowJob@8994ccb,com.adobe.granite.workflow.jobid=VolatileWorkItem_node1_var_workflow_instances_server0_2022-07-08_request_for_activation_1], will retry 7 more time(s), retryCount=3
08.07.2022 09:36:48.961 *INFO* [JobHandler: /var/workflow/instances/server0/2022-07-08/request_for_activation_1:/content/mysite/us/en/test] com.adobe.acs.commons.workflow.process.impl.WorkflowDelegationStep Delegating payload [ /content/mysite/us/en/test ] to Workflow Model [ /var/workflow/models/delegated-workflow ]
08.07.2022 09:36:48.962 *INFO* [JobHandler: /var/workflow/instances/server0/2022-07-08/request_for_activation_1:/content/mysite/us/en/test] com.adobe.acs.commons.workflow.process.impl.WorkflowDelegationStep Terminating current workflow due to PROCESS_ARGS[ terminateWorkflowOnDelegation ] = [ true ]
08.07.2022 09:36:48.962 *ERROR* [JobHandler: /var/workflow/instances/server0/2022-07-08/request_for_activation_1:/content/mysite/us/en/test] com.adobe.granite.workflow.core.job.JobHandler Error executing workflow step
com.adobe.granite.workflow.WorkflowException: Process execution resulted in an error
at com.adobe.granite.workflow.core.job.HandlerBase.executeProcess(HandlerBase.java:204)
at com.adobe.granite.workflow.core.job.JobHandler.process(JobHandler.java:275)
at org.apache.sling.event.impl.jobs.JobConsumerManager$JobConsumerWrapper.process(JobConsumerManager.java:502)
at org.apache.sling.event.impl.jobs.queues.JobQueueImpl.startJob(JobQueueImpl.java:351)
at org.apache.sling.event.impl.jobs.queues.JobQueueImpl.access$100(JobQueueImpl.java:60)
at org.apache.sling.event.impl.jobs.queues.JobQueueImpl$1.run(JobQueueImpl.java:287)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.IllegalStateException: Workflow is already finished.
at com.adobe.granite.workflow.core.WorkflowSessionImpl.terminateWorkflow(WorkflowSessionImpl.java:546)
at com.adobe.acs.commons.workflow.process.impl.WorkflowDelegationStep.execute(WorkflowDelegationStep.java:162) [com.adobe.acs.acs-aem-commons-bundle:5.3.2]
at com.adobe.granite.workflow.core.job.HandlerBase.executeProcess(HandlerBase.java:198)
... 8 common frames omitted
08.07.2022 09:36:48.963 *WARN* [sling-threadpool-fe608215-52b7-4533-9e28-8d13292fc433-(apache-sling-job-thread-pool)-31-Granite Workflow Queue(com/adobe/granite/workflow/job/var/workflow/models/request_for_activation)] org.apache.sling.event.impl.jobs.queues.JobQueueImpl.Granite Workflow Queue Failed job Sling Job [topic=com/adobe/granite/workflow/job/var/workflow/models/request_for_activation, id=2022/7/8/9/36/320a3470-3e33-4ef0-834a-26ebd8f9c954_14, properties=slingevent:application=320a3470-3e33-4ef0-834a-26ebd8f9c954,jcr:created=java.util.GregorianCalendar(Fri Jul 08 09:36:42 UTC 2022),slingevent:created=java.util.GregorianCalendar(Fri Jul 08 09:36:42 UTC 2022),event.job.queuename=Granite Workflow Queue,event.job.queued.time=java.util.GregorianCalendar(Fri Jul 08 09:36:42 UTC 2022),jcr:createdBy=sling-event,sling:resourceType=slingevent:Job,event.job.application=320a3470-3e33-4ef0-834a-26ebd8f9c954,event.job.retries=10,jcr:primaryType=slingevent:Job,event.job.retrycount=4,:sling:jobs:asynchandler=org.apache.sling.event.impl.jobs.JobConsumerManager$JobConsumerWrapper$1@4e414817,com.adobe.granite.workflow.job=com.adobe.granite.workflow.job.WorkflowJob@8994ccb,com.adobe.granite.workflow.jobid=VolatileWorkItem_node1_var_workflow_instances_server0_2022-07-08_request_for_activation_1], will retry 6 more time(s), retryCount=4
08.07.2022 09:36:50.000 *INFO* [CommitStats] CommitStats 38 commits by 4 users [57% sling-event, 23% workflow-process-service, 13% workflow-service, 5% admin] from 6 locations [36% jobhandler:/var/workflow/instances/server0/2022-07-08/re..., 15% other:java.util.TimerThread.run(Timer.java:505), 13% HTTP-POST:/etc/workflow/instances, 13% threadpool:o.a.jackrabbit.oak.spi.commit.BackgroundObser..., 10% jobhandler:/var/workflow/instances/server0/2022-07-08/de..., 10% jobmanager:job.finishJob] (5 types [47% jobhandler, 15% other, 13% HTTP-POST, 13% threadpool, 10% jobmanager]) [CommitStats overhead was 7ms = 184.0us / commit]
08.07.2022 09:36:51.010 *INFO* [JobHandler: /var/workflow/instances/server0/2022-07-08/request_for_activation_1:/content/mysite/us/en/test] com.adobe.acs.commons.workflow.process.impl.WorkflowDelegationStep Delegating payload [ /content/mysite/us/en/test ] to Workflow Model [ /var/workflow/models/delegated-workflow ]
08.07.2022 09:36:51.010 *INFO* [JobHandler: /var/workflow/instances/server0/2022-07-08/request_for_activation_1:/content/mysite/us/en/test] com.adobe.acs.commons.workflow.process.impl.WorkflowDelegationStep Terminating current workflow due to PROCESS_ARGS[ terminateWorkflowOnDelegation ] = [ true ]
08.07.2022 09:36:51.010 *ERROR* [JobHandler: /var/workflow/instances/server0/2022-07-08/request_for_activation_1:/content/mysite/us/en/test] com.adobe.granite.workflow.core.job.JobHandler Error executing workflow step
com.adobe.granite.workflow.WorkflowException: Process execution resulted in an error
at com.adobe.granite.workflow.core.job.HandlerBase.executeProcess(HandlerBase.java:204)
at com.adobe.granite.workflow.core.job.JobHandler.process(JobHandler.java:275)
at org.apache.sling.event.impl.jobs.JobConsumerManager$JobConsumerWrapper.process(JobConsumerManager.java:502)
at org.apache.sling.event.impl.jobs.queues.JobQueueImpl.startJob(JobQueueImpl.java:351)
at org.apache.sling.event.impl.jobs.queues.JobQueueImpl.access$100(JobQueueImpl.java:60)
at org.apache.sling.event.impl.jobs.queues.JobQueueImpl$1.run(JobQueueImpl.java:287)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.IllegalStateException: Workflow is already finished.
at com.adobe.granite.workflow.core.WorkflowSessionImpl.terminateWorkflow(WorkflowSessionImpl.java:546)
at com.adobe.acs.commons.workflow.process.impl.WorkflowDelegationStep.execute(WorkflowDelegationStep.java:162) [com.adobe.acs.acs-aem-commons-bundle:5.3.2]
at com.adobe.granite.workflow.core.job.HandlerBase.executeProcess(HandlerBase.java:198)
... 8 common frames omitted
08.07.2022 09:36:51.011 *WARN* [sling-threadpool-fe608215-52b7-4533-9e28-8d13292fc433-(apache-sling-job-thread-pool)-33-Granite Workflow Queue(com/adobe/granite/workflow/job/var/workflow/models/request_for_activation)] org.apache.sling.event.impl.jobs.queues.JobQueueImpl.Granite Workflow Queue Failed job Sling Job [topic=com/adobe/granite/workflow/job/var/workflow/models/request_for_activation, id=2022/7/8/9/36/320a3470-3e33-4ef0-834a-26ebd8f9c954_14, properties=slingevent:application=320a3470-3e33-4ef0-834a-26ebd8f9c954,jcr:created=java.util.GregorianCalendar(Fri Jul 08 09:36:42 UTC 2022),slingevent:created=java.util.GregorianCalendar(Fri Jul 08 09:36:42 UTC 2022),event.job.queuename=Granite Workflow Queue,event.job.queued.time=java.util.GregorianCalendar(Fri Jul 08 09:36:42 UTC 2022),jcr:createdBy=sling-event,sling:resourceType=slingevent:Job,event.job.application=320a3470-3e33-4ef0-834a-26ebd8f9c954,event.job.retries=10,jcr:primaryType=slingevent:Job,event.job.retrycount=5,:sling:jobs:asynchandler=org.apache.sling.event.impl.jobs.JobConsumerManager$JobConsumerWrapper$1@1823416b,com.adobe.granite.workflow.job=com.adobe.granite.workflow.job.WorkflowJob@8994ccb,com.adobe.granite.workflow.jobid=VolatileWorkItem_node1_var_workflow_instances_server0_2022-07-08_request_for_activation_1], will retry 5 more time(s), retryCount=5
08.07.2022 09:36:53.049 *INFO* [JobHandler: /var/workflow/instances/server0/2022-07-08/request_for_activation_1:/content/mysite/us/en/test] com.adobe.acs.commons.workflow.process.impl.WorkflowDelegationStep Delegating payload [ /content/mysite/us/en/test ] to Workflow Model [ /var/workflow/models/delegated-workflow ]
08.07.2022 09:36:53.049 *INFO* [JobHandler: /var/workflow/instances/server0/2022-07-08/request_for_activation_1:/content/mysite/us/en/test] com.adobe.acs.commons.workflow.process.impl.WorkflowDelegationStep Terminating current workflow due to PROCESS_ARGS[ terminateWorkflowOnDelegation ] = [ true ]
08.07.2022 09:36:53.050 *ERROR* [JobHandler: /var/workflow/instances/server0/2022-07-08/request_for_activation_1:/content/mysite/us/en/test] com.adobe.granite.workflow.core.job.JobHandler Error executing workflow step
com.adobe.granite.workflow.WorkflowException: Process execution resulted in an error
at com.adobe.granite.workflow.core.job.HandlerBase.executeProcess(HandlerBase.java:204)
at com.adobe.granite.workflow.core.job.JobHandler.process(JobHandler.java:275)
at org.apache.sling.event.impl.jobs.JobConsumerManager$JobConsumerWrapper.process(JobConsumerManager.java:502)
at org.apache.sling.event.impl.jobs.queues.JobQueueImpl.startJob(JobQueueImpl.java:351)
at org.apache.sling.event.impl.jobs.queues.JobQueueImpl.access$100(JobQueueImpl.java:60)
at org.apache.sling.event.impl.jobs.queues.JobQueueImpl$1.run(JobQueueImpl.java:287)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.IllegalStateException: Workflow is already finished.
at com.adobe.granite.workflow.core.WorkflowSessionImpl.terminateWorkflow(WorkflowSessionImpl.java:546)
at com.adobe.acs.commons.workflow.process.impl.WorkflowDelegationStep.execute(WorkflowDelegationStep.java:162) [com.adobe.acs.acs-aem-commons-bundle:5.3.2]
at com.adobe.granite.workflow.core.job.HandlerBase.executeProcess(HandlerBase.java:198)
... 8 common frames omitted
08.07.2022 09:36:53.051 *WARN* [sling-threadpool-fe608215-52b7-4533-9e28-8d13292fc433-(apache-sling-job-thread-pool)-35-Granite Workflow Queue(com/adobe/granite/workflow/job/var/workflow/models/request_for_activation)] org.apache.sling.event.impl.jobs.queues.JobQueueImpl.Granite Workflow Queue Failed job Sling Job [topic=com/adobe/granite/workflow/job/var/workflow/models/request_for_activation, id=2022/7/8/9/36/320a3470-3e33-4ef0-834a-26ebd8f9c954_14, properties=slingevent:application=320a3470-3e33-4ef0-834a-26ebd8f9c954,jcr:created=java.util.GregorianCalendar(Fri Jul 08 09:36:42 UTC 2022),slingevent:created=java.util.GregorianCalendar(Fri Jul 08 09:36:42 UTC 2022),event.job.queuename=Granite Workflow Queue,event.job.queued.time=java.util.GregorianCalendar(Fri Jul 08 09:36:42 UTC 2022),jcr:createdBy=sling-event,sling:resourceType=slingevent:Job,event.job.application=320a3470-3e33-4ef0-834a-26ebd8f9c954,event.job.retries=10,jcr:primaryType=slingevent:Job,event.job.retrycount=6,:sling:jobs:asynchandler=org.apache.sling.event.impl.jobs.JobConsumerManager$JobConsumerWrapper$1@512174c1,com.adobe.granite.workflow.job=com.adobe.granite.workflow.job.WorkflowJob@8994ccb,com.adobe.granite.workflow.jobid=VolatileWorkItem_node1_var_workflow_instances_server0_2022-07-08_request_for_activation_1], will retry 4 more time(s), retryCount=6
08.07.2022 09:36:55.083 *INFO* [JobHandler: /var/workflow/instances/server0/2022-07-08/request_for_activation_1:/content/mysite/us/en/test] com.adobe.acs.commons.workflow.process.impl.WorkflowDelegationStep Delegating payload [ /content/mysite/us/en/test ] to Workflow Model [ /var/workflow/models/delegated-workflow ]
08.07.2022 09:36:55.083 *INFO* [JobHandler: /var/workflow/instances/server0/2022-07-08/request_for_activation_1:/content/mysite/us/en/test] com.adobe.acs.commons.workflow.process.impl.WorkflowDelegationStep Terminating current workflow due to PROCESS_ARGS[ terminateWorkflowOnDelegation ] = [ true ]
08.07.2022 09:36:55.084 *ERROR* [JobHandler: /var/workflow/instances/server0/2022-07-08/request_for_activation_1:/content/mysite/us/en/test] com.adobe.granite.workflow.core.job.JobHandler Error executing workflow step
com.adobe.granite.workflow.WorkflowException: Process execution resulted in an error
at com.adobe.granite.workflow.core.job.HandlerBase.executeProcess(HandlerBase.java:204)
at com.adobe.granite.workflow.core.job.JobHandler.process(JobHandler.java:275)
at org.apache.sling.event.impl.jobs.JobConsumerManager$JobConsumerWrapper.process(JobConsumerManager.java:502)
at org.apache.sling.event.impl.jobs.queues.JobQueueImpl.startJob(JobQueueImpl.java:351)
at org.apache.sling.event.impl.jobs.queues.JobQueueImpl.access$100(JobQueueImpl.java:60)
at org.apache.sling.event.impl.jobs.queues.JobQueueImpl$1.run(JobQueueImpl.java:287)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.IllegalStateException: Workflow is already finished.
at com.adobe.granite.workflow.core.WorkflowSessionImpl.terminateWorkflow(WorkflowSessionImpl.java:546)
at com.adobe.acs.commons.workflow.process.impl.WorkflowDelegationStep.execute(WorkflowDelegationStep.java:162) [com.adobe.acs.acs-aem-commons-bundle:5.3.2]
at com.adobe.granite.workflow.core.job.HandlerBase.executeProcess(HandlerBase.java:198)
... 8 common frames omitted
08.07.2022 09:36:55.087 *WARN* [sling-threadpool-fe608215-52b7-4533-9e28-8d13292fc433-(apache-sling-job-thread-pool)-2-Granite Workflow Queue(com/adobe/granite/workflow/job/var/workflow/models/request_for_activation)] org.apache.sling.event.impl.jobs.queues.JobQueueImpl.Granite Workflow Queue Failed job Sling Job [topic=com/adobe/granite/workflow/job/var/workflow/models/request_for_activation, id=2022/7/8/9/36/320a3470-3e33-4ef0-834a-26ebd8f9c954_14, properties=slingevent:application=320a3470-3e33-4ef0-834a-26ebd8f9c954,jcr:created=java.util.GregorianCalendar(Fri Jul 08 09:36:42 UTC 2022),slingevent:created=java.util.GregorianCalendar(Fri Jul 08 09:36:42 UTC 2022),event.job.queuename=Granite Workflow Queue,event.job.queued.time=java.util.GregorianCalendar(Fri Jul 08 09:36:42 UTC 2022),jcr:createdBy=sling-event,sling:resourceType=slingevent:Job,event.job.application=320a3470-3e33-4ef0-834a-26ebd8f9c954,event.job.retries=10,jcr:primaryType=slingevent:Job,event.job.retrycount=7,:sling:jobs:asynchandler=org.apache.sling.event.impl.jobs.JobConsumerManager$JobConsumerWrapper$1@16edbab8,com.adobe.granite.workflow.job=com.adobe.granite.workflow.job.WorkflowJob@8994ccb,com.adobe.granite.workflow.jobid=VolatileWorkItem_node1_var_workflow_instances_server0_2022-07-08_request_for_activation_1], will retry 3 more time(s), retryCount=7
08.07.2022 09:36:57.123 *INFO* [JobHandler: /var/workflow/instances/server0/2022-07-08/request_for_activation_1:/content/mysite/us/en/test] com.adobe.acs.commons.workflow.process.impl.WorkflowDelegationStep Delegating payload [ /content/mysite/us/en/test ] to Workflow Model [ /var/workflow/models/delegated-workflow ]
08.07.2022 09:36:57.123 *INFO* [JobHandler: /var/workflow/instances/server0/2022-07-08/request_for_activation_1:/content/mysite/us/en/test] com.adobe.acs.commons.workflow.process.impl.WorkflowDelegationStep Terminating current workflow due to PROCESS_ARGS[ terminateWorkflowOnDelegation ] = [ true ]
08.07.2022 09:36:57.123 *ERROR* [JobHandler: /var/workflow/instances/server0/2022-07-08/request_for_activation_1:/content/mysite/us/en/test] com.adobe.granite.workflow.core.job.JobHandler Error executing workflow step
com.adobe.granite.workflow.WorkflowException: Process execution resulted in an error
at com.adobe.granite.workflow.core.job.HandlerBase.executeProcess(HandlerBase.java:204)
at com.adobe.granite.workflow.core.job.JobHandler.process(JobHandler.java:275)
at org.apache.sling.event.impl.jobs.JobConsumerManager$JobConsumerWrapper.process(JobConsumerManager.java:502)
at org.apache.sling.event.impl.jobs.queues.JobQueueImpl.startJob(JobQueueImpl.java:351)
at org.apache.sling.event.impl.jobs.queues.JobQueueImpl.access$100(JobQueueImpl.java:60)
at org.apache.sling.event.impl.jobs.queues.JobQueueImpl$1.run(JobQueueImpl.java:287)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.IllegalStateException: Workflow is already finished.
at com.adobe.granite.workflow.core.WorkflowSessionImpl.terminateWorkflow(WorkflowSessionImpl.java:546)
at com.adobe.acs.commons.workflow.process.impl.WorkflowDelegationStep.execute(WorkflowDelegationStep.java:162) [com.adobe.acs.acs-aem-commons-bundle:5.3.2]
at com.adobe.granite.workflow.core.job.HandlerBase.executeProcess(HandlerBase.java:198)
... 8 common frames omitted
08.07.2022 09:36:57.124 *WARN* [sling-threadpool-fe608215-52b7-4533-9e28-8d13292fc433-(apache-sling-job-thread-pool)-4-Granite Workflow Queue(com/adobe/granite/workflow/job/var/workflow/models/request_for_activation)] org.apache.sling.event.impl.jobs.queues.JobQueueImpl.Granite Workflow Queue Failed job Sling Job [topic=com/adobe/granite/workflow/job/var/workflow/models/request_for_activation, id=2022/7/8/9/36/320a3470-3e33-4ef0-834a-26ebd8f9c954_14, properties=slingevent:application=320a3470-3e33-4ef0-834a-26ebd8f9c954,jcr:created=java.util.GregorianCalendar(Fri Jul 08 09:36:42 UTC 2022),slingevent:created=java.util.GregorianCalendar(Fri Jul 08 09:36:42 UTC 2022),event.job.queuename=Granite Workflow Queue,event.job.queued.time=java.util.GregorianCalendar(Fri Jul 08 09:36:42 UTC 2022),jcr:createdBy=sling-event,sling:resourceType=slingevent:Job,event.job.application=320a3470-3e33-4ef0-834a-26ebd8f9c954,event.job.retries=10,jcr:primaryType=slingevent:Job,event.job.retrycount=8,:sling:jobs:asynchandler=org.apache.sling.event.impl.jobs.JobConsumerManager$JobConsumerWrapper$1@5b41a580,com.adobe.granite.workflow.job=com.adobe.granite.workflow.job.WorkflowJob@8994ccb,com.adobe.granite.workflow.jobid=VolatileWorkItem_node1_var_workflow_instances_server0_2022-07-08_request_for_activation_1], will retry 2 more time(s), retryCount=8
08.07.2022 09:36:59.161 *INFO* [JobHandler: /var/workflow/instances/server0/2022-07-08/request_for_activation_1:/content/mysite/us/en/test] com.adobe.acs.commons.workflow.process.impl.WorkflowDelegationStep Delegating payload [ /content/mysite/us/en/test ] to Workflow Model [ /var/workflow/models/delegated-workflow ]
08.07.2022 09:36:59.161 *INFO* [JobHandler: /var/workflow/instances/server0/2022-07-08/request_for_activation_1:/content/mysite/us/en/test] com.adobe.acs.commons.workflow.process.impl.WorkflowDelegationStep Terminating current workflow due to PROCESS_ARGS[ terminateWorkflowOnDelegation ] = [ true ]
08.07.2022 09:36:59.162 *ERROR* [JobHandler: /var/workflow/instances/server0/2022-07-08/request_for_activation_1:/content/mysite/us/en/test] com.adobe.granite.workflow.core.job.JobHandler Error executing workflow step
com.adobe.granite.workflow.WorkflowException: Process execution resulted in an error
at com.adobe.granite.workflow.core.job.HandlerBase.executeProcess(HandlerBase.java:204)
at com.adobe.granite.workflow.core.job.JobHandler.process(JobHandler.java:275)
at org.apache.sling.event.impl.jobs.JobConsumerManager$JobConsumerWrapper.process(JobConsumerManager.java:502)
at org.apache.sling.event.impl.jobs.queues.JobQueueImpl.startJob(JobQueueImpl.java:351)
at org.apache.sling.event.impl.jobs.queues.JobQueueImpl.access$100(JobQueueImpl.java:60)
at org.apache.sling.event.impl.jobs.queues.JobQueueImpl$1.run(JobQueueImpl.java:287)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.IllegalStateException: Workflow is already finished.
at com.adobe.granite.workflow.core.WorkflowSessionImpl.terminateWorkflow(WorkflowSessionImpl.java:546)
at com.adobe.acs.commons.workflow.process.impl.WorkflowDelegationStep.execute(WorkflowDelegationStep.java:162) [com.adobe.acs.acs-aem-commons-bundle:5.3.2]
at com.adobe.granite.workflow.core.job.HandlerBase.executeProcess(HandlerBase.java:198)
... 8 common frames omitted
08.07.2022 09:36:59.162 *WARN* [sling-threadpool-fe608215-52b7-4533-9e28-8d13292fc433-(apache-sling-job-thread-pool)-6-Granite Workflow Queue(com/adobe/granite/workflow/job/var/workflow/models/request_for_activation)] org.apache.sling.event.impl.jobs.queues.JobQueueImpl.Granite Workflow Queue Failed job Sling Job [topic=com/adobe/granite/workflow/job/var/workflow/models/request_for_activation, id=2022/7/8/9/36/320a3470-3e33-4ef0-834a-26ebd8f9c954_14, properties=slingevent:application=320a3470-3e33-4ef0-834a-26ebd8f9c954,jcr:created=java.util.GregorianCalendar(Fri Jul 08 09:36:42 UTC 2022),slingevent:created=java.util.GregorianCalendar(Fri Jul 08 09:36:42 UTC 2022),event.job.queuename=Granite Workflow Queue,event.job.queued.time=java.util.GregorianCalendar(Fri Jul 08 09:36:42 UTC 2022),jcr:createdBy=sling-event,sling:resourceType=slingevent:Job,event.job.application=320a3470-3e33-4ef0-834a-26ebd8f9c954,event.job.retries=10,jcr:primaryType=slingevent:Job,event.job.retrycount=9,:sling:jobs:asynchandler=org.apache.sling.event.impl.jobs.JobConsumerManager$JobConsumerWrapper$1@187b8b99,com.adobe.granite.workflow.job=com.adobe.granite.workflow.job.WorkflowJob@8994ccb,com.adobe.granite.workflow.jobid=VolatileWorkItem_node1_var_workflow_instances_server0_2022-07-08_request_for_activation_1], will retry 1 more time(s), retryCount=9
08.07.2022 09:37:00.000 *INFO* [CommitStats] CommitStats 40 commits by 3 users [62% sling-event, 25% workflow-process-service, 12% workflow-service] from 5 locations [37% jobhandler:/var/workflow/instances/server0/2022-07-08/re..., 25% other:java.util.TimerThread.run(Timer.java:505), 12% jobhandler:/var/workflow/instances/server0/2022-07-08/de..., 12% threadpool:o.a.jackrabbit.oak.spi.commit.BackgroundObser..., 12% jobmanager:job.finishJob] (4 types [50% jobhandler, 25% other, 12% jobmanager, 12% threadpool]) [CommitStats overhead was 5ms = 125.0us / commit]
08.07.2022 09:37:01.222 *INFO* [JobHandler: /var/workflow/instances/server0/2022-07-08/request_for_activation_1:/content/mysite/us/en/test] com.adobe.acs.commons.workflow.process.impl.WorkflowDelegationStep Delegating payload [ /content/mysite/us/en/test ] to Workflow Model [ /var/workflow/models/delegated-workflow ]
08.07.2022 09:37:01.222 *INFO* [JobHandler: /var/workflow/instances/server0/2022-07-08/request_for_activation_1:/content/mysite/us/en/test] com.adobe.acs.commons.workflow.process.impl.WorkflowDelegationStep Terminating current workflow due to PROCESS_ARGS[ terminateWorkflowOnDelegation ] = [ true ]
08.07.2022 09:37:01.226 *ERROR* [JobHandler: /var/workflow/instances/server0/2022-07-08/request_for_activation_1:/content/mysite/us/en/test] com.adobe.granite.workflow.core.job.JobHandler Error executing workflow step
com.adobe.granite.workflow.WorkflowException: Process execution resulted in an error
at com.adobe.granite.workflow.core.job.HandlerBase.executeProcess(HandlerBase.java:204)
at com.adobe.granite.workflow.core.job.JobHandler.process(JobHandler.java:275)
at org.apache.sling.event.impl.jobs.JobConsumerManager$JobConsumerWrapper.process(JobConsumerManager.java:502)
at org.apache.sling.event.impl.jobs.queues.JobQueueImpl.startJob(JobQueueImpl.java:351)
at org.apache.sling.event.impl.jobs.queues.JobQueueImpl.access$100(JobQueueImpl.java:60)
at org.apache.sling.event.impl.jobs.queues.JobQueueImpl$1.run(JobQueueImpl.java:287)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.IllegalStateException: Workflow is already finished.
at com.adobe.granite.workflow.core.WorkflowSessionImpl.terminateWorkflow(WorkflowSessionImpl.java:546)
at com.adobe.acs.commons.workflow.process.impl.WorkflowDelegationStep.execute(WorkflowDelegationStep.java:162) [com.adobe.acs.acs-aem-commons-bundle:5.3.2]
at com.adobe.granite.workflow.core.job.HandlerBase.executeProcess(HandlerBase.java:198)
... 8 common frames omitted
08.07.2022 09:37:01.226 *WARN* [sling-threadpool-fe608215-52b7-4533-9e28-8d13292fc433-(apache-sling-job-thread-pool)-8-Granite Workflow Queue(com/adobe/granite/workflow/job/var/workflow/models/request_for_activation)] org.apache.sling.event.impl.jobs.queues.JobQueueImpl.Granite Workflow Queue Failed job Sling Job [topic=com/adobe/granite/workflow/job/var/workflow/models/request_for_activation, id=2022/7/8/9/36/320a3470-3e33-4ef0-834a-26ebd8f9c954_14, properties=slingevent:application=320a3470-3e33-4ef0-834a-26ebd8f9c954,jcr:created=java.util.GregorianCalendar(Fri Jul 08 09:36:42 UTC 2022),slingevent:created=java.util.GregorianCalendar(Fri Jul 08 09:36:42 UTC 2022),event.job.queuename=Granite Workflow Queue,event.job.queued.time=java.util.GregorianCalendar(Fri Jul 08 09:36:42 UTC 2022),jcr:createdBy=sling-event,sling:resourceType=slingevent:Job,event.job.application=320a3470-3e33-4ef0-834a-26ebd8f9c954,event.job.retries=10,jcr:primaryType=slingevent:Job,event.job.retrycount=10,:sling:jobs:asynchandler=org.apache.sling.event.impl.jobs.JobConsumerManager$JobConsumerWrapper$1@7eec1428,com.adobe.granite.workflow.job=com.adobe.granite.workflow.job.WorkflowJob@8994ccb,com.adobe.granite.workflow.jobid=VolatileWorkItem_node1_var_workflow_instances_server0_2022-07-08_request_for_activation_1], will retry 0 more time(s), retryCount=10
08.07.2022 09:37:03.261 *INFO* [JobHandler: /var/workflow/instances/server0/2022-07-08/request_for_activation_1:/content/mysite/us/en/test] com.adobe.acs.commons.workflow.process.impl.WorkflowDelegationStep Delegating payload [ /content/mysite/us/en/test ] to Workflow Model [ /var/workflow/models/delegated-workflow ]
08.07.2022 09:37:03.261 *INFO* [JobHandler: /var/workflow/instances/server0/2022-07-08/request_for_activation_1:/content/mysite/us/en/test] com.adobe.acs.commons.workflow.process.impl.WorkflowDelegationStep Terminating current workflow due to PROCESS_ARGS[ terminateWorkflowOnDelegation ] = [ true ]
08.07.2022 09:37:03.262 *ERROR* [JobHandler: /var/workflow/instances/server0/2022-07-08/request_for_activation_1:/content/mysite/us/en/test] com.adobe.granite.workflow.core.job.JobHandler Error executing workflow step
com.adobe.granite.workflow.WorkflowException: Process execution resulted in an error
at com.adobe.granite.workflow.core.job.HandlerBase.executeProcess(HandlerBase.java:204)
at com.adobe.granite.workflow.core.job.JobHandler.process(JobHandler.java:275)
at org.apache.sling.event.impl.jobs.JobConsumerManager$JobConsumerWrapper.process(JobConsumerManager.java:502)
at org.apache.sling.event.impl.jobs.queues.JobQueueImpl.startJob(JobQueueImpl.java:351)
at org.apache.sling.event.impl.jobs.queues.JobQueueImpl.access$100(JobQueueImpl.java:60)
at org.apache.sling.event.impl.jobs.queues.JobQueueImpl$1.run(JobQueueImpl.java:287)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.IllegalStateException: Workflow is already finished.
at com.adobe.granite.workflow.core.WorkflowSessionImpl.terminateWorkflow(WorkflowSessionImpl.java:546)
at com.adobe.acs.commons.workflow.process.impl.WorkflowDelegationStep.execute(WorkflowDelegationStep.java:162) [com.adobe.acs.acs-aem-commons-bundle:5.3.2]
at com.adobe.granite.workflow.core.job.HandlerBase.executeProcess(HandlerBase.java:198)
... 8 common frames omitted
I could make it work by fiddling with the OSGi options . @danielchapman-impactteam Another workaround is to make the starter Request For Activation workflow transitive:
This seems to prevent the delegation process from spawning multiple workflows.
I could make it work by fiddling with the OSGi options . @danielchapman-impactteam Another workaround is to make the starter Request For Activation workflow transitive:
This seems to prevent the delegation process from spawning multiple workflows.
@YegorKozlov Confirmed, making the workflow transitive fixes the issue. Thank you providing this workaround, I think we will go with this approach.
What OSGi configuration changes did you make to fix it without making Request for Activation transitive?
@danielchapman-impactteam as @YegorKozlov shows in the screenshots - you can toggle a WF Model to be Transient by opening its (Page) Properties and checking the box. There is no OSGi config for setting a WF Model as transient.
@danielchapman-impactteam as @YegorKozlov shows in the screenshots - you can toggle a WF Model to be Transient by opening its (Page) Properties and checking the box. There is no OSGi config for setting a WF Model as transient.
Thank you @davidjgonzalez and @YegorKozlov both for your help
Required Information
Expected Behavior
A single instance of the delegated workflow is started.
Actual Behavior
Multiple instances of the delegated workflow is started.
Steps to Reproduce