This was an interesting scenario where incoming calls were getting ‘user busy’ message at the gateway and an engage tone was heard at calling party side.
*Aug 18 08:36:53.581: ISDN Se0/0/0:15 Q931: RX <-CALL_PROC pd = 8 callref = 0x8D7E
Channel ID i = 0xA9839E
Exclusive, Channel 30
*Aug 18 08:36:54.997: ISDN Se0/0/0:15 Q931: RX <- DISCONNECT pd = 8 callref = 0x8D7E
Cause i = 0x8091 -User busy
It was not just one extension but several extensions which were having the same issue. They were all running fine till yesterday!
Something must have happened…
I did debug voip ccapi inout for a working extension and a non-working one, this is what I found:
Successful call to 7536 and un-successful call to 7534:
Call to 7536:
Aug 19 08:41:00.697: //757/541618588180/CCAPI/cc_api_display_ie_subfields:
ccCallSetupRequest:
cisco-username=
—– ccCallInfo IE subfields —–
cisco-ani=9XXXXXXX395
cisco-anitype=2
cisco-aniplan=1
cisco-anipi=0
cisco-anisi=1
dest=7536
cisco-desttype=0
cisco-destplan=1
cisco-rdie=FFFFFFFF
cisco-rdn=
cisco-lastrdn=
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
Aug 19 08:41:00.697: //757/541618588180/CCAPI/ccIFCallSetupRequestPrivate:
Interface=0x480CDF30, Interface Type=1, Destination=, Mode=0x0,
Call Params(Calling Number=9XXXXXXX395,(Calling Name=)(TON=National, NPI=ISDN, Screening=User, Passed, Presentation=Allowed),
Called Number=7536(TON=Unknown, NPI=ISDN), Calling Translated=FALSE,
Subscriber Type Str=RegularLine, FinalDestinationFlag=TRUE, Outgoing Dial-peer=10, Call Count On=FALSE,
Source Trkgrp Route Label=, Target Trkgrp Route Label=, tg_label_flag=0, Application Call Id=)
Aug 19 08:41:00.701: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
Aug 19 08:41:00.701: :cc_get_feature_vsa malloc success
Aug 19 08:41:00.701: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
Aug 19 08:41:00.701: cc_get_feature_vsa count is 8
Aug 19 08:41:00.701: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
Aug 19 08:41:00.701: :FEATURE_VSA attributes are: feature_name:0,feature_time:1187854080,feature_id:785
Aug 19 08:41:00.701: //758/541618588180/CCAPI/ccIFCallSetupRequestPrivate:
SPI Call Setup Request Is Success; Interface Type=1, FlowMode=1
Aug 19 08:41:00.701: //758/541618588180/CCAPI/ccCallSetContext:
Context=0x46B3748C
Aug 19 08:41:00.701: //757/541618588180/CCAPI/ccSaveDialpeerTag:
Outgoing Dial-peer=10
Aug 19 08:41:00.901: //758/541618588180/CCAPI/cc_api_set_called_ccm_detected:
CallInfo(called ccm detected=TRUE ccmVersion 1)
Aug 19 08:41:00.901: //758/541618588180/CCAPI/cc_api_call_proceeding:
Interface=0x480CDF30, Progress Indication=NULL(0)
Aug 19 08:41:00.905: //758/541618588180/CCAPI/cc_api_set_called_ccm_detected:
CallInfo(called ccm detected=TRUE ccmVersion 1)
Aug 19 08:41:00.905: //758/541618588180/CCAPI/cc_api_set_delay_xport:
CallInfo(delay xport=TRUE)
Aug 19 08:41:00.905: //758/541618588180/CCAPI/cc_api_call_alert:
Interface=0x480CDF30, Progress Indication=NULL(0), Signal Indication=SIGNAL RINGBACK(1)
Aug 19 08:41:00.909: //758/541618588180/CCAPI/cc_api_call_alert:
Call Entry(Retry Count=0, Responsed=TRUE)
Aug 19 08:41:00.909: //758/541618588180/CCAPI/cc_api_set_called_ccm_detected:
CallInfo(called ccm detected=TRUE ccmVersion 1)
Aug 19 08:41:00.909: //758/541618588180/CCAPI/cc_api_call_notify:
Data Bitmask=0x5, Interface=0x480CDF30, Call Id=758
Aug 19 08:41:00.909: //757/541618588180/CCAPI/ccCallAlert:
Progress Indication=NULL(0), Signal Indication=SIGNAL RINGBACK(1)
Aug 19 08:41:00.909: //757/541618588180/CCAPI/ccCallAlert:
Call Entry(Responsed=TRUE, Alert Sent=TRUE)
Aug 19 08:41:00.913: //757/541618588180/CCAPI/ccGenerateToneInfo:
Stop Tone On Digit=FALSE, Tone=Ring Back,
Tone Direction=Network, Params=0x0, Call Id=757
Aug 19 08:41:00.921: //758/541618588180/CCAPI/cc_api_get_ssCTreRoutingNotSupported:
CallInfo(ssCTreRoutingNotSupported=FALSE)
Aug 19 08:41:00.921: //758/541618588180/CCAPI/cc_api_get_ccm_detected:
CallInfo(ccm detected=TRUE)
Aug 19 08:41:00.921: //757/541618588180/
CCAPI/ccCallNotify:
Data Bitmask=0x5, Call Id=757
Call to 7534:
—– ccCallInfo IE subfields —–
cisco-ani=9XXXXXXX395
cisco-anitype=2
cisco-aniplan=1
cisco-anipi=0
cisco-anisi=1
dest=7534
cisco-desttype=0
cisco-destplan=1
cisco-rdie=FFFFFFFF
cisco-rdn=
cisco-lastrdn=
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
Aug 19 08:36:26.159: //-1/B07908F8816D/CCAPI/cc_api_call_setup_ind_common:
Interface=0x49470D5C, Call Info(Calling Number=9XXXXXXX395,(Calling Name=)(TON=National, NPI=ISDN, Screening=User, Passed, Presentation=Allowed),Called Number=7534(TON=Unknown, NPI=ISDN),
Calling Translated=FALSE, Subscriber Type Str=RegularLine, FinalDestinationFlag=TRUE,
Incoming Dial-peer=2, Progress Indication=NULL(0), Calling IE Present=TRUE,
Source Trkgrp Route Label=, Target Trkgrp Route Label=, CLID Transparent=FALSE), Call Id=-1
Aug 19 08:36:26.159: //-1/B07908F8816D/CCAPI/ccCheckClipClir:
In: Calling Number=9XXXXXXX395(TON=National, NPI=ISDN, Screening=User, Passed, Presentation=Allowed)
Aug 19 08:36:26.159: //-1/B07908F8816D/CCAPI/ccCheckClipClir:
Out: Calling Number=9XXXXXXX395(TON=National, NPI=ISDN, Screening=User, Passed, Presentation=Allowed)
Aug 19 08:36:26.159: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
Aug 19 08:36:26.163: :cc_get_feature_vsa malloc success
Aug 19 08:36:26.163: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
Aug 19 08:36:26.163: cc_get_feature_vsa count is 11
Aug 19 08:36:26.163: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:
Aug 19 08:36:26.163: :FEATURE_VSA attributes are: feature_name:0,feature_time:1187856544,feature_id:752
Aug 19 08:36:26.163: //725/B07908F8816D/CCAPI/cc_api_call_setup_ind_common:
Set Up Event Sent;
Call Info(Calling Number=9XXXXXXX395(TON=National, NPI=ISDN, Screening=User, Passed, Presentation=Allowed),
Called Number=7534(TON=Unknown, NPI=ISDN))
Aug 19 08:36:26.167: //725/B07908F8816D/CCAPI/cc_process_call_setup_ind:
Event=0x48577A78
Aug 19 08:36:26.167: //-1/xxxxxxxxxxxx/CCAPI/cc_setupind_match_search:
Try with the demoted called number 7534
Aug 19 08:36:26.167: //725/B07908F8816D/CCAPI/ccCallSetContext:
Context=0x46B3C0AC
Aug 19 08:36:26.167: //725/B07908F8816D/CCAPI/cc_process_call_setup_ind:
>>>>CCAPI handed cid 725 with tag 2 to app “_ManagedAppProcess_Default”
Aug 19 08:36:26.179: //725/B07908F8816D/CCAPI/ccCallProceeding:
Progress Indication=NULL(0)
Aug 19 08:36:26.183: //-1/xxxxxxxxxxxx/CCAPI/cc_setupind_match_search:
Try with the demoted called number 7534
Aug 19 08:36:26.183: //-1/xxxxxxxxxxxx/CCAPI/cc_update_feature_vsa:
Aug 19 08:36:26.183: : updating existing feature vsa
Aug 19 08:36:26.183: //-1/xxxxxxxxxxxx/CCAPI/cc_update_feature_vsa:
Aug 19 08:36:26.183: feature call basic
Aug 19 08:36:26.203: //725/B07908F8816D/CCAPI/ccCallDisconnect:
Cause(Value=17, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=0)
Aug 19 08:36:26.203: //725/B07908F8816D/CCAPI/ccCallDisconnect:
Cause Value=17, Call Entry(Responsed=TRUE, Cause Value=17)
Aug 19 08:36:26.203: //725/B07908F8816D/CCAPI/cc_api_get_transfer_info:
Transfer Number Is Null
Aug 19 08:36:26.371: //725/B07908F8816D/CCAPI/cc_api_call_disconnect_done:
Disposition=0, Interface=0x49470D5C, Tag=0x0, Call Id=725,
Call Entry(Disconnect Cause=17, Voice Class Cause Code=0, Retry Count=0)
Aug 19 08:36:26.375: //725/B07908F8816D/CCAPI/cc_api_call_disconnect_done:
Call Disconnect Event Sent
Aug 19 08:36:26.375: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
Aug 19 08:36:26.375: :cc_free_feature_vsa freeing 46CD4098
Aug 19 08:36:26.375: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:
The above results show that a successful call did hit the outbound VoIP dialpeer which was pointing to CCM but the failed call was just hitting the Inbound POTS dialpeer and was not routing to the VoIP dialpeer. Why in the world one DDI of same range is routing to CCM while other is returning user busy (the cause code 17 is user busy). The phone at x7534 was registered to call manager and there were all ISDN channels available (Show isdn service). I checked the gateway configuration and found telephony-service configured on it with auto-provision none.
telephony-service
srst mode auto-provision none
srst ephone template 1
srst ephone description srst fallback auto-provision phone
srst dn template 1
srst dn line-mode dual
.
.
But I could also see all ephones and ephone-dn’s in the configuration. I found out that this failed extension x7534 was sitting there under one of the ephone-dn. I confirmed that a third party engineer configured SRST on the router previous evening and he checked everything working fine ….. what he did….he configured srst auto provision all to learn the dn’s so that he can configure the hunt groups and then locked it down using srst auto provision none. This, however, produced abnormal results as the phones which were learned by the gateway were preferred over VoIP dialpeer and a call to these numbers was not getting routed to Call manager. This is what I did to solve this issue:
Router(config)# dial-peer hunt 3
•0—Specifies longest match in phone number, explicit preference, random selection (default)
•1—Specifies longest match in phone number, explicit preference, least recent use.
•2—Specifies explicit preference, longest match in phone number, random selection.
•3—Specifies explicit preference, longest match in phone number, least recent use.
•4—Specifies least recent use, longest match in phone number, explicit preference.
•5—Specifies least recent use, explicit preference, longest match in phone number.
•6—Specifies random selection.
•7—Specifies least recent use.
ephone-dn 1 dual-line
preference 8
!
!
ephone-dn 2 dual-line
preference 8
!
!
ephone-dn 3 dual-line
preference 8
!
!
ephone-dn 4 dual-line
preference 8
!
!
ephone-dn 5 dual-line
preference 8
!
!
ephone-dn 6 dual-line
preference 8
!
to ephone-dn 45
– same –
Tested the call all working fine.
What was happening – the call was coming in and because the phone was learned as ephone it was preferred over VoIP dialpeer.
To avoid incorrect routing when you prebuild ephone-dns for Cisco Unified Communications Manager phones in Cisco Unified CME, use the preference command in ephone-dn and voip-dial-peer configuration mode to create a higher preference (0 being the highest) for the voip dial peer than the preference for the prebuilt directory number.
voiceonbits.com 
Really useful man – quite why Cisco cannot cover this in the CME as SRST documentation I don’t know!
Mine is a bit different.
I have a CallManager Cluster (ver 6.1) and a voice gateway (Cisco 3945). All my other gateways are running mgcp but this one cant as CUCM 6.1 does not support 3945 using mgcp.
Routing to and from a site using a 3945 works 100% using h323. Only problem is that when you’re calling a mobile number, and press decline on the mobile, the Cisco IP phones is still getting a ringback tone for a couple of second and finally gets a user busy tone and message on the screen.
Where can I configure this?
I’ve ran traces on the gateway and I see a User Busy message but CallManager does not clear the call:
025993: Nov 22 14:43:15.722: ISDN Se0/0/0:15 Q931: RX <- DISCONNECT pd = 8 callref = 0xA771
Cause i = 0×8091 – User busy
Please advise
Try service parameter “Send H225 user Info message” is set to “User info for Call Progress Tone”.
Never mind. Global config command: voice call disc-pi-off solved the problem.
Sorry Asharsidd, only saw you post after I sent mine.
I didnt really want to change anything on the Callmanager Cluster as other gateways are working fine. Only problem is that all the other ones are running mgcp and there is a lot of tuning and tweaking needed on the H.323 gateway.
I’m a fan of the site though 🙂
Thanks for sharing that info Zipho 🙂
ash man you are on another level. you make me wonder how you do it.
it did work on my case! so HELPFUL! and recommended!!!
Hi, I had the same issue so I have configured the dial-peer hunt, it resolved the issue but I have a new one, single number reach (snr or mobility) do not work anymore. Do you have an idea ? Thank you
call flow : Phone A—PBX( 3rd party) — ISDN BRI — Sip gateway — SIP — ITSP— PSTN USER
When Phone A user calls PSTN User, and that PSTN User defers the call, Phone A (PBX) user still hears ringing tone and it takes 30 seconds for the call to get disconnect.