Planet Collab

❌ About FreshRSS
There are new available articles, click to refresh the page.
Before yesterdayVOICE ON BITS

Scenario#50 – Cisco MRA: Jabber cannot connect Softphone mode over Expressway

By asharsidd
Photo by Pixabay on

Due to COVID-19 and the global pandemic situation more and more people are working from home and are coming across different challenges.

Many of them who use to work from a corporate location are coming across issues that they never faced before.

I worked on such a case recently where a user was having a problem connecting his Jabber over MRA (Mobile Remote Access) and getting softphone mode working. If he connects to corporate VPN and then fires up Jabber it connects fine and he can make and receive calls. The problem was that he was supposed to join an external training which was not accessible on his corporate VPN network and he also wanted to use Jabber for calls.

I started investigating and initially I thought if there is anything wrong with the Expressways? I did a quick health check and found no issues at Expressways. I also did an SRV check using Cisco Collaboration solutions Analyzer and that came out clean with all relevant ports open. From his PC I did an SRV check for Collab-Edge to see if it is resolving to correct Expressway cluster and that displayed correct result. You can do this quick test using the following command from a user’s PC command prompt:

nslookup -type=srv

When you start Cisco Jabber it goes through a sequence of discovering as to how your jabber is connected and where it should go to fetch all services. For Jabber which is inside a corporate network it looks for cisco-uds while outside a network it is looking for collab-edge. Hopefully I will discuss this in a separate post as how Jabber connects and the routine it follows.

Softphone - Not working
Status: Not connected
Protocol: SIP
Address: (CCMCIP - Expressway) (Unknown)
Cause: connection error. Make sure that the server information on the Phone Services tab in the Options window is correct. If you need help, contact the system administrator.

Desk phone - None
Status: Not connected
Protocol: CTI
Address: (CTI) (Unknown)

Video for desk phones - information
Status: Not available
Cause: Video for desk phones is not available in softphone mode.

Voicemail - None
Status: Not connected. Awaiting repetition.
Address: (IPV4)
Port: 443
Protocol: VMREST (HTTPS)

Presence - working
Status: Connected
Protocol: XMPP
Address: (IPV4)    <<< Expressway-E
Port: 5222

Conferences - working
Status: Last connection attempt successful.
Protocol: HTTPS
Address: (IPV4)

Outlook address book - working
Status: Last connection attempt successful.
Protocol: MAPI
Address: Outlook (Unknown)

Directory - working
Status: Last connection attempt successful.
Address:  (IPV4)
Protocol: UDS (HTTPS)

As you can see CCMCIP-Expressway was showing as unknown. I collected the PRT report and this is what I found after the discovering stage:

Note: All IP addresses and hostnames have been changed to dummy values:

## Jabber discovers the Expressway-E :

2020-05-06 16:29:30,457 DEBUG [0x000033e0] [ore\sipstack\sip_common_transport.c(717)] [csf.sip-call-control] [sip_get_local_ip_addr] – SIPCC-SIP_TRANS: sip_get_local_ip_addr: src_addr:
2020-05-06 16:29:30,457 INFO [0x000033e0] [mmon\network\SoftPhoneDnsHelper.cpp(129)] [csf.ecc] [csf::ecc::SoftPhoneDnsHelperImpl::queryDns] –, family=AF_INET, useDNSCache=true
2020-05-06 16:29:30,457 INFO [0x000033e0] [mmon\network\SoftPhoneDnsHelper.cpp(246)] [csf.ecc] [csf::ecc::SoftPhoneDnsHelperImpl::doNetworkLookup] –, family=AF_INET
2020-05-06 16:29:30,457 DEBUG [0x000033e0] [n\network\SocketHelperFunctions.cpp(294)] [] [getIpAddressByHostname] – Attempting to resolve “” for protocol AF_INET
2020-05-06 16:29:30,458 INFO [0x000036dc] [n\network\SocketHelperFunctions.cpp(181)] [] [getIpAddressExcuteThread] – start excute thread

## Jabber discovers the Expressway-E IP address

2020-05-06 16:29:30,458 DEBUG [0x000036dc] [n\network\SocketHelperFunctions.cpp(246)] [] [getIpAddressExcuteThread] – resolved to IP address:193.1.x.10, retCode:0
2020-05-06 16:29:30,458 DEBUG [0x000036dc] [n\network\SocketHelperFunctions.cpp(258)] [] [getIpAddressExcuteThread] – end excute thread, ctrl:17BE6CEC
2020-05-06 16:29:30,458 DEBUG [0x000033e0] [n\network\SocketHelperFunctions.cpp(320)] [] [getIpAddressByHostname] – IP Address:193.1.x.10, error code: 0
2020-05-06 16:29:30,458 INFO [0x000033e0] [mmon\network\SoftPhoneDnsHelper.cpp(235)] [csf.ecc] [csf::ecc::SoftPhoneDnsHelperImpl::queryDns] –, family=AF_INET – SUCCESS: lookup succeeded, v4(193.1.x.10) v6()2020-05-06 16:29:30,458 DEBUG [0x000033e0] [onewrapper\ccapi_plat_api_impl.cpp(2029)] [csf.ecc.sipcc] [SIPCCPlatBinding::platGetLocalIPAddr] – ipMode=IPv6Preferred, dst_addr->type=IPv4
2020-05-06 16:29:30,458 DEBUG [0x000033e0] [onewrapper\ccapi_plat_api_impl.cpp(2104)] [csf.ecc.sipcc] [SIPCCPlatBinding::platGetLocalIPAddr] – SIPCC will use local IPv4 address: for destination: 193.1.x.10
2020-05-06 16:29:30,458 INFO [0x000033e0] [re\sipstack\sip_common_transport.c(1133)] [csf.sip-call-control] [sip_transport_init_ti_addr] – SIPCC-SIP_TRANS: sip_transport_init_ti_addr: Entered transport: 3 Sec Level: 2 IP type: 1
2020-05-06 16:29:30,458 DEBUG [0x000033e0] [re\sipstack\sip_common_transport.c(1679)] [csf.sip-call-control] [sip_transport_setup_cc_conn] – SIPCC-SIP_CC_CONN: sip_transport_setup_cc_conn: ccm id:1, status:-1, other_status:-1, type:1, other_type:0
2020-05-06 16:29:30,458 DEBUG [0x000033e0] [onewrapper\ccapi_plat_api_impl.cpp(1078)] [csf.ecc.sipcc] [SIPCCPlatBinding::platSecIsServerSecure] – secIsServerSecure() indicated server is secure because we are in edge mode.
2020-05-06 16:29:30,458 DEBUG [0x000033e0] [\core\sipstack\ccsip_platform_tls.c(122)] [csf.sip-call-control] [sip_tls_create_connection] – SIPCC-SIP_TLS: sip_tls_create_connection: Creating secure connection
2020-05-06 16:29:30,458 DEBUG [0x000033e0] [onewrapper\ccapi_plat_api_impl.cpp(1332)] [csf.ecc.sipcc] [SIPCCPlatBinding::platSecSocConnect] – platSecSocConnect():, pIPAddrString=193.1.x.10:5061, blocking=false, plat_soc_connection_mode=1, plat_secure_connection_type=1
2020-05-06 16:29:30,458 DEBUG [0x000033e0] [roject\secCommon\src\sec_ssl_api.c(2501)] [csf.ecc.handyiron] [performSingleConnect] – Invoking non-blocking connect(). Will allow up to 3 seconds for this connect to succeed.
2020-05-06 16:29:30,458 DEBUG [0x000033e0] [honewrapper\ccapi_plat_api_impl.cpp(352)] [csf.ecc.sipcc] [SIPCCPlatBinding::isShuttingDown] – –>
2020-05-06 16:29:30,459 DEBUG [0x000033e0] [roject\secCommon\src\sec_ssl_api.c(2514)] [csf.ecc.handyiron] [performSingleConnect] – connect return.
2020-05-06 16:29:30,997 DEBUG [0x00001708] [ls\src\http\MultiHttpClientImpl.cpp(813)] [csf.httpclient] [csf::http::MultiHttpClientImpl::RequestProcessing::run] – [0x1795be78] waiting for new requests
2020-05-06 16:29:31,737 DEBUG [0x000010ec] [ch\TriDroppedConnectionDetector.cpp(120)] [csf.jwcpp] [gloox::CTriDroppedConnectionDetector::onKeepaliveTimer] – @XmppSDK: #0, onKeepaliveTimer, timer
2020-05-06 16:29:32,396 DEBUG [0x00002f0c] [etutils\src\http\CurlHttpUtils.cpp(1834)] [csf.httpclient] [csf::http::CurlHttpUtils::logOperationTiming] – Request #135 network IO timestamps: [name lookup = 0.031 ; connect = 0 ; ssl connect = 0 ; pre-transfer = 0 ; start-transfer = 0 ; total = 10 ; redirect = 0]

##Connection timing out

