cancel
Showing results for 
Search instead for 
Did you mean: 
cancel
612
Views
0
Helpful
3
Replies

voice class h323 1 wasn't good enough to avoid Recovery on timer expiry

Hello, my pub and sub were down due to maintenance outage to the location, however I had another sub that took place. So, all the phones were successful registered to this sub. However during the outage we were not able to make inbound calls to any sites because the ISDN Recovery on timer expiry.Thus, I've applied these commands:

voice class h323 1

h225 timeout tcp establish 3

voice-class h323 1 - for all voip dial-peer

--------

Now the funiest thing is: 13 of 14 sites worked fine after I applied these commands, one site I also had to change the preference in order to fix the timer expiry, however there was only one site that did not work at all. I was wondering to know if someone out there would be able to explain why these commands did not work in this specific site. Btw, the router is 2951 IOS 15.0(1r)M13 H.323 to CUCM 8.6.2, isdn switch-type primary-qsig in Germany.

Here is the debug I took when I faced this issue for that specific location:

012974: Aug 18 2013 03:58:40.784 BR: ISDN Se0/0/0:15 Q931: RX <- SETUP pd = 8  callref = 0x06D1

        Bearer Capability i = 0x8090A3

                Standard = CCITT

                Transfer Capability = Speech

                Transfer Mode = Circuit

                Transfer Rate = 64 kbit/s

        Channel ID i = 0xA18387

                Preferred, Channel 7

        Calling Party Number i = 0x2181, '69427299299'

                Plan:ISDN, Type:National

        Called Party Number i = 0xC1, '705390'

                Plan:ISDN, Type:Subscriber(local)

012975: Aug 18 2013 03:58:40.788 BR: //-1/72C54EDF920B/CCAPI/cc_api_display_ie_subfields:

   cc_api_call_setup_ind_common:

   cisco-username=

   ----- ccCallInfo IE subfields -----

   cisco-ani=69427299299

   cisco-anitype=2

   cisco-aniplan=1

   cisco-anipi=0

   cisco-anisi=1

   dest=705390

   cisco-desttype=4

   cisco-destplan=1

   cisco-rdie=FFFFFFFF

   cisco-rdn=

   cisco-rdntype=-1

   cisco-rdnplan=-1

   cisco-rdnpi=-1

   cisco-rdnsi=-1

   cisco-redirectreason=-1   fwd_final_type =0

   final_redirectNumber =

   hunt_group_timeout =0

012976: Aug 18 2013 03:58:40.788 BR: //-1/72C54EDF920B/CCAPI/cc_api_call_setup_ind_common:

   Interface=0xBCE21C8, Call Info(

   Calling Number=69427299299,(Calling Name=)(TON=National, NPI=ISDN, Screening=User, Passed, Presentation=Allowed),

   Called Number=705390(TON=Subscriber, NPI=ISDN),

   Calling Translated=FALSE, Subscriber Type Str=RegularLine, FinalDestinationFlag=TRUE,

   Incoming Dial-peer=998, Progress Indication=NULL(0), Calling IE Present=TRUE,

   Source Trkgrp Route Label=, Target Trkgrp Route Label=, CLID Transparent=FALSE), Call Id=-1

012977: Aug 18 2013 03:58:40.788 BR: //-1/72C54EDF920B/CCAPI/ccCheckClipClir:

   In: Calling Number=69427299299(TON=National, NPI=ISDN, Screening=User, Passed, Presentation=Allowed)

012978: Aug 18 2013 03:58:40.788 BR: //-1/72C54EDF920B/CCAPI/ccCheckClipClir:

   Out: Calling Number=69427299299(TON=National, NPI=ISDN, Screening=User, Passed, Presentation=Allowed)

012979: Aug 18 2013 03:58:40.788 BR: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

012980: Aug 18 2013 03:58:40.788 BR: :cc_get_feature_vsa malloc success

012981: Aug 18 2013 03:58:40.788 BR: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

012982: Aug 18 2013 03:58:40.788 BR:  cc_get_feature_vsa count is 1

012983: Aug 18 2013 03:58:40.788 BR: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

012984: Aug 18 2013 03:58:40.788 BR: :FEATURE_VSA attributes are: feature_name:0,feature_time:31979544,feature_id:55094

012985: Aug 18 2013 03:58:40.788 BR: //55877/72C54EDF920B/CCAPI/cc_api_call_setup_ind_common:

   Set Up Event Sent;

   Call Info(Calling Number=69427299299(TON=National, NPI=ISDN, Screening=User, Passed, Presentation=Allowed),

   Called Number=705390(TON=Subscriber, NPI=ISDN))

012986: Aug 18 2013 03:58:40.788 BR: //55877/72C54EDF920B/CCAPI/cc_process_call_setup_ind:

   Event=0x2006B30

012987: Aug 18 2013 03:58:40.788 BR: //-1/xxxxxxxxxxxx/CCAPI/cc_setupind_match_search:

   Try with the demoted called number 705390

