CCM Group

[mightyking]

Hello Everyone,

I am in weird situation.

I have two CM Groups (GM_CM1 and CM_GM2). Each groupe has 2 Subs as follow:

GM_CM1 = Sub_1 and Sub_2

GM_CM2 = Sub_2 and Sub_1

When the phone is registered with Sub_1 (GM_CM1) through the appropriate device pool everything works.

The problem starts when the phone is registered with Sub_2 (GM_CM2). All calls work except 911. A message stating "Your call can not be completed as it is dialed". The weired thing is as soon as I register the phone with Sub_1 everything inclusing 911 calls work.

Below is the trace for a local call using Sub_2 which works as well as a 911 call through the same Sub_2 which fails.

Not I see the Forbidden and No Found error message in the 911 call trace but don't understand why it works with Sub_1 and fails with Sub_2.

Working Local Call Through Sub_2

2015/02/02 13:59:33.471|SIPL|0|TCP|IN|10.116.131.18|5060|SEP002414B33E40|10.16.244.26|49294|3,100,63,1.468914^10.16.244.26^*|1669307|002414b3-3e4000df-e57ec560-93c4e455@10.16.244.26|INVITE
2015/02/02 13:59:33.472|SIPL|0|TCP|OUT|10.116.131.18|5060|SEP002414B33E40|10.16.244.26|49294|3,100,63,1.468914^10.16.244.26^*|1669308|002414b3-3e4000df-e57ec560-93c4e455@10.16.244.26|100 Trying
2015/02/02 13:59:36.743|CC|SETUP|53236359|53236360|18882061454|+15146027093|+15146027093
2015/02/02 13:59:36.748|CC|OFFERED|53236359|53236360|18882061454|+15146027093|+15146027093|SEP002414B33E40|SIP_Trunk_NACC_CUSPIntA5_CPODC1
2015/02/02 13:59:36.748|SIPT|53236360|UDP|OUT|10.116.131.18|5060|SIP_Trunk_NACC_CUSPIntA5_CPODC1|10.116.129.109|5060|3,100,63,1.468927^10.16.244.26^*|1669342|a041e180-4cf1c918-15c16-1283740a@10.116.131.18|INVITE
2015/02/02 13:59:36.751|SIPT|53236360|UDP|IN|10.116.131.18|5060|SIP_Trunk_NACC_CUSPIntA5_CPODC1|10.116.129.109|32785|3,100,230,1.253711^10.116.129.109^*|1669343|a041e180-4cf1c918-15c16-1283740a@10.116.131.18|100 Trying
2015/02/02 13:59:37.625|SIPT|53236360|UDP|IN|10.116.131.18|5060|SIP_Trunk_NACC_CUSPIntA5_CPODC1|10.116.129.109|32785|3,100,230,1.253713^10.116.129.109^*|1669351|a041e180-4cf1c918-15c16-1283740a@10.116.131.18|183 Session Progress
2015/02/02 13:59:37.626|SIPT|53236360|UDP|OUT|10.116.131.18|5060|SIP_Trunk_NACC_CUSPIntA5_CPODC1|10.116.130.14|5060|3,100,230,1.253713^10.116.129.109^*|1669352|a041e180-4cf1c918-15c16-1283740a@10.116.131.18|PRACK
2015/02/02 13:59:37.628|SIPT|53236360|UDP|IN|10.116.131.18|5060|SIP_Trunk_NACC_CUSPIntA5_CPODC1|10.116.130.14|64432|3,100,230,1.253714^10.116.130.14^*|1669353|a041e180-4cf1c918-15c16-1283740a@10.116.131.18|200 OK
2015/02/02 13:59:37.633|SIPL|53236359|TCP|OUT|10.116.131.18|5060|SEP002414B33E40|10.16.244.26|49294|3,100,68,19.1^*^*|1669354|002414b3-3e4000df-e57ec560-93c4e455@10.16.244.26|183 Session Progress
2015/02/02 13:59:37.634|SIPL|53236359|TCP|OUT|10.116.131.18|5060|SEP002414B33E40|10.16.244.26|49294|3,100,68,19.1^*^*|1669355|002414b3-3e4000df-e57ec560-93c4e455@10.16.244.26|SUBSCRIBE
2015/02/02 13:59:37.735|SIPL|53236359|TCP|IN|10.116.131.18|5060|SEP002414B33E40|10.16.244.26|49294|3,100,63,1.468931^10.16.244.26^*|1669356|002414b3-3e4000df-e57ec560-93c4e455@10.16.244.26|200 OK
2015/02/02 13:59:37.739|SIPL|53236359|TCP|IN|10.116.131.18|5060|SEP002414B33E40|10.16.244.26|49294|3,100,63,1.468932^10.16.244.26^*|1669357|002414b3-3e4000df-e57ec560-93c4e455@10.16.244.26|NOTIFY
2015/02/02 13:59:37.739|SIPL|53236359|TCP|OUT|10.116.131.18|5060|SEP002414B33E40|10.16.244.26|49294|3,100,63,1.468932^10.16.244.26^*|1669358|002414b3-3e4000df-e57ec560-93c4e455@10.16.244.26|200 OK
2015/02/02 13:59:45.304|SIPT|53236360|UDP|IN|10.116.131.18|5060|SIP_Trunk_NACC_CUSPIntA5_CPODC1|10.116.129.109|32785|3,100,230,1.253721^10.116.129.109^*|1669386|a041e180-4cf1c918-15c16-1283740a@10.116.131.18|200 OK
2015/02/02 13:59:45.305|SIPT|53236360|UDP|OUT|10.116.131.18|5060|SIP_Trunk_NACC_CUSPIntA5_CPODC1|10.116.130.14|5060|3,100,230,1.253721^10.116.129.109^*|1669387|a041e180-4cf1c918-15c16-1283740a@10.116.131.18|ACK
2015/02/02 13:59:45.311|SIPL|53236359|TCP|OUT|10.116.131.18|5060|SEP002414B33E40|10.16.244.26|49294|3,100,230,1.253721^10.116.129.109^*|1669388|002414b3-3e4000df-e57ec560-93c4e455@10.16.244.26|200 OK
2015/02/02 13:59:45.439|SIPL|53236359|TCP|IN|10.116.131.18|5060|SEP002414B33E40|10.16.244.26|49294|3,100,63,1.468940^10.16.244.26^*|1669389|002414b3-3e4000df-e57ec560-93c4e455@10.16.244.26|ACK
2015/02/02 13:59:49.020|SIPT|53236360|UDP|IN|10.116.131.18|5060|SIP_Trunk_NACC_CUSPIntA5_CPODC1|10.116.130.14|64432|3,100,230,1.253725^10.116.130.14^*|1669407|a041e180-4cf1c918-15c16-1283740a@10.116.131.18|BYE
2015/02/02 13:59:49.024|SIPL|53236359|TCP|OUT|10.116.131.18|5060|SEP002414B33E40|10.16.244.26|49294|3,100,230,1.253725^10.116.130.14^*|1669408|002414b3-3e4000df-e57ec560-93c4e455@10.16.244.26|SUBSCRIBE
2015/02/02 13:59:49.024|SIPT|53236360|UDP|OUT|10.116.131.18|5060|SIP_Trunk_NACC_CUSPIntA5_CPODC1|10.116.130.14|5060|3,100,230,1.253725^10.116.130.14^*|1669409|a041e180-4cf1c918-15c16-1283740a@10.116.131.18|200 OK
2015/02/02 13:59:49.025|SIPL|53236359|TCP|OUT|10.116.131.18|5060|SEP002414B33E40|10.16.244.26|49294|3,100,230,1.253725^10.116.130.14^*|1669410|002414b3-3e4000df-e57ec560-93c4e455@10.16.244.26|BYE
2015/02/02 13:59:49.059|SIPL|53236359|TCP|IN|10.116.131.18|5060|SEP002414B33E40|10.16.244.26|49294|3,100,63,1.468946^10.16.244.26^*|1669411|002414b3-3e4000df-e57ec560-93c4e455@10.16.244.26|200 OK
2015/02/02 13:59:49.064|SIPL|53236359|TCP|IN|10.116.131.18|5060|SEP002414B33E40|10.16.244.26|49294|3,100,63,1.468947^10.16.244.26^*|1669412|002414b3-3e4000df-e57ec560-93c4e455@10.16.244.26|NOTIFY
2015/02/02 13:59:49.065|SIPL|53236359|TCP|OUT|10.116.131.18|5060|SEP002414B33E40|10.16.244.26|49294|3,100,63,1.468947^10.16.244.26^*|1669413|002414b3-3e4000df-e57ec560-93c4e455@10.16.244.26|200 OK
2015/02/02 13:59:49.199|SIPL|53236359|TCP|IN|10.116.131.18|5060|SEP002414B33E40|10.16.244.26|49294|3,100,63,1.468949^10.16.244.26^*|1669416|002414b3-3e4000df-e57ec560-93c4e455@10.16.244.26|200 OK
2015/02/02 13:59:49.202|CC|RELEASE|53236359|53236360|16

