CUCM 8.6 Dropped call transfers involving SIP phones

[lesliemcgann]

Hi All,

I am a developer who has been tasked with figuring out why call transfers are being dropped by Cisco CUCM when the original call comes from a SIP phone.  This scenario works:

Cisco phone calls another Cisco phone, which transfers the original call to a SIP phone

These scenarios do not work:

SIP phone calls Cisco phone, which transfers the original call to another Cisco phone

SIP phone calls Cisco phone, which transfers the original call to another SIP phone

I have researched the Call Manager traces to the best of my ability, and I see some info in there that could potentially point to the source of the problem.  I am just unable to understand what the trace means:

10:23:08.672 |//SIP/SIPCdpc(1,74,2342)/ci=24377698/ccbId=175645/scbId=0/active_CcDisconnReq: ccDisconnReq.onBehalfOf=Media : ccDisconnReq.s.sv=2 : ccDisconnReq.c.cv=47 |1,100,63,1.93259^10.10.10.85^*

10:23:08.672 |//SIP/Stack/Info/0x0/sipConstructContainerContext #### Created container=0xb0b42f58|1,100,71,1.1^*^*

10:23:08.672 |//SIP/SIPCdpc(1,74,2342)/ci=24377698/ccbId=175645/scbId=0/appendReasonHdr: appendReasonHdr - Invalid Disconnect Cause(cause=47), No Reason Header Appended|1,100,63,1.93259^10.10.10.85^*

10:23:08.672 |//SIP/SIPCdpc(1,74,2342)/ci=24377698/ccbId=175645/scbId=0/appendRPIDHdrForOriginalCalledParty: SIP device does not Support Orig Dialled Phone nego: 0|1,100,63,1.93259^10.10.10.85^*

I have been wondering whether this could be a codec issue, however the SIP phones we are using are configured with the following codecs:

G711U

G711A

G722

ILBC

GSM

and our SIP software is  also set to accept the first codec offered by the remote side.  It seems from the SIP client logs that G722 is being used as the codec to communicate with the Cisco phones, but perhaps I'm misinterpreting.

I have attached a CUCM trace of a call from a SIP phone (ext. 491) to a Cisco handset (ext. 170) where the Cisco handset attempts to transfer the call to another SIP phone (ext. 492).  The trace snippet shown above is from this log.

I would really appreciate it if someone more experienced with VoIP/SIP/CUCM could take a look and offer any ideas on what the issue might be, and also how we might be able to address it.  I can try to provide more info about our CUCM configuration if needed.

Thanks in advance!

[paolo bevilacqua]

In a nutshell... Cisco does not support third party SIP phones (altough it asks that you pay licenses to use them).

If that is what you have, and your objective is to have things work good and realiably, avoid using them, and use Cisco SCCP phones only.

On the other hand if your SIP phones are Cisco, I would suggest that you convert them to SCCP if possible, and if they do not support SCCP at all, give the case to the TAC.

[lesliemcgann]

Hi Paolo,

Thanks for your reply.  My company's product includes SIP calling capability, and is actually used by various customers with various PBXs (Cisco, Vertical Wave, Avaya, etc.).  It is intended to run on non-proprietary mobile devices, so just using Cisco phones is not an option for us.  I hope that we can ultimately get our SIP calling working reliably with Cisco.

[Ayodeji Okanlawon]

Leslie,

I had a look at your trace files...Here is what I see..

+++++Call Elements++++++++++++

CUCM IP add: 10.10.10.195

sip phone :491 IP =10.10.10.99 (device=SEP000000000491)

SCCP Phone: 170---10.10.10.139 (SEP00233341D66C)

sip phone 492: 10.10.10.85

+++++++Call was established using G722 on both legs..here is the ACK to the transfer to 492+++++++++++++

