cucm 11.5 syslog error DbInfoError

cbrasolin · ‎04-06-2018

Hi, i have a cluster with 2 server (Pub + Sub) version 11.5.1.11900-26.

The Call Manger service on subscriber server crash, it seem that the service is restarted automatically for some numbers of times until it remain stopped, in the syslog message when the Call Manager service is started there are a lot of messages repeated:

pr 6 11:00:16 Servername local7 3 : 0: Servername.Domainname: Apr 06 2018 09:00:16.706 UTC : %UC_CALLMANAGER-3-DbInfoError: %[DeviceName=][AppID=Cisco CallManager][ClusterID=StandAloneCluster][NodeID=Servername]: Configuration information may be out of sync for the device and Unified CM database
Apr 6 11:00:17 Servername local7 3 : 1: Servername.Domainname: Apr 06 2018 09:00:17.19 UTC : %UC_CALLMANAGER-3-DbInfoError: %[DeviceName=][AppID=Cisco CallManager][ClusterID=StandAloneCluster][NodeID=Servername]: Configuration information may be out of sync for the device and Unified CM database
Apr 6 11:02:16 Servername local7 3 : 2: Servername.Domainname: Apr 06 2018 09:02:16.891 UTC : %UC_CALLMANAGER-3-DbInfoError: %[DeviceName=][AppID=Cisco CallManager][ClusterID=StandAloneCluster][NodeID=Servername]: Configuration information may be out of sync for the device and Unified CM database
Apr 6 11:02:17 Servername local7 3 : 3: Servername.Domainname: Apr 06 2018 09:02:17.194 UTC : %UC_CALLMANAGER-3-DbInfoError: %[DeviceName=][AppID=Cisco CallManager][ClusterID=StandAloneCluster][NodeID=Servername]: Configuration information may be out of sync for the device and Unified CM database
Apr 6 11:04:17 Servername local7 3 : 4: Servername.Domainname: Apr 06 2018 09:04:17.56 UTC : %UC_CALLMANAGER-3-DbInfoError: %[DeviceName=][AppID=Cisco CallManager][ClusterID=StandAloneCluster][NodeID=Servername]: Configuration information may be out of sync for the device and Unified CM database
Apr 6 11:04:17 Servername local7 3 : 5: Servername.Domainname: Apr 06 2018 09:04:17.344 UTC : %UC_CALLMANAGER-3-DbInfoError: %[DeviceName=][AppID=Cisco CallManager][ClusterID=StandAloneCluster][NodeID=Servername]: Configuration information may be out of sync for the device and Unified CM database
Apr 6 11:05:26 Servername local7 3 : 2: Servername.Domainname: Apr 06 2018 09:05:26.28 UTC : %UC_DB-3-ErrorChangeNotifyClientTimeout: %[AppID=Cisco Database Layer Monitor][ClusterID=StandAloneCluster][NodeID=Servername]: A change notification client was responding slowly and has been removed.
Apr 6 11:06:17 Servername local7 3 : 6: Servername.Domainname: Apr 06 2018 09:06:17.205 UTC : %UC_CALLMANAGER-3-DbInfoError: %[DeviceName=][AppID=Cisco CallManager][ClusterID=StandAloneCluster][NodeID=Servername]: Configuration information may be out of sync for the device and Unified CM database
Apr 6 11:06:17 Servername local7 3 : 7: Servername.Domainname: Apr 06 2018 09:06:17.646 UTC : %UC_CALLMANAGER-3-DbInfoError: %[DeviceName=][AppID=Cisco CallManager][ClusterID=StandAloneCluster][NodeID=Servername]: Configuration information may be out of sync for the device and Unified CM database
Apr 6 11:07:01 Servername local7 6 : 462: Servername: Apr 06 2018 09:07:01.647 UTC : %UC_GENERIC-6-ServiceStopped: %[ServiceName=Cisco CallManager][AppID=Cisco Service Manager][ClusterID=][NodeID=Servername]: Service stopped.
Apr 6 11:07:01 Servername local7 2 : 463: Servername: Apr 06 2018 09:07:01.652 UTC : %UC_SERVICEMANAGER-2-ServiceFailed: %[ServiceName=Cisco CallManager][Reason=Service stopped abruptly][AppID=Cisco Service Manager][ClusterID=][NodeID=Servername]: Service terminated.
Apr 6 11:07:05 Servername local7 2 : 5: Servername.Domainname: Apr 06 2018 09:07:05.71 UTC : %UC_LPMTCT-2-CoreDumpFileFound: %[TotalCoresFound=1][CoreDetails=The following lists up to 6 cores dumped by corresponding applications.][Core1=Cisco CallManager (core.28636.6.ccm.1523005619)][AppID=Cisco Log Partition Monitoring Tool][ClusterID=][NodeID=Servername]: The new core dump file(s) have been found in the system.
Apr 6 11:07:13 Servername local7 6 : 464: Servername: Apr 06 2018 09:07:13.636 UTC : %UC_GENERIC-6-ServiceStarted: %[ServiceName=Cisco CallManager][ProcessID=5248][AppID=Cisco Service Manager][ClusterID=][NodeID=Servername]: Service started.