2020-05-06 16:29:32,396 INFO [0x00002f0c] [ls\src\http\CurlAnswerEvaluator.cpp(122)] [csf.httpclient] [csf::http::CurlAnswerEvaluator::curlCodeToResult] – Request #135 got curlCode=[28] curl error message=[Connection timed out after 10000 milliseconds] ttpClientResult=CONNECTION_TIMEOUT_ERROR] fips enabled=[false]

##Trying second Expressway-E: but getting same CONNECTION FAILED Error

2020-05-06 16:29:32,396 INFO [0x00002f0c] [ls\src\http\BasicHttpClientImpl.cpp(562)] [csf.httpclient] [csf::http::executeImpl] – *—–* HTTP response code 0 for request #135 to
2020-05-06 16:29:32,396 ERROR [0x00002f0c] [ls\src\http\BasicHttpClientImpl.cpp(567)] [csf.httpclient] [csf::http::executeImpl] – There was an issue performing the call to curl_easy_perform for request #135: CONNECTION_TIMEOUT_ERROR
2020-05-06 16:29:32,396 DEBUG [0x00002f0c] [etutils\src\http\HttpRequestData.cpp(91)] [csf.httpclient] [csf::http::HttpRequestData::returnEasyCURLConnection] – Request #135 returning borrowed EasyCURLConnection
2020-05-06 16:29:32,396 DEBUG [0x00002f0c] [\src\edge\EdgeConfigRequestImpl.cpp(207)] [csf.edge] [csf::edge::EdgeConfigRequestImpl::execute] – *—–* Get Edge Config HTTP Result: CONNECTION_FAILED, HTTP Response Code: 0
2020-05-06 16:29:32,396 ERROR [0x00002f0c] [\src\edge\EdgeConfigRequestImpl.cpp(211)] [csf.edge] [csf::edge::EdgeConfigRequestImpl::execute] – Edge Config Request failed, httpResult: CONNECTION_FAILED
2020-05-06 16:29:32,396 INFO [0x00002f0c] [s\src\edge\GlobalEdgeStateImpl.cpp(1391)] [csf.edge] [csf::edge::GlobalEdgeStateImpl::executeEdgeConfigRequest] – server failed, but is the last server on the list, so will not be added to the failed list
2020-05-06 16:29:32,396 WARN [0x00002f0c] [s\src\edge\GlobalEdgeStateImpl.cpp(1437)] [csf.edge] [csf::edge::GlobalEdgeStateImpl::executeEdgeConfigRequest] – Warning, request failed with error: [INTERNAL_ERROR]. Attempting to failover.
2020-05-06 16:29:32,396 WARN [0x00002f0c] [s\src\edge\GlobalEdgeStateImpl.cpp(1462)] [csf.edge] [csf::edge::GlobalEdgeStateImpl::executeEdgeConfigRequest] – Failed to retrieve EdgeConfig with error:INTERNAL_ERROR
2020-05-06 16:29:32,396 INFO [0x000035bc] [s\src\edge\GlobalEdgeStateImpl.cpp(1279)] [csf.edge] [csf::edge::GlobalEdgeStateImpl::attemptServer] – Attempting request with host, port:8443

2020-05-06 16:29:32,397 INFO [0x000035bc] [etutils\src\http\CurlHttpUtils.cpp(1116)] [csf.httpclient] [csf::http::CurlHttpUtils::configureEasyRequest] – *—–* Configuring request #136 GET
2020-05-06 16:29:32,397 INFO [0x000035bc] [etutils\src\http\CurlHttpUtils.cpp(1895)] [csf.httpclient] [csf::http::CurlHeaders::CurlHeaders] – Number of Request Headers : 1
2020-05-06 16:29:32,397 DEBUG [0x000035bc] [etutils\src\http\CurlHttpUtils.cpp(1571)] [csf.httpclient] [csf::http::CurlHttpUtils::addOauthToken] – Using authentication OAUTH with token
2020-05-06 16:29:32,397 DEBUG [0x000035bc] [etutils\src\http\CurlHttpUtils.cpp(1523)] [csf.httpclient] [csf::http::CurlHttpUtils::configureEasyRequest] – Request #136 configured with: connection timeout 10000 msec, transfer timeout 30000 msec
2020-05-06 16:29:32,397 DEBUG [0x000035bc] [ls\src\http\BasicHttpClientImpl.cpp(633)] [csf.httpclient] [csf::http::performCurlRequest] – About to perform curl connection request #136
2020-05-06 16:29:32,402 DEBUG [0x000035bc] [netutils\src\http\CurlHttpUtils.cpp(191)] [csf.httpclient] [csf::http::CurlHttpUtils::curlTraceCallback] – Request #136 pre connect phase: ‘ Trying 193.1.x.20…’
2020-05-06 16:29:32,493 DEBUG [0x000033e0] [roject\secCommon\src\sec_ssl_api.c(2489)] [csf.ecc.handyiron] [isSockConnected] – getsockopt(SOL_SOCKET, SO_ERROR) : n=0, err=10061
2020-05-06 16:29:32,493 DEBUG [0x000033e0] [roject\secCommon\src\sec_ssl_api.c(2551)] [csf.ecc.handyiron] [performSingleConnect] – socket signalled an exception.
2020-05-06 16:29:32,493 ERROR [0x000033e0] [onewrapper\ccapi_plat_api_impl.cpp(1198)] [csf.ecc.sipcc] [eccSecEstablishSecureConnection] – secSSLConnect(remoteIP=193.1.x.10, port=5061) returned NULL.
2020-05-06 16:29:32,493 INFO [0x000033e0] [tiveapp\sipcc\core\ccapp\cc_alarm.c(816)] [csf.sip-call-control] [setUnregReason] – SIPCC-PLAT_API: setUnregReason: setting unreg reason to=106
2020-05-06 16:29:32,493 DEBUG [0x000033e0] [veapp\sipcc\core\api\ccapi_device.c(100)] [csf.sip-call-control] [CCAPI_Device_getDeviceInfo] – SNAPSHOT-CREATE: CCAPI_Device_getDeviceInfo: g_deviceInfo.ins_state=0
2020-05-06 16:29:32,494 DEBUG [0x000033e0] [veapp\sipcc\core\api\ccapi_device.c(122)] [csf.sip-call-control] [CCAPI_Device_getDeviceInfo] – SNAPSHOT-CREATE: CCAPI_Device_getDeviceInfo: deviceInfo->sis_name=
2020-05-06 16:29:32,494 DEBUG [0x000033e0] [veapp\sipcc\core\api\ccapi_device.c(125)] [csf.sip-call-control] [CCAPI_Device_getDeviceInfo] – SNAPSHOT-CREATE: CCAPI_Device_getDeviceInfo: reference pointer=1bf24998
2020-05-06 16:29:32,494 DEBUG [0x000033e0] [veapp\sipcc\core\api\ccapi_device.c(128)] [csf.sip-call-control] [CCAPI_Device_getDeviceInfo] – SNAPSHOT-CREATE: CCAPI_Device_getDeviceInfo: deviceInfo->ins_state=0
2020-05-06 16:29:32,494 DEBUG [0x000033e0] [\sipcc\core\api\ccapi_device_info.c(235)] [csf.sip-call-control] [CCAPI_DeviceInfo_getCUCMMode] – SIPCC-SIP_CC_PROV: 0x1bf24998, CCAPI_DeviceInfo_getCUCMMode: returned 00
2020-05-06 16:29:32,494 INFO [0x000033e0] [tiveapp\sipcc\core\ccapp\cc_alarm.c(880)] [csf.sip-call-control] [setUnregReason] – SIPCC-PLAT_API: setUnregReason: value of first_oos_alarm_set=1
2020-05-06 16:29:32,494 DEBUG [0x000033e0] [veapp\sipcc\core\api\ccapi_device.c(218)] [csf.sip-call-control] [CCAPI_Device_releaseDeviceInfo] – SNAPSHOT-RELEASE: CCAPI_Device_releaseDeviceInfo: reference pointer=1bf24998
2020-05-06 16:29:32,494 ERROR [0x000033e0] [\core\sipstack\ccsip_platform_tls.c(157)] [csf.sip-call-control] [sip_tls_create_connection] – SIPCC-SIP_TLS: sip_tls_create_connection: Secure connect failed!!

I jumped onto the Expressways-E/C and tried to search for the user id and the CSF profile but there were no records of any attempt by this user.

There seems to be a problem Jabber connecting to Expressways over Internet?

Could it be a User PC issue or something to do with his Internet?

I also have a Jabber account with this company as a test user so I thought I should give it a go to make sure there is no issue with MRA.

I fired up my Jabber, entered credentials for this Company account and viola I connected straight away no issues. My Softphone also came to live within seconds, and I could see my user id and CSF in Expressway Event logs.

Hmmm that means something wrong at his PC!

I went back to him and asked if he is using any special Firewall or Antivirus software which might be blocking connection but I found no issues there.

I then asked him to check his Internet and if there are any special settings for VoIP.

Guess what? He was told by his provider to go to his user account and disable this option :

 “Prevent use of internet telephony from the home network” under “Telephony > Telephone Numbers > Line Settings” in the “Security” section.

How Sweet!