012988: Aug 18 2013 03:58:40.788 BR: //55877/72C54EDF920B/CCAPI/ccCallSetContext:

   Context=0x1233BE44

012989: Aug 18 2013 03:58:40.788 BR: //55877/72C54EDF920B/CCAPI/cc_process_call_setup_ind:

   >>>>CCAPI handed cid 55877 with tag 998 to app "_ManagedAppProcess_Default"

012990: Aug 18 2013 03:58:40.788 BR: //55877/72C54EDF920B/CCAPI/ccCallProceeding:

   Progress Indication=NULL(0)

012991: Aug 18 2013 03:58:40.788 BR: //55877/72C54EDF920B/CCAPI/ccCallSetupRequest:

   Destination=, Calling IE Present=TRUE, Mode=0,

   Outgoing Dial-peer=114, Params=0x12336E34, Progress Indication=NULL(0)

012992: Aug 18 2013 03:58:40.788 BR: //55877/72C54EDF920B/CCAPI/ccCheckClipClir:

   In: Calling Number=69427299299(TON=National, NPI=ISDN, Screening=User, Passed, Presentation=Allowed)

012993: Aug 18 2013 03:58:40.788 BR: //55877/72C54EDF920B/CCAPI/ccCheckClipClir:

   Out: Calling Number=69427299299(TON=National, NPI=ISDN, Screening=User, Passed, Presentation=Allowed)

012994: Aug 18 2013 03:58:40.788 BR: //55877/72C54EDF920B/CCAPI/ccCallSetupRequest:

   Destination Pattern=.T, Called Number=705390, Digit Strip=FALSE

012995: Aug 18 2013 03:58:40.788 BR: //55877/72C54EDF920B/CCAPI/ccCallSetupRequest:

   Calling Number=69427299299(TON=National, NPI=ISDN, Screening=User, Passed, Presentation=Allowed),

   Called Number=705390(TON=Subscriber, NPI=ISDN),

   Redirect Number=, Display Info=

   Account Number=, Final Destination Flag=TRUE,

   Guid=72C54EDF-070A-11E3-920B-28940FF7B740, Outgoing Dial-peer=114

012996: Aug 18 2013 03:58:40.788 BR: //55877/72C54EDF920B/CCAPI/cc_api_display_ie_subfields:

   ccCallSetupRequest:

   cisco-username=

   ----- ccCallInfo IE subfields -----

   cisco-ani=69427299299

   cisco-anitype=2

   cisco-aniplan=1

   cisco-anipi=0

   cisco-anisi=1

   dest=705390

   cisco-desttype=4

   cisco-destplan=1

   cisco-rdie=FFFFFFFF

   cisco-rdn=

   cisco-rdntype=-1

   cisco-rdnplan=-1

   cisco-rdnpi=-1

   cisco-rdnsi=-1

   cisco-redirectreason=-1   fwd_final_type =0

   final_redirectNumber =

   hunt_group_timeout =0

012997: Aug 18 2013 03:58:40.788 BR: //55877/72C54EDF920B/CCAPI/ccIFCallSetupRequestPrivate:

   Interface=0x1D99E34, Interface Type=3, Destination=, Mode=0x0,

   Call Params(Calling Number=69427299299,(Calling Name=)(TON=National, NPI=ISDN, Screening=User, Passed, Presentation=Allowed),

   Called Number=705390(TON=Subscriber, NPI=ISDN), Calling Translated=FALSE,

   Subscriber Type Str=RegularLine, FinalDestinationFlag=TRUE, Outgoing Dial-peer=114, Call Count On=FALSE,

   Source Trkgrp Route Label=, Target Trkgrp Route Label=, tg_label_flag=0, Application Call Id=)

012998: Aug 18 2013 03:58:40.788 BR: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

012999: Aug 18 2013 03:58:40.788 BR: :cc_get_feature_vsa malloc success

013000: Aug 18 2013 03:58:40.788 BR: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

013001: Aug 18 2013 03:58:40.788 BR:  cc_get_feature_vsa count is 2

013002: Aug 18 2013 03:58:40.788 BR: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

013003: Aug 18 2013 03:58:40.788 BR: :FEATURE_VSA attributes are: feature_name:0,feature_time:31983128,feature_id:55095

013004: Aug 18 2013 03:58:40.792 BR: //55878/72C54EDF920B/CCAPI/ccIFCallSetupRequestPrivate:

   SPI Call Setup Request Is Success; Interface Type=3, FlowMode=1

013005: Aug 18 2013 03:58:40.792 BR: //55878/72C54EDF920B/CCAPI/ccCallSetContext:

   Context=0x12336DE4

013006: Aug 18 2013 03:58:40.792 BR: //55877/72C54EDF920B/CCAPI/ccSaveDialpeerTag:

   Outgoing Dial-peer=114

013007: Aug 18 2013 03:58:40.792 BR: //55878/72C54EDF920B/CCAPI/cc_api_call_proceeding:

   Interface=0x1D99E34, Progress Indication=NULL(0)

