CIPC sending Cancel after establishing a call

[Wonxie]

Hi

some users are facing issues with connecting a call. when they dial using cipc the cucm routes them via sip trunk for which i have attached one packet analysis and logs below. the caller says that the call rings and then he gets fast busy tone. the call reciever also complains of so.

10.65.102.11 is CUCM pub

10.65.12.3 is Router

*Dec 9 13:35:31.812: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
CANCEL sip:91xxxxxxxxxx@10.65.12.3:5060 SIP/2.0
Via: SIP/2.0/TCP 10.65.102.11:5060;branch=z9hG4bK5618a2904b5e
From: "UserX" <sip:2060@10.65.102.11>;tag=1029393~5f79ec65-2bba-42ae-995d-dd9649fc752b-49967349
To: <sip:91xxxxxxxxxx@10.65.12.3>
Date: Fri, 09 Dec 2022 14:44:06 GMT
Call-ID: ed2ec480-393149b6-545e1-b66410a@10.65.102.11
CSeq: 101 CANCEL
Max-Forwards: 70
Reason: Q.850;cause=47
Content-Length: 0

Timestamp: 3753437731812
UTC Timestamp:3753437731812
Source Filename: logs.txt

[Maren Mahoney · Accepted solution]

The behavior, plus the Q.850;cause=47 disconnect, indicates a codec negotiation issue. Specifically that no common codec is available based on the the Regions setting, device capabilities, and codec selection on the CUBE. I suggest examining the SDP exchange to see what is being offered, and if what is offered is supported on the call.

Looking at the ladder diagram, I'm guessing the problem might lie in the second INVITE offered by the CUBE after challenged by the service provider. Is what is offered there the same as what is offered in the initial INVITE on that call leg?

Maren

[Wonxie]

Hi Maren, 

Thanks for the input. I am a bit new to VoIP so i am budding atm so i will have to read more to find how exactly i can verify this as at the moment i do not know how to examine sdp exchanges and see that both sides agree on it.

regarding the second invite you mean the one INVITE w/SDP (102 INVITE) in the first teal color block ?

[Wonxie]

here is first INVITE SDP

v=0
o=CiscoSystemsCCM-SIP 1029393 1 IN IP4 10.65.102.11
s=SIP Call
c=IN IP4 10.65.102.10
t=0 0
m=audio 29200 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=ptime:20
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

here is second INVITE SDP

v=0
o=CiscoSystemsSIP-GW-UserAgent 9020 3260 IN IP4 2.2.2.2
s=SIP Call
c=IN IP4 2.2.2.2
t=0 0
m=audio 26782 RTP/AVP 0 101 19
c=IN IP4 2.2.2.2
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=rtpmap:19 CN/8000
a=ptime:20.

third INVITE

v=0
o=CiscoSystemsSIP-GW-UserAgent 9020 3260 IN IP4 2.2.2.2
s=SIP Call
c=IN IP4 2.2.2.2
t=0 0
m=audio 26782 RTP/AVP 0 101 19
c=IN IP4 2.2.2.2
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=rtpmap:19 CN/8000
a=ptime:20

Here is the first 183 response

v=0
o=BroadWorks 5511848467 1 IN IP4 y.y.y.y
s=-
c=IN IP4 y.y.y.y
t=0 0
m=audio 45924 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=bsoft: 1 image udptl t38
a=sendrecv
a=ptime:20

here is second 183 session proress 

v=0
o=CiscoSystemsSIP-GW-UserAgent 5778 4080 IN IP4 10.65.12.3
s=SIP Call
c=IN IP4 10.65.12.3
t=0 0
m=audio 26780 RTP/AVP 0 101
c=IN IP4 10.65.12.3
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20

[Scott Leport]

Hi,

Is the issue related to a group of users who have similar configurations?

Does the issue occur when dialled from a Cisco IP Phone?

If it works from an IP phone, but not from a CIPC, what's different? Do you have different Device Pool settings attached to the CIPC devices than what is attached to Cisco IP Phones?