Another wierd thing is that in the syslog/messages file, when the Call Manager service is started i see a flood of the messages below:

Apr 6 11:07:40 Servername local1 3 : myFile is NULL for filename /var/log/active/syslog/AlternateSyslog
Apr 6 11:07:40 Servername local1 3 : myFile is NULL for filename /var/log/active/syslog/AlternateSyslog
Apr 6 11:07:40 Servername local1 3 : myFile is NULL for filename /var/log/active/syslog/AlternateSyslog
Apr 6 11:07:40 Servername syslog 6 rsyslogd-2177:imuxsock begins to drop messages from pid 5248 due to rate-limiting
Apr 6 11:07:43 Servername syslog 6 rsyslogd-2177:imuxsock lost 540 messages from pid 5248 due to rate-limiting
Apr 6 11:07:43 Servername local1 3 : myFile is NULL for filename /var/log/active/syslog/AlternateSyslog
Apr 6 11:07:43 Servername local1 3 : myFile is NULL for filename /var/log/active/syslog/AlternateSyslog
Apr 6 11:07:46 Servername local1 3 : myFile is NULL for filename /var/log/active/syslog/AlternateSyslog
Apr 6 11:07:46 Servername local1 3 : myFile is NULL for filename /var/log/active/syslog/AlternateSyslog
Apr 6 11:07:46 Servername local1 3 : myFile is NULL for filename /var/log/active/syslog/AlternateSyslog
Apr 6 11:07:47 Servername local1 3 : myFile is NULL for filename /var/log/active/syslog/AlternateSyslog

DBReplication is Ok with state 2 for both server.

Any idea?

Regards,
Christian

cbrasolin · ‎04-06-2018

I think to have found the problem, on sdl trace i have seen that in the same time a user has invoked the CallBack feature, the Call Manager service is crashed:

00342477.022 |14:08:59.692 |AppInfo |CallBackManager::wait_SsDataInd - ssDataInd.ccmFeatureData.fac[2].operationValue=-1, ssDataInd.ccmFeatureData.fac[2].iapdu=0
00342477.023 |14:08:59.692 |AppInfo |CallBackManager - decodeCcBsRequest APDU
00342477.024 |14:08:59.692 |AppInfo |CALLBACKQSIGASN -
RawByteInput:A2100201 04300B02 01283006 8001FF81 0100
00342477.025 |14:08:59.692 |AppInfo |CALLBACKQSIGASN -
StructuredOutput:value CbbsRequest ::= retResult :
{
    invokeID 4,
    sequence
    {
      operationValue localValue : 40,
      result
      {
        no-path-reservation TRUE,
        retain-service FALSE
      }
    }
}
00342478.000 |14:08:59.692 |SdlSig   |CbBsApdu                               |cbOrigWaitAck                  |CBOrig(4,100,228,1)              |CallBackManager(4,100,229,1)     |4,100,14,84.89^10.100.153.85^SEPxxxxxxxxx |[R:N-H:0,N:0,L:0,V:0,Z:0,D:0] SsParty =69042732 SsOtherParty =69042731 ssDevType =5 ssOtherDevType =5 BasicCallCorrelation = 5 isBroadcasted = F controllingCcpid =(0,0,0) cdpn = cgpn = iapdu =0 isGarbled =F invokeId =0 mCalledPartition =
00342478.001 |14:08:59.692 |AppInfo |CScreenServerCallBack::GetXSIScreen - UserToDeviceData has locale 7 and encoding type 2
00342478.002 |14:08:59.692 |AppInfo |CScreenServerCallBack::GetXSIScreen - Locale 7 UTF-8 Alternate XML dictionary file is not installed!
00342478.003 |14:08:59.692 |AppInfo |CScreenServerCallBack::GetXSIScreen - Locale 7 UTF-8 XML dictionary file is not installed; Use ISO encoding instead

About that logs i have seen that there is a bug CSCvd67269 about that. The problem seem to be fixed in release 11.5(1.13900.52).

I am wondering why the Publisher server is not crashing for the same reason...

Regards