0

We are trying to publish multiple multimedia items - more than 1000, at a time and encounter 100s of failed items in publishing, along with the following stack trace. We are not able to find anything in particular with our setup that would cause this. Are we missing any configuration? Any help is much appreciated. TIA.

2019-03-29 20:11:18,202 DEBUG DeploymentHandler - Deploying tcd:pub[12]/componentmeta[160103]. 
2019-03-29 20:11:18,204 DEBUG DeploymentHandler - Active thread transaction: tcm:0-17724917-66560. 
2019-03-29 20:11:18,205 DEBUG DeploymentHandler - Handing references from: tcd:pub[12]/componentmeta[160103] to: 1 items 
2019-03-29 20:11:18,206 DEBUG DeploymentHandler - Total tracked references: 975 
2019-03-29 20:11:18,207 DEBUG DeploymentHandler - Retrieving typeHandler for itemURI: tcd:pub[12]/componentmeta[160103] 
2019-03-29 20:11:18,234 DEBUG TridionPreCommitStep - Executing worker. ExecutionId:tcm:0-17724768-66560, Class:com.tridion.storage.deploy.workers.ComponentWorker 
2019-03-29 20:11:18,236 DEBUG TridionPreCommitStep - Executing worker. ExecutionId:tcm:0-17724828-66560, Class:com.tridion.storage.deploy.workers.ComponentWorker 
2019-03-29 20:11:18,239 DEBUG TridionPreCommitStep - Executing worker. ExecutionId:tcm:0-17724856-66560, Class:com.tridion.storage.deploy.workers.ComponentWorker 
2019-03-29 20:11:18,240 DEBUG HybridStepDataStore - Found 1 step data in session database for ExecutionId = tcm:0-17724939-66560 and keys = [UnzipLocation] 2019-03-29 20:11:18,240 DEBUG HybridStepDataStore - Found 0 step data in session database for ExecutionId = tcm:0-17724920-66560 and keys = [InWait] 2019-03-29 20:11:18,292 DEBUG HybridStepDataStore - Trying to find all step data for ExecutionId = tcm:0-17724920-66560 and key = UnzipLocation 
2019-03-29 20:11:18,294 DEBUG HybridStepDataStore - Trying to find all step data for ExecutionId = tcm:0-17724920-66560 and keys = [UnzipLocation] 
2019-03-29 20:11:18,314 WARN  TridionTransactionalExecutableStep - Rollback transaction due to error. ExecutionId: tcm:0-17724943-66560 error: Error while removing entity 
2019-03-29 20:11:18,329 DEBUG HybridStepDataStore - Found 0 step data in session database for ExecutionId = tcm:0-17724875-66560 and keys = [InWait] 2019-03-29 20:11:20,065 DEBUG CommandQueuePoller - No more processing slots available on queue: ContentQueueStaging 
2019-03-29 20:11:20,166 DEBUG HybridStepDataStore - Found 1 step data in session database for ExecutionId = tcm:0-17724868-66560 and keys = [UnzipLocation] 
2019-03-29 20:11:20,173 DEBUG JSONCommandSerializer - Command de-serialized 'JSONCommand{verbs=[Content], action='TridionBootstrap', binaryIds=[tcm_0-17724822-66560.Content.zip], executionId='tcm:0-17724822-66560', properties={}}' 
2019-03-29 20:11:20,176 DEBUG StepActor - (metric) type=stepExecutionTime executionIdVal=tcm:0-17724939-66560 pipelineIdVal=Tridion-Process-Deploy stepIdVal=StructureGroupDeploy elapsed=7104 
2019-03-29 20:11:20,178 WARN  StepActor - Step 'TridionPreCommitStep' for 'tcm:0-17724943-66560' failed with message: com.sdl.delivery.deployer.api.processing.exception.ProcessingException: Failed to execute transaction worker. Worker:com.tridion.storage.deploy.workers.ComponentWorker TransactionId:tcm:0-17724943-66560 
2019-03-29 20:11:20,179 DEBUG HybridStepDataStore - Trying to find all step data for ExecutionId = tcm:0-17724875-66560 and key = UnzipLocation 
2019-03-29 20:11:20,180 INFO  StepActor - Step 'TridionPreCommitStep' for 'tcm:0-17724943-66560' can retry at StepRetryPoint[ pipelineId = Tridion-PreCommit-TX, stepId = TridionPreCommitStep ] 
2019-03-29 20:11:20,180 DEBUG HybridStepDataStore - Trying to find all step data for ExecutionId = tcm:0-17724875-66560 and keys = [UnzipLocation] 
2019-03-29 20:11:20,182 DEBUG PipelineActor - Received RetryStepException for original 'BasicProcessingContext [executionId = tcm:0-17724943-66560, binaryId = tcm_0-17724943-66560.Content.zip, action = Deploy verbs = [Commit, Content, PreCommit, Process], currentPipeline = Optional[BasicPipeline [id=Tridion-PreCommit-TX, finalizePipeline=false, actions=[Undeploy, Deploy], verb=[PreCommit]]], currentStep = Optional[BasicStep [id=TridionPreCommitStep, factory=]]], finalizeContext = false]'. Will try to retry with retryProcessingContext: BasicProcessingContext [executionId = tcm:0-17724943-66560, binaryId = tcm_0-17724943-66560.Content.zip, action = Deploy verbs = [Commit, Content, PreCommit, Process], currentPipeline = Optional[BasicPipeline [id=Tridion-PreCommit-TX, finalizePipeline=false, actions=[Undeploy, Deploy], verb=[PreCommit]]], currentStep = Optional[BasicStep [id=TridionPreCommitStep, factory=]]], finalizeContext = false] 
2019-03-29 20:11:20,184 DEBUG PipelineActor - Retry attempt: 2 for execution id 'tcm:0-17724943-66560' 
2019-03-29 20:11:20,190 DEBUG HybridStateStore - Found step entity for execution id: tcm:0-17724939-66560, pipeline id: Tridion-Process-Deploy and step id: StructureGroupDeploy 
2019-03-29 20:11:20,203 DEBUG StepActor - (metric) type=stepExecutionTime executionIdVal=tcm:0-17724917-66560 pipelineIdVal=Tridion-Process-Deploy stepIdVal=ComponentDeploy elapsed=6995 
2019-03-29 20:11:20,212 DEBUG BasicProcessingContextProvider - Received processing context: BasicProcessingContext [executionId = tcm:0-17724939-66560, binaryId = tcm_0-17724939-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=StructureGroupDeploy, factory=com.sdl.delivery.deployer.steps.TridionExecutableStepFactory]]], finalizeContext = false]. Proceeding to create new processing context. 
2019-03-29 20:11:20,213 DEBUG HybridStateStore - Found step entity for execution id: tcm:0-17724917-66560, pipeline id: Tridion-Process-Deploy and step id: ComponentDeploy 
2019-03-29 20:11:20,213 DEBUG BasicProcessingContextProvider - Found current step: BasicStep [id=StructureGroupDeploy, factory=com.sdl.delivery.deployer.steps.TridionExecutableStepFactory]. Looking for next step. 
2019-03-29 20:11:20,215 DEBUG BasicProcessingContextProvider - Created new processing context: BasicProcessingContext [executionId = tcm:0-17724939-66560, binaryId = tcm_0-17724939-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.empty], finalizeContext = false] 
2019-03-29 20:11:20,216 DEBUG HybridStepDataStore - Found 9 step data in session database for ExecutionId = tcm:0-17724785-66560 and key startsWith = TransactionLog 
2019-03-29 20:11:20,217 DEBUG PipelineActor - Step 'StructureGroupDeploy' of pipelineId: 'Tridion-Process-Deploy' for 'tcm:0-17724939-66560' processed. 2019-03-29 20:11:20,233 DEBUG HybridStateStore - Found pipeline entity for execution id: tcm:0-17724939-66560 and pipeline id: Tridion-Process-Deploy 2019-03-29 20:11:20,234 DEBUG TridionPreCommitStep - Retrieved transaction log. ExecutionId:tcm:0-17724785-66560
**2019-03-29 20:11:20,235 WARN  TridionTransactionalExecutableStep - Rollback transaction due to error. ExecutionId: tcm:0-17724768-66560 error: Error while removing entity** 
2019-03-29 20:11:20,238 DEBUG TridionPreCommitStep - Executing worker. ExecutionId:tcm:0-17724887-66560, Class:com.tridion.storage.deploy.workers.ReferenceEntryWorker 
2019-03-29 20:11:20,248 DEBUG StepActor - (metric) type=stepExecutionTime executionIdVal=tcm:0-17724868-66560 pipelineIdVal=Tridion-Process-Deploy stepIdVal=StructureGroupDeploy elapsed=7073
2019-03-29 20:11:20,252 DEBUG TridionPreCommitStep - Executing worker. ExecutionId:tcm:0-17724785-66560, Class:com.tridion.storage.deploy.workers.BinaryCheckerWorker 
2019-03-29 20:11:20,253 DEBUG BasicProcessingContextProvider - Received processing context: BasicProcessingContext [executionId = tcm:0-17724917-66560, binaryId = tcm_0-17724917-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 new processing context. 
2019-03-29 20:11:20,254 DEBUG BasicProcessingContextProvider - Found current step: BasicStep [id=ComponentDeploy, factory=com.sdl.delivery.deployer.steps.TridionExecutableStepFactory]. Looking for next step. 
2019-03-29 20:11:20,256 DEBUG BasicProcessingContextProvider - Created new processing context: BasicProcessingContext [executionId = tcm:0-17724917-66560, binaryId = tcm_0-17724917-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=TemplateDeploy, factory=com.sdl.delivery.deployer.steps.TridionExecutableStepFactory]]], finalizeContext = false] 
2019-03-29 20:11:20,261 DEBUG PipelineActor - Step 'ComponentDeploy' of pipelineId: 'Tridion-Process-Deploy' for 'tcm:0-17724917-66560' processed. 
2019-03-29 20:11:20,265 DEBUG HybridStateStore - Found step entity for execution id: tcm:0-17724868-66560, pipeline id: Tridion-Process-Deploy and step id: StructureGroupDeploy 
2019-03-29 20:11:20,267 DEBUG HybridStepDataStore
- Found 1 step data in session database for ExecutionId = tcm:0-17724920-66560 and keys = [UnzipLocation]