If the settings between CIPC and IP Phones are different, try moving an affected CIPC from the Device Pool it's currently in to a known good working Device Pool (for example, one your IP phones might be in), apply the config and do the same test call. If it works, you've narrowed in on the issue. If it doesn't, it's a different issue.

If it doesn't work after that, please post the output of the debug ccsip messages command from your CUBE.

If it doesn't currently work from either CIPC or IP phone, avoid making any config changes and post the output of the ccsip messages command.

[Wonxie]

the problem is for few users of a team all have same setting.

they are working from home connected via company provided vpn to our data center so never tried hardphone. however configuring their softphone and using on un resrected network inside office also generates same probelm.

the gateway is a cisco router not CUBE.

I will coordinate with the concerned team and share the logs for debug ccsip messages

[Maren Mahoney]

Okay, so the media (m=) line in each of the INVITE messages provides for G711ulaw (that's the 0) and rtp-nte DTMF relay (that's the 101). The 19 is CN or 'comfort noise'. This means that the disconnect cause code of Q.850 cause=47 would not appear to be a codec negotiation issue as the same codec (G711ulaw) is supported on all call legs.

(While you may not have CUBE licensing on that gateway giving you the additional CUBE features, the fact that you have an inbound SIP dial peer connecting to an outbound SIP dial peer on that router means that is it acting as if it were a CUBE. So don't be surprised if it is referred to that way.)

Well, then....  So that I understand: This problem is occurring on CIPC phones at user's homes where they are VPNed in. Does it happen when these same users are on prem? Does it happen to any other category of user? Does it happen all the time, or only for certain category of calls?

Also: What is IP address 10.65.102.10? Is that the VPN terminator inside your facility or is that the IP issued to the user while they are VPNed in?

One thing that I could see being an issue with a VPN-based call is CUCM accepting the early media offer from the service provider. This setting is part of the SIP Profile associated with the trunk, specifically "SIP Rel1XX Options". That has been changed from the default of Disabled. It is likely that the Early Media cannot actually be established with the VPNed CIPC phones, so after the offer is accepted and RTP is attempted the call fails, and this would generate a Q.850 cause=47. It would be worth changing that setting back to the default of Disabled to see if that clears the problem.

Before you change the setting, you will want to investigate why it was changed from the default. (What this to accommodate some system like a contact center app? Or was it simply the 'style' of the implementing engineer to turn it on?) Also, if you do change the setting it will require a reset of the trunk, and in fact would cause a reset of all trunks that have that setting. If it is only this one trunk that needs to change you can copy the existing SIP Profile and create a new one with the changed setting for this one trunk. That would not disturb other trunks using the same profile.

I hope this is helpful information for your investigation. Let us know if you have more questions.

Maren

[Wonxie]

10.65.102.10/11 are my cucm servers.

10.65.12.3 is the router.

same issue when on prem

the issue started some 3 days ago . no change done on cucm/router acting as gateway .

sip early offer setting is not changed it has been so for ages .

one user having same settings can call flawlessly 3 users are facing this issue. he is connected to same vpn as the affected users.

i am running cucm8.6 and do not see an option for sip early offer on trunk nor do i see SIP Rel1XX Options. i will google it as well.

[Maren Mahoney]

This means that the initial INVITE is telling the CUBE to send the RTP stream to your CUCM server. Does that server have Media Termination Points registered? Do the affected phones have an MRGL that have access to the MTPs?

More to the point, if the problem began about 3 days ago what changed around that time in your environment? Something that changed may seem irrelevant, but is affecting the RTP. (Like an update to the VPN, an update to anything really.)

It may be that we'd need to see the CUCM side of the conversation via a Trace file, but I'm hoping another one of the folks here has an idea of what might be going on.)

Maren

[Scott Leport]

Hi,

Can you clarify what you mean by "same settings" please?

What changed a few days ago? Did the users on the affected CIPC ever work before? Are the working and non-working users registered to the same Call Manager and are they registered using the same signalling protocol (e.g. SCCP or SIP)?

The Early Offer and Rel1XX Options Maren refers to are on the SIP Profile (she did say that), not the SIP trunk. The SIP profile is attached to the SIP trunk (note any changes on the SIP trunk itself would require a reset of the trunk to take effect).