Failing 911 CALL Throught Sub_2

2015/02/02 13:59:51.270|SIPL|0|TCP|IN|10.116.131.18|5060|SEP002414B33E40|10.16.244.26|49294|3,100,63,1.468953^10.16.244.26^*|1669427|002414b3-3e4000e0-fcac178b-dd5d511e@10.16.244.26|INVITE
2015/02/02 13:59:51.271|SIPL|0|TCP|OUT|10.116.131.18|5060|SEP002414B33E40|10.16.244.26|49294|3,100,63,1.468953^10.16.244.26^*|1669428|002414b3-3e4000e0-fcac178b-dd5d511e@10.16.244.26|100 Trying
2015/02/02 13:59:56.938|CC|SETUP|53236361|53236362|012720215004|911|911
2015/02/02 13:59:56.946|CC|OFFERED|53236361|53236362|012720215004|911|911|SEP002414B33E40|RP_NACC_911
2015/02/02 13:59:56.961|CC|SETUP|53236361|53236364|15148581256|911|911
2015/02/02 13:59:56.965|CC|OFFERED|53236361|53236364|18882061454|911|911|SEP002414B33E40|SIP_Trunk_NACC_Montreal01
2015/02/02 13:59:56.965|SIPT|53236364|UDP|OUT|10.116.131.18|5060|SIP_Trunk_NACC_Montreal01|10.18.201.5|5060|2,200,21,1.7537875^10.116.131.14^RP_NACC_911|1669455|ac2da380-4cf1c92c-15c1e-1283740a@10.116.131.18|INVITE
2015/02/02 13:59:56.970|CC|RELEASE|53236362|0|0
2015/02/02 13:59:56.982|SIPT|53236364|UDP|IN|10.116.131.18|5060|SIP_Trunk_NACC_Montreal01|10.18.201.5|63575|3,100,230,1.253733^10.18.201.5^*|1669460|ac2da380-4cf1c92c-15c1e-1283740a@10.116.131.18|100 Trying
2015/02/02 13:59:56.982|SIPT|53236364|UDP|IN|10.116.131.18|5060|SIP_Trunk_NACC_Montreal01|10.18.201.5|63575|3,100,230,1.253734^10.18.201.5^*|1669461|ac2da380-4cf1c92c-15c1e-1283740a@10.116.131.18|403 Forbidden
2015/02/02 13:59:56.982|SIPT|53236364|UDP|OUT|10.116.131.18|5060|SIP_Trunk_NACC_Montreal01|10.18.201.5|5060|3,100,230,1.253734^10.18.201.5^*|1669462|ac2da380-4cf1c92c-15c1e-1283740a@10.116.131.18|ACK
2015/02/02 13:59:56.987|SIPT|53236364|UDP|OUT|10.116.131.18|5060|SIP_Trunk_NACC_CUSPIntA5_CPODC1|10.116.129.109|5060|3,100,230,1.253734^10.18.201.5^*|1669463|ac2da380-4cf1c92c-15c1f-1283740a@10.116.131.18|INVITE
2015/02/02 13:59:56.988|SIPT|53236364|UDP|IN|10.116.131.18|5060|SIP_Trunk_NACC_CUSPIntA5_CPODC1|10.116.129.109|32785|3,100,230,1.253735^10.116.129.109^*|1669464|ac2da380-4cf1c92c-15c1f-1283740a@10.116.131.18|100 Trying
2015/02/02 13:59:57.023|SIPT|53236364|UDP|IN|10.116.131.18|5060|SIP_Trunk_NACC_CUSPIntA5_CPODC1|10.116.129.109|32785|3,100,230,1.253737^10.116.129.109^*|1669467|ac2da380-4cf1c92c-15c1f-1283740a@10.116.131.18|404 Not Found
2015/02/02 13:59:57.023|SIPT|53236364|UDP|OUT|10.116.131.18|5060|SIP_Trunk_NACC_CUSPIntA5_CPODC1|10.116.129.109|5060|3,100,230,1.253737^10.116.129.109^*|1669468|ac2da380-4cf1c92c-15c1f-1283740a@10.116.131.18|ACK
2015/02/02 13:59:57.038|SIPL|53236361|TCP|OUT|10.116.131.18|5060|SEP002414B33E40|10.16.244.26|49294|2,100,13,32.125932^10.116.131.19^ANN_CPODC1|1669469|002414b3-3e4000e0-fcac178b-dd5d511e@10.16.244.26|183 Session Progress
2015/02/02 13:59:58.747|SIPL|53236361|TCP|IN|10.116.131.18|5060|SEP002414B33E40|10.16.244.26|49294|3,100,63,1.468965^10.16.244.26^*|1669474|002414b3-3e4000e0-fcac178b-dd5d511e@10.16.244.26|CANCEL
2015/02/02 13:59:58.748|SIPL|53236361|TCP|OUT|10.116.131.18|5060|SEP002414B33E40|10.16.244.26|49294|3,100,63,1.468965^10.16.244.26^*|1669475|002414b3-3e4000e0-fcac178b-dd5d511e@10.16.244.26|200 OK
2015/02/02 13:59:58.750|SIPL|53236361|TCP|OUT|10.116.131.18|5060|SEP002414B33E40|10.16.244.26|49294|3,100,63,1.468965^10.16.244.26^*|1669476|002414b3-3e4000e0-fcac178b-dd5d511e@10.16.244.26|487 Request Cancelled
2015/02/02 13:59:58.750|CC|RELEASE|53236361|53236364|1
2015/02/02 13:59:58.769|SIPL|53236361|TCP|IN|10.116.131.18|5060|SEP002414B33E40|10.16.244.26|49294|3,100,63,1.468966^10.16.244.26^*|1669477|002414b3-3e4000e0-fcac178b-dd5d511e@10.16.244.26|ACK

