isdn incoming calls fail

[sampath9614]

Hello all, 

I am dying with this issue from the past one week.

3 different location with 3 routers and 3 pbxs PRI trunking between router and pbx.

Calls from voip to analog works fin

calls from analog to IP or analog to analog fail.

after receiving one digit from isdn, receiving rx <- disconnect msg from pbx.

please find the attached config below.. along with the log

note: in the logs, the last call is from analog to ip which is failed.

IP phone: 501

analog phone: 270 / 140

thank you in advance.

[maveer]

As i can see from logs you are using Overlap digit from PBX and with Overlap receiving the router, it tries to place the call after enough digits have been received to match the destination number. In this case, after the 5 has been received. To prevent this from occurring the "T" terminator should be placed after the digits in the destination pattern. This causes the router to wait for the T302 timer to expire after each digit's reception, allowing the full number to be collected before placing the call.

So please put ammend dial-peer 10 pots which is your Incoming pots dial-peer with T after incoming called-number and it would be:

dial-peer voice 10 pots
description ## Inbound from Iris PBX ##
incoming called-number .T
direct-inward-dial
forward-digits all

[sampath9614]

Hi maveer,

Actually by deleting the direct-inward-dial solved the issue.. 

Now am facing a very annoying issue.

Ip phone registered to cme --> ip phone registered to cucm

configured voip dialpeer in cme 

configured sip trunk in cucm

not able establish the call.

output from the debugs: 

debug ip tcp transactions

debug voice ccapi inout 

Oct 17 14:59:33.531: TCP0: ACK timeout timer expired
Oct 17 15:00:19.056: TCP0: keepalive timeout (0/4)
Oct 17 15:00:20.481: TCB7FFA4432B328 getting property TCP_VRFTABLEID (20)
Oct 17 15:00:20.482: TCB7FFA4432B328 setting property TCP_TOS (11) 7FFA415B25E8
Oct 17 15:00:23.314: TCP0: ACK timeout timer expired
Oct 17 15:00:26.766: TCP0: ACK timeout timer expired
Oct 17 15:00:26.967: TCP0: ACK timeout timer expired
Oct 17 15:01:12.159: TCP0: ACK timeout timer expired
Oct 17 15:01:20.501: TCP0: keepalive timeout (0/4)
Oct 17 15:01:22.157: TCB7FFA4432B328 getting property TCP_VRFTABLEID (20)
Oct 17 15:01:22.159: TCB7FFA4432B328 setting property TCP_TOS (11) 7FFA415B25E8
Oct 17 15:02:07.678: TCP0: ACK timeout timer expired
Oct 17 15:02:22.179: TCP0: keepalive timeout (0/4)
Oct 17 15:02:23.438: TCB7FFA4432B328 getting property TCP_VRFTABLEID (20)
Oct 17 15:02:23.440: TCB7FFA4432B328 setting property TCP_TOS (11) 7FFA415B25E8
Oct 17 15:03:06.309: TCP0: ACK timeout timer expired
Oct 17 15:03:23.460: TCP0: keepalive timeout (0/4)
Oct 17 15:03:24.204: TCB7FFA4432B328 getting property TCP_VRFTABLEID (20)
Oct 17 15:03:24.206: TCB7FFA4432B328 setting property TCP_TOS (11) 7FFA415B25E8
Oct 17 15:03:55.813: TCP0: ACK timeout timer expired
Oct 17 15:04:24.226: TCP0: keepalive timeout (0/4)
Oct 17 15:04:25.354: TCB7FFA4432B328 getting property TCP_VRFTABLEID (20)
Oct 17 15:04:25.356: TCB7FFA4432B328 setting property TCP_TOS (11) 7FFA415B25E8
Oct 17 15:04:55.675: TCP0: ACK timeout timer expired
Oct 17 15:05:25.375: TCP0: keepalive timeout (0/4)
Oct 17 15:05:26.004: TCB7FFA4432B328 getting property TCP_VRFTABLEID (20)
Oct 17 15:05:26.006: TCB7FFA4432B328 setting property TCP_TOS (11) 7FFA415B25E8
Oct 17 15:05:52.148: TCP0: ACK timeout timer expired
Oct 17 15:06:26.026: TCP0: keepalive timeout (0/4)
Oct 17 15:06:26.338: TCB7FFA4432B328 getting property TCP_VRFTABLEID (20)
Oct 17 15:06:26.340: TCB7FFA4432B328 setting property TCP_TOS (11) 7FFA415B25E8
Oct 17 15:07:26.371: TCP0: keepalive timeout (0/4)
Oct 17 15:07:28.158: TCB7FFA4432B328 getting property TCP_VRFTABLEID (20)
Oct 17 15:07:28.160: TCB7FFA4432B328 setting property TCP_TOS (11) 7FFA415B25E8
Oct 17 15:07:39.810: TCP0: ACK timeout timer expired
Oct 17 15:08:28.179: TCP0: keepalive timeout (0/4)
Oct 17 15:08:29.054: TCP0: ACK timeout timer expired
Oct 17 15:08:29.340: TCB7FFA4432B328 getting property TCP_VRFTABLEID (20)
Oct 17 15:08:29.342: TCB7FFA4432B328 setting property TCP_TOS (11) 7FFA415B25E8
CORP_VGW#
CORP_VGW#
CORP_VGW#
CORP_VGW#
CORP_VGW#debug voice ccapininou
CORP_VGW#debug voice ccapi inou
CORP_VGW#debug voice ccapi inout
voip ccapi inout debugging is on
CORP_VGW#
Oct 17 15:09:00.209: //-1/77A40A498134/CCAPI/cc_api_display_ie_subfields:
cc_api_call_setup_ind_common:
cisco-username=
----- ccCallInfo IE subfields -----
cisco-ani=5555
cisco-anitype=0
cisco-aniplan=0
cisco-anipi=0
cisco-anisi=0
dest=
cisco-desttype=0
cisco-destplan=0
cisco-rdie=FFFFFFFFFFFFFFFF
cisco-rdn=
cisco-rdntype=0
cisco-rdnplan=0
cisco-rdnpi=0
cisco-rdnsi=0
cisco-redirectreason=0 fwd_final_type =0
final_redirectNumber =
hunt_group_timeout =0

