CUCM returns internal service error for un-allocated numbers

Ayodeji Okanlawon · ‎11-21-2013

Setup...

ITSP----sip---CUBE1------sip----CUCM

------sip----CUBE2-----sip---CUCM

Calls come in via the ITSP to CUBE via SIP. CUBE then send the call to CUCM via sip signalling. This call is matched to a xlation pattern in CUCM, which then xlates the called number to an internal extension.

The issue that was brough to my attention recently is that when users dial an unallocated number within the DDI range, the calls go into a loop. So I pulled up the traces and to my horror, CUCM doesnt send un allocated/un assigned number back to CUBE rather cucm sends an internal service error...Hence CUBE continues to another dial-peer which matches the secondary CUCM and then finally tries another dial-peer which is for outbound calls to the ITSP. As a result of this, ITSP sends the call back to our CUBES and the call goes into a loop...An excerpt of the trace is shown below:

5668923: .Nov 21 10:26:04.120: //-1/xxxxxxxxxxxx/SIP/Msg/ccsipDisplayMsg:
Received:
INVITE sip:441115248457@192.168.40.54:5060 SIP/2.0
Via: SIP/2.0/UDP 10.106.38.24:5081;branch=z9hG4bKjk1ufl30dok1h9v7f070.1
From: <sip:08834433593@202.156.18.16:5060;user=phone>;tag=1919469313-1385029564105-
To: <sip:441115248457@pbx.emea.globalipcom.com>
Call-ID: BW102604105211113689361282@202.156.18.16
CSeq: 1025047397 INVITE
Contact: <sip:08834433593@10.106.38.24:5081;transport=udp>
Allow: ACK,BYE,CANCEL,INFO,INVITE,OPTIONS,PRACK,REFER,NOTIFY
Accept: application/media_control+xml,application/sdp,multipart/mixed
Supported:
Max-Forwards: 69
Content-Type: application/sdp
Content-Length: 206

v=0
o=BroadWorks 21539594 1 IN IP4 10.106.38.132
s=-
c=IN IP4 10.106.38.132
t=0 0
m=audio 18792 RTP/AVP 18 0 8 101
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=fmtp:18 annexb=no

5668924: .Nov 21 10:26:04.122: //-1/28D1E35FAE8C/CCAPI/cc_api_display_ie_subfields:
   cc_api_call_setup_ind_common:
   cisco-username=08834433593
   ----- ccCallInfo IE subfields -----
   cisco-ani=sip:08834433593@202.156.18.16:5060;user=phone
   cisco-anitype=0
   cisco-aniplan=0
   cisco-anipi=0
   cisco-anisi=0
   dest=sip:441115248457@192.168.40.54:5060
   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

5668925: .Nov 21 10:26:04.122: //-1/28D1E35FAE8C/CCAPI/cc_api_call_setup_ind_common:
   Interface=0x20E01378, Call Info(
   Calling Number=sip:08834433593@202.156.18.16:5060;user=phone,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
   Called Number=sip:441115248457@192.168.40.54:5060(TON=Unknown, NPI=Unknown),
   Calling Translated=FALSE, Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE,
   Incoming Dial-peer=1, Progress Indication=NULL(0), Calling IE Present=TRUE,
   Source Trkgrp Route Label=, Target Trkgrp Route Label=, CLID Transparent=FALSE), Call Id=11209976
