Re: CUCM SIP trunk incoming call reject - No CUBE

jasonrothwell · ‎07-24-2022

I know it's not recommended, but this is in a lab environment. I have CUCM connected directly to a SIP trunk provider and outgoing calls work fine. Incoming calls are getting rejected. I have the appropriate translation in place and have verified the trunk settings. Below is the log:

2022/07/24 22:18:01.594|SIPT|0|UDP|IN|10.10.30.10|5060|ToBV|206.15.130.13|5060|1,100,230,1.9142^206.15.130.13^*|33319|0gQAAC8WAAACBAAALxYAAJxBZ8EZSkAokT1hYqU/5/aJaiEYuRn7M4+rJZz/44YU@206.15.130.13|INVITE
2022/07/24 22:18:01.594|SIPT|0|UDP|OUT|10.10.30.10|5060|ToBV|206.15.130.13|5060|1,100,230,1.9142^206.15.130.13^*|33320|0gQAAC8WAAACBAAALxYAAJxBZ8EZSkAokT1hYqU/5/aJaiEYuRn7M4+rJZz/44YU@206.15.130.13|100 Trying
2022/07/24 22:18:01.596|SIPT|23980638|UDP|OUT|10.10.30.10|5060|ToBV|206.15.130.13|5060|1,100,230,1.9142^206.15.130.13^*|33321|0gQAAC8WAAACBAAALxYAAJxBZ8EZSkAokT1hYqU/5/aJaiEYuRn7M4+rJZz/44YU@206.15.130.13|404 Not Found
2022/07/24 22:18:01.804|SIPT|23980638|UDP|IN|10.10.30.10|5060|ToBV|206.15.130.13|5060|1,100,230,1.9143^206.15.130.13^*|33322|0gQAAC8WAAACBAAALxYAAJxBZ8EZSkAokT1hYqU/5/aJaiEYuRn7M4+rJZz/44YU@206.15.130.13|ACK
2022/07/24 22:18:01.804|CC|REJECT|23980638|23980639|6033156508|6037822792@50.195.28.117|6037822792@50.195.28.117|1

I'm not concerned about exposing my IP address as there is a firewall only allowing access from the SIP trunk provider. 10.10.30.10 is CUCM, 50.195.28.117 is CUCM NAT'd public IP, 206.15.130.13 is the SIP trunk provider IP address.

Any help would be appreciated.

Thanks,
Jason

Roger Kallberg · ‎07-24-2022

Looks like you get a 404 Not Found, so the call is not really rejected, it fails because it doesn’t find the called number. Not sure what type of log that is, but it doesn’t seem to show relevant parts such as called number and a bunch more. I guess that you would get a better idea of what is causing the call to not work if you look at the SDL logs in CM.

jasonrothwell · ‎07-25-2022

Thanks for the reply. These logs are from the CM. They include the called and the calling number (6033156508|6037822792@50.195.28.117). The called number is 6037822792 and the extension is 2792. I have a translation pattern that maps 6037822792 to 2792.

Roger Kallberg · ‎07-25-2022

If this is logs from CM there are much more detailed information that pertains to the SIP dialogue that you’ll find in the SDL logs.

IP 50.195.28.117 in your last reply that is seen after the @ sign would likely not be an IP that you CM would identify as belonging to it. With address translation and SIP you’ll need to have an firewall that modifies the content of the fields in the SIP dialog from the public IPs to the private IPs. Otherwise the signalling will not work. With a SBC, like Cube, you could do that modification in it. For a Cisco SBC you would use SIP profiles for this modification.

jasonrothwell · ‎07-25-2022

Thanks again.

I configured a CUBE router and looks like I may be having a similar issue, except now I'm getting 403 Forbidden. It doesn't seem like it's making it to the CUCM. Here is the log from the CUBE:

002708: Jul 25 2022 12:56:05.520 edt: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
INVITE sip:6037822792@50.195.28.117:5060;transport=udp SIP/2.0
Via: SIP/2.0/UDP 206.15.130.13:5060;branch=z9hG4bK+9a51504ed82f50a6e28c3e5d9cbf406d1+sip+3+c165d450
From: "HARMONIC DRIVE " <sip:6033156508@206.15.130.13:5060>;tag=206.15.130.13+3+bf42ea1c+a67c97f2
To: <sip:6037822792@50.195.28.117>
CSeq: 815469751 INVITE
Expires: 180
Content-Length: 197
Call-Info: <sip:206.15.130.13:5060>;method="NOTIFY;Event=telephone-event;Duration=2000"
Supported: resource-priority,siprec, 100rel
Contact: <sip:6033156508@206.15.130.13:5060>
Content-Type: application/sdp
Allow-Events: message-summary, refer, dialog, line-seize, presence, call-info, as-feature-event, calling-name, ua-profile
Call-ID: 0gQAAC8WAAACBAAALxYAAGpvdbu+UeGy4tCM01VKk3MRJQJ8D2X9hjIMpKNJhZii@206.15.130.13
Organization: Metaswitch Networks
Max-Forwards: 66
Accept: application/sdp, application/dtmf-relay