10:22:51.892 |//SIP/SIPTcp/wait_SdlSPISignal: Outgoing SIP TCP message to 10.10.10.85 on port 52609 index 1361
[836111,NET]
ACK sip:492@10.10.10.85:52609;transport=tcp SIP/2.0
Via: SIP/2.0/TCP 10.10.10.195:5060;branch=z9hG4bK1f8052336f72
From: <170>;tag=175645~d8e94532-127d-4dca-bba0-64b1675da032-24377698
To: <492>;tag=C28C66CD8FA357BD9F8B3E2B70FC8658
Date: Tue, 12 Feb 2013 15:22:47 GMT
Call-ID: cde0300-11a15e47-1b09-c30a0a0a@10.10.10.195
Max-Forwards: 70
CSeq: 101 ACK
Allow-Events: presence
Content-Type: application/sdp
Content-Length: 237

v=0
o=CiscoSystemsCCM-SIP 175645 1 IN IP4 10.10.10.195
s=SIP Call
c=IN IP4 10.10.10.139--------------------------------IP of sccp phone
b=TIAS:64000
b=AS:64
t=0 0
m=audio 31536 RTP/AVP 9 101
a=rtpmap:9 G722/8000---------------------------------G722 negotiated
a=ptime:20
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

+++++++++++++++Now here is where it broke+++++++++++++++++

When the transfer was commited, we get an error on the Media manager..The reason is this...

10:22:56.591 |DET-MediaExchange-(695)::wait_ErrorReport, Moh Ann connect error for SIP, reConnect=0, reason=1|1,100,63,1.93253^10.10.10.99

10:22:55.631 |StationInit: (0003336) SoftKeyEvent softKeyEvent=4(Trnsfer) lineInstance=1 callReference=24377696.|1,100,13,4650.3373^10.10.10.139^SEP00233341D66C

10:22:55.631 |StationD:    (0003336) processTwoHitFeature - INFO: call=24377696 on line=1 fid=4.|1,100,13,4650.3373^10.10.10.139^SEP00233341D66C

10:22:55.631 |StationD:    (0003336) processTwoHitFeature - DBUG: cdpc=440 is linked to cdpc=439 and linkIsPrm=1.|1,100,13,4650.3373^10.10.10.139^SEP00233341D66C

10:22:55.631 |StationD:    (0003336) SelectSoftKeys instance=1 reference=24377696 softKeySetIndex=5 validKeyMask=fffffffb.|1,100,13,4650.3373^10.10.10.139^SEP00233341D66C

10:22:55.632 |StationD:    (0003336) setCcInfoPartyEntranceTone - (partyEntranceTone=2, ServiceParameter(tone)=true)|1,100,13,4650.3373^10.10.10.139^SEP00233341D66C

10:22:55.632 |Cdcc - (0001697) - dumpSecureStatus - sideA=(cap=1,1, media=0,0, feature=0,0), sideB=(cap=1,1 media=0,0, feature=0,0)|1,100,13,4650.3373^10.10.10.139^SEP00233341D66C

10:22:55.632 |Cdcc - (0001697) - updateDchanCrp - secure capability on side 1 is (1,1)|1,100,13,4650.3373^10.10.10.139^SEP00233341D66C

10:22:55.632 |Cdcc - (0001697) - dumpSecureStatus - sideA=(cap=1,1, media=0,0, feature=0,0), sideB=(cap=1,1 media=0,0, feature=0,0)|1,100,13,4650.3373^10.10.10.139^SEP00233341D66C

10:22:55.632 |TransferManager: SsInfoInd : init transfer,XFERringPriSsPty=24377696, XFERringPtyDslAddr (0,0,10.10.10.139,0), XFERringPtyPID (1,164,8500),XFERredSsPty=24377698, XFERredPtyDslAddr (0,0,10.10.10.85,52609), XFERredPtyPID (0,0,0), transactionId=16777252|*^*^*