[Chris Deren]

Do you have the IP address of Sub2 defined as trusted IP in the voice gateway?

Can you provide "debug ccsip messages" from the GW?

[mightyking]

Hi Chris,

I don`t have the Sub_2 defined as trusted IP in the GW but I don`t have the Sub_1 defined either and when the phone is registered with Sub_1 the 911 call goes out. When the phone is registered with Sub-2 the call doesn`t even hit the GW. The debug ccsip message shows nothing.

Thanks,

MK

[Chris Deren]

Do you have a dial-peer defined on the GW that has session-target of sub-1? 

Do you get anything in the debug when phone is registered to sub-1?

Is the 911 non-working pattern pointing to the same route list as other working patterns?

[mightyking]

Yes, a dial-peer is pointed to Sub_1 for the incoming calls (see  below)

dial-peer voice 3001 voip
 description ** Call to CUCM Subscriber 01 **
 preference 1
 destination-pattern 1514[2-9]......$
 session protocol sipv2
 session target ipv4:Sub_1

voice-class codec 1 
 voice-class sip options-keepalive up-interval 5 down-interval 10 retry 1
 dtmf-relay rtp-nte
 ip qos dscp cs3 signaling
 no vad

Here`s the output of debug isdn q931 when the phone is registered to Sub_1 when dialing 911