5668926: .Nov 21 10:26:04.122: //-1/28D1E35FAE8C/CCAPI/ccCheckClipClir:
   In: Calling Number=sip:08834433593@202.156.18.16:5060;user=phone(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
5668927: .Nov 21 10:26:04.122: //-1/28D1E35FAE8C/CCAPI/ccCheckClipClir:
   Out: Calling Number=sip:08834433593@202.156.18.16:5060;user=phone(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
5668928: .Nov 21 10:26:04.122: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

5668929: .Nov 21 10:26:04.122: :cc_get_feature_vsa malloc success
5668930: .Nov 21 10:26:04.122: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

5668931: .Nov 21 10:26:04.122: cc_get_feature_vsa count is 179
5668932: .Nov 21 10:26:04.122: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

5668933: .Nov 21 10:26:04.122: :FEATURE_VSA attributes are: feature_name:0,feature_time:743075624,feature_id:8589877
5668934: .Nov 21 10:26:04.122: //11209976/28D1E35FAE8C/CCAPI/cc_api_call_setup_ind_common:
   Set Up Event Sent;
   Call Info(Calling Number=(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
   Called Number=(TON=Unknown, NPI=Unknown))
5668935: .Nov 21 10:26:04.122: //11209976/28D1E35FAE8C/CCAPI/cc_process_call_setup_ind:
   Event=0x229E6D50
5668936: .Nov 21 10:26:04.122: //-1/xxxxxxxxxxxx/CCAPI/cc_setupind_match_search:
   Try with the demoted called number 441115248457
5668937: .Nov 21 10:26:04.122: //11209976/28D1E35FAE8C/CCAPI/ccCallSetContext:
   Context=0x287E5458
5668938: .Nov 21 10:26:04.122: //11209976/28D1E35FAE8C/CCAPI/cc_process_call_setup_ind:
   >>>>CCAPI handed cid 11209976 with tag 1 to app "_ManagedAppProcess_Default"
5668939: .Nov 21 10:26:04.122: //11209976/28D1E35FAE8C/CCAPI/ccCallProceeding:
   Progress Indication=NULL(0)
5668940: .Nov 21 10:26:04.122: //-1/xxxxxxxxxxxx/CCAPI/ccGetMemPoolFromContainer:
   mempool not found from usrContainer(27E94C5C)
5668941: .Nov 21 10:26:04.122: //-1/xxxxxxxxxxxx/CCAPI/ccCreateMemPoolInContainer:
   Mempool(2948E434) created in usrContainer(27E94C5C)
5668942: .Nov 21 10:26:04.122: //11209976/28D1E35FAE8C/CCAPI/ccCallSetupRequest:
   Destination=, Calling IE Present=TRUE, Mode=0,
   Outgoing Dial-peer=20, Params=0x2BCAEA00, Progress Indication=NULL(0)
5668943: .Nov 21 10:26:04.122: //11209976/28D1E35FAE8C/CCAPI/ccCheckClipClir:
   In: Calling Number=sip:08834433593@202.156.18.16:5060;user=phone(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
5668944: .Nov 21 10:26:04.122: //11209976/28D1E35FAE8C/CCAPI/ccCheckClipClir:
   Out: Calling Number=sip:08834433593@202.156.18.16:5060;user=phone(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
5668945: .Nov 21 10:26:04.122: //11209976/28D1E35FAE8C/CCAPI/ccCallSetupRequest:
   Destination Pattern=44T, Called Number=901115248457, Digit Strip=FALSE
5668946: .Nov 21 10:26:04.122: //11209976/28D1E35FAE8C/CCAPI/ccCallSetupRequest:
   Calling Number=sip:08834433593@202.156.18.16:5060;user=phone(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
   Called Number=901115248457(TON=Unknown, NPI=Unknown),
   Redirect Number=, Display Info=
   Account Number=08834433593, Final Destination Flag=TRUE,
   Guid=28D1E35F-51CE-11E3-AE8C-8F4D5D7E5E41, Outgoing Dial-peer=20
5668947: .Nov 21 10:26:04.122: //11209976/28D1E35FAE8C/CCAPI/cc_api_display_ie_subfields:
   ccCallSetupRequest:
   cisco-username=08834433593
   ----- ccCallInfo IE subfields -----
   cisco-ani=sip:08834433593@202.156.18.16:5060;user=phone
   cisco-anitype=0
   cisco-aniplan=0
   cisco-anipi=0
   cisco-anisi=0
   dest=901115248457
   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

5668948: .Nov 21 10:26:04.122: //11209976/28D1E35FAE8C/CCAPI/ccIFCallSetupRequestPrivate:
   Interface=0x20E01378, Interface Type=3, Destination=, Mode=0x0,
   Call Params(Calling Number=sip:08834433593@202.156.18.16:5060;user=phone,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
   Called Number=901115248457(TON=Unknown, NPI=Unknown), Calling Translated=FALSE,
   Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE, Outgoing Dial-peer=20, Call Count On=FALSE,
   Source Trkgrp Route Label=, Target Trkgrp Route Label=, tg_label_flag=0, Application Call Id=)
5668949: .Nov 21 10:26:04.122: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

5668950: .Nov 21 10:26:04.122: :cc_get_feature_vsa malloc success
5668951: .Nov 21 10:26:04.122: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

5668952: .Nov 21 10:26:04.122: cc_get_feature_vsa count is 180
5668953: .Nov 21 10:26:04.122: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

5668954: .Nov 21 10:26:04.122: :FEATURE_VSA attributes are: feature_name:0,feature_time:743086152,feature_id:8589878
5668955: .Nov 21 10:26:04.122: //11209977/28D1E35FAE8C/CCAPI/ccIFCallSetupRequestPrivate:
   SPI Call Setup Request Is Success; Interface Type=3, FlowMode=1
5668956: .Nov 21 10:26:04.122: //11209977/28D1E35FAE8C/CCAPI/ccCallSetContext:
   Context=0x2BCAE9B4
5668957: .Nov 21 10:26:04.122: //11209976/28D1E35FAE8C/CCAPI/ccSaveDialpeerTag:
   Outgoing Dial-peer=20
5668958: .Nov 21 10:26:04.122: //11209977/28D1E35FAE8C/CCAPI/cc_api_call_proceeding:
   Interface=0x20E01378, Progress Indication=NULL(0)
5668959: .Nov 21 10:26:04.124: //11209977/28D1E35FAE8C/SIP/Msg/ccsipDisplayMsg:
Sent:
INVITE sip:901115248457@10.105.40.14:5060 SIP/2.0
Via: SIP/2.0/TCP 192.168.40.54:5060;branch=z9hG4bK222733C1466
Remote-Party-ID: <sip:08834433593@192.168.40.54>;party=calling;screen=no;privacy=off
From: <sip:08834433593@192.168.40.54>;tag=35AE4FA-F40
To: <sip:901115248457@10.105.40.14>
Date: Thu, 21 Nov 2013 10:26:04 GMT
Call-ID: 28D23173-51CE11E3-AE928F4D-5D7E5E41@192.168.40.54
Supported: timer,resource-priority,replaces,sdp-anat
Min-SE: 1800
Cisco-Guid: 0684843871-1372459491-2928447309-1568562753
User-Agent: Cisco-SIPGateway/IOS-12.x
Allow: INVITE, OPTIONS, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY, INFO, REGISTER
CSeq: 101 INVITE
Timestamp: 1385029564
Contact: <sip:08834433593@192.168.40.54:5060;transport=tcp>
Expires: 180
Allow-Events: kpml, telephone-event
Max-Forwards: 68
Content-Type: application/sdp
Content-Disposition: session;handling=required
Content-Length: 355

v=0
o=CiscoSystemsSIP-GW-UserAgent 8736 4303 IN IP4 192.168.40.54
s=SIP Call
c=IN IP4 192.168.40.54
t=0 0
m=audio 21236 RTP/AVP 18 0 8 100 101
c=IN IP4 192.168.40.54
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:100 X-NSE/8000
a=fmtp:100 192-194
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

5668960: .Nov 21 10:26:04.124: //11209976/28D1E35FAE8C/SIP/Msg/ccsipDisplayMsg:
Sent:
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 10.106.38.24:5081;branch=z9hG4bKjk1ufl30dok1h9v7f070.1
From: <sip:08834433593@202.156.18.16:5060;user=phone>;tag=1919469313-1385029564105-
To: <sip:441115248457@pbx.emea.globalipcom.com>
Date: Thu, 21 Nov 2013 10:26:04 GMT
Call-ID: BW102604105211113689361282@202.156.18.16
CSeq: 1025047397 INVITE
Allow-Events: kpml, telephone-event
Server: Cisco-SIPGateway/IOS-12.x
Content-Length: 0

5668961: .Nov 21 10:26:04.126: //11209977/28D1E35FAE8C/SIP/Msg/ccsipDisplayMsg:
Received:
SIP/2.0 100 Trying
Via: SIP/2.0/TCP 192.168.40.54:5060;branch=z9hG4bK222733C1466
From: <sip:08834433593@192.168.40.54>;tag=35AE4FA-F40
To: <sip:901115248457@10.105.40.14>
Date: Thu, 21 Nov 2013 10:26:04 GMT
Call-ID: 28D23173-51CE11E3-AE928F4D-5D7E5E41@192.168.40.54
CSeq: 101 INVITE
Allow-Events: presence
Content-Length: 0

5668962: .Nov 21 10:26:04.128: //11209977/28D1E35FAE8C/SIP/Msg/ccsipDisplayMsg:
Received:
SIP/2.0 500 Internal Server Error
Via: SIP/2.0/TCP 192.168.40.54:5060;branch=z9hG4bK222733C1466
From: <sip:08834433593@192.168.40.54>;tag=35AE4FA-F40
To: <sip:901115248457@10.105.40.14>;tag=4622451~ffa80926-5fac-4dd6-b405-2dbbc56ae9a2-475524409
Date: Thu, 21 Nov 2013 10:26:04 GMT
Call-ID: 28D23173-51CE11E3-AE928F4D-5D7E5E41@192.168.40.54
CSeq: 101 INVITE
Allow-Events: presence
Content-Length: 0

5668963: .Nov 21 10:26:04.128: //11209977/28D1E35FAE8C/CCAPI/cc_api_call_disconnected:
   Cause Value=41, Interface=0x20E01378, Call Id=11209977
5668964: .Nov 21 10:26:04.128: //11209977/28D1E35FAE8C/CCAPI/cc_api_call_disconnected:
   Call Entry(Responsed=TRUE, Cause Value=41, Retry Count=0)
5668965: .Nov 21 10:26:04.128: //11209976/28D1E35FAE8C/CCAPI/ccCallReleaseResources:
   release reserved xcoding resource.
5668966: .Nov 21 10:26:04.128: //11209977/28D1E35FAE8C/CCAPI/ccCallSetAAA_Accounting:
   Accounting=1, Call Id=11209977
5668967: .Nov 21 10:26:04.128: //11209977/28D1E35FAE8C/CCAPI/ccCallDisconnect:
   Cause Value=41, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=41)
5668968: .Nov 21 10:26:04.128: //11209977/28D1E35FAE8C/CCAPI/ccCallDisconnect:
   Cause Value=41, Call Entry(Responsed=TRUE, Cause Value=41)
5668969: .Nov 21 10:26:04.128: //11209977/28D1E35FAE8C/CCAPI/cc_api_call_disconnect_done:
   Disposition=0, Interface=0x20E01378, Tag=0x0, Call Id=11209977,
   Call Entry(Disconnect Cause=41, Voice Class Cause Code=0, Retry Count=0)
5668970: .Nov 21 10:26:04.128: //11209977/28D1E35FAE8C/CCAPI/cc_api_call_disconnect_done:
   Call Disconnect Event Sent
5668971: .Nov 21 10:26:04.128: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

5668972: .Nov 21 10:26:04.128: :cc_free_feature_vsa freeing 2C4A9840
5668973: .Nov 21 10:26:04.128: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

5668974: .Nov 21 10:26:04.128: vsacount in free is 179
5668975: .Nov 21 10:26:04.128: //11209976/28D1E35FAE8C/CCAPI/ccCallSetupRequest:
   Destination=, Calling IE Present=TRUE, Mode=0,
   Outgoing Dial-peer=21, Params=0x2AA85790, Progress Indication=NULL(0)
5668976: .Nov 21 10:26:04.128: //11209976/28D1E35FAE8C/CCAPI/ccCheckClipClir:
   In: Calling Number=sip:08834433593@202.156.18.16:5060;user=phone(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
5668977: .Nov 21 10:26:04.128: //11209976/28D1E35FAE8C/CCAPI/ccCheckClipClir:
   Out: Calling Number=sip:08834433593@202.156.18.16:5060;user=phone(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
5668978: .Nov 21 10:26:04.128: //11209976/28D1E35FAE8C/CCAPI/ccCallSetupRequest:
   Destination Pattern=44T, Called Number=901115248457, Digit Strip=FALSE
5668979: .Nov 21 10:26:04.128: //11209976/28D1E35FAE8C/CCAPI/ccCallSetupRequest:
   Calling Number=sip:08834433593@202.156.18.16:5060;user=phone(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
   Called Number=901115248457(TON=Unknown, NPI=Unknown),
   Redirect Number=, Display Info=
   Account Number=08834433593, Final Destination Flag=TRUE,
   Guid=28D1E35F-51CE-11E3-AE8C-8F4D5D7E5E41, Outgoing Dial-peer=21
5668980: .Nov 21 10:26:04.128: //11209976/28D1E35FAE8C/CCAPI/cc_api_display_ie_subfields:
   ccCallSetupRequest:
   cisco-username=08834433593
   ----- ccCallInfo IE subfields -----
   cisco-ani=sip:08834433593@202.156.18.16:5060;user=phone
   cisco-anitype=0
   cisco-aniplan=0
   cisco-anipi=0
   cisco-anisi=0
   dest=901115248457
   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

5668981: .Nov 21 10:26:04.128: //11209976/28D1E35FAE8C/CCAPI/ccIFCallSetupRequestPrivate:
   Interface=0x20E01378, Interface Type=3, Destination=, Mode=0x0,
   Call Params(Calling Number=sip:08834433593@202.156.18.16:5060;user=phone,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
   Called Number=901115248457(TON=Unknown, NPI=Unknown), Calling Translated=FALSE,
   Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE, Outgoing Dial-peer=21, Call Count On=FALSE,
   Source Trkgrp Route Label=, Target Trkgrp Route Label=, tg_label_flag=0, Application Call Id=)
5668982: .Nov 21 10:26:04.128: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

Question is why such a behaviour by CUCM. Is it because the call is sent to a xlation pattern first..Any remedies?

Please rate all useful posts

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

Please rate all useful posts

Ayodeji Okanlawon · ‎04-04-2014

This is for the benefit of anyone who experience a similar issue like this..

Cisco CUCM and CUBE by default do not drop a call when it receives a 486 busy, 404 not found or out of bandwidth. They reroute for all cause codes other than Out of Bandwidth, User Busy, and Unallocated Number.

For CUCM, the value of the associated service parameters for the Cisco Call Manager service determines the rerouting decision for those cause codes. The Cluster wide Parameters (Route Plan) : Stop Routing on Out of Bandwidth Flag, Stop Routing on User Busy Flag, and Stop Routing on Unallocated Number Flag service parameters, determines what re-routing decision happens in this scenario.

All well and good fro CUCM, but what about CUBE...

We can also tell CUBE what to do in this circumstances just as with CUCM. The magic is to use the voice hunt command

#conf t

no voice hunt unassigned-number

no voice hunt invalid-number

no voice hunt user-busy

Please rate all useful posts

Suresh Subramanian · ‎04-04-2014

Thanks Deji for the helpful information. It seems it is also clearing the hung calls on the CUBE.

//Suresh Please rate all the useful posts.

Ayodeji Okanlawon · ‎04-04-2014

Thanks Suresh for the nice rating. I didnt know it clears hung calls. Did you use this in the past?

Please rate all useful posts

Suresh Subramanian · ‎04-04-2014

I tried it few mins ago. We have CUBE which is in testing phase, and there were more than 100 calls when entered 'show call active voice compact' command on the CUBE. I entered the above commands and checked the calls again. they became zero. observing more on that.

//Suresh Please rate all the useful posts.

charles.reid.10.ctr · ‎10-27-2022

I am running CUBE IOS 17.6.3a and unfortunately I am still getting a 486 BUSY HERE instead of the 404 NOT FOUND that the provider is looking to get in return for unallocated numbers.... I have the above commands on the router. We have stop routing on unallocated numbers set to false which is what we do on all of our clusters.

charles.reid.10.ctr · ‎10-27-2022

CUCM 14.x su2

b.winter · ‎10-27-2022

But if you have set the parameter to "False", then CUCM doens't stop the hunting. CUCM will then try the next member in the route list (if available). Is this your intention?

charles.reid.10.ctr · ‎10-27-2022

Hello, This is for inbound calls from the provider, not for outbound calls. Provider wants to see a 404 and we are sending a 486 busy which is the issue for inbound calls to CUCM.

charles.reid.10.ctr · ‎10-27-2022

We have another CUBE router in service and i will have to check that as it was returning the expected 404 for unallocated calls. Perhaps something has changed as we upgraded that cluster from 11.5 to 14.x and I don't think we have checked that CUBE since we did the upgrade as far as 404, if that still works or not.