10:22:55.632 |TransferManager: SsInfoInd : complete transfer,TransferringSecondarSsParty=24377696, TransferringPartyDslAddr (0,0,10.10.10.139,0), TransferringPartyPID (1,164,8500),TransferDestinationSsParty=24377698, TransferDestinationDslAddr (0,0,10.10.10.85,52609), TransferDesinatonPID (0,0,0), transactionId=16777252|*^*^*

10:22:56.591 |DET-MediaExchange-(695)::expectedWayPathEstablised, connType(1,2,3), sdpMode(0,0), path(1), ret(0)|1,100,63,1.93253^10.10.10.99^*

10:22:56.591 |DET-MediaExchange-(695)::wait_ErrorReport, Moh Ann connect error for SIP, reConnect=0, reason=1|1,100,63,1.93253^10.10.10.99^*

10:22:56.591 |!!ERROR!! -MediaManager-(717)::wait_AuConnectErrorInd, mCleanupPreallocatedMTP=0|1,100,63,1.93253^10.10.10.99^*

10:22:56.591 |!!ERROR!! -MediaManager-(717)::wait_AuConnectErrorInd, send disconn to 1 MXs|1,100,63,1.93253^10.10.10.99^*

10:22:56.591 |!!ERROR!! -MediaManager-(717)::handleAuConnectErrorInd, auConnectRequestMsg party video capable (1=0, 2=0), ConnecterrorInd p

+++++++++ Action Plan +++++++++++++

What I think is going on is this...

When 491 (SIP Phone on 10.10.10.99) called 170, When 170 attempted to transfer the call, 491 will be out on hold and MOH will be played to it. I think this is where this is failing. CUCM is unable to play MOH to the phone during the transfer..hence the error "Moh Ann connect error for SIP, reConnect=0, reason=1|1,100,63,1.93253^10.10.10.99^*

Possible causes: MOH server not enabled for G722

                         No MOH server in the MRGL for SIP phone 491.

NB: By default CUCM MOH server is only enabled for G711ulaw (from memory).

You can either disable G722 in your cluster or enable MOH server to support G722 codec. You can enable MOH to use G722 by doing this from CUCM>Enterprise Parameter>IP Voice streaming Media service....Then select G722 as one of the codecs to use in addition to the already selected codecs

Please rate all useful posts

"opportunity is a haughty goddess who waste no time with those who are unprepared"

[lesliemcgann]

Hi aokanlawon,

Thank you very much for looking into my issue.  Your interpretation of what could be happening makes a lot of sense, and I will try out the solutions you recommended (either disabling G722 or enabling the MOH server to support G722).  I probably will not be able to try this until Tuesday as tomorrow is a holiday for us, but will definitely post back with the results.

[Ayodeji Okanlawon]

Leslie.

Just an update for you. CUCM MOH does not support G722..

What codecs does the Cisco CallManager Music On Hold (MOH) server support?

A. These audio codecs are supported by the Cisco CallManager MOH server:

• G.711 u-law.

  
  

• G.711 a-law.

  
  

• G.729 Annex A (G.729A).

  
  

• Wideband - uncompressed (proprietary 16-bit resolution and 16 kHz sampled audio).

  
  

I suggest as a test, you disable G722 in the CUCM Enterprise parameters and see if that works

Please rate all useful posts

"opportunity is a haughty goddess who waste no time with those who are unprepared"

[lesliemcgann]

Hi aokanlawon,

I wasn't able to figure out how to disable G.722 in the CUCM admin settings, so instead I disabled it on the SIP phone I used to initiate the call, then I ran this test:

SIP phone (ext. 492) calls Cisco handset (ext. 170) which transfers the call to another Cisco handset (ext. 160)

The call from the SIP phone now uses G.711u, and I now hear music on hold, which seems to be progress.  But the transfer still does not succeed (trace attached).  Both calls stay open with the transferrer (ext. 170), and the transferrer's handset displays the message "Cannot complete transfer".