000922: *Feb  2 22:18:35.255: ISDN Se0/1/0:23 Q931: Applying typeplan for sw-type 0x5 is 0x2 0x1, Calling num 5148581256
000923: *Feb  2 22:18:35.255: ISDN Se0/1/0:23 Q931: Sending SETUP  callref = 0x0088 callID = 0x8009 switch = primary-dms100 interface = User
000924: *Feb  2 22:18:35.255: ISDN Se0/1/0:23 Q931: TX -> SETUP pd = 8  callref = 0x0088
        Bearer Capability i = 0x8090A2
                Standard = CCITT
                Transfer Capability = Speech 
                Transfer Mode = Circuit
                Transfer Rate = 64 kbit/s
        Channel ID i = 0xA98381
                Exclusive, Channel 1
        Display i = 0xB1, 'Paco 7962'
        Calling Party Number i = 0x2180, '5148581256'
                Plan:ISDN, Type:National
        Called Party Number i = 0xA1, '911'
                Plan:ISDN, Type:National
000925: *Feb  2 22:18:35.339: ISDN Se0/1/0:23 Q931: RX <- CALL_PROC pd = 8  callref = 0x8088
        Channel ID i = 0xA98381
                Exclusive, Channel 1
000926: *Feb  2 22:18:35.343: ISDN Se0/1/0:23 Q931: RX <- PROGRESS pd = 8  callref = 0x8088
        Progress Ind i = 0x8081 - Call not end-to-end ISDN, may have in-band info
