Here I wanted to share simple solution to an ongoing issue of publishing with Sitecore 7.2 with my company. It is such a simple solution but took lots of efforts and time to get to it. Thought to share it so that if someone is facing same kind of issue, can be benefited out of it.

The problem:

Out marketing team(who is also responsible for the content management) continuously reporting us with the issue of publishing. They mentioned that whenever we try to publish any item, the publishing took lot of time to finish. Most of the time publishing dialog stuck at Initialization stage. This issue sometimes go worst, even after waiting for half an hour to 45 minutes the publishing dialog still shows initialization and we need to ask web admin guys to re-cycle application pool and start publishing again(this is worst case scenario).

So as a first step, I asked them to avoid bulky publishing. I also suggested then to avoid using publishing related items rather go to individual items changed and only publish those items. The reason is to minimize items count in publishing which keeps publishing process as short as possible and keep them moving.

Even though content authors follow my suggestions, the issue still persist. So we started investigating even more. We planned to take help of Sitecore support personal who visiting us once every month. He suggested us to compare all the config files with pure vanilla version and along with all the other files and folder so we can be absolute sure we are having all the goodies what should be there. After this huge activity we identified couple of missing files and configurations in both CM and CD environments.

So we have gathered all those missing pieces and deployed to the respected environments.

After this we have reported a side effect from marketing, that what ever we are deploying to Fail-over publishing target(which is our DR cum internal Preview servers) it also eventually published to production(which is very strange to us and this was not the behavior before we deploy the missing bits).

Root cause

So, I started investigating in context to new side effects. While going through the log file for CM server, my eyes struck with an strange log entry which looks something like below.

5768 2016-03-10 11:03:57 INFO AUDIT (ad\paragd): Execute workflow command. Item: master:/sitecore/content/Site1/Home/test, language: en, version: 11, id: {23005A37-6BB5-4025-AC5B-047A8D3F3719}, command: /sitecore/system/Workflows/Site1 Workflow/Draft/Submit, previous state: Draft, next state: /sitecore/system/Workflows/Site1 Workflow/Awaiting Approval, user: ad\paragd
ManagedPoolThread #3 2016-03-10 11:03:59 INFO Starting update of index for the database 'master' (1 pending).
ManagedPoolThread #3 2016-03-10 11:03:59 INFO Update of index for the database 'master' done.
ManagedPoolThread #16 2016-03-10 11:03:59 INFO Starting update of index for the database 'master' (1 pending).
ManagedPoolThread #16 2016-03-10 11:03:59 INFO Update of index for the database 'master' done.
5284 2016-03-10 11:04:00 INFO AUDIT (ad\paragd): Execute workflow command. Item: master:/sitecore/content/Site1/Home/test, language: en, version: 11, id: {23005A37-6BB5-4025-AC5B-047A8D3F3719}, command: /sitecore/system/Workflows/Site1 Workflow/Awaiting Approval/Approve, previous state: Awaiting Approval, next state: /sitecore/system/Workflows/Site1 Workflow/Approved, user: ad\paragd
5284 2016-03-10 11:04:00 INFO AUDIT (ad\paragd): [Publishing]: Starting to process 2 publishing options
4572 2016-03-10 11:04:00 INFO HttpModule is being initialized
568 2016-03-10 11:04:00 INFO HttpModule is being initialized
5456 2016-03-10 11:04:01 INFO Job started: Publish
2736 2016-03-10 11:04:01 INFO Job started: Publish to 'web'
.
.
.
2736 2016-03-10 11:04:01 INFO Job ended: Publish to 'web' (units processed: 11)
7052 2016-03-10 11:04:01 INFO Job started: Publish to 'web_Failover'
.
.
.
7052 2016-03-10 11:04:02 INFO Job ended: Publish to 'web_Failover' (units processed: 11)

Above lines, I found in the log just above the log line for manually triggering of publishing just for the single publishing target which is “fail-Over”.

4392 2016-03-10 11:04:18 INFO AUDIT (ad\paragd): Publish item: master:/sitecore/content/Site1/Home/test, language: en, version: 11, id: {23005A37-6BB5-4025-AC5B-047A8D3F3719}
3600 2016-03-10 11:04:28 INFO AUDIT (ad\paragd): Publish, root: {23005A37-6BB5-4025-AC5B-047A8D3F3719}, languages:en, targets:WWW_Failover, databases:web_Failover, incremental:false, smart:true, republish:false, children:false, related:false
3600 2016-03-10 11:04:28 INFO AUDIT (ad\paragd): [Publishing]: Starting to process 1 publishing options
2864 2016-03-10 11:04:29 INFO Job started: Publish
5240 2016-03-10 11:04:29 INFO Job started: Publish to 'web_Failover'

Solution

From above behavior on the log file, it was clear that the workflow has to do something with this. When I checked the default workflow assigned, I found that there is an auto publishing action configured with final stage of the workflow as shown in below screen grab.



But alone having auto publish action configured, should not be making publishing this slow. So I have investigated more and found the real culprit.

The auto published action is configured with deep=1 as parameters.
So now, I have dive into the de-compiled code and found this is very dangerous parameter configured with auto publishing action.
Having deep parameter set, you are instructing auto publisher to publish everything underneath the selected item(approving item here) to every publishing targets(in this case 2 targets).

So, if you are approving leaf node/item, the auto publishing will be quick as it will only publish that node along with no child. But if you are approving, lets say home node of the site, you are actually publishing not just that root home item but pretty much the whole site to all available publishing targets…!!!(Very shocking…isn’t it?).

So now after approving the item, when you trying to publish that home node to selected target, it always queue up in the publishing queue and Sitecore publishing dialog box show you Initialization message screen as shown above. The item publishing will be picked up when previous auto publishing job is done. This is the case with just one editor, if you have 5-6 content editor, then the situation can go into really worst.

So the easy solution is to remove that auto publishing action item which was publishing lot of unwanted items to all targets in background without any visible signs.

So we did that and everyone is happy ever after…..

But the story does not ended here. I was thinking while going to home that day, when the auto publishing action was configured and present with default workflow since the edges then why approving the item wasn’t picked by both the CD servers?

So next day, I have kept my investigation going and discover the ScalabilitySettings.config file which was missing on all CD servers. While deploying the missing configurations and file we have deployed this file on all CD serves started picking the events execution for all CDs.

So, happy publishing….!!!!

Reference

https://sitecorebasics.wordpress.com/2011/05/28/is-your-sitecore-publishing-stucks/