Also, if some users on CIPC can use the same SIP service without issue and others can't, it would suggest that there are some settings between the two CIPC configurations which are different. Different Device Pools as I mentioned before? That could influence which Call Manager they register to, depending on your CMG setup.

Possibly different MRGL settings between the affected and unaffected CIPCs, which will determine media resources they can access (MTPs, XCODERS, ANN etc...)

If you were to get some debugs from the CUBE and post up a working call and a non-working call, that would certainly fill in some blanks, but given that the CUBE is receiving a disconnect message from CUCM, that's where the troubleshooting needs to be focussed on.

[Wonxie]

i think  i was to early to say that unchecking the option to optimize for low bandwidth fixed it.

the issue still persists.

-working for some users and not working for others.

- working for users in one device pool with same MRGL and not working for others with same settings. 

- issue persists inside office and on vpn clients and on hardphone and softphone.

- all clients are sccp and it worked for them earlier. nothing changed on cucm i.e device pool,region,gatway,sip profile, sip trunk etc

- got below trace and rebooted the cluster still same issue.

539424142109:27:37.027 |!!ERROR!! -MediaManager-(12442)::disconnOnResourceAllocationFailure, ERROR  disconnOnResourceAllocationFailure - fails to allocate MTP/XCoder,connCount=3|2,200,21,1.2184634^10.65.102.20^CCX_2238

09:27:37.027 |DET-MediaManager-(12442)::disconnOnResourceAllocationFailure, send disconn to MX(2,17296) mrid(0 0)|2,200,21,1.2184634^10.65.102.20^CCX_2238

[Maren Mahoney]

Well, in your original post we noted the Q850 Cause 47, which usually indicates a codec mismatch (inability to negotiate a codec), and the above clearly indicates that a transcoder is needed to establish the RTP stream...meaning a common codec was not negotiated. If the problem is intermittent, it may mean that transcoders are used for all of these calls but sometimes all of the transcoders are in use and the 'next' call is denied. Or, there is a region problem that is as yet unnoticed. Or it may be that certain phones are requesting an MTP (like for DTMF relay or something) and none is available. I don't see that last one as likely, but it is on the list of "well...maybe".

At this point I'd need to look at a trace file of a problem call to see exactly what is going on. If you want to do that, let me know and we can exchange emails.

Maren

[Wonxie]

MTP is used and its CUCM software based and RFC2833 is enabled for inband DTMF.

So above issue is due to Transcoders ? the error message says MTP in it though.  and same MRGL is assigned to both device pools the problematic and the non problematic.

i have checked  in CUCM there are 2 Transcoders defined in CUCM ( Cisco IOS Enhanced Media Termination Point ) and they are assigned DP-DEN device pool .. the device pool on which users faced no issue. but looking at those two transcoders status  both are in "unknown status"

[Maren Mahoney]

A transcoder is a form of MTP. You'll note the error message said "MTP/XCoder"

The region relationship between the region of the originating phone and the region of the egress trunk is what you'd need to look at. As for what/why something changed...there is no way for me to know. But I have a theory: When you make a change to a region relationship in CUCM I find that the region itself must be reset on the region configuration page for the change to take effect. It may be that a relationship was changed a while back, but the reset did not happen until more recently. Just a possibility as a 'for instance'.

Regardless. You have identified the problem, which is a region relationship causing a codec mismatch. If transcoders are available in the MRGL for the phone and/or SIP trunk it may be that the resources are exhausted from time to time. Another possible issue is that your CUBE needs local transcode resources. Do a search for "cisco cube transcode LTI" and you'll see a bunch of documentation on it.

Maren

[Wonxie]

seems like i hit a luck .after discussion with the affected teams TL i found that it worked fine only for one user and most others it was mixed working.

i checked for the working user, he had different device pool and only difference was the Region settings. 

so the guys having the region where g729 was used were having issues . but the guy having g711 were fine. however i need to know why it happend all of sudden. 

screenshots of both regions attached. RG-Den works fine but Den-Remote does'nt.