v=0
o=- 26927162959368 26927162959368 IN IP4 206.15.130.13
s=-
c=IN IP4 206.15.130.13
t=0 0
m=audio 51860 RTP/AVP 0 18 100
a=rtpmap:100 telephone-event/8000
a=fmtp:18 annexb=no
a=ptime:20

SIP: (178) Attribute mid, level 1 instance 1 not found.
002709: Jul 25 2022 12:56:05.520 edt: //178/81CC2BC880F1/SIP/Error/sipSPI_ipip_update_codec_params_in_channelInfo:
failed to update call entry
002710: Jul 25 2022 12:56:05.520 edt: //178/81CC2BC880F1/SIP/Error/sipSPI_ipip_upd_2833_dtmf_params: Unable to find proper instance for FMTP
SIP: (178) fmtp attribute, level 1 instance 0 not found.
002711: Jul 25 2022 12:56:05.520 edt: //178/81CC2BC880F1/SIP/Error/sipSPI_ipip_upd_2833_dtmf_params: Unable to acquire event mask for rfc2833
002712: Jul 25 2022 12:56:05.520 edt: //178/81CC2BC880F1/SIP/Error/sipSPI_ipip_update_call_entry:
failed to update call entry
002713: Jul 25 2022 12:56:05.520 edt: //-1/xxxxxxxxxxxx/SIP/Error/sipSPI_ipip_set_channel_count: Unable to set CHANNEL_COUNT for callid 178
002714: Jul 25 2022 12:56:05.520 edt: //178/81CC2BC880F1/SIP/Error/sip_iwf_sip_copy_sdp_to_channelInfo: Channel count is not set at this point. Not SIP-SIP or SET_MODE is not done.
002715: Jul 25 2022 12:56:05.520 edt: //-1/81CC2BC880F1/CCAPI/cc_api_display_ie_subfields:
cc_api_call_setup_ind_common:
cisco-username=6033156508
----- ccCallInfo IE subfields -----
cisco-ani=6033156508
cisco-anitype=0
cisco-aniplan=0
cisco-anipi=0
cisco-anisi=0
dest=6037822792
cisco-desttype=0
cisco-destplan=0
cisco-rdie=FFFFFFFF
cisco-rdn=
cisco-rdntype=0
cisco-rdnplan=0
cisco-rdnpi=-1
cisco-rdnsi=-1
cisco-redirectreason=-1 fwd_final_type =0
final_redirectNumber =
hunt_group_timeout =0