I looked at the trace for an indication of what is happening now, but I am unable to find anything enlightening.

I would be very grateful for any suggestions!

[lesliemcgann]

By pure chance, I seem to have fixed the issue.  I enabled Media Termination Point Required on the SIP device, and the transfer started working.

Thanks!

[Ayodeji Okanlawon]

Leslie,

Thanks for the update. Hmmm..I wont advise going down MTP route, perhaps its because this is a 3rd party phone. I will look at the logs and see if we can find an alternativ to using MTP

Please rate all useful posts

"opportunity is a haughty goddess who waste no time with those who are unprepared"

[Ayodeji Okanlawon]

Leslie,

I looked at the  logs and here is what I see...

2:39:12.727 |StationD:    (0003373) (1,100,13,5146) CallInfo callingPartyName='Leslie2' callingParty=492 cgpnVoiceMailbox=    alternateCallingParty= 492    calledPartyName='' calledParty=170 cdpnVoiceMailbox=    originalCalledPartyName='' originalCalledParty=170 originalCdpnVoiceMailbox= originalCdpnRedirectReason=0    lastRedirectingPartyName='' lastRedirectingParty=170 lastRedirectingVoiceMailbox= lastRedirectingReason=0    callType=1(InBound) lineInstance=1 callReference=24378215. version: 85600010|1,100,13,5146.216^10.10.10.139^SEP00233341D66C

12:39:12.727 |StationD:    (0003373) DisplayNotify timeOutValue=10 notify='€R' content='Cannot Complete Transfer' ver=85600010.|1,100,13,5146.216^10.10.10.139^SEP00233341D66C

So CUCM is telling the phone its unable to complete the trannsfer and you will then see that displayed on the phone..The sad thing is CUCM doesnt tell us why..but like you have figured out its due to MTP...

Will try and figure out why CUCM needed MTP for this transfer

Can you send me a trace with a succesful call please..I will like to compare

Please rate all useful posts

"opportunity is a haughty goddess who waste no time with those who are unprepared"

[lesliemcgann]

Hi aokanlawon,

I was also doing some research and found out that using the MTP Required setting to resolve the transfer issue is a superficial solution, as you suggested. If possible, I would like to discover the underlying cause for the dropped transfers, and be able to resolve it without relying on MTP Required. I really appreciate your help.

I've attached two trace files that I hope will be helpful. One (CiscoLog_MTP.txt) shows a successful call transfer with MTP Required enabled for the SIP devices (SIP phone (ext. 491) calls Cisco phone (ext. 170), which transfers the call to another SIP phone (ext. 492)). The other (CiscoLog_CiscoToCiscoToSIP.txt) shows a successful call transfer where the SIP device acting as the "destination" of the transfer does not use MTP Required (Cisco phone (ext. 160) calls another Cisco phone (ext. 170), which transfers the call to a SIP phone (ext. 492)). As I mentioned in the original post, the call transfer works when the SIP phone is the "destination" of the transfer, but not when it is the "source" (original caller).

Once again, thank you for looking into this!

[Ayodeji Okanlawon]

Can you please re-send the files. There seems to be roblems with them, as cisco website is complaining of a virus on them

Please rate all useful posts

"opportunity is a haughty goddess who waste no time with those who are unprepared"

[lesliemcgann]

Hi,

Trying to attach both logs in a single zip file...

[Ayodeji Okanlawon]

Leslie,

I am not sure whats going on with the files..But I cant open this one either. Maybe you should attach then individually..Try and scan your pc, ensure you dont have a virus

Please rate all useful posts

"opportunity is a haughty goddess who waste no time with those who are unprepared"

[lesliemcgann]

The files were created in TextWrangler on a Mac, and I seriously doubt they contain any viruses.  I scanned both of the log files at virustotal.com, and they are both clean.  Trying again...  If this doesn't work, I could try exporting them to PDF for viewing, although it's not as easy to work with as text.

Thanks...