Oct 17 15:09:00.209: //-1/77A40A498134/CCAPI/cc_api_call_setup_ind_common:
Interface=0x7FFA43AEE058, Call Info(
Calling Number=5555,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
Called Number=(TON=Unknown, NPI=Unknown),
Calling Translated=FALSE, Subscriber Type Str=RegularLine, FinalDestinationFlag=FALSE,
Incoming Dial-peer=20002, Progress Indication=ORIGINATING SIDE IS NON ISDN(3), Calling IE Present=TRUE,
Source Trkgrp Route Label=, Target Trkgrp Route Label=, CLID Transparent=FALSE), Call Id=-1
Oct 17 15:09:00.209: //-1/77A40A498134/CCAPI/ccCheckClipClir:
In: Calling Number=5555(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
Oct 17 15:09:00.209: //-1/77A40A498134/CCAPI/ccCheckClipClir:
Out: Calling Number=5555(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
Oct 17 15:09:00.209: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

Oct 17 15:09:00.209: :cc_get_feature_vsa malloc success
Oct 17 15:09:00.209: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

Oct 17 15:09:00.209: cc_get_feature_vsa count is 1
Oct 17 15:09:00.209: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

Oct 17 15:09:00.209: :FEATURE_VSA attributes are: feature_name:0,feature_time:140712758476436,feature_id:65
Oct 17 15:09:00.210: //176/77A40A498134/CCAPI/cc_api_call_setup_ind_common:
Set Up Event Sent;
Call Info(Calling Number=5555(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
Called Number=(TON=Unknown, NPI=Unknown))
Oct 17 15:09:00.210: //176/77A40A498134/CCAPI/cc_process_call_setup_ind:
Event=0x7FFA3DFE1FB8
Oct 17 15:09:00.210: //176/77A40A498134/CCAPI/ccCallSetContext:
Context=0x7FFA4C8BA950
Oct 17 15:09:00.211: //176/77A40A498134/CCAPI/cc_process_call_setup_ind:
>>>>CCAPI handed cid 176 with tag 20002 to app "_ManagedAppProcess_Default"
Oct 17 15:09:00.211: //176/77A40A498134/CCAPI/ccCallSetupAck:
Call Id=176
Oct 17 15:09:00.211: //176/77A40A498134/CCAPI/cc_api_set_transfer_info:
Transfer Number=, Transfer Reason=0x0
Oct 17 15:09:00.211: //176/77A40A498134/CCAPI/ccGenerateToneInfo:
Stop Tone On Digit=TRUE, Tone=Dial Tone,
Tone Direction=Network, Params=0x0, Call Id=176
Oct 17 15:09:00.211: //176/77A40A498134/CCAPI/ccSetDigitTimeouts:
Initial Digit Timeout=-1000(ms), Inter Digit Timeout=-1000(ms)
Oct 17 15:09:00.211: //176/77A40A498134/CCAPI/ccSetDigitTimeouts:
Call Entry(Inter Digit Timeout=10000(ms), Initial Digit Timeout=10000(ms))
Oct 17 15:09:00.211: //176/77A40A498134/CCAPI/ccCallReportDigits:
(callID=0xB0, digit_event=0x1, enable=TRUE, consume=FALSE)
Oct 17 15:09:00.211: //176/77A40A498134/CCAPI/ccCallReportDigits:
Enabled=TRUE, Call Id=176
Oct 17 15:09:00.211: //176/77A40A498134/CCAPI/cc_api_call_report_digits_done:
(vdbPtr=0x7FFA43AEE058, callID=0xB0, disp=0, digit_event=0x1, enable=TRUE, consume=FALSE)
Oct 17 15:09:00.211: //176/77A40A498134/CCAPI/cc_api_call_report_digits_done:
Enabled=TRUE, Disposition=0x0, Interface=0x7FFA43AEE058, Call Id=176
Oct 17 15:09:00.211: //176/77A40A498134/CCAPI/cc_api_call_report_digits_done:
Call Entry(Initial Digit Timeout=15000(ms), Inter Digit Timeout=10000(ms))
Oct 17 15:09:00.411: //176/77A40A498134/CCAPI/cc_api_call_digit_begin:
Destination Interface=0x0, Destination Mask=0x3, Destination Call Id=-1,
Source Call Id=176, Digit=5, DigitBeginFlags=0x0,
Rtp Timestamp=0x3CC698, Rtp Expiration=0x0
Oct 17 15:09:00.412: //176/77A40A498134/CCAPI/cc_api_call_digit_end:
Destination Interface=0x0, Destination Mask=0x3, Destination Call Id=-1,
Source Call Id=176, Digit=5, Duration=100,
Xrule Calling Tag=0, Xrule Called Tag=0, Digit Tone Mode=DTMF
Oct 17 15:09:00.412: //176/77A40A498134/CCAPI/cc_api_call_digit_end:
Call Entry(Handoff Depth=0)
Oct 17 15:09:00.423: TCP0: ACK timeout timer expired
Oct 17 15:09:00.612: //176/77A40A498134/CCAPI/cc_api_call_digit_begin:
Destination Interface=0x0, Destination Mask=0x3, Destination Call Id=-1,
Source Call Id=176, Digit=2, DigitBeginFlags=0x0,
Rtp Timestamp=0x3D4398, Rtp Expiration=0x0
Oct 17 15:09:00.612: //176/77A40A498134/CCAPI/cc_api_call_digit_end:
Destination Interface=0x0, Destination Mask=0x3, Destination Call Id=-1,
Source Call Id=176, Digit=2, Duration=100,
Xrule Calling Tag=0, Xrule Called Tag=0, Digit Tone Mode=DTMF
Oct 17 15:09:00.612: //176/77A40A498134/CCAPI/cc_api_call_digit_end:
Call Entry(Handoff Depth=0)
Oct 17 15:09:00.812: //176/77A40A498134/CCAPI/cc_api_call_digit_begin:
Destination Interface=0x0, Destination Mask=0x3, Destination Call Id=-1,
Source Call Id=176, Digit=2, DigitBeginFlags=0x0,
Rtp Timestamp=0x3DC098, Rtp Expiration=0x0
Oct 17 15:09:00.812: //176/77A40A498134/CCAPI/cc_api_call_digit_end:
Destination Interface=0x0, Destination Mask=0x3, Destination Call Id=-1,
Source Call Id=176, Digit=2, Duration=100,
Xrule Calling Tag=0, Xrule Called Tag=0, Digit Tone Mode=DTMF
Oct 17 15:09:00.812: //176/77A40A498134/CCAPI/cc_api_call_digit_end:
Call Entry(Handoff Depth=0)
Oct 17 15:09:00.812: //176/77A40A498134/CCAPI/ccCallReportDigits:
(callID=0xB0, digit_event=0x0, enable=FALSE, consume=FALSE)
Oct 17 15:09:00.812: //176/77A40A498134/CCAPI/ccCallReportDigits:
Enabled=TRUE, Call Id=176
Oct 17 15:09:00.812: //176/77A40A498134/CCAPI/cc_api_call_report_digits_done:
(vdbPtr=0x7FFA43AEE058, callID=0xB0, disp=0, digit_event=0x0, enable=FALSE, consume=FALSE)
Oct 17 15:09:00.813: //176/77A40A498134/CCAPI/cc_api_call_report_digits_done:
Enabled=TRUE, Disposition=0x0, Interface=0x7FFA43AEE058, Call Id=176
Oct 17 15:09:00.813: //176/77A40A498134/CCAPI/cc_api_call_report_digits_done:
Call Entry(Initial Digit Timeout=15000(ms), Inter Digit Timeout=10000(ms))
Oct 17 15:09:00.813: //176/77A40A498134/CCAPI/ccCallProceeding:
Progress Indication=NULL(0)
Oct 17 15:09:00.813: //176/77A40A498134/CCAPI/ccCallSetupRequest:
Destination=, Calling IE Present=TRUE, Mode=0,
Outgoing Dial-peer=40, Params=0x7FFA4C8B9328, Progress Indication=ORIGINATING SIDE IS NON ISDN(3)
Oct 17 15:09:00.813: //176/77A40A498134/CCAPI/ccCheckClipClir:
In: Calling Number=5555(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
Oct 17 15:09:00.813: //176/77A40A498134/CCAPI/ccCheckClipClir:
Out: Calling Number=5555(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
Oct 17 15:09:00.813: //176/77A40A498134/CCAPI/ccCallSetupRequest:
Destination Pattern=5.., Called Number=522, Digit Strip=FALSE
Oct 17 15:09:00.813: //176/77A40A498134/CCAPI/ccCallSetupRequest:
Calling Number=5555(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
Called Number=522(TON=Unknown, NPI=Unknown),
Redirect Number=, Display Info=
Account Number=, Final Destination Flag=FALSE,
Guid=77A40A49-93B2-11E6-8134-9CEC34145737, Outgoing Dial-peer=40
Oct 17 15:09:00.813: //176/77A40A498134/CCAPI/cc_api_display_ie_subfields:
ccCallSetupRequest:
cisco-username=
----- ccCallInfo IE subfields -----
cisco-ani=5555
cisco-anitype=0
cisco-aniplan=0
cisco-anipi=0
cisco-anisi=0
dest=522
cisco-desttype=0
cisco-destplan=0
cisco-rdie=FFFFFFFFFFFFFFFF
cisco-rdn=
cisco-rdntype=0
cisco-rdnplan=0
cisco-rdnpi=0
cisco-rdnsi=0
cisco-redirectreason=0 fwd_final_type =0
final_redirectNumber =
hunt_group_timeout =0

Oct 17 15:09:00.814: //176/77A40A498134/CCAPI/ccIFCallSetupRequestPrivate:
Interface=0x7FFA397A8C38, Interface Type=3, Destination=, Mode=0x0,
Call Params(Calling Number=5555,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
Called Number=522(TON=Unknown, NPI=Unknown), Calling Translated=FALSE,
Subscriber Type Str=RegularLine, FinalDestinationFlag=FALSE, Outgoing Dial-peer=40, Call Count On=FALSE,
Source Trkgrp Route Label=, Target Trkgrp Route Label=, tg_label_flag=0, Application Call Id=)
Oct 17 15:09:00.814: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

Oct 17 15:09:00.814: :cc_get_feature_vsa malloc success
Oct 17 15:09:00.814: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

Oct 17 15:09:00.814: cc_get_feature_vsa count is 2
Oct 17 15:09:00.814: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

Oct 17 15:09:00.814: :FEATURE_VSA attributes are: feature_name:0,feature_time:140712758476884,feature_id:66
Oct 17 15:09:00.814: //177/77A40A498134/CCAPI/ccIFCallSetupRequestPrivate:
SPI Call Setup Request Is Success; Interface Type=3, FlowMode=1
Oct 17 15:09:00.814: //177/77A40A498134/CCAPI/ccCallSetContext:
Context=0x7FFA4C8B92A8
Oct 17 15:09:00.814: //176/77A40A498134/CCAPI/ccSaveDialpeerTag:
Outgoing Dial-peer=40
Oct 17 15:09:00.816: //177/77A40A498134/CCAPI/cc_api_call_proceeding:
Interface=0x7FFA397A8C38, Progress Indication=NULL(0)
Oct 17 15:09:00.843: //177/77A40A498134/CCAPI/cc_api_call_disconnected:
Cause Value=38, Interface=0x7FFA397A8C38, Call Id=177
Oct 17 15:09:00.843: //177/77A40A498134/CCAPI/cc_api_call_disconnected:
Call Entry(Responsed=TRUE, Cause Value=38, Retry Count=0)
Oct 17 15:09:00.843: //176/77A40A498134/CCAPI/ccCallReleaseResources:
release reserved xcoding resource.
Oct 17 15:09:00.843: //177/77A40A498134/CCAPI/ccCallSetAAA_Accounting:
Accounting=0, Call Id=177
Oct 17 15:09:00.843: //177/77A40A498134/CCAPI/ccCallDisconnect:
Cause Value=38, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=38)
Oct 17 15:09:00.843: //177/77A40A498134/CCAPI/ccCallDisconnect:
Cause Value=38, Call Entry(Responsed=TRUE, Cause Value=38)
Oct 17 15:09:00.844: //177/77A40A498134/CCAPI/cc_api_call_disconnect_done:
Disposition=0, Interface=0x7FFA397A8C38, Tag=0x0, Call Id=177,
Call Entry(Disconnect Cause=38, Voice Class Cause Code=0, Retry Count=0)
Oct 17 15:09:00.844: //177/77A40A498134/CCAPI/cc_api_call_disconnect_done:
Call Disconnect Event Sent
Oct 17 15:09:00.844: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

Oct 17 15:09:00.844: :cc_free_feature_vsa freeing 7FFA3DFC0048
Oct 17 15:09:00.844: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

Oct 17 15:09:00.844: vsacount in free is 1
Oct 17 15:09:00.844: //176/77A40A498134/CCAPI/ccCallDisconnect:
Cause Value=38, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=0)
Oct 17 15:09:00.844: //176/77A40A498134/CCAPI/ccCallDisconnect:
Cause Value=38, Call Entry(Responsed=TRUE, Cause Value=38)
Oct 17 15:09:00.844: //176/77A40A498134/CCAPI/cc_api_get_transfer_info:
Transfer Number=NULL
Oct 17 15:09:09.347: //176/77A40A498134/CCAPI/cc_api_call_disconnect_done:
Disposition=0, Interface=0x7FFA43AEE058, Tag=0x0, Call Id=176,
Call Entry(Disconnect Cause=38, Voice Class Cause Code=0, Retry Count=0)
Oct 17 15:09:09.347: //176/77A40A498134/CCAPI/cc_api_call_disconnect_done:
Call Disconnect Event Sent
Oct 17 15:09:09.347: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

Oct 17 15:09:09.347: :cc_free_feature_vsa freeing 7FFA3DFBFE88
Oct 17 15:09:09.347: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

Oct 17 15:09:09.347: vsacount in free is 0

please let me know what wrong with my config