002716: Jul 25 2022 12:56:05.524 edt: //-1/81CC2BC880F1/CCAPI/cc_api_call_setup_ind_common:
Interface=0x2B1F2788, Call Info(
Calling Number=6033156508,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
Called Number=6037822792(TON=Unknown, NPI=Unknown),
Calling Translated=FALSE, Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE,
Incoming Dial-peer=3, Progress Indication=NULL(0), Calling IE Present=TRUE,
Source Trkgrp Route Label=, Target Trkgrp Route Label=, CLID Transparent=FALSE), Call Id=178
002717: Jul 25 2022 12:56:05.524 edt: //-1/81CC2BC880F1/CCAPI/ccCheckClipClir:
In: Calling Number=6033156508(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
002718: Jul 25 2022 12:56:05.524 edt: //-1/81CC2BC880F1/CCAPI/ccCheckClipClir:
Out: Calling Number=6033156508(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
002719: Jul 25 2022 12:56:05.524 edt: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

002720: Jul 25 2022 12:56:05.524 edt: :cc_get_feature_vsa malloc success
002721: Jul 25 2022 12:56:05.524 edt: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

002722: Jul 25 2022 12:56:05.524 edt: cc_get_feature_vsa count is 1
002723: Jul 25 2022 12:56:05.524 edt: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

002724: Jul 25 2022 12:56:05.524 edt: :FEATURE_VSA attributes are: feature_name:0,feature_time:806282696,feature_id:13
002725: Jul 25 2022 12:56:05.524 edt: //178/81CC2BC880F1/CCAPI/cc_api_call_setup_ind_common:
Set Up Event Sent;
Call Info(Calling Number=6033156508(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
Called Number=6037822792(TON=Unknown, NPI=Unknown))
002726: Jul 25 2022 12:56:05.524 edt: //178/81CC2BC880F1/CCAPI/cc_process_call_setup_ind:
Event=0x3152AF70
002727: Jul 25 2022 12:56:05.524 edt: //-1/xxxxxxxxxxxx/CCAPI/cc_setupind_match_search:
Try with the demoted called number 6037822792
002728: Jul 25 2022 12:56:05.524 edt: //178/81CC2BC880F1/CCAPI/ccCallSetContext:
Context=0x2AB8173C
002729: Jul 25 2022 12:56:05.524 edt: //178/81CC2BC880F1/CCAPI/cc_process_call_setup_ind:
>>>>CCAPI handed cid 178 with tag 3 to app "_ManagedAppProcess_TOLLFRAUD_APP"
002730: Jul 25 2022 12:56:05.524 edt: //178/81CC2BC880F1/CCAPI/ccCallDisconnect:
Cause Value=21, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=0)
002731: Jul 25 2022 12:56:05.524 edt: //178/81CC2BC880F1/CCAPI/ccCallDisconnect:
Cause Value=21, Call Entry(Responsed=TRUE, Cause Value=21)
002732: Jul 25 2022 12:56:05.524 edt: //178/81CC2BC880F1/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 206.15.130.13:5060;branch=z9hG4bK+9a51504ed82f50a6e28c3e5d9cbf406d1+sip+3+c165d450
From: "HARMONIC DRIVE " <sip:6033156508@206.15.130.13:5060>;tag=206.15.130.13+3+bf42ea1c+a67c97f2
To: <sip:6037822792@50.195.28.117>
Date: Mon, 25 Jul 2022 16:56:05 GMT
Call-ID: 0gQAAC8WAAACBAAALxYAAGpvdbu+UeGy4tCM01VKk3MRJQJ8D2X9hjIMpKNJhZii@206.15.130.13
CSeq: 815469751 INVITE
Allow-Events: telephone-event
Server: Cisco-SIPGateway/IOS-12.x
Content-Length: 0

002733: Jul 25 2022 12:56:05.524 edt: //178/81CC2BC880F1/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 403 Forbidden
Via: SIP/2.0/UDP 206.15.130.13:5060;branch=z9hG4bK+9a51504ed82f50a6e28c3e5d9cbf406d1+sip+3+c165d450
From: "HARMONIC DRIVE " <sip:6033156508@206.15.130.13:5060>;tag=206.15.130.13+3+bf42ea1c+a67c97f2
To: <sip:6037822792@50.195.28.117>;tag=459C2C-6FF
Date: Mon, 25 Jul 2022 16:56:05 GMT
Call-ID: 0gQAAC8WAAACBAAALxYAAGpvdbu+UeGy4tCM01VKk3MRJQJ8D2X9hjIMpKNJhZii@206.15.130.13
CSeq: 815469751 INVITE
Allow-Events: telephone-event
Server: Cisco-SIPGateway/IOS-12.x
Reason: Q.850;cause=21
Content-Length: 0

002734: Jul 25 2022 12:56:05.620 edt: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
ACK sip:6037822792@50.195.28.117:5060;transport=udp SIP/2.0
Via: SIP/2.0/UDP 206.15.130.13:5060;branch=z9hG4bK+9a51504ed82f50a6e28c3e5d9cbf406d1+sip+3+c165d450
From: "HARMONIC DRIVE " <sip:6033156508@206.15.130.13:5060>;tag=206.15.130.13+3+bf42ea1c+a67c97f2
To: <sip:6037822792@50.195.28.117>;tag=459C2C-6FF
CSeq: 815469751 ACK
Content-Length: 0
Call-ID: 0gQAAC8WAAACBAAALxYAAGpvdbu+UeGy4tCM01VKk3MRJQJ8D2X9hjIMpKNJhZii@206.15.130.13
Max-Forwards: 66

002735: Jul 25 2022 12:56:05.620 edt: //178/81CC2BC880F1/CCAPI/cc_api_call_disconnect_done:

MA-HQ-VG01#Disposition=0, Interface=0x2B1F2788, Tag=0x0, Call Id=178,
Call Entry(Disconnect Cause=21, Voice Class Cause Code=0, Retry Count=0)
002736: Jul 25 2022 12:56:05.620 edt: //178/81CC2BC880F1/CCAPI/cc_api_call_disconnect_done:
Call Disconnect Event Sent
002737: Jul 25 2022 12:56:05.620 edt: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

002738: Jul 25 2022 12:56:05.620 edt: :cc_free_feature_vsa freeing 300EE5C0
002739: Jul 25 2022 12:56:05.620 edt: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

002740: Jul 25 2022 12:56:05.620 edt: vsacount in free is 0

These are my dial peers on the CUBE:

dial-peer voice 1 voip
description incoming dial-peer from CUCM to CUBE
session protocol sipv
session transport udp
incoming called-number .T
voice-class codec 1
dtmf-relay rtp-nte
no vad

dial-peer voice 2 voip
description outgoing dial-peer from CUBE to CUCM
destination-pattern [2-9].........
session protocol sipv
session target ipv4:10.10.30.10
session transport udp
voice-class codec 1
voice-class sip options-keepalive
dtmf-relay rtp-nte
no vad

dial-peer voice 3 voip
description incoming dial-peer from BV to CUBE
no translation-profile incoming DID
session protocol sipv
session transport udp
incoming called-number [2-9].........
voice-class codec 1
dtmf-relay rtp-nte
no vad

dial-peer voice 4 voip
description outgoing dial-peer from CUBE to BV
destination-pattern .T
session protocol sipv
session target sip-server
session transport udp
voice-class codec 1
voice-class sip asserted-id pai
voice-class sip options-keepalive
dtmf-relay rtp-nte
no vad

Roger Kallberg · ‎07-25-2022

Have you created and applied the needed SIP profiles to handle the transformation of the public IP to the private IP?

Apart from this I would recommend you to use the information in the VIA header to match on your inbound dial peers as that is a much better option to use than incoming called number. Have a look at this excellent document for more details on how to route calls in IOS. https://www.cisco.com/c/en/us/support/docs/voice/ip-telephony-voice-over-ip-voip/211306-In-Depth-Explanation-of-Cisco-IOS-and-IO.html

jasonrothwell · ‎07-26-2022

Thanks. Yes, I have created the SIP profiles below, I believe they are global, but still not working. I'll look at changing the inbound dial peer matching.

voice class sip-profiles 1
request ANY sip-header Contact modify "10.10.30.11" "50.195.28.117"
request ANY sip-header Contact modify "10.10.30.11" "206.15.130.13"
response ANY sdp-header Audio-Connection-Info modify "10.10.30.11" "50.195.28.117"
response ANY sdp-header Connection-Info modify "10.10.30.11" "50.195.28.117"
response ANY sdp-header Session-Owner modify "10.10.30.11" "50.195.28.117"
request ANY sdp-header Audio-Connection-Info modify "10.10.30.11" "50.195.28.117"
request ANY sdp-header Connection-Info modify "10.10.30.11" "50.195.28.117"
request ANY sdp-header Session-Owner modify "10.10.30.11" "50.195.28.117"
response ANY sdp-header Audio-Connection-Info modify "10.10.30.11" "206.15.130.13"
response ANY sdp-header Connection-Info modify "10.10.30.11" "206.15.130.13"
response ANY sdp-header Session-Owner modify "10.10.30.11" "206.15.130.13"
request ANY sdp-header Audio-Connection-Info modify "10.10.30.11" "206.15.130.13"
request ANY sdp-header Connection-Info modify "10.10.30.11" "206.15.130.13"
request ANY sdp-header Session-Owner modify "10.10.30.11" "206.15.130.13"

Roger Kallberg · ‎07-26-2022

AFAIK You’ll need to have one SIP profile for inbound traffic from your ITSP and another for outbound to your ITSP. So you cannot use the SIP profile with global configuration in the voice service voip section. Search for how to configure Direct Routing for Microsoft Teams calling with Cube as the SBC for an idea of how to configure this.

jasonrothwell · ‎07-27-2022

Thank you very much for all the help this far. I decided to bypass the CUBE again and go direct SIP Trunk to CUCM. I configured the ASA to deal with the public IP address NAT issue and I've gotten further, but stuck here. The CUCM reports the phone is ringing, but the phone never rings. This only happens external to internal calls, internal ext to ext work fine and outbound calls work fine. See attached.

EDIT: The actual called phone is ringing, but the ringback on the calling phone is not being played. I researched this and it seems this can be resolved with a normalization script. I'm looking into trying that.

Roger Kallberg · ‎07-26-2022

This is the document that I referenced earlier.

https://www.cisco.com/c/dam/en/us/solutions/collateral/enterprise/interoperability-portal/direct-routing-with-cube.pdf

Namaka78 · ‎07-25-2022

I believe you get a 404 Not Found, this means that the call is not actually rejected, rather, it fails as a result of being unable to locate the called number.I'm not sure what type of log it is, but the calls and other relevant information do not appear.