We spent all this time thinking if it is something to do with MRA and at the end it was his Internet connection and some special settings to access VoIP.

This is a snippet below from his Provider Fritzbox Cable as how it should be configured.

I hope this post was useful. Please like and Subscribe to this post and share.

Scenario#49 – UCCX: Call gets System Error message on IVR

By asharsidd
Photo by on

I was looking at an issue a few days back where a customer complained that when they are selecting a particular IVR option the call gets connected to Music on Hold and then before it gets transferred to an Agent the caller hears “Sorry we are experiencing system problems……” the famous CCX default message when something goes wrong! I am sure you all have come across this dreaded message during your UC Career.

I made some test calls myself and collected logs from SIP Gateway, CCM and CCX to find out where exactly is the call failing.

I looked at the script which was a bit complex as there were several IVR options with nested scripts. This particular case was related to option#4 where CCX will send the call to another script to check opening hours based on Local office number you dialed. I checked IVR logs and I can see the call has gone fine up until this point and got queued correctly. I could also hear Music on hold. This is the section of script which I was interested in.

In IVR logs I am skipping right at the end where Agent was selected and call was delivered to the agent. This is where I heard RINGING tone just after Music on Hold. It just rang once and then I hear “Sorry we are having system problems…..”

## CCX has selected AGENT_3 with extension +4799999999

114292827: May 8 13:05:10.724 GMT %MIVR-SS_RM-7-UNK:[MIVR_SS_RM_RmMsgProcessor-67-0-RmMsgProcessor] Agent: Agent AGENT_3 .setWrapupData(6231017/2, null)

114292829: May 8 13:05:10.724 GMT %MIVR-ICD_CTI-7-UNK:[EventQueue.DispatchThread-0-17] CRACTIEventHandler: EventHandler:got rsrcStateChangedEvent
114292830: May 8 13:05:10.724 GMT %MIVR-ICD_CTI-7-UNK:[EventQueue.DispatchThread-0-17] CRACTIEventHandler: EventHandler: posting {AGENT_STATE_EVENT: Socket:Socket: null monitoredDeviceDN:+4799998888, agentDN:+4799998888, agentID:AGENT_3, monitorID = 0, stateDuration = 0, agentstate = RESERVED, eventreasoncode = 0, agentID = AGENT_3, agentExtension = +4799999999, agentID_Long = AGENT_3 } to outboundQ

114292850: May 8 13:05:10.734 GMT %MIVR-SS_CM-7-UNK:[MIVR_ENG_TASKS-31-14-TASK:0xf2253f431_Script101.aef] TransferCompletionState: Reseting All the flags of CallContact to false

## Here I observed that CCX is complaining about “\” before DN in CUCM but it is without “\” in CCX under Resources. This is not an issue anymore but in older versions of CCX you must have AGENT DN without “\+”

114292851: May 8 13:05:10.734 GMT %MIVR-SS_TEL-7-UNK:[MIVR_ENG_TASKS-31-14-TASK:0xf2253f431_Script101.aef] Port: Agent AGENT_3 Extension contains ‘\’ at the start, ignoring that character : Original Extension=[\+4799999999] New =[+4799999999]
114292852: May 8 13:05:10.734 GMT %MIVR-SS_TEL-7-UNK:[MIVR_ENG_TASKS-31-14-TASK:0xf2253f431_Script101.aef] InCallObserverImpl: CallID:24607 MediaId:6231017/2 Task:65000436785, transfer(+4799999999, 20000, ACKNOWLEDGED)