cd_core.log

2019-03-30 08:07:02,409 DEBUG TridionPreCommitStep - Executing worker. ExecutionId:tcm:0-17728592-66560, Class:com.tridion.storage.deploy.workers.ReferenceEntryWorker
2019-03-30 08:07:02,409 DEBUG StorageManagerImpl - Loading a cached DAO for publicationId/typeMapping/itemExtension: 12 / Reference / null
2019-03-30 08:07:02,409 DEBUG StorageManagerImpl - Wrapping DAO's, currently 0 wrappers installed
2019-03-30 08:07:02,415 DEBUG CacheManagerImpl - Adding key 1:12:tcd:pub[12]/schema[3263]:tcd:pub[12]/componentmeta[123082]
2019-03-30 08:07:02,416 DEBUG TridionPreCommitStep - Executing worker. ExecutionId:tcm:0-17728592-66560, Class:com.tridion.storage.deploy.workers.ComponentWorker
2019-03-30 08:07:02,416 DEBUG StorageManagerImpl - Loading a cached DAO for publicationId/typeMapping/itemExtension: 12 / ComponentMeta / null
2019-03-30 08:07:02,417 DEBUG JPADAOFactory - Loaded DAO with type: JPAItemDAO inside transaction: tcm:0-17728592-66560
2019-03-30 08:07:02,417 DEBUG StorageManagerImpl - Wrapping DAO's, currently 0 wrappers installed
2019-03-30 08:07:02,424 WARN  JPAItemDAO - CustomMeta string value is bigger than what the database might support; the database might throw an error, for item abc.com-0901d196802888a7- Rod ends for the food  industry (123082)
2019-03-30 08:07:02,464 WARN  TridionTransactionalExecutableStep - Rollback transaction due to error. ExecutionId: tcm:0-17728592-66560 error: Error while removing entity
2019-03-30 08:07:02,464 INFO  TransactionManagerImpl - Rolling back storage transaction: tcm:0-17728592-66560
2019-03-30 08:07:02,474 DEBUG LocalThreadTransaction - Removing storageTransactionId tcm:0-17728592-66560 from the current thread.
2019-03-30 08:07:02,474 DEBUG LocalThreadTransaction - Received a set on the new method with value: null
2019-03-30 08:07:02,474 WARN  StepActor - Step 'TridionPreCommitStep' for 'tcm:0-17728592-66560' failed with message: com.sdl.delivery.deployer.api.processing.exception.ProcessingException: Failed to execute transaction worker. Worker:com.tridion.storage.deploy.workers.ComponentWorker TransactionId:tcm:0-17728592-66560
2019-03-30 08:07:02,474 INFO  StepActor - Step 'TridionPreCommitStep' for 'tcm:0-17728592-66560' can retry at StepRetryPoint[ pipelineId = Tridion-PreCommit-TX, stepId = TridionPreCommitStep ]
2019-03-30 08:07:02,475 DEBUG PipelineActor - Received RetryStepException for original 'BasicProcessingContext [executionId = tcm:0-17728592-66560, binaryId = tcm_0-17728592-66560.Content.zip, action = Deploy verbs = [Commit, Content, PreCommit, Process], currentPipeline = Optional[BasicPipeline [id=Tridion-PreCommit-TX, finalizePipeline=false, actions=[Undeploy, Deploy], verb=[PreCommit]]], currentStep = Optional[BasicStep [id=TridionPreCommitStep, factory=]]], finalizeContext = false]'. Will try to retry with retryProcessingContext: BasicProcessingContext [executionId = tcm:0-17728592-66560, binaryId = tcm_0-17728592-66560.Content.zip, action = Deploy verbs = [Commit, Content, PreCommit, Process], currentPipeline = Optional[BasicPipeline [id=Tridion-PreCommit-TX, finalizePipeline=false, actions=[Undeploy, Deploy], verb=[PreCommit]]], currentStep = Optional[BasicStep [id=TridionPreCommitStep, factory=]]], finalizeContext = false]
2019-03-30 08:07:02,475 DEBUG PipelineActor - Retry attempt: 3 for execution id 'tcm:0-17728592-66560'
2019-03-30 08:07:02,589 DEBUG PipelineActor - Start pipeline 'Tridion-PreCommit-TX' for 'tcm:0-17728592-66560'.
2019-03-30 08:07:02,592 DEBUG HybridStateStore - Found pipeline entity for execution id: tcm:0-17728592-66560 and pipeline id: Tridion-PreCommit-TX
2019-03-30 08:07:02,604 DEBUG StepActor - Start step 'Optional[BasicStep [id=TridionPreCommitStep, factory=]]' for 'tcm:0-17728592-66560'
Improve this question
5
  • If you are doing bulk publishing are you up to date with hotfixes? You will find hotfix related to bulk publishing raise ticket with SDL.
    – k951
    Commented Mar 30, 2019 at 4:26
  • Yes, the hotfixes are in place.
    – NewUser
    Commented Mar 30, 2019 at 7:43
  • How is your deployer setup implementation? Is it scale-out deployer? Is it deployer/deployer-worker or deployer-combined? double check your deployer for cd_core.log to check the ERROR logs?
    – Velmurugan ♦
    Commented Mar 30, 2019 at 9:04
  • It is deployer/deployer-worker set up.
    – NewUser
    Commented Mar 30, 2019 at 9:08
  • In the publishing, queue double click failed item and update the question with error and state? Is that error log from worker or deployer?
    – Velmurugan ♦
    Commented Mar 30, 2019 at 17:50

1 Answer 1

Reset to default
1

Looking at the error messages, there are hints that the transaction might just be too big. Given that you are publishing large amounts of multimedia items, this probably makes sense.

Try to figure out exactly how large these publish transactions are, and whether this is what's causing to to exceed some limit. Experiment with smaller packages to see what does work.

Improve this answer

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Not the answer you're looking for? Browse other questions tagged or ask your own question.