000927: *Feb  2 22:18:37.139: ISDN Se0/1/0:23 Q931: RX <- CONNECT pd = 8  callref = 0x8088
000928: *Feb  2 22:18:37.139: ISDN Se0/1/0:23 Q931: TX -> CONNECT_ACK pd = 8  callref = 0x0088
000929: *Feb  2 22:18:48.363: ISDN Se0/1/0:23 Q931: TX -> DISCONNECT pd = 8  callref = 0x0088
        Cause i = 0x8090 - Normal call clearing
000930: *Feb  2 22:18:48.391: ISDN Se0/1/0:23 Q931: RX <- RELEASE pd = 8  callref = 0x8088
000931: *Feb  2 22:18:48.391: ISDN Se0/1/0:23 Q931: TX -> RELEASE_COMP pd = 8  callref = 0x0088

[Chris Deren]

Is the 911 non-working pattern pointing to the same route list as other working patterns?

Can you see if you get anything when running "debug voice ccapi inout" for the non-working call?

[mightyking]

Yes they all point to the same RL. All I do is changing the DP in the phone

DP1  points to GM_CM1 = Sub_1 and Sub_2

DP2 pints to GM_CM2 = Sub_2 and Sub_1

In the same phone when DP is DP1 everything works but as soon as it`s pointed to DP2 only 911 calls fail.

Here`s the output of debug voice ccapi inout:

000940: *Feb  2 22:34:07.387: //-1/857E65800000/CCAPI/cc_api_display_ie_subfields:
   cc_api_call_setup_ind_common:
   cisco-username=15148581256
   ----- ccCallInfo IE subfields -----
   cisco-ani=15148581256
   cisco-anitype=0
   cisco-aniplan=0
   cisco-anipi=0
   cisco-anisi=0
   dest=911
   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

000941: *Feb  2 22:34:07.391: //-1/857E65800000/CCAPI/cc_api_call_setup_ind_common:
   Interface=0x3167E110, Call Info(
   Calling Number=15148581256,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
   Called Number=911(TON=Unknown, NPI=Unknown),
   Calling Translated=FALSE, Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE,
   Incoming Dial-peer=3002, Progress Indication=NULL(0), Calling IE Present=TRUE,
   Source Trkgrp Route Label=, Target Trkgrp Route Label=, CLID Transparent=FALSE), Call Id=51533
