Why Content Manager Service restart automatically

[ricky_ru]

Dears,

I monitored that the Content Manager Service restarts automatically every several days at about midnight. Can you explain what's the possible reason or is it normal. Because if it is stopped, all the request for CM will be failed.
I spotted the the content as below in cogserver.log
10.31.6.102:9300   23170   2013-02-25 01:00:07.453   +8   Termination_SESS   Termination_REQ         main   CM   2652   1   Audit.cms.CM   StopService   ContentManagerService      Success      CM-SYS-5094 Content Manager stopped.; Build=8.4.2652.0
10.31.6.102:9300   23170   2013-02-25 01:00:07.467   +8               stopper-migrationService   MIS   2192   1   Audit.mis.MIS   StopService   MIS      Success   Migration service stopped.   
10.31.6.102:9300   23170   2013-02-25 01:00:07.464   +8               stopper-monitorService   MS   2189   1   Audit.ms.MS   StopService   MonitorService      Success      
10.31.6.102:9300   23170   2013-02-25 01:00:07.494   +8               stopper-deliveryService   DLS   2166   1   Audit.ds.DLS   StopService   DeliveryService      Success      
10.31.6.102:9300   23170   2013-02-25 01:00:07.459   +8   shutdown   na   na   0   main   DISP   2170   1   Audit.Other.dispatcher.DISP.com.cognos.pogo.services.DispatcherServices   StopService   CPS Producer Registration Service      Success      
.................
10.31.6.102:9300   32422   2013-02-25 01:17:42.971   +8   Initialization_SESS   Initialization_REQ         Thread-16   CM   2652   1   Audit.cms.CM   StartService   ContentManagerService      Success      CM-SYS-5090 Content Manager build 8.4.2652.0 started (schema version 5.0001).

[simon.hodgkiss]

Hi Ricky,

any chance that the host server is restarting due to some scheduled event (patching or similar)?

Just noting that the restart time appears to be exactly 01:00, and the restart initialisation doesn't recommence until 17 minutes later.

Server event logs may also give you some idea what's going on at that time.

Regards,

Simon

[ricky_ru]

Dear Simon,

There is the same error log between the stop and start of the CM service. Please check the following. no patch/hot fix.

