3

Within our environment (doesn't occur in any lower environments) I am seeing the following error every night in the TcmPublisher.xml. I am thinking there is some batch process running every night either on TCM or DB causing some connection issues or maybe the pool connection times out after it keeps trying to connect to the firewall.?

When I look at the service on the server it says its running.. but the only way it can be fixed is to restart publisher..

6/24/2015 1:03:18 PM <10976> Stopping Deployment feedback handler thread.
6/24/2015 1:03:19 PM <10976> Deployment feedback handler thread stopped.
6/24/2015 1:03:19 PM <10976> Stopping worker threads for DeployQueue.
6/24/2015 1:03:19 PM <10976> Stopping Queue message handler for DeployQueue [0].
6/24/2015 1:03:19 PM <10976> Queue message handler for DeployQueue [0] stopped.
6/24/2015 1:03:20 PM <13052> Closing DeployQueue.
6/24/2015 1:03:20 PM <10976> All worker threads for DeployQueue stopped.
6/24/2015 1:03:20 PM <10976> Stopping worker threads for PublishQueue.
6/24/2015 1:03:20 PM <10976> Stopping Queue message handler for PublishQueue [0].
6/24/2015 1:03:20 PM <10976> Queue message handler for PublishQueue [0] stopped.
6/24/2015 1:03:20 PM <10592> Closing PublishQueue.
6/24/2015 1:03:20 PM <10976> All worker threads for PublishQueue stopped.
6/24/2015 1:03:20 PM <10976> Tridion Content Manager Publisher service stopped
6/24/2015 1:03:21 PM <4124> Starting 1 worker threads for PublishQueue.
6/24/2015 1:03:21 PM <4124> Starting 1 worker threads for DeployQueue.
6/24/2015 1:03:21 PM <4124> Starting Deployment feedback handler thread.
6/24/2015 1:03:21 PM <4124> Tridion Content Manager Publisher service started
6/24/2015 1:03:21 PM <12492> Deployment feedback handler thread started.
6/24/2015 1:03:22 PM <3436> Listening for messages on PublishQueue.
6/24/2015 1:03:22 PM <13088> Listening for messages on DeployQueue.
6/25/2015 4:33:30 AM <3436> Error occurred while retrieving message from PublishQueue:
6/25/2015 4:33:30 AM <3436> A database error occurred while executing Stored Procedure "TCM_QUEUE.MESSAGES_READ".
ORA-03113: end-of-file on communication channelProcess ID: 7876Session ID: 764 Serial number: 7939

6/25/2015 10:49:25 AM <15220> Stopping Deployment feedback handler thread.
6/25/2015 10:49:25 AM <15220> Deployment feedback handler thread stopped.
6/25/2015 10:49:25 AM <15220> Stopping worker threads for DeployQueue.
6/25/2015 10:49:25 AM <15220> Stopping Queue message handler for DeployQueue [0].
6/25/2015 10:49:26 AM <15220> Queue message handler for DeployQueue [0] stopped.
6/25/2015 10:49:26 AM <3436> Closing PublishQueue.
6/25/2015 10:49:27 AM <13088> Closing DeployQueue.
6/25/2015 10:49:27 AM <15220> All worker threads for DeployQueue stopped.
6/25/2015 10:49:27 AM <15220> Stopping worker threads for PublishQueue.
6/25/2015 10:49:27 AM <15220> Stopping Queue message handler for PublishQueue [0].
6/25/2015 10:49:27 AM <15220> Queue message handler for PublishQueue [0] stopped.
6/25/2015 10:49:27 AM <15220> All worker threads for PublishQueue stopped.
6/25/2015 10:49:27 AM <15220> Tridion Content Manager Publisher service stopped
6/25/2015 10:49:28 AM <13432> Starting 1 worker threads for PublishQueue.
6/25/2015 10:49:28 AM <13432> Starting 1 worker threads for DeployQueue.
6/25/2015 10:49:28 AM <13432> Starting Deployment feedback handler thread.
6/25/2015 10:49:28 AM <14364> Deployment feedback handler thread started.
6/25/2015 10:49:28 AM <13432> Tridion Content Manager Publisher service started
6/25/2015 10:49:30 AM <14700> Listening for messages on PublishQueue.
6/25/2015 10:49:30 AM <13816> Listening for messages on DeployQueue.

Has anyone more experienced in Tridion services seen any kind of activity like this in the past and possibly from a high level just understand exactly what could possibly be the causing this to stop?

  • 2
    Is it always around the same time? Does the organisation batch publish anything overnight? - if so, is there any correlation? As Saurabh says - are there any scheduled tasks that can be affecting this? I'd get the sys admin to stick monitoring on the box and see if there's any processes kicking of 5 minutes before, perhaps is just when the RAM used hits a threshold - it's a tricky one really given it could well be environmental (in which case the CMS usually becomes the scape-goat ;) ) – Dylan .. Mark Saunders Jun 25 '15 at 17:07
4

This isn't about the publisher but about the database. Your log clearly shows the Oracle error.

ORA-03113: end-of-file on communication channelProcess

Whenever you see an ORA- error in your logs, you should Google it. In this case, it seems to be a catch-all error that could mean lots of things.

If it's occurring at a specific time, then perhaps there's a scheduled activity that affects the database. An incorrectly configured backup, perhaps. In any case, you can look in the ORACLE logs to see if there's any more information to be found that correlates with the timestamp in the log you already have.

Of course, the root cause might be something else such as a network problem, which then triggers the error condition in ORACLE, which in turn breaks your publisher.

In any case, you should report this to SDL customer support, because if restarting the publisher is enough to fix it, perhaps the exception handling can be improved so that the publisher itself can recover without a restart.

  • 1
    10-4 @DominicCronin I will keep that in mind about the ORA error. I am in the process of investigating any correlations based upon time-frames that both you and Saurabh Gangwar mentioned with the DB and server teams. A ticket is also open with SDL support. I will report back my findings to this thread for future references. – Andrew William Ross Jun 25 '15 at 20:30
  • 1
    IIRC, this is an issue with the Oracle Client, as SQL Server-based publishers will recover. I can't remember if we patched this for Oracle or not, but most definitely it is something we've covered for the next release. As @DominicCronin says, ping customer support, they will know if there was a fix done. – Nuno Linhares Jun 25 '15 at 22:32
  • 1
    And meanwhile, if it really does happen every night at the exact same time... maybe a small script to restart the publisher a few minutes after that time could come in handy? – Nuno Linhares Jun 25 '15 at 22:33
  • @NunoLinhares great idea! – Andrew William Ross Jun 26 '15 at 13:40
2

As you mentioned, looks like there is some kind of scheduled automated maintenance batch process is in place. Which stops the publishing process.

So I would suggest first check if there is any Scheduled Automated Script, and if it there how it's stopping/starting the services. Looks like, while stopping/re-starting the publishing process the script is not doing it in a proper way.

One such case I can guess of is a "Clean Up Script" of temporary items during publishing process:

As, we have a lots of intermediate files(stored in temp/Incoming folders) during publishing process and in some cases when anything goes wrong during the process the files remains there forever.

So to clean up those files by a automated script, the publishing process needs to be stopped first and a then re-start after clean up of files.

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

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