114292858: May 8 13:05:10.741 GMT %MIVR-SS_TEL-7-UNK:[(P1- EventThread] ConsultCallObserver: OrigCall=CallID:24607 MediaId:6231017/2 Task:65000436785, ConsultEvent= ConsultCallActive
114292859: May 8 13:05:10.741 GMT %MIVR-SS_TEL-7-UNK:[(P1- EventThread] ConsultCallObserver: OrigCall=CallID:24607 MediaId:6231017/2 Task:65000436785, ConsultEvent= ConnCreatedEv 04720100164:UCCX_P:1
114292860: May 8 13:05:10.741 GMT %MIVR-SS_TEL-7-UNK:[(P1- EventThread] ConsultCallObserver: OrigCall=CallID:24607 MediaId:6231017/2 Task:65000436785, ConsultEvent= ConnConnectedEv 04720100164:UCCX_P:1
114292861: May 8 13:05:10.741 GMT %MIVR-SS_TEL-7-UNK:[(P1- EventThread] ConsultCallObserver: OrigCall=CallID:24607 MediaId:6231017/2 Task:65000436785, ConsultEvent= CallCtlConnInitiatedEv 04720100164:UCCX_P:1
114292862: May 8 13:05:10.741 GMT %MIVR-SS_TEL-7-UNK:[(P1- EventThread] ConsultCallObserver: OrigCall=CallID:24607 MediaId:6231017/2 Task:65000436785, ConsultEvent= TermConnCreatedEv CX_04720100164
114292863: May 8 13:05:10.741 GMT %MIVR-SS_TEL-7-UNK:[(P1- EventThread] ConsultCallObserver: OrigCall=CallID:24607 MediaId:6231017/2 Task:65000436785, ConsultEvent= TermConnActiveEv CX_04720100164
114292864: May 8 13:05:10.741 GMT %MIVR-SS_TEL-7-UNK:[(P1- EventThread] ConsultCallObserver: OrigCall=CallID:24607 MediaId:6231017/2 Task:65000436785, ConsultEvent= CallCtlTermConnTalkingEv CX_04720100164
114292865: May 8 13:05:10.741 GMT %MIVR-SS_TEL-7-UNK:[(P1- EventThread] ConsultCallObserver: OrigCall=CallID:24607 MediaId:6231017/2 Task:65000436785, ConsultEvent= CallCtlConnDialingEv 04720100164:UCCX_P:1
114292866: May 8 13:05:10.742 GMT %MIVR-SS_TEL-7-UNK:[MIVR_SS_TEL_TPG_EXE-40-529158-CALL_EVENT_LOG:04720100164] RequestImpl: CallID:24607 MediaId:6231017/2 Task:65000436785 Got CallCtlConnDialingEv 04720100164:UCCX_P:1, events on the AddressCallObserver.
114292867: May 8 13:05:10.743 GMT %MIVR-SS_TEL-7-UNK:[(P1- EventThread] ConsultCallObserver: OrigCall=CallID:24607 MediaId:6231017/2 Task:65000436785, ConsultEvent= CallCtlConnEstablishedEv 04720100164:UCCX_P:1
114292868: May 8 13:05:10.743 GMT %MIVR-SS_TEL-7-UNK:[MIVR_SS_TEL_TPG_EXE-40-529159-CALL_EVENT_LOG:04720100164] RequestImpl: CallID:24607 MediaId:6231017/2 Task:65000436785 Got CallCtlConnEstablishedEv 04720100164:UCCX_P:1, events on the AddressCallObserver.

##Here as you can see I saw an Error “CTIERR_UNSPECIFIED” and this is when I hear “System Error message”

114292869: May 8 13:05:10.746 GMT %MIVR-SS_TEL-7-UNK:[MIVR_ENG_TASKS-31-14-TASK:0xf2253f431_Script101.aef] InCallObserverImpl: CallID:24607 MediaId:6231017/2 Task:65000436785 consultWithoutMedia gets CiscoJtapiException: 0x0(CTIERR_UNSPECIFIED)::Unspecified error

114292870: May 8 13:05:10.747 GMT %MIVR-SS_TEL-7-UNK:[MIVR_SS_TEL_TPG_EXE-40-529160-CALL_EVENT_LOG:04720100164] RequestImpl: CallID:24607 MediaId:6231017/2 Task:65000436785 Got ConnFailedEv 04720100164:UCCX_P:1, CallCtlConnFailedEv 04720100164:UCCX_P:1, events on the AddressCallObserver.

114292875: May 8 13:05:10.938 GMT %MIVR-SS_TEL-7-UNK:[MIVR_ENG_TASKS-31-14-TASK:0xf2253f431_Script101.aef] ConsultCallObserver: OrigCall=CallID:24607 MediaId:6231017/2 Task:65000436785, ConsultEvent= CallObservationEndedEv
114292876: May 8 13:05:10.938 GMT %MIVR-SS_TEL-7-UNK:[MIVR_ENG_TASKS-31-14-TASK:0xf2253f431_Script101.aef] CallImpl: Call.transferFailed(+4799999999, UNKNOWN) JTAPICallContact[id=24607,type=Cisco JTAPI Call,implId=6231017/2

114292879: May 8 13:05:10.939 GMT %MIVR-SS_RM-7-UNK:[MIVR_SS_RM_RmMsgProcessor-67-0-RmMsgProcessor] RsrcMgrMsgProcessor: Processing msg: SessionNotAnsweredMsg
114292880: May 8 13:05:10.939 GMT %MIVR-SS_CM-7-UNK:[MIVR_SS_RM_RmMsgProcessor-67-0-RmMsgProcessor] ContactMgr: ContactMgr.getRmCmContact(6231017/2) returns 39785449 [6231017/2]
114292881: May 8 13:05:10.939 GMT %MIVR-SS_CM-7-UNK:[MIVR_SS_RM_RmMsgProcessor-67-0-RmMsgProcessor] CTIPort: The Resource to which the transfer failed is AGENT_3 in CTIPort 04720100164 .processSessionNotAnsweredMsg (24607, 39785449 [6231017/2])
114292882: May 8 13:05:10.939 GMT %MIVR-SS_RM-7-UNK:[MIVR_SS_RM_RmMsgProcessor-67-0-RmMsgProcessor] RsrcMgr: RsrcMgr.cancelSession(AGENT_3, 39785449 [6231017/2], SESSION_CANCELLED_CAUSE_OTHER)
114292883: May 8 13:05:10.939 GMT %MIVR-SS_RM-7-UNK:[MIVR_SS_RM_RmMsgProcessor-67-0-RmMsgProcessor] RsrcMgrMsgProcessor: Processing msg: SessionCancelledMsg (Rsrc:6231017/2 Cause:SESSION_CANCELLED_CAUSE_OTHER)
114292884: May 8 13:05:10.939 GMT %MIVR-SS_RM-7-UNK:[MIVR_SS_RM_RmMsgProcessor-67-0-RmMsgProcessor] Agent: Agent AGENT_3.processSessionCancelledMsg(SessionCancelledMsg (Rsrc:6231017/2 Cause:SESSION_CANCELLED_CAUSE_OTHER))

I Went back to CUCM to check DN settings for this AGENT_3 and found AGENT had a CALL FORWARD ALL set on the DN. This is a big NO for any CCX Agent as that will cause issues such as above. I removed the Call Forwarding from Agent Extension and calls started to work perfectly fine!

Please note whenever you come across issues like these, always get as much information as possible and most of the time customers describe the problem in a very generic way which would increase your troubleshooting time. Concise and accurate information is inversely proportional to the time you will spend troubleshooting a case. The more concise problem description is the less time you will spend resolving the problem. Even in this case which I discussed above, customer initially said calls to the main number are failing and they are getting that “System error message”. I thought it is failing for all their IVR options so I made some test calls and selected random Menu options and they all worked fine. I then went back to the customer to find out exactly which option is failing and then they confirmed it is option#4. Always get as much information as possible before start troubleshooting as that will save time.

I hope this post was useful. Please like and Subscribe to this post and share.

UCCX: Converting Audio Prompt

By asharsidd

You have been asked by your customer to update a menu prompt or insert a Holiday message to the script and they provided you with an audio WAV file or an MP3 file recorded either using Windows Recording application or any other application for that matter.

Most often than not the file provided you will not be in a format acceptable to UCCX.

I am sure you already know that Cisco UCCX Prompt, CUC greeting audio file or CUCM MOH wave file must all adhere to a strict format before you can upload it to the system. If you don’t convert the file in an acceptable format and go ahead with the upload then a system will accept the file but it will not work leaving you scratching your head as why it is not working!

The file must be in this format:

  • Audio Sample Size : 8-bit words
  • 8000 samples per second
  • Audio Format: CCITT u-law
  • Channels: 1 (Mono, not stereo)
  • Bit Rate: 8-bits x 8000 = 64Kbit Audio

Looks confusing? don’t worry! I will explain.

Audacity is a simple free software that will convert your file in any format to above Cisco acceptable format. I use it all the time and currently using version 2.1.1 at the moment but you can download the latest from their website.

Before you convert the file it would be good to know which format your current file is in. The easiest way which I normally do is play the file in VLC Player. If you don’t have VLC then you can download it for free.

Play the file and while it is playing go to Tools > Codec Information and a window like below will open with all relevant details.

As you can see below the file is not in the format mentioned above so we will need to convert the file using Audacity.

 Open Audacity and drag it open the file in it.

Note format and settings on the left hand side. File is Mono and bottom shows bit rate which is 44100 Hz.

Make sure the file is Mono otherwise you can drop down the little arrow near file name and select “Split Stereo to Mono”. Once you select that the file will be split in two. You may close one and just keep one open in the window. Because the file in this example is already Mono so I skipped this step and as you can see that option is grayed out. Once this is done go at the bottom of the file and change bit rate to 8000.

Next Select File > Export > Change the Save as type to “Other Uncompressed Files”

Click the Options button at the bottom right

Select WAV (Microsoft) for Header and U-Law for Encoding

Click OK

Choose a name and save

Click OK to Edit the Metadata

Now play the saved file in VLC and check Codec information

The file is now in acceptable format.

You may now upload the prompt in UCCX.

There is one more scenario which I came across once when I got some audio prompts from a customer in MPEG AAC format. This format is not acceptable in Audacity which means you cannot convert it to Cisco format. Well, I found a workaround for that.

Open VLC player and then go to Media > Convert/Save

You will get this first screen: From here browse to the file and then at the bottom Convert/Save drop down and go to Convert. You will come to the second screen where you select “Audio CD” under profile and bingo! You will have a file in Audacity Acceptable format and now you can convert it to U-law 8000 Hz.

In this post I have discussed how to convert an audio file using Audacity for UCCX Prompts. This same procedure can be applied for a Unity greeting or a MOH file.

There is another way to record a prompts in UCCX using a CRS script which is quite handy as you don’t have to do any conversions or uploads and the prompt is saved in the repository for you to just point script to the prompt or just overwrite existing prompt. I will discuss that in my next post.

I hope this post was useful. Let me know in the comments down below if you have any queries regarding this post.

Unity Connection & Aging Policy

By asharsidd

We all know that Unity connection use Quotas and Aging Policy to control the size of mailboxes and keep a check on “those” users who don’t want to delete their voicemails or maybe don’t care.

More often than not I have come across issues where a client requested to reduce the size of a user’s mailbox or wanted to understand how a user’s mailbox has actually crossed the allocated quota and still getting voicemails or simply wanted to see how we can delete the voicemails automatically without user intervention etc.

Here is a recent example I was working on for a client where a user clealy exceeded the default allocated quota of 14MB and the number of messages in his mailbox were standing 250 and growing. Client was not sure how and why the mailbox size exceeded the quota and how we can delete all the vociemails without user intervention (they did not want to delete the user’s mailbox and re-create it as he was not the only offender)


One of the reasons why the user’s mailbox exceed the quota was because most of the messages left on his mailbox were outside callers. If you look at system-wide mailbox quotas you will find a check box specifically for outside callers. If you don’t check that box Unity connection will keep on taking messages without giving any warning to caller even if the mailbox size exceed the allocated quota. I will explain this further later on.


Now how do we delete all these 250 messages without user intervention and without deleting the voicemail box?

Here comes the Aging Policy for the rescue. Aging policy is used to control the size of hard disk used by voice messages. You can have one system-wide policy or you can have a policy per user or per template depending upon your business needs. They way it works:

  • New message received
  • Move New message to Saved messages folder after x days
  • Move Saved messages to Deleted Item folder after x days
  • Permanently delete messages from Deleted folder after x days

Please note that when you delete a voicemail it just does not vanish away from your mailbox. It still exists in deleted folder taking up your mailbox quota. If you have aging policy enabled normally these deleted messages are erased after 15 days.

Coming back to our original issue. This is what I created to delete the voicemails automatically for “those” users. The idea was to move new messages  to Saved Messages in 1 day then to Deleted item in 1 day then Erase after 1 day. So in about 72 hours any new message coming into the mailbox will be gone. Any old message which were in deleted folder were deleted right away as they were > 1 day. Similarly New and Saved messages which were > 1 day moved to next cycle until they reach deleted items folder.


Below an excerpt from a Cisco document which explains why a mailbox size can increase beyond quota and how Unity handles if a mailbox is no longer allowed to receive messages.

If a user mailbox is no longer allowed to receive messages, Unity Connection handles the message in one of two ways:

• By default, when an unidentified caller attempts to send a message to a user whose mailbox has exceeded the send/receive quota, Unity Connection still delivers the message. You can instead configure Unity Connection to indicate to the caller that the recipient mailbox is full, and prevent the caller from recording a message for that recipient. (In Cisco Unity Connection Administration, on the Message Storage > Mailbox Quotas page, check the Full Mailbox Check for Outside Caller Messages check box.)

If the recipient mailbox has not yet exceeded the send/receive quota at the time an unidentified caller records a message, but the quota is exceeded in the act of delivering the message, Unity Connection delivers the message regardless of the quota.

• When a user tries to leave a message for another user whose mailbox has exceeded the send/receive quota, Unity Connection allows the user to record and send the message. However, if the mailbox for the recipient is full, he or she does not receive the message, and if the user account for the recipient is configured to send non-delivery receipts when message delivery fails, Unity Connection sends the message sender a non-delivery receipt.
If the recipient mailbox has not yet exceeded the send/receive quota at the time a Unity Connection user records a message, but the quota is exceeded in the act of delivering the message, Unity Connection delivers the message regardless of the quota.

This is why it is important that you check that box “Full mailbox check for outside caller messages” if you don’t want a user’s mailbox going beyond quota otherwise by default system will keep taking messages from outside callers.

I am back!!

By asharsidd

Yes you read it right.. I am back after almost 2 years and will be writing exciting new stuff very soon! I do apologize for this long break as I had some work and family committments but have now decided to start giving some time to this blog and bring it back to life. I know most of you have got in touch with me asking as to why I am not writing anymore and how they use to enjoy reading my stuff so that has kind of motivated me to come back! Thank you.

Some of you old subscribers will notice a new look and a different structure to this website. I am also giving this blog a new name…VOBTIGO…sounds interesting? thought about many but this one just got stuck to my mind and was available as well (domain registration etc.)..So in near future you may see retiring to but I cannot confirm timeline as to when this will happen as I am still discussing this mapping of domain with relevant providers. For the time being stick to until is up and mapped (I will keep you guys posted).

Finally,  I would be happy to get feedback from you guys if you want me to write on a specific topic. Due to time constratints and my full time job I cannot promise that I will write on every topic requested so I will have to prioritise those requested by more people but I will come to other ones as well.



Scenario# 48 – Desktop share won’t work Jabber conference call

By asharsidd

I was working on an issue for a client where they were not able to share screen if there are 3 or more particpants in a jabber conference call.

They tested it on Jabber 10.6.1 and 10.6.6 but had same issue.

Chat only conference works fine if there are 3 or more particpats. 5 is the limit at the moment for Jabber desktop share. Not sure if it will be increased in future relases.

Anyways, we made several test calls with 4 users all connected to Jabber in soft client mode, registered to same cucm and on same cups cluster. I couldn’t find anything useful in Jabber problem report. In CUCM, however, I noticed that BFCP protocol changes IP to in ACK even though INVITE goes with proper and correct IP of conference initiator. You will see something like below:
o=CiscoSystemsCCM-SIP 75015974 5 IN IP4
s=SIP Call
t=0 0
m=audio 24682 RTP/AVP 0
c=IN IP4
a=rtpmap:0 PCMU/8000
m=video 0 RTP/AVP 126
c=IN IP4
a=rtpmap:126 H264/90000
a=fmtp:126 profile-level-id=42E01F;packetization-mode=1;max-fs=3601;max-rcmd-nalu-size=32000;level-asymmetry-allowed=1
m=video 0 RTP/AVP 126
c=IN IP4
a=rtpmap:126 H264/90000
a=fmtp:126 profile-level-id=42E01F;packetization-mode=1;max-fs=9001;max-rcmd-nalu-size=32000;level-asymmetry-allowed=1
m=application 0 UDP/BFCP *
c=IN IP4

I had to log a TAC case for this and even he struggled a bit to find out why it is not working. Later he confirmed that BFCP* protocol does not support phone conference calls if MCU is not used as Conference Bridge. You must add a conductor / MCU to use desktop share in a conference call of 3 or more participants. This is nowhere documented in any Cisco documentation which the TAC agreed as well and it will be added in future release notes of Jabber.


Scenario#47 – Jabber users see ‘offline’ status after logging in

By asharsidd

I came across an issue for a client where few of their users would login to Jabber (ver 10.5) and see their presence status as ‘offline’. They won’t be able to change it as well. Other Jabber users will also see them as ‘offline’ even though they are logged in and should be online. That was one issue. Few other users would give ‘false’ presence status like if they are ‘away’ they will be shown online and vice versa. They were on 10.5(2) IM&P which is a fairly new release so I was so sure it cannot be due to a bug (I have seen in past these kind of issues in older version of CUPS due to bugs).

I checked the configuration of users in CUCM and IM&P which was all good. Both nodes were in balanced mode and that looking ok as well. I checked the services and they were up and running all fine. I did a dbreplication runtimestate and dbreplication status and found as follows:

admin:utils dbreplication runtimestate

Server Time: Thu Aug  6 01:37:15 MST 2015

Cluster Replication State: Replication status command started at: 2015-08-06-01-27
Replication status command COMPLETED 305 tables checked out of 305
Last Completed Table: batfileinfojobmap
Errors or Mismatches Were Found!!!

Use ‘file view activelog cm/trace/dbl/sdi/ReplicationStatus.2015_08_06_01_27_31.out’ to see the details

DB Version: ccm10_5_2_21900_4
Repltimeout set to: 300s
PROCESS option set to: 1

Cluster Detailed View from lxus3tp04 (2 Servers):

PING      DB/RPC/   REPL.    Replication    REPLICATION SETUP
SERVER-NAME         IP ADDRESS        (msec)    DbMon?    QUEUE    Group ID       (RTMT) & Details
———–         ———-        ——    ——-   —–    ———–    ——————
lxus3tp04       0.022     Y/Y/Y     0        (g_5)          (2) Setup Completed
lxus3tp05       0.248     Y/Y/Y     0        (g_6)          (2) Setup Completed




Errors found from the ‘utils dbreplication status’ command.
Please review the below logs for details.

options: q=quit, n=next, p=prev, b=begin, e=end (lines 1 – 7 of 7) :
Thu Aug  6 01:26:43 2015 main()  DEBUG:  –>
Thu Aug  6 01:26:48 2015 main()  DEBUG:  Replication cluster summary:
g_5_ccm10_5_2_21900_4    5 Active   Local           0
g_6_ccm10_5_2_21900_4    6 Active   Connected       0 Jul 20 06:32:24
Thu Aug  6 01:26:56 2015 main()  DEBUG:  <–

———- Suspect Replication Summary ———-

For table: ccmdbtemplate_g_5_ccm10_5_2_21900_4_1_150_peuritoiuid
replication is suspect for node(s):


I noticed replication is showing errors for peuritoiuid table. I was a but curious so I jumped on the bug toolkit and searched for all bugs related to Presence server for Jabber offline status. After a bit of digging I came across a new bug for this kind of behavior where Jabber users will show offline status (on random) and the dbreplication will show a ‘bad’ peuritoiuid table. It is documented under Bug id: CSCuu65533.

To fix this I repaired the peuritoiuid table from IM&P at first node and after that replication was good and the issue related to ‘offline’ and ‘false’ presence status was resolved.


admin:utils dbreplication repairtable peuritoiuid
Repairing of replication for table peuritoiuid is in progress.
repairing replicate
replicatename: ccmdbtemplate_g_5_ccm10_5_2_21900_4_1_150_peuritoiuid
Output is in file cm/trace/dbl/sdi/ReplicationTblRepair.2015_08_06_01_54_02.out

Please use “file view activelog cm/trace/dbl/sdi/ReplicationTblRepair.2015_08_06_01_54_02.out” command to see the output
admin:file view activelog cm/trace/dbl/sdi/ReplicationTblRepair.2015_08_06_01_54_02.out

utils dbreplication repairtable tablename [nodename]|all output

To determine if replication is suspect, look for the following:
(1) Number of rows in a table do not match on all nodes.
(2) Non-zero values occur in any of the other output columns for a table

First, a cdr list of the replication status of the servers

g_5_ccm10_5_2_21900_4    5 Active   Local           0
g_6_ccm10_5_2_21900_4    6 Active   Connected       0 Jul 20 06:32:24

Thu Aug  6 01:54:07 2015 dbllib.getReplServerName  DEBUG:  –>
Thu Aug  6 01:54:12 2015 dbllib.getReplServerName  DEBUG:  replservername: g_5_ccm10_5_2_21900_4
Thu Aug  6 01:54:12 2015 dbllib.getReplServerName  DEBUG:  <–

Aug 06 2015 01:54:13 ——   Table scan for ccmdbtemplate_g_5_ccm10_5_2_21900_4_1_150_peuritoiuid start  ——–

options: q=quit, n=next, p=prev, b=begin, e=end (lines 1 – 20 of 44) :
Node                  Rows     Extra   Missing  Mismatch Processed
—————- ——— ——— ——— ——— ———
g_5_ccm10_5_2_21900_4      3270         0         0         0       905
g_6_ccm10_5_2_21900_4      3240         0        30         0         0

The repair operation completed. Validating the repaired rows …
Validation completed successfully.
Aug 06 2015 01:54:15 ——   Table scan for ccmdbtemplate_g_5_ccm10_5_2_21900_4_1_150_peuritoiuid end   ———

Running a cdr check after repair to insure table is in sync

Aug 06 2015 01:54:16 ——   Table scan for ccmdbtemplate_g_5_ccm10_5_2_21900_4_1_150_peuritoiuid start  ——–

Node                  Rows     Extra   Missing  Mismatch Processed
—————- ——— ——— ——— ——— ———
g_5_ccm10_5_2_21900_4      3270         0         0         0         0

options: q=quit, n=next, p=prev, b=begin, e=end (lines 21 – 40 of 44) :
g_6_ccm10_5_2_21900_4      3270         0         0         0         0

Aug 06 2015 01:54:16 ——   Table scan for ccmdbtemplate_g_5_ccm10_5_2_21900_4_1_150_peuritoiuid end   ———

end of the file reached

To access Jabber-config.xml

By asharsidd

If you want to check what has been configured on a Jabber-config.xml then you need to go to CLI of CUCM and execute this command to display its contents:

admin:file view tftp jabber-config.xml

<?xml version=”1.0″ encoding=”utf-8″?>
<config version=”1.0″>

end of the file reached
options: q=quit, n=next, p=prev, b=begin, e=end (lines 1 – 14 of 14) :


You can see the file by using this URL:



You can also find a local copy on user PC at:

%USERPROFILE%\AppData\Roaming\Cisco\Unified Communications\Jabber\CSF\Config

Remmeber EDI is used for authentication from LDAP directory server (default)

UDS is used for CUCM authentication (need to configure the UDS service and Proile)

CUCM 8.6 and above support UDS.

Selecting a Vendor to Replace Cisco Attendant Console

By asharsidd

Since Cisco Unified Attendant Console has reached its end of life, clients are offered several alternatives from Cisco Solution Partners. This article will help you to make the rights choice.

Directory and Basic Call Control Features

If a Cisco IP phone is one of your main business tools you need the most convenient interface to:

  • quickly find any person and call him,
  • see who’s calling you,
  • perform the basic call control actions – call forward, conference, parking etc.

So, when selecting the attendant console for Cisco UCM pay attention directory and call control features. Make sure that the solution supports:

  • several directories – employees, clients, personal contacts etc,
  • customizable structure for each directory – for example, first/last name and position for employee, company name and city for clients and so on,
  • presence status for internal contacts,
  • convenient search and filter tools,
  • easy to use call control features – put the call on hold, forward the call (blind and consultative), organize an ad-hoc conference.

Then, depending on who is going to use the console software, pay attention to special features.

  1. Features for Managers

If the console app is going to be used by sales people or top managers, the key feature is the intuitive user interface which doesn’t require much training. Employees photo, large buttons, drag-and-drop features would be nice. And, of course, the call history panel.

  1. Features for Assistants

If you need a solution for top manager assistants, pay attention to some special features, like:

  • phone lines monitoring – to know who the manager is talking to and who’s calling him,
  • call interception – to intercept and answer the incoming call when the manager is away,
  • “whisper” feature – to notify manager about important call while he is on the phone,
  • conference control features – to create audio-meetings for manager and control the conference even without being its participant.
  1. Features for Receptionists and Contact Center Agents

Lastly, when it comes to reception or contact center personnel, whose main task is to answer incoming calls, make sure the attendant console provides superior call routing and distribution tools:

  • queue support (both UCCX and CUCM native queuing) with the ability to see who’s on queue and choose the call to answer,
  • intelligent call routing assistant, which shows a list of employees to whom calls from the current calling party were routed most often,
  • hot keys support to process the incoming calls as fast as possible,
  • dynamic search, fast enough even when searching tens of thousands of contacts,
  • comments to calls, visible for other operators.

The article is provided by Aurus, the official Cisco Solution Partner. Aurus PhoneUP is the application suite for Cisco Unified Communications Manager Enterprise and BE 6000/7000 which includes both Enterprise Directory and Attendant Console for CUCM modules.

Scenario#46 – 9951 SIP phones drop call after 18 seconds

By asharsidd

Recently I came across an issue with a new customer deployment where the 9951 SIP phones would drop call after 18s. All other SCCP phones were working fine but only these SIP phones would drop the call.


Call flow:

9951 -> SIP -> CUCM -> SIP -> CUBE

Bind commands were in place and the only way I could resolve the issue was forcing RTCP parameter “disabled” under Common phone profile and Enterprise Phone parameters.

System -> Enterprise Phone Configuration


Device -> Device Settings -> Common Phone Profile


  • July 17th 2014 at 20:41

Scenario#45: 7841 SIP phone in Registration loop

By asharsidd

I was working on this customer issue last week where they added a new 7841 phone but it was not registering properly or should I say it was registering briefly before unregistering.

Call Manager was which does not support 78XX phones so customer actually applied the device pack cmterm-devicepack9.1.2.12039-1.cop  so that they can add 78XX phones.

Looking at the logs I found that it is registering with Pub and not Sub even though Sub was the Primary CCM in Call Manager group. At Pub I can see something like this:


Via: SIP/2.0/TCP;branch=z9hG4bK739dd207
From: <sip:49715220XXXXX@>;tag=544a003629fd000a741be677-22e1dea8
To: <sip:49715220XXXXX@>
Call-ID: 544a0036-29fd0008-13a9ded8-614a41b9@
Max-Forwards: 70
Date: Tue, 17 Jun 2014 06:32:10 GMT
User-Agent: Cisco-CP7841/10.1.1
Contact: <sip:61131fd1-5eb6-b49e-5d2f-9f9aee1b125c@;transport=tcp>;+sip.instance=”<urn:uuid:00000000-0000-0000-0000-544a003629fd>”;+u.sip!”SEP544A003629FD”;+u.sip!”622″

[Registration Accepted by Publisher]
SIP/2.0 202 Accepted
Via: SIP/2.0/TCP;branch=z9hG4bK6c29941b
From: <sip:544a003629fd@>;tag=544a003629fd000c3890afb1-54d723a2
To: <sip:>;tag=875713562
Date: Tue, 17 Jun 2014 06:32:10 GMT
Call-ID: 544a0036-29fd0006-22434855-1719a3c1@
CSeq: 1000 REFER
Contact: <sip:;transport=tcp>
Content-Length: 0




But then I noticed this further down:

08:32:16.866 |AppInfo  |SIPStationD(607) – setUaTypeAndCepn: uaType is CISCO_ENHANCED_PHONE

08:32:16.866 |AppInfo  |SIPStationD(607) – Received REGISTER from 4971522036708@

08:32:16.866 |AppInfo  |SIPStationD(607) – verifyAddressAndPort — Endpoint unregistered (expires=0), old ip:, new ip:


08:32:16.866 |AppInfo  |SIPStationD(607) – parseLoad: InactiveLoad= name is: [sip78xx.10-1-1-9.loads]

08:32:16.866 |AppInfo  |SIPStationD(607) – processReasonCode:  Processing phone provided reason code=[105]

08:32:16.866 |AppInfo  |SIPStationD(607) – DevStat-NewState : line 4971522036708: Registered ==> Unregistered


While on Subscriber this is what I saw:



[Registration Request]

Via: SIP/2.0/TCP;branch=z9hG4bK5fead06f
From: <sip:49715220XXXXX@>;tag=544a003629fd00020eea65f9-659c5963
To: <sip:49715220XXXXX@>
Call-ID: 544a0036-29fd0003-4c3d829b-12a9daae@
Max-Forwards: 70
Date: Wed, 11 Apr 2012 08:28:24 GMT
User-Agent: Cisco-CP7841/10.1.1
Contact: <sip:61131fd1-5eb6-b49e-5d2f-9f9aee1b125c@;transport=tcp>;+sip.instance=”<urn:uuid:00000000-0000-0000-0000-544a003629fd>”;+u.sip!”SEP544A003629FD”;+u.sip!”622″
Supported: replaces,join,sdp-anat,norefersub,resource-priority,extended-refer,X-cisco-callinfo,X-cisco-serviceuri,X-cisco-escapecodes,X-cisco-service-control,X-cisco-srtp-fallback,X-cisco-monrec,X-cisco-config,X-cisco-sis-6.0.2,X-cisco-xsi-8.5.1
Reason: SIP;cause=200;text=”cisco-alarm:25 Name=SEP544A003629FD ActiveLoad=sip78xx.10-1-1SR1-4.loads InactiveLoad=sip78xx.10-1-1-9.loads Last=initialized”
Expires: 3600
Content-Type: multipart/mixed; boundary=uniqueBoundary
Mime-Version: 1.0
Content-Length: 1203


08:31:40.497 |AppInfo  |SIPStationD(684) – setUaTypeAndCepn: uaType is CISCO_ENHANCED_PHONE

08:31:40.497 |AppInfo  |CcmdbStationRegistrationProfileBuilder::init – No typemodel table-entry for device SEP544A003629FD.

08:31:40.497 |AppInfo  |CcmdbStationRegistrationProfileBuilder::getBasicRegistrationProfile::init() – failed rc(1)

08:31:40.497 |AppInfo  |SIPStationD(684) – Registration profile error: Database error, sending registration reject and closing station

08:31:40.497 |AppInfo  |SIPStationD(684) – sendRegisterResp: non-200 response code 404, ccbId 336776, expires 4294967295, warning Database error

08:31:40.497 |AlarmErr |AlarmClass: CallManager, AlarmName: EndPointTransientConnection




So what does it tells us?

Subscriber is not accepting the registration from this 7841 as it does not see that phone type as a legitimate phone.

But hang on did the customer not applied the device pack? yes they did.

A quick phone call with customer revelaed some secrets… Yes they did applied the device pack but rebooted only the Publisher. He questioned me in amazement  “Do we need to reboot Subscribers as well?”


Anyways, issue was resolved after rebooting the Sub as well. The device pack although applies would not take affect until you reboot it. So remember that if you are going to apply a device pack then:

  1. Apply on all nodes
  2. Reboot all nodes in cluster starting from Publisher





Scenario#44 – CME Call Forward to Internal Extension not Working

By asharsidd

I came across an interesting issue for a Swiss customer where they were having problem with Call-forward to an internal extension on their CME systems.

Call-forward to an internal extension seems quite straight-forward so I checked how telephony-service is configured and found both call-forward patterns as well as transfer-pattern were configured as .T .. so no real issue there. Customer added that it use to work fine before but not working anymore. After asking few questions I found that they recently migrated from ISDN to a SIP provider so all incoming calls are coming on SIP while I was thinking it’s all ISDN.

Ran our usual ccsip all, dial-peer all, ccapi inout debugs and found that when call is getting forwarded from 608 to 612, we are getting “SIP/2.0 302 Moved Temporarily” and then the call was getting disconnected.


SIP/2.0 302 Moved Temporarily
Via: SIP/2.0/UDP 62.2.x.x:5060;branch=z9hG4bKtjjtl830982hmqr9f6u0.1
From: 076XXXXXX<;user=phone>;tag=1680239575
To: 608<sip:0442296008@cableXXX:5060;user=phone>;tag=BA4F3C-6D2
Date: Mon, 24 Feb 2014 12:06:50 GMT
Call-ID: 7692dde2-11ccfac8-1ce04e37-1bb8@cableXXX
Allow-Events: telephone-event
Server: Cisco-SIPGateway/IOS-12.x
Diversion: ;reason=no-answer;counter=1
Contact: <sip:612@192.168.x.x>
Content-Length: 0


When a call comes in on an SIP trunk and gets forwarded (CFNA / CFB / CFA), then the default behavior is for the CME to send the 302 “Moved Temporarily” SIP message to the Service Provider (SP) proxy. Sometimes provider may not support this and that was the case in this problem. Same issue is for Transfer as by default CME sends a SIP REFER message to Service Provider (SP) proxy and in this case SP was not able to handle it well.

I decided to configure the following commands before going to carrier as I was trying to disable this default behavior of CME.

voice service voip
no supplementary-service sip refer
no supplementary-service sip moved-temporarily

This fixed the issue without logging any ticket with carrier as I changed the behavior of CME.

Now when call is forwarded to 612 I was getting this instead of 302 Moved Temp.

SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 62.2.X.X:5060;branch=z9hG4bKsn1fs200c8g1qq3af7f1.1
From: 072XXXXXX <sip:072XXXXXX@CableXXX:5060;user=phone>;tag=1247061884
To: 608 <;user=phone>;tag=12BA304-1D1B
Date: Mon, 24 Feb 2014 14:10:38 GMT
Call-ID: 5e59c683-7fa02bdf-214b80c1-5e8d@CableXXX
Allow-Events: telephone-event
Remote-Party-ID: “Michele 612” <sip:612@192.168.X.X>;party=called;screen=no;privacy=off
Contact: <sip:608@192.168.X.X:5060>
Server: Cisco-SIPGateway/IOS-12.x
Content-Length: 0

Scenario#43 – CUCM 9.1(2) RL/RG Reject Issue

By asharsidd

Few weeks back I came across a issue for a customer who are on CUCM 9.12() cluster.

The issue was outbound calls not reaching either of the MGCP gateways from a Translation pattern even though both gateways were registered fine with Call manager.

I checked the E1s and MGCP status and all was OK. The Route List was reset as well but had no joy. I also did a Reset on MGCP quite few times but had no luck.

During test calls I found this in CCM logs:

93958336.006 |18:10:05.348 |AppInfo  |RouteListCdrc::null0_CcSetupReq – Selecting a device.

93958336.007 |18:10:05.348 |AppInfo  |RouteListCdrc::selectDevices — mTemporaryDeviceInfoList.size = 1.

93958336.008 |18:10:05.348 |AppInfo  |RouteListCdrc::null0_CcSetupReq: Execute a route action.

93958336.009 |18:10:05.348 |AppInfo  |RouteListCdrc::algorithmCategorization — CDRC_SERIAL_DISTRIBUTION type=1

93958336.010 |18:10:05.348 |AppInfo  |RouteListCdrc::whichAction — DOWN (Current Group) = 1

93958336.011 |18:10:05.348 |AppInfo  |RouteListCdrc::routeAction — current device name=a75fd367-37e5-e702-9336-505837d6fc48, down

93958336.012 |18:10:05.348 |AppInfo  |RouteListCdrc::executeRouteAction: SKIP_TO_NEXT_MEMBER

93958336.013 |18:10:05.348 |AppInfo  |RouteListCdrc::skipToNextMember




93958337.005 |18:10:05.348 |AppInfo  |RouteListCdrc::algorithmCategorization — CDRC_SERIAL_DISTRIBUTION type=1

93958337.006 |18:10:05.348 |AppInfo  |RouteListCdrc::whichAction — DOWN (Current Group) = 1

93958337.007 |18:10:05.348 |AppInfo  |RouteListCdrc::routeAction — current device name=64b7ded7-1c4b-87c4-dbde-dd931577cd99, down

93958337.008 |18:10:05.348 |AppInfo  |RouteListCdrc::executeRouteAction: SKIP_TO_NEXT_MEMBER

93958337.009 |18:10:05.348 |AppInfo  |RouteListCdrc::skipToNextMember




93958338.001 |18:10:05.348 |AppInfo  |RouteListCdrc::null0_CcSetupReq check vipr call mViprReroute=0 mViprAlreadyAttempt=0 CI=35154630 BRANCH=0

93958338.002 |18:10:05.348 |AppInfo  |RouteListCdrc::null0_CcSetupReq – Terminating a call after the RouteListCdrc cannot find any more device.

93958338.003 |18:10:05.348 |AppInfo  |RouteListCdrc::terminateCall – No more Routes in RouteListName = RL_LIP.  Rejecting the call

93958338.004 |18:10:05.348 |AppInfo  |RouteListCdrc::terminateCall – Sending CcRejInd, with the cause code (41), to RouteListControl because all devices are busy/stopped.

93958338.005 |18:10:05.348 |AppInfo  |GenAlarm: AlarmName = RouteListExhausted, subFac = CALLMANAGERKeyParam = , severity = 4, AlarmMsg = RouteListName : RL_LIP, Reason=41,



This shows the problem. For some reason both gateways appeared to be either stopped or busy to Call manager even though they were available with full 30 channels.

I searched for bugs but could not find any for CUCM 9.1(2) and RL problem. Tried to change order of E1s in RG but that did not help as well.

The issue was only resolved when I went for a cluster reboot. It seems like the Provisioning service sometimes is not updated properly and get stuck.

Just today I found that Cisco has in fact added this as a bug (Feb 7th) on their Bug Toolkit. Even though they mention Reset of RL/RG will resolve the issue, it did not for me.

This is just a heads up for you guys if you come across similar issue for a 9.1(2) cluster. You may try resetting RL/RG but cluster reboot will definitely resolve the issue.

Bug Id is CSCum85086 -Outbound calls through RL failing, RG members reported as down


Scenario#42 – CUC not working after adding Secondary Server

By asharsidd

I came across an interesting scenario few days back where customer added a CUC Secondary server back to the Cluster but it was not working as it should.

Customer had two CUC servers in the cluster in a load-balanced configuration with half of the ports on unity-02(sub) and other half on unity-01(Pub). For some hardware failure the secondary failed and they had to re-build it from Scratch. The problem they were facing was that unity was not taking any calls as the first 80 ports were on unity-02 and for some reason it was not happy.

I checked the replication status first and found this:

admin:utils dbreplication runtimestate

DB and Replication Services: ALL RUNNING

Cluster Replication State: Replication status command started at: 2012-10-18-11-44
Replication status command COMPLETED 1 tables checked out of 425
Processing Table: typedberrors with 982 records
No Errors or Mismatches found.

Use ‘file view activelog cm/trace/dbl/sdi/ReplicationStatus.2012_10_23_11_44_00.out’ to see the details

DB Version: ccm7_1_2_20000_2
Number of replicated tables: 425

Cluster Detailed View from PUB (2 Servers):

PING                     REPLICATION    REPL.     DBver&                REPL.     REPLICATION SETUP
SERVER-NAME IP ADDRESS        (msec)  RPC?     STATUS                QUEUE TABLES                 LOOP?  (RTMT) & details
———–             ————           ——      —-         ———–             —–       ——-    —–       —————–
UNITY-01                x.x.0.35            0.049     Yes         Connected         0             match   N/A       (2) PUB Setup Completed
unity-02                x.x.0.36             0.254     Yes         Off-Line               N/A       0      N/A        (4) Setup Completed

admin:file view activelog cm/trace/dbl/sdi/ReplicationStatus.2012_10_23_11_44_00.out

g_unity_01_ccm7_1_2_20000_2    2 Active   Local           0

I can see (4) with Secondary which means not good!

I then found Secondary server complaining about some CDR records. A little search at Cisco and I found a well known defect. Bug Id: CSCta15666 for CUC

– – –

In CDR Define logs (file list activelog /cm/trace/dbl/*)
We got exception in Cdr define
Ignoreable exception occurred will continue. Value:92

In CDR output broadcast logs (file list activelog /cm/trace/dbl/*)
Error 17 while doing cdr check, will cdr deleteTime taken to do cdr check[1.92180991173]

Exception from cdr delete e.value [37] e.msg[Error executing [su -c ‘ulimit -c 0;cdr delete server g_nhbl_vo_cl1fs02_ccm7_1_2_10000_16’ – informix] returned [9472]]

The steps taken to fix this were the following:
– utils dbreplication stop all on publisher
– utils dbreplication dropadmindb on both servers
– utils dbreplication forcedatasyncsub on subscriber
– utils dbreplication reset all
– rebooted the subscriber

After this, the dbreplication was fixed.

Scenario#41 – No Ringback tone from H323 Gateway going to SIP trunk

By asharsidd

One of our customer reported an issue with ring back tone when calling their Contact center.

I made a test call and observed that as a caller when you call their main Contact center number all you hear is dead silence and then when agent picks up the phone you could hear them talk. There was no ring back tone and no automated messages before an agent picks up the call.

The call flow was something like this:

PSTN > ISDN30 > H323 Dial-peer > SIP Trunk > 3rd-party Contact Center Equipment

First I thought it could be the third-party equipment which was not sending back the ring back tone so I asked them to confirm this. They came back saying they are definitely sending ring back and there was no issue with their equipment.

Looking at Q931 debugs I could see ALERTING message with payload but wasn’t sure why there was no ring back.

The dial-peers were looking ok as well:


dial-peer voice 8500 voip
corlist outgoing CCM
description DC1CCM01
preference 1
destination-pattern 361[01].
progress_ind setup enable 3
progress_ind alert enable 8
session target ipv4:
dtmf-relay h245-signal h245-alphanumeric
no vad


dial-peer voice 8501 voip
corlist outgoing CCM
description DC1CCM02 Cycos Ansage
preference 2
destination-pattern 361[01].
progress_ind setup enable 3
progress_ind alert enable 8
session target ipv4:
dtmf-relay h245-signal h245-alphanumeric
no vad
I then decided to run some debugs to get a complete picture as to what is going wrong. These were the debugs I opened on the gateway:

debug voip ccapi inout
debug cch323 all
debug h225 asn1
debug h245 asn1
debug ip tcp trans
debug ccsip all

Collected debugs in the following manner:

Router(config)# service sequence
Router(config)# service timestamps debug datetime localtime msec
Router(config)# logging buffered 10000000 7
Router(config)# no logging con
Router(config)# no logging mon
Router(config)# voice iec syslog

Note: Please be very careful when you run the above debugs as these are processor intensive and make sure you are not logging monitor and console.

The debugs were massive but this is what I observed:

From Gateway traces I can see RINGBACK has definitely been sent to Gateway –

005302: *Aug 25 23:44:07.256: //-1/xxxxxxxxxxxx/H323/cch323_h225_receiver: Received msg of type ALERTIND_CHOSEN
005303: *Aug 25 23:44:07.256: //3610/D48C17148501/H323/alert_ind: ====== PI = 0
005304: *Aug 25 23:44:07.256: //3610/D48C17148501/H323/alert_ind: alert ind ie_bit_mask 0x1260, displayInfo
005305: *Aug 25 23:44:07.256: //3610/D48C17148501/H323/alert_ind: delay H245 address in alert
005306: *Aug 25 23:44:07.256: //3610/D48C17148501/H323/alert_ind: Call Manager detected
005307: *Aug 25 23:44:07.256: //3610/D48C17148501/H323/cch323_h225_receiver: ALERTIND_CHOSEN: src address =; dest address =
005308: *Aug 25 23:44:07.256: //3610/D48C17148501/H323/run_h225_sm: Received event H225_EV_ALERT_IND while at state H225_REQ_FS_CALLPROC
005309: *Aug 25 23:44:07.256: //3610/D48C17148501/H323/cch323_get_embedded_obj_from_ccb: ccb=0x4715D7A0, tag=18, size=83
005310: *Aug 25 23:44:07.256: //3610/D48C17148501/H323/cch323_get_embedded_obj_from_ccb: Extraction FAILED
005311: *Aug 25 23:44:07.256: //3610/D48C17148501/CCAPI/cc_api_set_called_ccm_detected:
CallInfo(called ccm detected=TRUE ccmVersion 3)
005312: *Aug 25 23:44:07.256: //3610/D48C17148501/CCAPI/cc_api_set_delay_xport:
CallInfo(delay xport=TRUE)
005313: *Aug 25 23:44:07.256: //3610/D48C17148501/CCAPI/cc_api_call_alert:
Interface=0x46B2BAA8, Progress Indication=NULL(0), Signal Indication=SIGNAL RINGBACK(1)
005314: *Aug 25 23:44:07.256: //3610/D48C17148501/CCAPI/cc_api_call_alert:
Call Entry(Retry Count=0, Responsed=TRUE)
005315: *Aug 25 23:44:07.256: //3610/D48C17148501/H323/cch323_h225_set_new_state: Changing from H225_REQ_FS_CALLPROC state to H225_REQ_FS_ALERT state
005316: *Aug 25 23:44:07.260: //3609/D48C17148501/CCAPI/ccCallAlert:
Progress Indication=INBAND(8), Signal Indication=SIGNAL RINGBACK(1)

Then ALERTING Signal shown in ISDN Q931 debug:

005331: *Aug 25 23:44:07.264: ISDN Se0/0/0:15 Q931: TX -> ALERTING pd = 8 callref = 0x803A

But then Observed this:

005332: *Aug 25 23:44:07.264: //3610/D48C17148501/H323/h323_open_rtp_stream: Media In-active notification object not attached to ccb
005333: *Aug 25 23:44:07.264: //3610/D48C17148501/H323/cch323_set_dtmf_iw_enabled: negotiated dtmf relay: 0, dtmf_iw_enabled: 0, dtmf_sccp_enabled: 0
005334: *Aug 25 23:44:07.264: //3610/D48C17148501/H323/cch323_caps_ind: gw_id=1
005335: *Aug 25 23:44:07.264: //3610/D48C17148501/H323/cch323_peer_caps_ind_common: Load DSP with Preferred codec(16) g729r8, Bytes=20
005336: *Aug 25 23:44:07.264: //3610/D48C17148501/H323/cch323_peer_caps_ind_common: Set DSP for dtmf-relay = CC_CAP_DTMF_RELAY_INBAND_VOICE
005337: *Aug 25 23:44:07.396: TCP0: ACK timeout timer expired
005338: *Aug 25 23:44:07.448: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 2 Event 0x1
005339: *Aug 25 23:44:07.448: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: owner_data=0x46DA9F30, len=53, msgPtr=0x475C62BC
005340: *Aug 25 23:44:07.448: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: Received msg for H.225

I was a bit surprised as to why G729 codec was negotiated when the whole path is G711. Even the SIP trunk was in all-G711 region.

Looking closely at dial-peers I found what was missing!! The VOIP dial-peers were missing the “Voice class codec 1” command which had G711 as priority 1 codec. As the command was not there, the call was matching dial-peer 0 and hence negotiating G729 codec. I added the command and the problem was solved. I can now hear ring back tone as well as all automated messages.

This is how it looks after I made the changes:

005935: *Aug 26 00:15:26.432: //3620/349708E58506/H323/h323_open_rtp_stream: Media In-active notification object not attached to ccb
005936: *Aug 26 00:15:26.432: //3620/349708E58506/H323/cch323_set_dtmf_iw_enabled: negotiated dtmf relay: 0, dtmf_iw_enabled: 0, dtmf_sccp_enabled: 0
005937: *Aug 26 00:15:26.432: //3620/349708E58506/H323/cch323_caps_ind: gw_id=1
005938: *Aug 26 00:15:26.432: //3620/349708E58506/H323/cch323_peer_caps_ind_common: Load DSP with Preferred codec(5) g711ulaw, Bytes=160
005939: *Aug 26 00:15:26.432: //3620/349708E58506/H323/cch323_peer_caps_ind_common: Set DSP for dtmf-relay = CC_CAP_DTMF_RELAY_INBAND_VOICE
005940: *Aug 26 00:15:26.568: TCP0: ACK timeout timer expired
005941: *Aug 26 00:15:26.620: //-1/xxxxxxxxxxxx/H323/cch323_ct_main: SOCK 2 Event 0x1
005942: *Aug 26 00:15:26.620: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: owner_data=0x46DAB900, len=53, msgPtr=0x475C5200
005943: *Aug 26 00:15:26.620: //-1/xxxxxxxxxxxx/H323/cch323_gw_process_read_socket: Received msg for H.225
005944: *Aug 26 00:15:26.620: H225.0 INCOMING ENCODE BUFFER::= 28501900060008914A0005003497A50DEE3911E19D37B87571A7872310800100
005945: *Aug 26 00:15:26.620:
005946: *Aug 26 00:15:26.620: H225.0 INCOMING PDU ::=

Most of the time problems like these are Codec or MRG related so it’s always a good idea to start checking your codecs first.