[cisco-voip] MRA and Phone server selection

Thu Nov 19 09:02:18 EST 2015

Hi Ryan,

There UCS servers were actually powered down last weekend due to power issues in the DC so the whole cluster has been power cycled. This issue has been ongoing prior to the shutdown but only coming to light as they are rolling Jabber out to mobile devices.

It seems odd that the jabber client would be told to register with one of the none CCM servers I don't think this would come from the expressway.

Just been looking through the ipad log files and it looks like the jabber client uses the CCMCIP server to register the phone service to. In the first instance the CCMCIP servers are referencing the publisher, One of the TFTP server and one of the Media Servers.

In the below snippets the 5th character in the server name define their role.

P = Publisher
M =  Media Subscriber
S = CCM subscriber
T = TFTP Subscriber

The Below snippit is from the log file when the phone services don't register

type=eSIP, isRelevant=true, server=cucms01.Company.co.uk:5060, connectionState=eNone, isEncrypted=false, serverType=ePrimary, role=eNone
type=eSIP, isRelevant=true, server=cucms02.Company.co.uk:5060, connectionState=eNone, isEncrypted=false, serverType=eSecondary, role=eNone
type=eUDS, isRelevant=true, vcse=expresswaye01.Company.co.uk:8443, server=cucmp01.Company.co.uk:8443, connectionState=eConnected, isEncrypted=true
type=eUDS, isRelevant=true, server=cucmm01.Company.co.uk:8443, connectionState=eNotApplicable, isEncrypted=false
type=eUDS, isRelevant=true, server=cucmt01.Company.co.uk:8443, connectionState=eNotApplicable, isEncrypted=false
type=eCCMCIP, isRelevant=true, server=cucmp01.Company.co.uk:8443, connectionState=eNotApplicable, isEncrypted=false
type=eCCMCIP, isRelevant=true, server=cucmm01.Company.co.uk:8443, connectionState=eNotApplicable, isEncrypted=false
type=eCCMCIP, isRelevant=true, server=cucmt01.Company.co.uk:8443, connectionState=eNotApplicable, isEncrypted=false
type=eEMAPI, isRelevant=true, server=cucmp01.Company.co.uk:8443, connectionState=eNotApplicable, isEncrypted=false
type=eEMAPI, isRelevant=true, server=cucmp01.Company.co.uk:8080, connectionState=eNotApplicable, isEncrypted=false
type=eEMAPI, isRelevant=true, server=cucmm01.Company.nhs.uk:8443, connectionState=eNotApplicable, isEncrypted=false
type=eEMAPI, isRelevant=true, server=cucmm01.Company.co.uk:8080, connectionState=eNotApplicable, isEncrypted=false
type=eEMAPI, isRelevant=true, server=cucmt01.Company.co.uk:8443, connectionState=eNotApplicable, isEncrypted=false
type=eEMAPI, isRelevant=true, server=cucmt01.Company.co.uk:8080, connectionState=eNotApplicable, isEncrypted=false
type=eConfigFile, isRelevant=true, vcse=expresswaye01.Company.co.uk:8443, server=cucmt01.Company.co.uk:6970, connectionState=eConnected, isEncrypted=true
type=eConfigFile, isRelevant=true, server=cucmt01.Company.co.uk:69, connectionState=eNotApplicable, isEncrypted=false
type=eConfigFile, isRelevant=true, server=cucmt02.Company.co.uk:6970, connectionState=eNotApplicable, isEncrypted=false
type=eConfigFile, isRelevant=true, server=cucmt02.Company.co.uk:69, connectionState=eNotApplicable, isEncrypted=false

