We have a Tridion 9 deployer (receiver and worker) with some custom code that is having occasional failures in the Deploying
phase.
The failures are random and after some persistent republishing, the components do actually get published successfully. For example, I publish 100 components, 20 fails, then I republish those 20, 5 fails, etc...
All of these components have in common are assets (thumbnails).
These are the logs that I have extracted by setting the deployer worker to DEBUG and grepping the transaction ID as well as the thread that was processing the request.
2019-11-20 13:34:08,728 DEBUG [pool(JMSDeploymentQueue - myapp-qa-ContentQueue)-1-thread-1] JSONCommandSerializer - Command de-serialized 'JSONCommand{verbs=[Content], action='TridionBootstrap', binaryIds=[tcm_0-1693950-66560.Content.zip], ex ecutionId='tcm:0-1693950-66560', properties={}}'
2019-11-20 13:34:09,649 INFO [pool-3-thread-1] CommandQueuePoller - Current active: 7 max: 11 scheduling: JSONCommand{verbs=[Content], action='TridionBootstrap', binaryIds=[tcm_0-1693950-66560.Content.zip], executionId='tcm:0-1693950-66560 ', properties={}}
2019-11-20 13:34:09,649 INFO [pool(Queue Workers - myapp-qa-ContentQueue)-4-thread-11] CommandQueuePoller - Processing command: JSONCommand{verbs=[Content], action='TridionBootstrap', binaryIds=[tcm_0-1693950-66560.Content.zip], executionId ='tcm:0-1693950-66560', properties={}}
2019-11-20 13:34:09,649 DEBUG [pool(Queue Workers - capi-qa-ContentQueue)-4-thread-11] AkkaProcessingService - Handling request: JSONCommand{verbs=[Content], action='TridionBootstrap', binaryIds=[tcm_0-1693950-66560.Content.zip], executionI d='tcm:0-1693950-66560', properties={}}
2019-11-20 13:34:09,649 DEBUG [pool(Queue Workers - myapp-qa-ContentQueue)-4-thread-11] BasicProcessingContextProvider - Creating initial processing context for command: JSONCommand{verbs=[Content], action='TridionBootstrap', binaryIds=[tcm_ 0-1693950-66560.Content.zip], executionId='tcm:0-1693950-66560', properties={}}
2019-11-20 13:34:09,649 DEBUG [pool(Queue Workers - myapp-qa-ContentQueue)-4-thread-11] BasicProcessingContextProvider - Created: BasicProcessingContext [executionId = tcm:0-1693950-66560, binaryId = tcm_0-1693950-66560.Content.zip, action = TridionBootstrap verbs = [Content], currentPipeline = Optional[BasicPipeline [id=Tridion-Bootstrap, finalizePipeline=false, actions=[TridionBootstrap], verb=[Commit, Content, Prepare, Rollback]]], currentStep = Optional[BasicStep [id=Tridi onUnzipStep, factory=]]], finalizeContext = false]
2019-11-20 13:34:09,651 INFO [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] ExecutionActor - Started deployment for execution 'tcm:0-1693950-66560'
2019-11-20 13:34:09,653 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] HybridStateStore - Creating new execution entity for execution id: tcm:0-1693950-66560
2019-11-20 13:34:09,661 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] PipelineActor - Start pipeline 'Tridion-Bootstrap' for 'tcm:0-1693950-66560'.
2019-11-20 13:34:09,665 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] HybridStateStore - Creating new pipeline entity for execution id: tcm:0-1693950-66560 and pipeline id: Tridion-Bootstrap
2019-11-20 13:34:09,676 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] StepActor - Start step 'Optional[BasicStep [id=TridionUnzipStep, factory=]]' for 'tcm:0-1693950-66560'
2019-11-20 13:34:09,678 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] HybridStateStore - Creating new step entity for execution id: tcm:0-1693950-66560, pipeline id: Tridion-Bootstrap and step id: TridionUnzipStep
2019-11-20 13:34:09,735 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] HybridStepDataStore - Trying to find all step data for ExecutionId = tcm:0-1693950-66560 and key = InWait
2019-11-20 13:34:09,735 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] HybridStepDataStore - Trying to find all step data for ExecutionId = tcm:0-1693950-66560 and keys = [InWait]
2019-11-20 13:34:09,737 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] HybridStepDataStore - Found 0 step data in session database for ExecutionId = tcm:0-1693950-66560 and keys = [InWait]
2019-11-20 13:34:09,763 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] StepActor - (metric) type=stepExecutionTime executionIdVal=tcm:0-1693950-66560 pipelineIdVal=Tridion-Bootstrap stepIdVal=TridionUnzipStep elapsed =67
2019-11-20 13:34:09,765 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] HybridStateStore - Found step entity for execution id: tcm:0-1693950-66560, pipeline id: Tridion-Bootstrap and step id: TridionUnzipStep
2019-11-20 13:34:09,775 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] BasicProcessingContextProvider - Received processing context: BasicProcessingContext [executionId = tcm:0-1693950-66560, binaryId = tcm_0-1693950 -66560.Content.zip, action = Deploy verbs = [Commit, Content, PreCommit, Process], currentPipeline = Optional[BasicPipeline [id=Tridion-Bootstrap, finalizePipeline=false, actions=[TridionBootstrap], verb=[Commit, Content, Prepare, Rollback] ]], currentStep = Optional[BasicStep [id=TridionUnzipStep, factory=]]], finalizeContext = false]. Proceeding to create new processing context.
2019-11-20 13:34:09,775 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] BasicProcessingContextProvider - Created new processing context: BasicProcessingContext [executionId = tcm:0-1693950-66560, binaryId = tcm_0-1693 950-66560.Content.zip, action = Deploy verbs = [Commit, Content, PreCommit, Process], currentPipeline = Optional[BasicPipeline [id=Tridion-Bootstrap, finalizePipeline=false, actions=[TridionBootstrap], verb=[Commit, Content, Prepare, Rollba ck]]], currentStep = Optional.empty], finalizeContext = false]
2019-11-20 13:34:09,775 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] PipelineActor - Step 'TridionUnzipStep' of pipelineId: 'Tridion-Bootstrap' for 'tcm:0-1693950-66560' processed.
2019-11-20 13:34:09,777 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] HybridStateStore - Found pipeline entity for execution id: tcm:0-1693950-66560 and pipeline id: Tridion-Bootstrap
2019-11-20 13:34:09,787 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] ExecutionActor - Processed pipeline 'Optional[BasicPipeline [id=Tridion-Bootstrap, finalizePipeline=false, actions=[TridionBootstrap], verb=[Comm it, Content, Prepare, Rollback]]]' for execution tcm:0-1693950-66560
2019-11-20 13:34:09,787 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] BasicProcessingContextProvider - Received processing context: BasicProcessingContext [executionId = tcm:0-1693950-66560, binaryId = tcm_0-1693950 -66560.Content.zip, action = Deploy verbs = [Commit, Content, PreCommit, Process], currentPipeline = Optional[BasicPipeline [id=Tridion-Bootstrap, finalizePipeline=false, actions=[TridionBootstrap], verb=[Commit, Content, Prepare, Rollback] ]], currentStep = Optional.empty], finalizeContext = false]. Proceeding to create new processing context.
2019-11-20 13:34:09,787 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] BasicProcessingContextProvider - Created new processing context: BasicProcessingContext [executionId = tcm:0-1693950-66560, binaryId = tcm_0-1693 950-66560.Content.zip, action = Deploy verbs = [Commit, Content, PreCommit, Process], currentPipeline = Optional[BasicPipeline [id=Tridion-Process-Deploy, finalizePipeline=false, actions=[Deploy], verb=[Process]]], currentStep = Optional[Ba sicStep [id=BinaryDeploy, factory=com.sdl.delivery.deployer.steps.TridionExecutableStepFactory]]], finalizeContext = false]
2019-11-20 13:34:09,788 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] PipelineActor - Start pipeline 'Tridion-Process-Deploy' for 'tcm:0-1693950-66560'.
2019-11-20 13:34:09,790 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] HybridStateStore - Creating new pipeline entity for execution id: tcm:0-1693950-66560 and pipeline id: Tridion-Process-Deploy
2019-11-20 13:34:09,803 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] StepActor - Start step 'Optional[BasicStep [id=BinaryDeploy, factory=com.sdl.delivery.deployer.steps.TridionExecutableStepFactory]]' for 'tcm:0-1 693950-66560'
2019-11-20 13:34:09,805 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] HybridStateStore - Creating new step entity for execution id: tcm:0-1693950-66560, pipeline id: Tridion-Process-Deploy and step id: BinaryDeploy
2019-11-20 13:34:09,815 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] TridionDeployerStepAdapter - Creating new transaction log for execution id: tcm:0-1693950-66560 and step id: BinaryDeploy
2019-11-20 13:34:09,818 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] HybridStepDataStore - Trying to find all step data for ExecutionId = tcm:0-1693950-66560 and key = InWait
2019-11-20 13:34:09,818 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] HybridStepDataStore - Trying to find all step data for ExecutionId = tcm:0-1693950-66560 and keys = [InWait]
2019-11-20 13:34:09,820 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] HybridStepDataStore - Found 0 step data in session database for ExecutionId = tcm:0-1693950-66560 and keys = [InWait]
2019-11-20 13:34:09,825 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] HybridStepDataStore - Trying to find all step data for ExecutionId = tcm:0-1693950-66560 and key = UnzipLocation
2019-11-20 13:34:09,825 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] HybridStepDataStore - Trying to find all step data for ExecutionId = tcm:0-1693950-66560 and keys = [UnzipLocation]
2019-11-20 13:34:09,827 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] HybridStepDataStore - Found 1 step data in session database for ExecutionId = tcm:0-1693950-66560 and keys = [UnzipLocation]
2019-11-20 13:34:09,854 INFO [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] BinaryDeployHandler - [tcm:0-1693950-66560] Package binaries processing is started
2019-11-20 13:34:09,876 INFO [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] BinaryDeployHandler - [tcm:0-1693950-66560] Package binary item processing is started. Path: /esES/Images/2019/09/test-stan-smtih_193-147195.png
2019-11-20 13:34:11,235 INFO [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] BinaryDeployHandler - [tcm:0-1693950-66560] Package binary item processing is completed. Path: /esES/Images/2019/09/test-stan-smtih_193-147195.png
2019-11-20 13:34:11,240 INFO [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] BinaryDeployHandler - [tcm:0-1693950-66560] Package binary item processing is started. Path: /esES/Images/2019/09/test-gazelle_193-147196.jpg
2019-11-20 13:34:12,186 INFO [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] BinaryDeployHandler - [tcm:0-1693950-66560] Package binary item processing is completed. Path: /esES/Images/2019/09/test-gazelle_193-147196.jpg
2019-11-20 13:34:12,192 INFO [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] BinaryDeployHandler - [tcm:0-1693950-66560] Package binary item processing is started. Path: /esES/Images/2019/09/test-zx-4000_193-147197.jpeg
2019-11-20 13:34:12,862 INFO [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] BinaryDeployHandler - [tcm:0-1693950-66560] Package binary item processing is completed. Path: /esES/Images/2019/09/test-zx-4000_193-147197.jpeg
2019-11-20 13:34:12,862 INFO [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] BinaryDeployHandler - [tcm:0-1693950-66560] Package binaries processing is completed
2019-11-20 13:34:12,872 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] StepActor - (metric) type=stepExecutionTime executionIdVal=tcm:0-1693950-66560 pipelineIdVal=Tridion-Process-Deploy stepIdVal=BinaryDeploy elapsed=3057
2019-11-20 13:34:12,874 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] HybridStateStore - Found step entity for execution id: tcm:0-1693950-66560, pipeline id: Tridion-Process-Deploy and step id: BinaryDeploy
2019-11-20 13:34:12,881 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] BasicProcessingContextProvider - Received processing context: BasicProcessingContext [executionId = tcm:0-1693950-66560, binaryId = tcm_0-1693950-66560.Content.zip, action = Deploy verbs = [Commit, Content, PreCommit, Process], currentPipeline = Optional[BasicPipeline [id=Tridion-Process-Deploy, finalizePipeline=false, actions=[Deploy], verb=[Process]]], currentStep = Optional[BasicStep [id=BinaryDeploy, factory=com.sdl.delivery.deployer.steps.TridionExecutableStepFactory]]], finalizeContext = false]. Proceeding to create new processing context.
2019-11-20 13:34:12,882 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] BasicProcessingContextProvider - Created new processing context: BasicProcessingContext [executionId = tcm:0-1693950-66560, binaryId = tcm_0-1693950-66560.Content.zip, action = Deploy verbs = [Commit, Content, PreCommit, Process], currentPipeline = Optional[BasicPipeline [id=Tridion-Process-Deploy, finalizePipeline=false, actions=[Deploy], verb=[Process]]], currentStep = Optional[BasicStep [id=ComponentDeploy, factory=com.sdl.delivery.deployer.steps.TridionExecutableStepFactory]]], finalizeContext = false]
2019-11-20 13:34:12,882 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] PipelineActor - Step 'BinaryDeploy' of pipelineId: 'Tridion-Process-Deploy' for 'tcm:0-1693950-66560' processed.
2019-11-20 13:34:12,882 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] StepActor - Start step 'Optional[BasicStep [id=ComponentDeploy, factory=com.sdl.delivery.deployer.steps.TridionExecutableStepFactory]]' for 'tcm:0-1693950-66560'
2019-11-20 13:34:12,884 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] HybridStateStore - Creating new step entity for execution id: tcm:0-1693950-66560, pipeline id: Tridion-Process-Deploy and step id: ComponentDeploy
2019-11-20 13:34:12,892 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] TridionDeployerStepAdapter - Creating new transaction log for execution id: tcm:0-1693950-66560 and step id: ComponentDeploy
2019-11-20 13:34:12,894 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] HybridStepDataStore - Trying to find all step data for ExecutionId = tcm:0-1693950-66560 and key = InWait
2019-11-20 13:34:12,894 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] HybridStepDataStore - Trying to find all step data for ExecutionId = tcm:0-1693950-66560 and keys = [InWait]
2019-11-20 13:34:12,902 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] HybridStepDataStore - Found 0 step data in session database for ExecutionId = tcm:0-1693950-66560 and keys = [InWait]
2019-11-20 13:34:12,909 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] HybridStepDataStore - Trying to find all step data for ExecutionId = tcm:0-1693950-66560 and key = UnzipLocation
2019-11-20 13:34:12,909 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] HybridStepDataStore - Trying to find all step data for ExecutionId = tcm:0-1693950-66560 and keys = [UnzipLocation]
2019-11-20 13:34:12,912 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] HybridStepDataStore - Found 1 step data in session database for ExecutionId = tcm:0-1693950-66560 and keys = [UnzipLocation]
2019-11-20 13:34:12,927 INFO [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] ContentDeployHandler - [tcm:0-1693950-66560] Package content processing is started
2019-11-20 13:34:12,932 INFO [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] ContentDeployHandler - [tcm:0-1693950-66560] Package content template: MyApp.Templates.CUSTOM.v2 (tcm:193-116549-32)
2019-11-20 13:34:23,402 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] LocalThreadTransaction - Received a set on the new method with value: null
2019-11-20 13:34:23,402 WARN [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] StepActor - Step 'ComponentDeploy' for 'tcm:0-1693950-66560' failed with message: java.lang.RuntimeException: Timeout waiting for parallel processing
2019-11-20 13:34:23,404 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] HybridStateStore - Found step entity for execution id: tcm:0-1693950-66560, pipeline id: Tridion-Process-Deploy and step id: ComponentDeploy
2019-11-20 13:34:23,412 ERROR [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] StepActor - Step 'ComponentDeploy' for 'tcm:0-1693950-66560' can NOT retry
2019-11-20 13:34:23,412 ERROR [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] StepActor - Step 'ComponentDeploy' for 'tcm:0-1693950-66560':
java.lang.RuntimeException: Timeout waiting for parallel processing.
at com.cloudinary.strategies.AbstractUploaderStrategy.processResponse(AbstractUploaderStrategy.java:85)
at com.cloudinary.http44.UploaderStrategy.callApi(UploaderStrategy.java:140)
at com.cloudinary.Uploader.callApi(Uploader.java:34)
at com.cloudinary.Uploader.upload(Uploader.java:76)
at com.cloudinary.Uploader.upload(Uploader.java:68)
at com.myapp.deployer.modules.client.binary.CloudinaryClient.put(CloudinaryClient.java:95)
at com.myapp.deployer.modules.client.widget.DefaultWidgetClient.updateUrl(DefaultWidgetClient.java:23)
at com.myapp.deployer.modules.handlers.content.ContentDeployHandler.parseOrCopyVideoUrls(ContentDeployHandler.java:196)
at com.myapp.deployer.modules.handlers.content.ContentDeployHandler.handle(ContentDeployHandler.java:97)
at com.myapp.deployer.modules.MyAppContentDeployModule.process(MyAppContentDeployModule.java:31)
at com.sdl.delivery.deployer.steps.TridionDeployerStepAdapter.process(TridionDeployerStepAdapter.java:91)
at com.sdl.delivery.deployer.engine.pipeline.actor.StepActor.execute(StepActor.scala:72)
at com.sdl.delivery.deployer.engine.pipeline.actor.StepActor.com$sdl$delivery$deployer$engine$pipeline$actor$StepActor$$processStep(StepActor.scala:57)
at com.sdl.delivery.deployer.engine.pipeline.actor.StepActor$$anonfun$receive$1.applyOrElse(StepActor.scala:40)
at akka.actor.Actor.aroundReceive(Actor.scala:517)
at akka.actor.Actor.aroundReceive$(Actor.scala:515)
at com.sdl.delivery.deployer.engine.pipeline.actor.StepActor.aroundReceive(StepActor.scala:26)
at akka.actor.ActorCell.receiveMessage(ActorCell.scala:588)
at akka.actor.ActorCell.invoke(ActorCell.scala:557)
at akka.dispatch.Mailbox.processMailbox(Mailbox.scala:258)
at akka.dispatch.Mailbox.run(Mailbox.scala:225)
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)
2019-11-20 13:34:23,412 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] BasicProcessingContextProvider - Received processing context: BasicProcessingContext [executionId = tcm:0-1693950-66560, binaryId = tcm_0-1693950-66560.Content.zip, action = Deploy verbs = [Commit, Content, PreCommit, Process], currentPipeline = Optional[BasicPipeline [id=Tridion-Process-Deploy, finalizePipeline=false, actions=[Deploy], verb=[Process]]], currentStep = Optional[BasicStep [id=ComponentDeploy, factory=com.sdl.delivery.deployer.steps.TridionExecutableStepFactory]]], finalizeContext = false]. Proceeding to create finalizing processing context.
2019-11-20 13:34:23,412 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] BasicProcessingContextProvider - Current pipeline was found. Looking for final pipeline of: BasicPipeline [id=Tridion-Process-Deploy, finalizePipeline=false, actions=[Deploy], verb=[Process]].
2019-11-20 13:34:23,412 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] BasicPipelineProvider - Found 6 pipelines after pipeline: Tridion-Process-Deploy. Filtering for finalizing pipeline that matches action Deploy and verbs [Commit, Content, PreCommit, Process].
2019-11-20 13:34:23,412 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] BasicProcessingContextProvider - Finalize pipeline configured after : BasicPipeline [id=Tridion-Process-Deploy, finalizePipeline=false, actions=[Deploy], verb=[Process]] is Optional[BasicPipeline [id=Tridion-Cleanup, finalizePipeline=true, actions=[Undeploy, Deploy], verb=[*]]].
2019-11-20 13:34:23,412 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] BasicProcessingContextProvider - Created finalizing processing context: BasicProcessingContext [executionId = tcm:0-1693950-66560, binaryId = tcm_0-1693950-66560.Content.zip, action = Deploy verbs = [Commit, Content, PreCommit, Process], currentPipeline = Optional[BasicPipeline [id=Tridion-Cleanup, finalizePipeline=true, actions=[Undeploy, Deploy], verb=[*]]], currentStep = Optional[BasicStep [id=TridionCleanupStep, factory=]]], finalizeContext = true]
2019-11-20 13:34:23,412 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] PipelineActor - Received FinalizeExecutionException for original 'BasicProcessingContext [executionId = tcm:0-1693950-66560, binaryId = tcm_0-1693950-66560.Content.zip, action = Deploy verbs = [Commit, Content, PreCommit, Process], currentPipeline = Optional[BasicPipeline [id=Tridion-Process-Deploy, finalizePipeline=false, actions=[Deploy], verb=[Process]]], currentStep = Optional[BasicStep [id=ComponentDeploy, factory=com.sdl.delivery.deployer.steps.TridionExecutableStepFactory]]], finalizeContext = false]'. Will try to finalize execution with finalizeProcessingContext: BasicProcessingContext [executionId = tcm:0-1693950-66560, binaryId = tcm_0-1693950-66560.Content.zip, action = Deploy verbs = [Commit, Content, PreCommit, Process], currentPipeline = Optional[BasicPipeline [id=Tridion-Cleanup, finalizePipeline=true, actions=[Undeploy, Deploy], verb=[*]]], currentStep = Optional[BasicStep [id=TridionCleanupStep, factory=]]], finalizeContext = true]
2019-11-20 13:34:23,414 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] HybridStateStore - Found pipeline entity for execution id: tcm:0-1693950-66560 and pipeline id: Tridion-Process-Deploy
2019-11-20 13:34:23,420 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] PipelineActor - Start finalizing pipeline 'Tridion-Cleanup' for 'tcm:0-1693950-66560'.
2019-11-20 13:34:23,422 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] HybridStateStore - Creating new pipeline entity for execution id: tcm:0-1693950-66560 and pipeline id: Tridion-Cleanup
2019-11-20 13:34:23,431 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] StepActor - Start step 'Optional[BasicStep [id=TridionCleanupStep, factory=]]' of finalizing pipeline for 'tcm:0-1693950-66560'
2019-11-20 13:34:23,433 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] HybridStateStore - Creating new step entity for execution id: tcm:0-1693950-66560, pipeline id: Tridion-Cleanup and step id: TridionCleanupStep
2019-11-20 13:34:23,439 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] BasicExecutableStepFactoryManager - Providing ExecutableStep for PipelineId: Tridion-Cleanup and StepId: TridionCleanupStep
2019-11-20 13:34:23,439 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] BasicExecutableStepFactoryManager - Factory for stepId: TridionCleanupStep not defined. Using SpringAwareExecutableStepFactory
2019-11-20 13:34:23,439 INFO [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] SpringAwareExecutableStepFactory - Initialized executable step TridionCleanupStep using SpringAwareExecutableStepFactory factory
2019-11-20 13:34:23,452 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] HybridStepDataStore - Trying to find all step data for ExecutionId = tcm:0-1693950-66560 and key = ZipLocation
2019-11-20 13:34:23,452 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] HybridStepDataStore - Trying to find all step data for ExecutionId = tcm:0-1693950-66560 and keys = [ZipLocation]
2019-11-20 13:34:23,457 DEBUG [ProcessingAkkaSpringContext-akka.actor.default-dispatcher-1757] HybridStepDataStore - Found 1 step data in session database for ExecutionId = tcm:0-1693950-66560 and keys = [ZipLocation]
See the full debug log here, it was to big to paste here -> https://we.tl/t-mZvWgXe1rJ
I am by no means an expert in Tridion but does this seems like there is a limitation in our custom code processing? We are integrated with a 3rd party API for uploading assets (Cloudinary) so not sure if this is the root cause when we publish a lot of components.
Any help is appreciated. Thanks