000942: *Feb  2 22:34:07.391: //-1/857E65800000/CCAPI/ccCheckClipClir:
   In: Calling Number=15148581256(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
000943: *Feb  2 22:34:07.391: //-1/857E65800000/CCAPI/ccCheckClipClir:
   Out: Calling Number=15148581256(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
000944: *Feb  2 22:34:07.391: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
  
000945: *Feb  2 22:34:07.391: :cc_get_feature_vsa malloc success
000946: *Feb  2 22:34:07.391: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
  
000947: *Feb  2 22:34:07.391:  cc_get_feature_vsa count is 1
000948: *Feb  2 22:34:07.391: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
  
000949: *Feb  2 22:34:07.391: :FEATURE_VSA attributes are: feature_name:0,feature_time:805408392,feature_id:47
000950: *Feb  2 22:34:07.391: //51533/857E65800000/CCAPI/cc_api_call_setup_ind_common:
   Set Up Event Sent;
   Call Info(Calling Number=15148581256(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
   Called Number=911(TON=Unknown, NPI=Unknown))
000951: *Feb  2 22:34:07.391: //51533/857E65800000/CCAPI/cc_process_call_setup_ind:
   Event=0x32101B08
000952: *Feb  2 22:34:07.391: //-1/xxxxxxxxxxxx/CCAPI/cc_setupind_match_search:
   Try with the demoted called number 911
000953: *Feb  2 22:34:07.391: //51533/857E65800000/CCAPI/ccCallSetContext:
   Context=0x2C610150
000954: *Feb  2 22:34:07.391: //51533/857E65800000/CCAPI/cc_process_call_setup_ind:
   >>>>CCAPI handed cid 51533 with tag 3002 to app "_ManagedAppProcess_TOLLFRAUD_APP"
000955: *Feb  2 22:34:07.391: //51533/857E65800000/CCAPI/ccCallDisconnect:
   Cause Value=21, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=0)
000956: *Feb  2 22:34:07.391: //51533/857E65800000/CCAPI/ccCallDisconnect:
   Cause Value=21, Call Entry(Responsed=TRUE, Cause Value=21)
000957: *Feb  2 22:34:07.403: //51533/857E65800000/CCAPI/cc_api_call_disconnect_done:
   Disposition=0, Interface=0x3167E110, Tag=0x0, Call Id=51533,
   Call Entry(Disconnect Cause=21, Voice Class Cause Code=0, Retry Count=0)
000958: *Feb  2 22:34:07.403: //51533/857E65800000/CCAPI/cc_api_call_disconnect_done:
   Call Disconnect Event Sent
000959: *Feb  2 22:34:07.403: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
  
000960: *Feb  2 22:34:07.403: :cc_free_feature_vsa freeing 30018E80
000961: *Feb  2 22:34:07.403: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
  
000962: *Feb  2 22:34:07.403:  vsacount in free is 0

Thanks,

MK

[Chris Deren · Accepted solution]

As suspected toll-fraud prevention on IOS is blocking the call, see "CCAPI handed cid 51533 with tag 3002 to app "_ManagedAppProcess_TOLLFRAUD_APP""

you have 3 options:

1. add another redundant dial-peer with preference 1, etc that points to the other sub (you need this anyway in case your sub-1 fails for inbound calls to work)

2. Add sub-2 IP under trust list

3. Add "no ip address truster authenticate" to disable toll-fraud feature (not recommended).

[mightyking]

Thanks 1000 times my firend!!!!

I added a redundnat dial-peer and It worked!!!!

But I don`t understand what adding an inbound voip dial-peer has to do with an outbound 911 call???? Would you mind axplaining this?

Many TAHNKS,

MK

[Chris Deren]

Having an IP address on any dial-peers tells the IOS that it's secured IP and automatically adds it to the trusted list.

[mightyking]

Many thanks Chris

MK