14:02:25,198 INFO  [l/src/callcontrol/Authenticator.cpp(602)] [csf.ecc] [getLastCCMCIPServerUsed] - getLastCCMCIPServerUsed() = cucmp01.Company.co.uk
14:02:25,198 INFO  [/call/YLCTelephonyAuthentication.mm(308)] [UI.Telephony] [-[YLCTelephonyAuthentication onAuthenticationStatusChanged:]] - JCF Telephony service authentication status InProgress.
14:02:25,199 INFO  [fecycle/YLCAccountStatusPresenter.m(203)] [UI.Lifecycle.Login] [-[YLCAccountStatusPresenter cucmConnectionStatusChanged:]] - -[YLCAccountStatusPresenter cucmConnectionStatusChanged:] -- before changed, the cucm status is 2
14:02:25,200 INFO  [/impl/system/UserProfileManager.cpp(131)] [UserProfileManager] [getCredentialsForAuthenticator] -  for authenticator: 2100
14:02:25,200 INFO  [/impl/system/UserProfileManager.cpp(131)] [UserProfileManager] [getCredentialsForAuthenticator] -  for authenticator: 2100
14:02:25,205 INFO  [0x000000016ed37000] [/tahiti/module/util/YLCMemoryInfo.mm(74)] [UI.Util] [-[YLCMemoryInfo logMemUsage:]] - (MEMORY MONITOR IN FUNCTION)-->: -[YLCTelephonyAuthentication onAuthenticationStatusChanged:] |current memory usage is 80.3 MB
14:02:25,230 INFO  [fecycle/YLCAccountStatusPresenter.m(205)] [UI.Lifecycle.Login] [-[YLCAccountStatusPresenter cucmConnectionStatusChanged:]] - -[YLCAccountStatusPresenter cucmConnectionStatusChanged:] -- After changed, the cucm status is 2
14:02:25,230 INFO  [fecycle/YLCAccountStatusPresenter.m(210)] [UI.Lifecycle.Login] [-[YLCAccountStatusPresenter cucmConnectionStatusChanged:]] - [trace login time]  -[YLCAccountStatusPresenter cucmConnectionStatusChanged:], cucm status is ACCOUNT_RECONNECTING
14:02:25,235 INFO  [services/impl/ConfigServiceImpl.cpp(185)] [ConfigService-ConfigServiceImpl] [findConfig] - findConfig key : [CcmcipServer1] is an alias for key : [DeviceAuthenticationPrimaryServer] actual lookup done on this key - value : [cucmp01.Company.co.uk]
14:02:25,235 INFO  [services/impl/ConfigServiceImpl.cpp(185)] [ConfigService-ConfigServiceImpl] [findConfig] - findConfig key : [CcmcipServer2] is an alias for key : [DeviceAuthenticationBackupServer] actual lookup done on this key - value : [cucmm01.Company.co.uk]
14:02:25,249 INFO  [0x000000017026b000] [lcontrol/CallControlManagerImpl.cpp(500)] [csf.ecc.api] [setCCMCIPServers] - setCCMCIPServers(cucmp01.Company.co.uk, cucmm01.Company.co.uk, cucmt01.Company.co.uk)
14:02:25,249 INFO  [0x000000017026b000] [l/src/callcontrol/Authenticator.cpp(124)] [csf.ecc] [setCCMCIPServers] - setCCMCIPServers(cucmp01.Company.co.uk, cucmm01.Company.co.uk, cucmt01.Company.co.uk)
14:02:25,249 INFO  [0x000000017026b000] [lcontrol/CallControlManagerImpl.cpp(567)] [csf.ecc.api] [setExtensionMobilityServers] - setExtensionMobilityServers(cucmp01.Company.co.uk, cucmm01.Company.co.uk, cucmt01.Company.co.uk)
14:02:25,249 INFO  [0x000000017026b000] [ontrol/src/callcontrol/EmHelper.cpp(266)] [csf.ecc] [setExtensionMobilityServers] - setExtensionMobilityServers(cucmp01.Company.co.uk, cucmm01.Company.co.uk, cucmt01.Company.co.uk)
14:02:25,274 INFO  [services/impl/ConfigServiceImpl.cpp(185)] [ConfigService-ConfigServiceImpl] [findConfig] - findConfig key : [TftpServer1] is an alias for key : [TFTPPrimaryServer] actual lookup done on this key - value : [cucmt01.Company.co.uk]
14:02:25,274 INFO  [services/impl/ConfigServiceImpl.cpp(185)] [ConfigService-ConfigServiceImpl] [findConfig] - findConfig key : [TftpServer2] is an alias for key : [TFTPBackupServer1] actual lookup done on this key - value : [cucmt02.Company.co.uk]
14:02:25,275 INFO  [services/impl/ConfigServiceImpl.cpp(185)] [ConfigService-ConfigServiceImpl] [findConfig] - findConfig key : [TftpServer3] is an alias for key : [TFTPBackupServer2] actual lookup done on this key - value : []
14:02:25,292 INFO  [0x000000017026b000] [lcontrol/CallControlManagerImpl.cpp(527)] [csf.ecc.api] [setTFTPServers] - setTFTPServers(cucmt01.Company.co.uk, cucmt02.Company.co.uk)
14:02:25,294 INFO  [services/impl/ConfigServiceImpl.cpp(185)] [ConfigService-ConfigServiceImpl] [findConfig] - findConfig key : [CtiServer1] is an alias for key : [CTIPrimaryServer] actual lookup done on this key - value : [cucms01.Company.co.uk]
14:02:25,294 INFO  [services/impl/ConfigServiceImpl.cpp(185)] [ConfigService-ConfigServiceImpl] [findConfig] - findConfig key : [CtiServer2] is an alias for key : [CTIBackupServer] actual lookup done on this key - value : [cucms02.Company.co.uk]
14:02:25,294 INFO  [0x000000017026b000] [lcontrol/CallControlManagerImpl.cpp(585)] [csf.ecc.api] [setCTIServers] - setCTIServers(cucms01.Company.co.uk, cucms02.Company.co.uk)
14:02:25,294 INFO  [0x000000017026b000] [control/CallControlManagerImpl.cpp(4379)] [csf.ecc.api] [setPreferredRegistrationMode] - setPreferredRegistrationMode (Default) to (Default)