10.31.6.102:9300   25939   2013-03-18 01:00:07.353   +8   Termination_SESS   Termination_REQ         main   CM   2652   1   Audit.cms.CM   StopService   ContentManagerService      Success      CM-SYS-5094 Content Manager stopped.; Build=8.4.2652.0
10.31.6.102:9300   25939   2013-03-18 01:00:07.360   +8   shutdown   na   na   0   main   DISP   2170   1   Audit.Other.dispatcher.DISP.com.cognos.pogo.services.DispatcherServices   StopService   CPS Producer Registration Service      Success      
10.31.6.102:9300   25939   2013-03-18 01:00:07.381   +8               stopper-deliveryService   DLS   2166   1   Audit.ds.DLS   StopService   DeliveryService      Success      
10.31.6.102:9300   25939   2013-03-18 01:00:07.368   +8               stopper-monitorService   MS   2189   1   Audit.ms.MS   StopService   MonitorService      Success      
10.31.6.102:9300   25939   2013-03-18 01:00:07.373   +8               stopper-migrationService   MIS   2192   1   Audit.mis.MIS   StopService   MIS      Success   Migration service stopped.   
10.31.6.102:9300   25939   2013-03-18 01:00:09.381   +8               stopper-eventManagementService   EMS   2189   1   Audit.ems.EMS   StopService   EventService      Success      
10.31.6.102:9300   25939   2013-03-18 01:00:09.389   +8               Thread-1797   xts   2040   1   Audit.ps.xts   StopService   PresentationService      Success      
10.31.6.102:9300   25939   2013-03-18 01:00:09.411   +8   na   na         stopper-dispatcher   DISP   2170   1   Audit.Other.dispatcher.DISP.pogo   pogo   com.cognos.pogo.handlers.engine.DispatcherStatusHandler      Failure   <messages><message><messageString>DPR-DPR-1035 Dispatcher detected an error.</messageString></message><message><messageString>DPR-DPR-1004 Expecting a BI Bus XML response but got: &#10;&#10;</messageString></message></messages>   Unable to update runningState on CMDPR-DPR-1004 Expecting a BI Bus XML response but got: com.cognos.pogo.bibus.CommandExecutionException: DPR-DPR-1004 Expecting a BI Bus XML response but got:    at com.cognos.pogo.bibus.BIBusCommand.execute(BIBusCommand.java:309)   at com.cognos.pogo.handlers.engine.DispatcherStatusHandler.sendStatusesToCM(DispatcherStatusHandler.java:302)   at com.cognos.pogo.handlers.engine.DispatcherStatusHandler.stop(DispatcherStatusHandler.java:145)   at com.cognos.pogo.services.DefaultHandlerService.stop(DefaultHandlerService.java:189)   at com.cognos.pogo.services.DispatcherServices$ServiceStopper.run(DispatcherServices.java:360)Caused by: com.cognos.pogo.bibus.CommandExecutionException: DPR-DPR-1004 Expecting a BI Bus XML response but got:    at com.cognos.pogo.bibus.BIBusCommand.checkResponseContentType(BIBusCommand.java:353)   at com.cognos.pogo.bibus.BIBusCommand.execute(BIBusCommand.java:261)   ... 4 more
10.31.6.102:9300   25939   2013-03-18 01:00:09.387   +8   shutdown   na   na   0   main   DISP   2170   1   Audit.Other.dispatcher.DISP.com.cognos.pogo.services.DispatcherServices   StopService   SystemService      Success      
10.31.6.102:9300   25939   2013-03-18 01:00:09.383   +8               stopper-jobService   JS   2136   1   Audit.js.JS   StopService   JobService      Success      
10.31.6.102:9300   25939   2013-03-18 01:00:09.422   +8               stopper-logService   LOGSV   2015   1   server.Audit.IPF   StopService   LogService      Success      <parameters><item name="Port"><![CDATA[9362]]></item><item name="Mode"><![CDATA[UDP]]></item><item name="Secure"><![CDATA[FALSE]]></item></parameters>
10.31.6.102:9300   20674   2013-03-18 01:17:20.780   +8               main   LOGSV   2015   1   server.Audit.IPF   StartService   LogService      SUCCESS      <parameters><item name="DB URL"><![CDATA[jdbc:oracle:thin:@miscs.db.paic.com.cn:1543:miscs]]></item><item name="Audit Logging Tables"><![CDATA[COGIPF_ACTION, COGIPF_NATIVEQUERY, COGIPF_PARAMETER, COGIPF_RUNJOB, COGIPF_RUNJOBSTEP, COGIPF_RUNREPORT, COGIPF_USERLOGON, COGIPF_VIEWREPORT, COGIPF_SYSPROPS]]></item></parameters>
10.31.6.102:9300   20674   2013-03-18 01:17:20.802   +8               main   LOGSV   2015   1   server.Audit.IPF   StartService   LogService      Success      <parameters><item name="Port"><![CDATA[9362]]></item><item name="Mode"><![CDATA[UDP]]></item><item name="Secure"><![CDATA[FALSE]]></item></parameters>
10.31.6.102:9300   20674   2013-03-18 01:17:41.284   +8   Initialization_SESS   Initialization_REQ         Thread-16   CM   2652   1   Audit.cms.CM   StartService   ContentManagerService      Success      CM-SYS-5090 Content Manager build 8.4.2652.0 started (schema version 5.0001).
10.31.6.102:9300   20674   2013-03-18 01:17:42.861   +8               Thread-4   LOGSV   2121   1   server.Audit.IPF   Execute   AuditDatabaseConnection   jdbc:oracle:thin:@miscs.db.paic.com.cn:1543:miscs   Success      <parameters><item name="DB Connection"><![CDATA[Established]]></item></parameters>
10.31.6.102:9300   20674   2013-03-18 01:17:42.204   +8   BootstrapConfigurePublish   na      0   Thread-16   DISP   2170   1   Audit.Other.dispatcher.DISP.com.cognos.pogo.contentmanager.coordinator.CMBootstrap   StartService   dispatcherBootstrap      Info      DPR-DPR-1002 Successfully registered the dispatcher http://10.31.6.102:9300/p2pd in Content Manager.
10.31.6.102:9300   20674   2013-03-18 01:17:41.285   +8   Initialization_SESS   Initialization_REQ         Thread-16   CM   2652   1   Audit.cms.CM   StartService   ContentManagerService      Info      CM-SYS-5160 Content Manager is running in standby mode. The active Content Manager URL is http://10.31.6.140:9300/p2pd/servlet.

[simon.hodgkiss]

Hi Ricky,

sorry for any confusion - I did not mean the cogserver.logs, I meant to say check the event viewer logs on the host server (eg. in Windows Server goto Start > Run "eventvwr") and check the application and\or system event logs.  Look to see what activity (if any) occurs around 01:00 on 18th March on the CM server 10.31.6.102 for service and system restarts.

From the 2 extracts (one from Feb and one from March) you have included from your log files, it looks like in both instances the restart occurred on a Monday morning at 01:00, and restarts 17 mins later.  Is it part of a bigger pattern?

Sorry I can't really tell from the extracts here what is causing the restart, but my best guess is some graceful service shutdown brought on by Windows Server Update Services or similar.

Simon