Problem in sip-trunk between 2811 and ISP (huawei softx3000)

[ronin]

Hi all

I have run a scenario with 2811 cisco router (PVDM2-32 and 2mft2-t1/e1) 

2811 is connected to ISP to receive 5 digit 79063 from outside and also 2811 is connected to panasonic TDA100D via a PRI/e1 link 

 called number = 79063

calling number  = 8907161493

sip provider ip address : 172.123.101.165

TDA100D----(PRI-link)---->2811----(SIP-trunk)----Huawei softx3000

the problem is incoming call from ISP to 2811 rings but drops.....

here there are sh run , debug ccsip message, debug ccsip  calls, debug idsn q931 ,debug ccsip error ,

debug voice ccapi inout

debugs are based on a call from outside calling number is 8906171493 and called number is 79063

 ios version is 15.0

would you please help me to solve the problem ? 

thanks in advance

[ronin]

hi 
I also replaced 2811 with Elastix and everything is ok when call
comes to a softphone which is registered in elastix
and these parameters monitored in asterisk sip debug in this case

timer B : 32000
min-se : 90
sess-expires : 1800
sip options : 100rel timer
auto framing : no
sess-timers : accept
sess-Refresh : uas
qualify freq : 60000msec
use reason : no
Encription : no
Rtp engin : Asterisk
Prim.Transp. : UDP
Allowed.Trsp : UDP
codecs : 0xe (gsm|ulaw|alaw)
status : ok 65 mse

could you please give me a hint to sove this problem ?

[KHud_2010]

Hi,

thanks for additional info. Which version of Elastix did you use? Did the call lasted more than 30 seconds with Elastix?

[ronin]

thanks for your attention 

 I tested this sip trunk with elastix version 2.4 32 bit 

and 

 The call did not last  with Elastix and continued as long as we wanted...

[ronin]

I also tested this scenario , I located an Elastix server between Softx3000 and 2811.
TDA100D--(PRI-link)-->2811--(SIP-trunk)-->Elastix --(Sip-trunk)-->Huawei softx3000
and also in this case everything works normal ,

but when I try to config a sip-trunk on 2811 directly to the Sip-provider it does not work .......

[Aeby Vinod]

I don't understand why there sre two SIP legs for this call, eth Invite coming in from the telco is forwarded to 10.194.22.16 as an Invite message however we do not get a response for this