The Below snippet is from the log file when the phone services do register there is a CCM subscriber registered and the client connects to the phone services.

type=eSIP, isRelevant=true, server=cucms01.company.co.uk:5060, connectionState=eNone, isEncrypted=false, serverType=ePrimary, role=eActive
type=eSIP, isRelevant=true, server=cucms02.company.co.uk:5060, connectionState=eNone, isEncrypted=false, serverType=eSecondary, role=eNone
type=eUDS, isRelevant=true, vcse=expresswaye01.company.co.uk:8443, server=cucms02.company.co.uk:8443, connectionState=eConnected, isEncrypted=true
type=eUDS, isRelevant=true, server=cucmp01.company.co.uk:8443, connectionState=eNotApplicable, isEncrypted=false
type=eUDS, isRelevant=true, server=cucmm01.company.co.uk:8443, connectionState=eNotApplicable, isEncrypted=false
type=eCCMCIP, isRelevant=true, server=cucms02.company.co.uk:8443, connectionState=eNotApplicable, isEncrypted=false
type=eCCMCIP, isRelevant=true, server=cucmp01.company.co.uk:8443, connectionState=eNotApplicable, isEncrypted=false
type=eCCMCIP, isRelevant=true, server=cucmm01.company.co.uk:8443, connectionState=eNotApplicable, isEncrypted=false
type=eEMAPI, isRelevant=true, server=cucms02.company.co.uk:8443, connectionState=eNotApplicable, isEncrypted=false
type=eEMAPI, isRelevant=true, server=cucms02.company.co.uk:8080, connectionState=eNotApplicable, isEncrypted=false
type=eEMAPI, isRelevant=true, server=cucmp01.company.co.uk:8443, connectionState=eNotApplicable, isEncrypted=false
type=eEMAPI, isRelevant=true, server=cucmp01.company.co.uk:8080, connectionState=eNotApplicable, isEncrypted=false
type=eEMAPI, isRelevant=true, server=cucmm01.company.co.uk:8443, connectionState=eNotApplicable, isEncrypted=false
type=eEMAPI, isRelevant=true, server=cucmm01.company.co.uk:8080, connectionState=eNotApplicable, isEncrypted=false
type=eConfigFile, isRelevant=true, vcse=expresswaye01.company.co.uk:8443, server=cucmt01.company.co.uk:6970, connectionState=eConnected, isEncrypted=true
type=eConfigFile, isRelevant=true, server=cucmt01.company.co.uk:69, connectionState=eNotApplicable, isEncrypted=false
type=eConfigFile, isRelevant=true, server=cucmt02.company.co.uk:6970, connectionState=eNotApplicable, isEncrypted=false
type=eConfigFile, isRelevant=true, server=cucmt02.company.co.uk:69, connectionState=eNotApplicable, isEncrypted=false