013008: Aug 18 2013 03:58:40.792 BR: ISDN Se0/0/0:15 SERROR: process_pri_simple: NO name in GTD

013009: Aug 18 2013 03:58:40.792 BR: ISDN Se0/0/0:15 Q931: TX -> CALL_PROC pd = 8  callref = 0x86D1

        Channel ID i = 0xA98387

                Exclusive, Channel 7

RTR_BRK_WSS_ADM_01#

RTR_BRK_WSS_ADM_01#

RTR_BRK_WSS_ADM_01#

RTR_BRK_WSS_ADM_01#

RTR_BRK_WSS_ADM_01#

RTR_BRK_WSS_ADM_01#

RTR_BRK_WSS_ADM_01#

013010: Aug 18 2013 03:59:10.816 BR: ISDN Se0/0/0:15 Q931: RX <- DISCONNECT pd = 8  callref = 0x06D1

        Cause i = 0x82E6 - Recovery on timer expiry

013011: Aug 18 2013 03:59:10.816 BR: ISDN Se0/0/0:15 Q931: TX -> RELEASE pd = 8  callref = 0x86D1

013012: Aug 18 2013 03:59:10.816 BR: //55877/72C54EDF920B/CCAPI/cc_api_call_disconnected:

   Cause Value=102, Interface=0xBCE21C8, Call Id=55877

013013: Aug 18 2013 03:59:10.816 BR: //55877/72C54EDF920B/CCAPI/cc_api_call_disconnected:

   Call Entry(Responsed=FALSE, Cause Value=102, Retry Count=0)

013014: Aug 18 2013 03:59:10.816 BR: //55878/72C54EDF920B/CCAPI/ccCallDisconnect:

   Cause Value=102, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=0)

013015: Aug 18 2013 03:59:10.816 BR: //55878/72C54EDF920B/CCAPI/ccCallDisconnect:

   Cause Value=102, Call Entry(Responsed=FALSE, Cause Value=102)

013016: Aug 18 2013 03:59:10.816 BR: //55877/72C54EDF920B/CCAPI/ccCallDisconnect:

   Cause Value=102, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=102)

013017: Aug 18 2013 03:59:10.816 BR: //55877/72C54EDF920B/CCAPI/ccCallDisconnect:

   Cause Value=102, Call Entry(Responsed=TRUE, Cause Value=102)

013018: Aug 18 2013 03:59:10.816 BR: //55877/72C54EDF920B/CCAPI/cc_api_get_transfer_info:

   Transfer Number Is Null

013019: Aug 18 2013 03:59:10.832 BR: ISDN Se0/0/0:15 Q931: RX <- RELEASE_COMP pd = 8  callref = 0x06D1

013020: Aug 18 2013 03:59:10.836 BR: //55877/72C54EDF920B/CCAPI/cc_api_call_disconnect_done:

   Disposition=0, Interface=0xBCE21C8, Tag=0x0, Call Id=55877,

   Call Entry(Disconnect Cause=102, Voice Class Cause Code=0, Retry Count=0)

013021: Aug 18 2013 03:59:10.836 BR: //55877/72C54EDF920B/CCAPI/cc_api_call_disconnect_done:

   Call Disconnect Event Sent

013022: Aug 18 2013 03:59:10.836 BR: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

013023: Aug 18 2013 03:59:10.836 BR: :cc_free_feature_vsa freeing 1E7F810

013024: Aug 18 2013 03:59:10.836 BR: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

013025: Aug 18 2013 03:59:10.836 BR:  vsacount in free is 1

Thanks in advance!

3 Replies 3

Jorge Armijo
Level 4
Level 4

Service Provider is disconnecting the call after about 30 seconds:

012974: Aug 18 2013 03:58:40.784 BR: ISDN Se0/0/0:15 Q931: RX <- SETUP pd = 8  callref = 0x06D1

013009: Aug 18 2013 03:58:40.792 BR: ISDN Se0/0/0:15 Q931: TX -> CALL_PROC pd = 8  callref = 0x86D1

        Channel ID i = 0xA98387

                Exclusive, Channel 7

013010: Aug 18 2013 03:59:10.816 BR: ISDN Se0/0/0:15 Q931: RX <- DISCONNECT pd = 8  callref = 0x06D1

        Cause i = 0x82E6 - Recovery on timer expiry

This is expected, 30 seconds is too long for a call signaling

I'm pretty sure CUCM was not replying to the H323 Setup promptly.

HTH

--
Jorge Armijo

Please remember to rate helpful responses and identify helpful or correct answers.

-- Jorge Armijo Please remember to rate helpful responses and identify helpful or correct answers.

brmeade
Level 4
Level 4

Next time, grab the h225 messages as well to see if they're going out.

debug h225 asn1

I do not believe there is nothing related to the CM because 13 of 14 sites worked just fine, and all those sites are associated to the same CM.

Brian, thanks for the tip I hope I will not face this again, but I'll keep in mind for this command.

Getting Started

Find answers to your questions by entering keywords or phrases in the Search bar above. New here? Use these resources to familiarize yourself with the community: