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).
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
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: </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.
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