13:13:56,413 INFO  [control/CallControlManagerImpl.cpp(4379)] [csf.ecc.api] [setPreferredRegistrationMode] - setPreferredRegistrationMode (Default) to (Default)
13:13:56,414 INFO  [control/CallControlManagerImpl.cpp(4967)] [csf.ecc.api] [setCertificateExternalVerificationPolicy] - setCertificateExternalVerificationPolicy(policy=eDefaultPolicy)
13:13:56,415 INFO  [control/CallControlManagerImpl.cpp(2903)] [csf.ecc.api] [getAudioControl] - getAudioControl()
13:13:56,415 INFO  [control/CallControlManagerImpl.cpp(2896)] [csf.ecc.api] [getVideoControl] - getVideoControl()
13:13:56,415 INFO  [src/media/CSFVideoControlWrapper.cpp(11)] [csf.ecc.api] [setRenderSinkFactory] - setRenderSinkFactory(0x0x14780d880)
13:13:56,417 INFO  [lephonyservice/TelephonyAdapter.cpp(735)] [jcf.tel.adapter] [startTelephonyMediaDeviceFeatureSet] - -->
13:13:56,418 INFO  [control/CallControlManagerImpl.cpp(3554)] [csf.ecc] [setPcmPlayer] - setPcmPlayer(0x145e1b440)
13:13:56,419 INFO  [0x00000001707bb000] [l/src/common/thread/WorkerThread.cpp(94)] [csf.ecc] [run] - Started thread: PcmPlayerToneOutput::worker
13:13:56,419 INFO  [lephonyservice/TelephonyAdapter.cpp(756)] [jcf.tel.adapter] [startTelephonyMediaDeviceFeatureSet] - <--
13:13:56,420 INFO  [lephonyservice/TelephonyAdapter.cpp(769)] [jcf.tel.adapter] [startTelephonyServerHealthFeatureSet] - -->
13:13:56,420 INFO  [lephonyservice/TelephonyAdapter.cpp(774)] [jcf.tel.adapter] [startTelephonyServerHealthFeatureSet] - <--
13:13:56,420 INFO  [/impl/system/UserProfileManager.cpp(131)] [UserProfileManager] [getCredentialsForAuthenticator] -  for authenticator: 2100
13:13:56,420 INFO  [/impl/system/UserProfileManager.cpp(131)] [UserProfileManager] [getCredentialsForAuthenticator] -  for authenticator: 1800
13:13:56,420 INFO  [services/impl/ConfigServiceImpl.cpp(185)] [ConfigService-ConfigServiceImpl] [findConfig] - findConfig key : [TftpServer1] is an alias for key : [TFTPPrimaryServer] actual lookup done on this key - value : [cucmt01.company.co.uk]
13:13:56,421 INFO  [services/impl/ConfigServiceImpl.cpp(185)] [ConfigService-ConfigServiceImpl] [findConfig] - findConfig key : [TftpServer2] is an alias for key : [TFTPBackupServer1] actual lookup done on this key - value : [cucmt02.company.co.uk]
13:13:56,421 INFO  [services/impl/ConfigServiceImpl.cpp(185)] [ConfigService-ConfigServiceImpl] [findConfig] - findConfig key : [TftpServer3] is an alias for key : [TFTPBackupServer2] actual lookup done on this key - value : [cucmt01.company.co.uk]
13:13:56,421 INFO  [services/impl/ConfigServiceImpl.cpp(185)] [ConfigService-ConfigServiceImpl] [findConfig] - findConfig key : [CcmcipServer1] is an alias for key : [DeviceAuthenticationPrimaryServer] actual lookup done on this key - value : [cucms02.company.co.uk]
13:13:56,421 INFO  [services/impl/ConfigServiceImpl.cpp(185)] [ConfigService-ConfigServiceImpl] [findConfig] - findConfig key : [CcmcipServer2] is an alias for key : [DeviceAuthenticationBackupServer] actual lookup done on this key - value : [cucmp01.company.co.uk]
13:13:56,421 INFO  [services/impl/ConfigServiceImpl.cpp(185)] [ConfigService-ConfigServiceImpl] [findConfig] - findConfig key : [CtiServer1] is an alias for key : [CTIPrimaryServer] actual lookup done on this key - value : [cucms01.company.co.uk]
13:13:56,421 INFO  [services/impl/ConfigServiceImpl.cpp(185)] [ConfigService-ConfigServiceImpl] [findConfig] - findConfig key : [CtiServer2] is an alias for key : [CTIBackupServer] actual lookup done on this key - value : [cucms02.company.co.uk]
13:13:56,424 INFO  [control/CallControlManagerImpl.cpp(2692)] [csf.ecc.api] [getConnectionStatus] - getConnectionStatus() = eIdle
13:13:56,424 INFO  [services/impl/ConfigServiceImpl.cpp(185)] [ConfigService-ConfigServiceImpl] [findConfig] - findConfig key : [CcmcipServer1] is an alias for key : [DeviceAuthenticationPrimaryServer] actual lookup done on this key - value : [cucms02.company.co.uk]
13:13:56,424 INFO  [services/impl/ConfigServiceImpl.cpp(185)] [ConfigService-ConfigServiceImpl] [findConfig] - findConfig key : [CcmcipServer2] is an alias for key : [DeviceAuthenticationBackupServer] actual lookup done on this key - value : [cucmp01.company.co.uk]
13:13:56,424 INFO  [lcontrol/CallControlManagerImpl.cpp(500)] [csf.ecc.api] [setCCMCIPServers] - setCCMCIPServers(cucms02.company.co.uk, cucmp01.company.co.uk, cucmm01.company.co.uk)
13:13:56,424 INFO  [l/src/callcontrol/Authenticator.cpp(124)] [csf.ecc] [setCCMCIPServers] - setCCMCIPServers(cucms02.company.co.uk, cucmp01.company.co.uk, cucmm01.company.co.uk)
13:13:56,424 INFO  [lcontrol/CallControlManagerImpl.cpp(567)] [csf.ecc.api] [setExtensionMobilityServers] - setExtensionMobilityServers(cucms02.company.co.uk, cucmp01.company.co.uk, cucmm01.company.co.uk)
13:13:56,424 INFO  [ontrol/src/callcontrol/EmHelper.cpp(266)] [csf.ecc] [setExtensionMobilityServers] - setExtensionMobilityServers(cucms02.company.co.uk, cucmp01.company.co.uk, cucmm01.company.co.uk)
13:13:56,424 INFO  [services/impl/ConfigServiceImpl.cpp(185)] [ConfigService-ConfigServiceImpl] [findConfig] - findConfig key : [TftpServer1] is an alias for key : [TFTPPrimaryServer] actual lookup done on this key - value : [cucmt01.company.co.uk]
13:13:56,424 INFO  [services/impl/ConfigServiceImpl.cpp(185)] [ConfigService-ConfigServiceImpl] [findConfig] - findConfig key : [TftpServer2] is an alias for key : [TFTPBackupServer1] actual lookup done on this key - value : [cucmt02.company.co.uk]
13:13:56,424 INFO  [services/impl/ConfigServiceImpl.cpp(185)] [ConfigService-ConfigServiceImpl] [findConfig] - findConfig key : [TftpServer3] is an alias for key : [TFTPBackupServer2] actual lookup done on this key - value : [cucmt01.company.co.uk]
13:13:56,425 INFO  [lcontrol/CallControlManagerImpl.cpp(527)] [csf.ecc.api] [setTFTPServers] - setTFTPServers(cucmt01.company.co.uk, cucmt02.company.co.uk, cucmt01.company.co.uk)
13:13:56,425 INFO  [services/impl/ConfigServiceImpl.cpp(185)] [ConfigService-ConfigServiceImpl] [findConfig] - findConfig key : [CtiServer1] is an alias for key : [CTIPrimaryServer] actual lookup done on this key - value : [cucms01.company.co.uk]
13:13:56,425 INFO  [services/impl/ConfigServiceImpl.cpp(185)] [ConfigService-ConfigServiceImpl] [findConfig] - findConfig key : [CtiServer2] is an alias for key : [CTIBackupServer] actual lookup done on this key - value : [cucms02.company.co.uk]
13:13:56,425 INFO  [lcontrol/CallControlManagerImpl.cpp(585)] [csf.ecc.api] [setCTIServers] - setCTIServers(cucms01.company.co.uk, cucms02.company.co.uk)
13:13:56,425 INFO  [control/CallControlManagerImpl.cpp(4379)] [csf.ecc.api] [setPreferredRegistrationMode] - setPreferredRegistrationMode (Default) to (Default)

Regards

Matthew Collins
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://puck.nether.net/pipermail/cisco-voip/attachments/20151119/21c3c4fd/attachment.html>