Additionally the Q(31 debugs says "Requested circuit/channel not available" however this looks like a diff call.

*Feb 24 13:51:30.290: ISDN Se0/0/0:15 Q931: RX <- RELEASE_COMP pd = 8 callref = 0x8086
Cause i = 0x81AC - Requested circuit/channel not available

Please attach a show run and the following debugs taken simultaneously for a call and not separately

debug ccsip message
debug idsn q931
debug voice ccapi inout

Please rate if you find this helpful.

Regards,
Aeby

[ronin]

!
ip cef
!

no ipv6 cef
!
multilink bundle-name authenticated
!
!
!
!
isdn switch-type primary-net5
!
!
!
voice service voip
allow-connections h323 to h323
allow-connections h323 to sip
allow-connections sip to h323
allow-connections sip to sip
h323
sip
bind control source-interface FastEthernet0/1
bind media source-interface FastEthernet0/1

controller E1 0/0/0
framing NO-CRC4
pri-group timeslots 1-32
!
controller E1 0/0/1
!
!
!
!
!
!
!
!
!
interface FastEthernet0/0
no ip add
duplex auto
speed auto
!
!
interface FastEthernet0/1
ip address 172.194.22.166 255.255.255.252
duplex auto
speed auto
!
!
interface Serial0/0/0:15
no ip address
encapsulation hdlc
isdn switch-type primary-qsig
isdn overlap-receiving
isdn protocol-emulate network
isdn incoming-voice voice
!
!
ip forward-protocol nd
ip http server
no ip http secure-server
!
!
ip route 0.0.0.0 0.0.0.0 172.194.22.165
ip route 172.123.101.0 255.255.255.0 172.194.22.165
!
!
!
!
!
!
!
control-plane
!
!
!
voice-port 0/0/0:15
!
!
!
!
dial-peer voice 100 pots
destination-pattern 79063
port 0/0/0:15

!
dial-peer voice 10 voip
destination-pattern .T
session protocol sipv2
session target ipv4:172.123.101.165

dtmf-relay rtp-nte sip-notify
no vad
!

[ronin]

Router#debug isdn q931
debug isdn q931 is ON.

*Feb 24 13:51:30.254: ISDN Se0/0/0:15 Q931: Applying typeplan for sw-type 0x12 is 0x0 0x1, Calling num 8907161493
*Feb 24 13:51:30.254: ISDN Se0/0/0:15 Q931: Sending SETUP callref = 0x0086 callID = 0x8007 switch = primary-net5 interface = Network
*Feb 24 13:51:30.254: ISDN Se0/0/0:15 Q931: TX -> SETUP pd = 8 callref = 0x0086
Bearer Capability i = 0x8090A3
Standard = CCITT
Transfer Capability = Speech
Transfer Mode = Circuit
Transfer Rate = 64 kbit/s
Channel ID i = 0xA98381
Exclusive, Channel 1
Calling Party Number i = 0x0180, '8907161493'
Plan:ISDN, Type:Unknown
Called Party Number i = 0x81, '79063'
Plan:ISDN, Type:Unknown
*Feb 24 13:51:30.290: ISDN Se0/0/0:15 Q931: RX <- RELEASE_COMP pd = 8 callref = 0x8086
Cause i = 0x81AC - Requested circuit/channel not available
Router#

_____________________________________________________________________________

debug voice ccapi inout

Router#
*Feb 24 13:48:07.262: //121/xxxxxxxxxxxx/CCAPI/cc_api_caps_ind:
Call Entry Is Not Found
*Feb 24 13:48:07.262: //-1/2D88678E802E/CCAPI/cc_api_display_ie_subfields:
cc_api_call_setup_ind_common:
cisco-username=8907161493
----- ccCallInfo IE subfields -----
cisco-ani=8907161493
cisco-anitype=0
cisco-aniplan=0
cisco-anipi=0
cisco-anisi=0
dest=79063
cisco-desttype=0
cisco-destplan=0
cisco-rdie=FFFFFFFF
cisco-rdn=
cisco-lastrdn=
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

*Feb 24 13:48:07.266: //-1/2D88678E802E/CCAPI/cc_api_call_setup_ind_common:
Interface=0x4909657C, Call Info(
Calling Number=8907161493,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
Called Number=79063(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=121
*Feb 24 13:48:07.266: //-1/2D88678E802E/CCAPI/ccCheckClipClir:
In: Calling Number=8907161493(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
*Feb 24 13:48:07.266: //-1/2D88678E802E/CCAPI/ccCheckClipClir:
Out: Calling Number=8907161493(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
*Feb 24 13:48:07.266: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 13:48:07.266: :cc_get_feature_vsa malloc success
*Feb 24 13:48:07.266: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 13:48:07.266: cc_get_feature_vsa count is 1
*Feb 24 13:48:07.266: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 13:48:07.266: :FEATURE_VSA attributes are: feature_name:0,feature_time:1248335056,feature_id:16
*Feb 24 13:48:07.266: //121/2D88678E802E/CCAPI/cc_api_call_setup_ind_common:
Set Up Event Sent;
Call Info(Calling Number=8907161493(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
Called Number=79063(TON=Unknown, NPI=Unknown))
*Feb 24 13:48:07.270: //121/2D88678E802E/CCAPI/cc_process_call_setup_ind:
Event=0x49EB7860
*Feb 24 13:48:07.270: //-1/xxxxxxxxxxxx/CCAPI/cc_setupind_match_search:
Try with the demoted called number 79063
*Feb 24 13:48:07.270: //121/2D88678E802E/CCAPI/ccCallSetContext:
Context=0x4BFE8244
*Feb 24 13:48:07.270: //121/2D88678E802E/CCAPI/cc_process_call_setup_ind:
>>>>CCAPI handed cid 121 with tag 1 to app "_ManagedAppProcess_Default"
*Feb 24 13:48:07.270: //121/2D88678E802E/CCAPI/ccCallProceeding:
Progress Indication=NULL(0)
*Feb 24 13:48:07.274: //121/2D88678E802E/CCAPI/ccCallSetupRequest:
Destination=, Calling IE Present=TRUE, Mode=0,
Outgoing Dial-peer=100, Params=0x4BFE959C, Progress Indication=NULL(0)
*Feb 24 13:48:07.274: //121/2D88678E802E/CCAPI/ccCheckClipClir:
In: Calling Number=8907161493(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
*Feb 24 13:48:07.274: //121/2D88678E802E/CCAPI/ccCheckClipClir:
Out: Calling Number=8907161493(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
*Feb 24 13:48:07.274: //121/2D88678E802E/CCAPI/ccCallSetupRequest:
Destination Pattern=79063T, Called Number=79063, Digit Strip=FALSE
*Feb 24 13:48:07.278: //121/2D88678E802E/CCAPI/ccCallSetupRequest:
Calling Number=8907161493(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
Called Number=79063(TON=Unknown, NPI=Unknown),
Redirect Number=, Display Info=
Account Number=8907161493, Final Destination Flag=TRUE,
Guid=2D88678E-18A0-11E8-802E-AE3C56001BD5, Outgoing Dial-peer=100
*Feb 24 13:48:07.278: //121/2D88678E802E/CCAPI/cc_api_display_ie_subfields:
ccCallSetupRequest:
cisco-username=8907161493
----- ccCallInfo IE subfields -----
cisco-ani=8907161493
cisco-anitype=0
cisco-aniplan=0
cisco-anipi=0
cisco-anisi=0
dest=79063
cisco-desttype=0
cisco-destplan=0
cisco-rdie=FFFFFFFF
cisco-rdn=
cisco-lastrdn=
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

*Feb 24 13:48:07.278: //121/2D88678E802E/CCAPI/ccIFCallSetupRequestPrivate:
Interface=0x49F02D68, Interface Type=6, Destination=, Mode=0x0,
Call Params(Calling Number=8907161493,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
Called Number=79063(TON=Unknown, NPI=Unknown), Calling Translated=FALSE,
Subscriber Type Str=Unknown, FinalDestinationFlag=TRUE, Outgoing Dial-peer=100, Call Count On=FALSE,
Source Trkgrp Route Label=, Target Trkgrp Route Label=, tg_label_flag=0, Application Call Id=)
*Feb 24 13:48:07.278: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 13:48:07.278: :cc_get_feature_vsa malloc success
*Feb 24 13:48:07.278: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 13:48:07.278: cc_get_feature_vsa count is 2
*Feb 24 13:48:07.278: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 13:48:07.278: :FEATURE_VSA attributes are: feature_name:0,feature_time:1248334832,feature_id:17
*Feb 24 13:48:07.278: //122/2D88678E802E/CCAPI/ccIFCallSetupRequestPrivate:
SPI Call Setup Request Is Success; Interface Type=6, FlowMode=1
*Feb 24 13:48:07.278: //122/2D88678E802E/CCAPI/ccCallSetContext:
Context=0x4BFE954C
*Feb 24 13:48:07.278: //121/2D88678E802E/CCAPI/ccSaveDialpeerTag:
Outgoing Dial-peer=100
*Feb 24 13:48:07.326: //122/2D88678E802E/CCAPI/cc_api_call_disconnected:
Cause Value=44, Interface=0x49F02D68, Call Id=122
*Feb 24 13:48:07.326: //122/2D88678E802E/CCAPI/cc_api_call_disconnected:
Call Entry(Responsed=TRUE, Cause Value=44, Retry Count=0)
*Feb 24 13:48:07.326: //121/xxxxxxxxxxxx/CCAPI/ccCallReleaseResources:
release reserved xcoding resource.
*Feb 24 13:48:07.326: //122/2D88678E802E/CCAPI/ccCallSetAAA_Accounting:
Accounting=1, Call Id=122
*Feb 24 13:48:07.326: //122/2D88678E802E/CCAPI/ccCallDisconnect:
Cause Value=44, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=44)
*Feb 24 13:48:07.326: //122/2D88678E802E/CCAPI/ccCallDisconnect:
Cause Value=44, Call Entry(Responsed=TRUE, Cause Value=44)
*Feb 24 13:48:07.330: //122/2D88678E802E/CCAPI/cc_api_call_disconnect_done:
Disposition=0, Interface=0x49F02D68, Tag=0x0, Call Id=122,
Call Entry(Disconnect Cause=44, Voice Class Cause Code=0, Retry Count=0)
*Feb 24 13:48:07.330: //122/2D88678E802E/CCAPI/cc_api_call_disconnect_done:
Call Disconnect Event Sent
*Feb 24 13:48:07.330: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*Feb 24 13:48:07.330: :cc_free_feature_vsa freeing 4A6813E8
*Feb 24 13:48:07.330: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*Feb 24 13:48:07.330: vsacount in free is 1
*Feb 24 13:48:07.334: //121/2D88678E802E/CCAPI/ccCallSetupRequest:
Destination=, Calling IE Present=TRUE, Mode=0,
Outgoing Dial-peer=10, Params=0x4BFEA8A4, Progress Indication=NULL(0)
*Feb 24 13:48:07.334: //121/2D88678E802E/CCAPI/ccCheckClipClir:
In: Calling Number=8907161493(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
*Feb 24 13:48:07.334: //121/2D88678E802E/CCAPI/ccCheckClipClir:
Out: Calling Number=8907161493(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed)
*Feb 24 13:48:07.334: //121/2D88678E802E/CCAPI/ccCallSetupRequest:
Destination Pattern=.T, Called Number=79063, Digit Strip=FALSE
*Feb 24 13:48:07.334: //121/2D88678E802E/CCAPI/ccCallSetupRequest:
Calling Number=8907161493(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
Called Number=79063(TON=Unknown, NPI=Unknown),
Redirect Number=, Display Info=
Account Number=8907161493, Final Destination Flag=TRUE,
Guid=2D88678E-18A0-11E8-802E-AE3C56001BD5, Outgoing Dial-peer=10
*Feb 24 13:48:07.334: //121/2D88678E802E/CCAPI/cc_api_display_ie_subfields:
ccCallSetupRequest:
cisco-username=8907161493
----- ccCallInfo IE subfields -----
cisco-ani=8907161493
cisco-anitype=0
cisco-aniplan=0
cisco-anipi=0
cisco-anisi=0
dest=79063
cisco-desttype=0
cisco-destplan=0
cisco-rdie=FFFFFFFF
cisco-rdn=
cisco-lastrdn=
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

*Feb 24 13:48:07.334: //121/2D88678E802E/CCAPI/ccIFCallSetupRequestPrivate:
Interface=0x4909657C, Interface Type=3, Destination=, Mode=0x0,
Call Params(Calling Number=8907161493,(Calling Name=)(TON=Unknown, NPI=Unknown, Screening=Not Screened, Presentation=Allowed),
Called Number=79063(TON=Unknown, NPI=Unknown), Calling Translated=FALSE,
Subscriber Type Str=Unknown, 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=)
*Feb 24 13:48:07.334: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 13:48:07.334: :cc_get_feature_vsa malloc success
*Feb 24 13:48:07.334: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 13:48:07.334: cc_get_feature_vsa count is 2
*Feb 24 13:48:07.334: //-1/xxxxxxxxxxxx/CCAPI/cc_get_feature_vsa:

*Feb 24 13:48:07.334: :FEATURE_VSA attributes are: feature_name:0,feature_time:1248334832,feature_id:18
*Feb 24 13:48:07.338: //123/2D88678E802E/CCAPI/ccIFCallSetupRequestPrivate:
SPI Call Setup Request Is Success; Interface Type=3, FlowMode=1
*Feb 24 13:48:07.338: //123/2D88678E802E/CCAPI/ccCallSetContext:
Context=0x4BFEA854
*Feb 24 13:48:07.338: //121/2D88678E802E/CCAPI/ccSaveDialpeerTag:
Outgoing Dial-peer=10
*Feb 24 13:48:07.342: //123/2D88678E802E/CCAPI/cc_api_call_proceeding:
Interface=0x4909657C, Progress Indication=NULL(0)
*Feb 24 13:48:26.870: //121/2D88678E802E/CCAPI/cc_api_call_disconnected:
Cause Value=16, Interface=0x4909657C, Call Id=121
*Feb 24 13:48:26.870: //121/2D88678E802E/CCAPI/cc_api_call_disconnected:
Call Entry(Responsed=FALSE, Cause Value=16, Retry Count=0)
*Feb 24 13:48:26.870: //123/2D88678E802E/CCAPI/ccCallDisconnect:
Cause Value=16, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=0)
*Feb 24 13:48:26.870: //123/2D88678E802E/CCAPI/ccCallDisconnect:
Cause Value=16, Call Entry(Responsed=FALSE, Cause Value=16)
*Feb 24 13:48:26.870: //121/2D88678E802E/CCAPI/ccCallDisconnect:
Cause Value=16, Tag=0x0, Call Entry(Previous Disconnect Cause=0, Disconnect Cause=16)
*Feb 24 13:48:26.870: //121/2D88678E802E/CCAPI/ccCallDisconnect:
Cause Value=16, Call Entry(Responsed=TRUE, Cause Value=16)
*Feb 24 13:48:26.886: //121/2D88678E802E/CCAPI/cc_api_call_disconnect_done:
Disposition=0, Interface=0x4909657C, Tag=0x0, Call Id=121,
Call Entry(Disconnect Cause=16, Voice Class Cause Code=0, Retry Count=0)
*Feb 24 13:48:26.886: //121/2D88678E802E/CCAPI/cc_api_call_disconnect_done:
Call Disconnect Event Sent
*Feb 24 13:48:26.886: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*Feb 24 13:48:26.886: :cc_free_feature_vsa freeing 4A6814C8
*Feb 24 13:48:26.886: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*Feb 24 13:48:26.886: vsacount in free is 1

Router#
*Feb 24 13:49:10.846: //123/2D88678E802E/CCAPI/cc_api_call_disconnect_done:
Disposition=-11, Interface=0x4909657C, Tag=0x0, Call Id=123,
Call Entry(Disconnect Cause=16, Voice Class Cause Code=0, Retry Count=0)
*Feb 24 13:49:10.846: //123/2D88678E802E/CCAPI/cc_api_call_disconnect_done:
Call Disconnect Event Sent
*Feb 24 13:49:10.846: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*Feb 24 13:49:10.846: :cc_free_feature_vsa freeing 4A6813E8
*Feb 24 13:49:10.846: //-1/xxxxxxxxxxxx/CCAPI/cc_free_feature_vsa:

*Feb 24 13:49:10.846: vsacount in free is 0
Router#

[R0g22]

This does not look like a incoming call from the ISP. This is you sending a call to your ISP and they reject it. You are sending the calls in an ascending order using the first channel. The IOS should default to descending order in order to avoid a possible call collision.

[ronin]

it seems that in  normal sip trunk between cisco 2811 and telecomm sip provider , option sip message should send and receive every 10 seconds

but in my case there is no sip option message ...

how can I chage option settings and parameters in my router ?

thanks 

[R0g22]

https://www.cisco.com/c/en/us/td/docs/ios/voice/cube/configuration/guide/vb_book/vb_book/vb_9321.html

[Saurabh · Accepted solution]

Hi Amir

After referring to your logs, following are the observations.
1. Call coming into 2811 from Huawei softphone hits the incoming dial-peer 1
2. Based on called number, outbound dial-peer 100 is hit which i assume is pots dial-peer and from their call gets reject with cause code=44 which occurs when pri-lines are not available.
3. After this cause code, hunting moves to other dial peer 10 which is voip and which sends sip invite to remote destination but no response from it.

Can you check whether your PRI lines are up and are functional. check "show isdn status" output. and check with TDA100D system when request comes this system is not able to assign channel. "debug isdn q931" can help in this.

[ronin]

Hi

thanks for your reply 

you are right , I'll check the isdn link status to fix the issue

thanks in advance

[R0g22 · Accepted solution]

PRI would be working otherwise Q.931 wouldn't have been possible. I see SETUP being extended out and being disconnected. The hex for the cause code -

0x81AC >> 81 is the disconnect originator. This is a private network close to you as a user. Check the smartjack. If possible, reboot it. Check the output for "show controller t1". If you see a lot of LCV/PCV, replace the cabling and then test.

[ronin]

thank you all for your help and support

problem is now solved by reconfiguration of TDA PRI link and e1/t1...