We are integrating a PRI Trunk with our Softswitch and a NEC 5000. Both Inbound and Outgoing trunks are not working. The inbound call does come through out trunk
to the Adtran but we are getting an a busy from the PRI. The outbound call does attempt through the NEC to the Adtran and to our softswitch but the Adtran doesn't send the call out to the SIP trunk.
Below are logs that show the issues and attached is the complete log and configuration.
We would appreciate what ever assistance can be provided.
For the Inbound call leg we are getting a busy per below is the logs for both incoming and outgoing call legs:
5:50:20.786 SIP.CLDU Cldu::CallLegCreatedEv: (0x24d6240)
15:50:20.787 SIP.CLDU Incoming CallLeg created from +1248766xxxx@Softswitch.net:5060 to 201@9x.xx.xxx.13:5060
15:50:20.789 SIP.CLDU Searching for a matching trunk account by Via (1xx.xx.xxx.139:5060)
15:50:20.790 SIP.CLDU findClduInterface: 1xx.xx.xxx.139 match to configured SIP server (host/port) succeeded for T01
15:50:20.790 SIP.CLDU Routing call to trunk from +1248766xxxx
15:50:20.791 SIP.CLDU Incoming message received from 1xx.xx.xxx.139:5060 via UDP
15:50:20.792 TM.T01 01 SipTM_Idle rcvd SIP call-leg request: INVITE
15:50:20.793 SIP.CLDU Cldu::CallLegStateChangedEv: (0x24d6240)->Offering
15:50:20.794 TM.T01 01 SipTM_Idle call-leg -> Offering
15:50:20.795 TM.T01 01 SipTM_Idle State change >> SipTM_Idle->SipTM_Trying
15:50:20.797 TM.T01 01 SipTM_Trying SDP offer is not loopback request
15:50:20.798 TM.T01 01 SipTM_Trying Processing From for Caller-ID.
15:50:20.799 TM.T01 01 T01 01 SipTM_Trying e164 calling number converted to dialstring 248766xxxx
15:50:20.799 TM.T01 01 SipTM_Trying Caller ID Name = VOIP PROVIDER
15:50:20.800 TM.T01 01 SipTM_Trying Caller ID Number = "248766xxxx"
15:50:20.800 TM.T01 01 SipTM_Trying info: unable to set redirect number(s) from INVITE
15:50:20.801 TM.T01 01 SipTM_Trying sent: TA->InboundCall
15:50:20.802 SIP.CLDU Looking up outbound interface to 1xx.xx.xxx.139
15:50:20.803 TM.T01 01 call-leg (0x24d6240) -> src-ip: 9x.xx.xxx.13 dst-ip: 1xx.xx.xxx.139
15:50:20.806 SIP.STACK MSG Tx: UDP src=9x.xx.xxx.13:5060 dst=1xx.xx.xxx.139:5060
15:50:20.807 SIP.STACK MSGSUM Tx: SIP/2.0 100 Trying
15:50:20.807 SIP.STACK MSG SIP/2.0 100 Trying
15:50:20.808 SIP.STACK MSG From: VOIP PROVIDER<sip:+1248766xxxx@Softswitch.net>;tag=1699168939
15:50:20.808 SIP.STACK MSG To: Customer<sip:1084@Softswitch.net>
15:50:20.809 SIP.STACK MSG Call-ID: 00d65e31@pbx
15:50:20.809 SIP.STACK MSG CSeq: 1933 INVITE
15:50:20.810 SIP.STACK MSG Via: SIP/2.0/UDP 1xx.xx.xxx.139:5060;rport=5060;branch=z9hG4bK-5d985245cb53599a7f14372272542583
15:50:20.810 SIP.STACK MSG Contact: <sip:201@9x.xx.xxx.13:5060;transport=UDP>
15:50:20.811 SIP.STACK MSG Supported: 100rel,replaces
15:50:20.812 SIP.STACK MSG Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, PRACK, REFER, REGISTER
15:50:20.812 SIP.STACK MSG User-Agent: ADTRAN_Total_Access_908_1st_Gen/A4.11.00.E
15:50:20.813 SIP.STACK MSG Content-Length: 0
15:50:20.813 SIP.STACK MSG
15:50:20.814 TM.T01 01 SipTM_Trying sent: 100 Trying
15:50:20.815 TA.T01 01 TAIdle rcvd: inboundCall from TM
15:50:20.816 TA.T01 01 State change >> TAIdle->TAInboundCall (TAS_Calling)
15:50:20.817 TA.T01 01 Failed - DID translation: no match for 201, using 201
15:50:20.817 TA.T01 01 TAIdle sent: call to SB
15:50:20.818 TM.T01 01 SipTM_Trying tachg -> TAInboundCall
15:50:20.819 TM.T01 01 SipTM_Trying State change >> SipTM_Trying->SipTM_Pending
15:50:20.819 SB.CALL 2 Idle Called the call routine with 201
15:50:20 SB.TGMgr For dialed number 201, against template $, on TrunkGroup PRI, the score is 500
15:50:20 SB.TGMgr For dialed number 201, against template $, on TrunkGroup SIP, the score is 500
15:50:20.821 SB.CCM isMappable:
15:50:20.822 SB.CCM : Call Struct 0x2823610 : Call-ID = 2
15:50:20.822 SB.CCM : Org Acct = T01 Dst Acct = T02
15:50:20.823 SB.CCM : Org Port ID = 0/0.0 Dst Port ID = 0/0.0
15:50:20.823 SB.CCM : Org TID = Dst TID =
15:50:20.824 SB.CCM : SDP Transaction = CallID: 2
15:50:20.825 SB.CCM : SDP Offer = 0x0281d010, (1xx.xx.xxx.139:53254)
15:50:20.825 SB.CCM isMappable: Call Connection Type is RTP_TO_TDM
15:50:20.826 SB.CCM isMappable: Reserving RTP Channel 0/1.1
15:50:20.827 SB.CCM isMappable: Creating SDP Answer based on SDP Offer
15:50:20.828 SB.CCM getBestMatchCodec: PCMU
15:50:20.831 SB.CALL 2 Idle Call sent from T01 to T02 (201)
15:50:20.832 VOICE.SUMMARY T01 is calling T02 (201).
15:50:20.833 SB.CALL 2 State change >> Idle->Delivering
15:50:20.833 RTP.MANAGER isdn 0/0.0 - empty - RTP: Reserve resource
15:50:20.834 RTP.MANAGER isdn 0/0.0 - dsp 0/1.1 - RTP: (null)
15:50:20.835 RTP.PROVIDER unknown - dsp 0/1.1 - RTP: reserving already allocated RTP channel
15:50:20.835 TA.T01 01 TAInboundCall CallResp event accepted
15:50:20.836 TA.T01 01 State change >> TAInboundCall->TAConnectWaitIn (TAS_Calling)
15:50:20.837 TA.T02 22 State change >> TAIdle->TAOutGoing (TAS_Delivering)
15:50:20.838 TM.T02 22 tachg_Delivering
15:50:20.839 TM.T02 22 IsdnTmStateIdle->IsdnTmStateOutboundDeliver
15:50:20.839 TM.T02 22 IsdnTmStateOutboundDeliver::enter()
15:50:20.840 ISDN.L2_FMT PRI 1 ==============================================
15:50:20.841 ISDN.L2_FMT PRI 1 Sent Sapi:00 C/R:C Tei:00 INFO Ns:1 Nr:1 P:0
15:50:20.841 ISDN.L2_FMT PRI 1 Prot:08 CRL:2 CRV:0002
15:50:20.842 ISDN.L2_FMT PRI 1 M - 05 SETUP
15:50:20.842 ISDN.L2_FMT PRI 1 IE - 04 BEARER CAPABILITY Len=3
15:50:20.842 ISDN.L2_FMT PRI 1 80 Xfer Cap.:SPEECH
15:50:20.843 ISDN.L2_FMT PRI 1 90 Xfer Rate:64k
15:50:20.843 ISDN.L2_FMT PRI 1 A2 Layer 1:u-Law
15:50:20.843 ISDN.L2_FMT PRI 1 IE - 18 CHANNEL ID Len=3
15:50:20.844 ISDN.L2_FMT PRI 1 A1 Primary Rate
15:50:20.844 ISDN.L2_FMT PRI 1 Intfc ID:IMPLICIT
15:50:20.844 ISDN.L2_FMT PRI 1 Pref/Excl:PREFERRED
15:50:20.845 ISDN.L2_FMT PRI 1 D-Chan Indicated:NO
15:50:20.845 ISDN.L2_FMT PRI 1 Chan. Sel:FOLLOWS
15:50:20.845 ISDN.L2_FMT PRI 1 83 Numb/Map:NUMBER
15:50:20.846 ISDN.L2_FMT PRI 1 96 Channel:22
15:50:20.846 ISDN.L2_FMT PRI 1 IE - 1C FACILITY Len=26
15:50:20.846 ISDN.L2_FMT PRI 1 Calling Name: caller name
15:50:20.847 ISDN.L2_FMT PRI 1 IE - 6C CALLING PARTY # Len=12
15:50:20.847 ISDN.L2_FMT PRI 1 00 Numb. Type:UNKNOWN
15:50:20.847 ISDN.L2_FMT PRI 1 Numb. Plan:UNKNOWN
15:50:20.848 ISDN.L2_FMT PRI 1 80 Presentation:ALLOWED
15:50:20.848 ISDN.L2_FMT PRI 1 Ph.# 248766xxxx
15:50:20.849 ISDN.L2_FMT PRI 1 IE - 70 CALLED PARTY # Len=4
15:50:20.849 ISDN.L2_FMT PRI 1 80 Numb. Type:UNKNOWN
15:50:20.849 ISDN.L2_FMT PRI 1 Numb. Plan:UNKNOWN
15:50:20.850 ISDN.L2_FMT PRI 1 Ph.# 201
15:50:20.850 SB.CALL 2 Delivering Called the deliverResponse routine from Delivering
15:50:20.851 SB.CALL 2 Delivering DeliverResponse(accept) sent from T02 to T01
15:50:20.852 TA.T01 01 TAConnectWaitIn deliverResponse event accepted
15:50:20.852 TA.T01 01 TAConnectWaitIn ERROR! deliverResponse ignored
15:50:20.944 ISDN.L2_FMT PRI 1 ==============================================
15:50:20.945 ISDN.L2_FMT PRI 1 Recd Sapi:00 C/R:R Tei:00 INFO Ns:1 Nr:2 P:0
15:50:20.945 ISDN.L2_FMT PRI 1 Prot:08 CRL:2 CRV:8002
15:50:20.945 ISDN.L2_FMT PRI 1 M - 5A RELEASE_CMP
15:50:20.946 ISDN.L2_FMT PRI 1 IE - 08 CAUSE Len=2
15:50:20.946 ISDN.L2_FMT PRI 1 80 Location:U
15:50:20.946 ISDN.L2_FMT PRI 1 91 Cause:17 (USER_BUSY)
15:50:20.949 TM.T02 22 IsdnTmStateOutboundDeliver->IsdnTmStateTrunkClearing
15:50:20.949 TM.T02 22 IsdnTmStateTrunkClearing::enter()
15:50:20.950 TM.T02 22 IsdnTmStateTrunkClearing->IsdnTmStateIdling
15:50:20.950 TM.T02 22 IsdnTmStateIdling::enter()
15:50:20.951 TM.T02 22 IsdnTmStateIdling - send appearance off
15:50:20.951 TM.T02 22 IsdnTmStateIdling->IsdneChangedEv: (0x24d6240)->Terminated
15:50:21.086 SIP.CLDU Looking up outbound interface to 1xx.xx.xxx.139
Outbound call
1st attempt
15:52:04.175 SB.CALL 3 Idle Call sent from T02 to T01 (1248766xxxx)
15:52:04.176 VOICE.SUMMARY T02 is calling T01 (1248766xxxx).
15:52:04.176 SB.CALL 3 State change >> Idle->Delivering
15:52:04.177 RTP.MANAGER t1 0/2.0.23 - empty - RTP: Request resource
15:52:04.177 RTP.MANAGER t1 0/2.0.23 - dsp 0/1.1 - RTP: DSP channel allocated for the resource
15:52:04.178 RTP.PROVIDER t1 0/2.0.23 - dsp 0/1.1 - RTP: providing already allocated RTP channel
15:52:04.179 TA.T02 23 TAInboundCall CallResp event accepted
15:52:04.179 TA.T02 23 State change >> TAInboundCall->TAConnectWaitIn (TAS_Calling)
15:52:04.180 TA.T01 42 State change >> TAIdle->TAOutGoing (TAS_Delivering)
15:52:04.180 TM.T01 42 SipTM_Idle State change >> SipTM_Idle->SipTM_Delivering
15:52:04.182 TA.T01 42 DNIS Substitution: dialed number 1248766xxxx -> 248766xxxx
15:52:04.183 VOICE.SUMMARY DNIS Substitution: dialed number 1248766xxxx -> 248766xxxx
15:52:04.184 SIP.CLDU Looking up outbound interface to 1xx.xx.xxx.139
15:52:04.184 TM.T01 42 call-leg (0x24d6420) -> src-ip: 9x.xx.xxx.13 dst-ip: 1xx.xx.xxx.139
15:52:04.187 TM.T01 42 Undo of previous operation not required (RTP NAT Entry for 127.0.0.2:10000 not found)
15:52:04.187 TM.T01 42 Checking for internal Media Gateway IP Address
15:52:04.188 TM.T01 42 Using RTP Channel 0/1.1
15:52:04.188 SIP.CLDU Looking up outbound interface to 1xx.xx.xxx.139
15:52:04.189 TM.T01 42 Inserting 9x.xx.xxx.13 into SDP for Media Gateway on interface eth 0/1
15:52:04.190 TM.T01 42 Adding RTP Media Gateway Entry: 127.0.0.2:10000 -> 9x.xx.xxx.13:10000
15:52:04.190 TM.T01 42 No action taken, firewall traversal is not enabled
15:52:04.195 SIP.STACK MSG Tx: UDP src=9x.xx.xxx.13:5060 dst=1xx.xx.xxx.139:5060
15:52:04.196 SIP.STACK MSGSUM Tx: INVITE sip:248766xxxx@Softswitch.net:5060 SIP/2.0 (with SDP)
15:52:04.196 SIP.STACK MSG INVITE sip:248766xxxx@Softswitch.net:5060 SIP/2.0
15:52:04.197 SIP.STACK MSG From: <sip:Softswitch.net:5060;transport=UDP>;tag=24b6770-7f000001-13c4-1c1-d2d40655-1c1
15:52:04.197 SIP.STACK MSG To: <sip:248766xxxx@Softswitch.net:5060>
15:52:04.198 SIP.STACK MSG Call-ID: 24d6420-7f000001-13c4-1c1-e82689ba-1c1@Softswitch.net
15:52:04.199 SIP.STACK MSG CSeq: 1 INVITE
15:52:04.199 SIP.STACK MSG Via: SIP/2.0/UDP 9x.xx.xxx.13:5060;branch=z9hG4bK-1c1-6da03-33014e17
15:52:04.200 SIP.STACK MSG Max-Forwards: 70
15:52:04.200 SIP.STACK MSG Supported: 100rel,replaces
15:52:04.201 SIP.STACK MSG Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, PRACK, REFER, REGISTER
15:52:04.201 SIP.STACK MSG User-Agent: ADTRAN_Total_Access_908_1st_Gen/A4.11.00.E
15:52:04.202 SIP.STACK MSG Contact: <sip:9x.xx.xxx.13:5060;transport=UDP>
15:52:04.202 SIP.STACK MSG Content-Type: application/sdp
15:52:04.203 SIP.STACK MSG Content-Length: 264
15:52:04.204 SIP.STACK MSG
15:52:04.204 SIP.STACK MSG v=0
15:52:04.205 SIP.STACK MSG o=- 1527277924 1527277924 IN IP4 9x.xx.xxx.13
15:52:04.205 SIP.STACK MSG s=-
15:52:04.206 SIP.STACK MSG c=IN IP4 9x.xx.xxx.13
15:52:04.206 SIP.STACK MSG t=0 0
15:52:04.207 SIP.STACK MSG m=audio 10000 RTP/AVP 0 18 101
15:52:04.207 SIP.STACK MSG a=rtpmap:0 PCMU/8000
15:52:04.208 SIP.STACK MSG a=rtpmap:18 G729/8000
15:52:04.209 SIP.STACK MSG a=fmtp:18 annexb=no
15:52:04.209 SIP.STACK MSG a=silenceSupp:off - - - -
15:52:04.210 SIP.STACK MSG a=rtpmap:101 telephone-event/8000
15:52:04.210 SIP.STACK MSG a=fmtp:101 0-15
15:52:04.211 SIP.STACK MSG
15:52:04.212 SIP.CLDU Cldu::CallLegStateChangedEv: (0x24d6420)->Inviting
15:52:04.213 TM.T01 42 SipTM_Delivering call-leg -> Inviting
15:52:04.214 TM.T01 42 SipTM_Delivering sent: INVITE
15:52:04.215 SB.CALL 3 Delivering Called the deliverResponse routine from Delivering
15:52:04.215 SB.CALL 3 Delivering DeliverResponse(accept) sent from T01 to T02
15:52:04.216 TA.T02 23 TAConnectWaitIn deliverResponse event accepted
15:52:04.217 TA.T02 23 TAConnectWaitIn ERROR! deliverResponse ignored
15:52:04.246 SIP.STACK MSG Rx: UDP src=1xx.xx.xxx.139:5060 dst=9x.xx.xxx.13:5060
15:52:04.247 SIP.STACK MSGSUM Rx: SIP/2.0 100 Trying
15:52:04.248 SIP.STACK MSG SIP/2.0 100 Trying
15:52:04.249 SIP.STACK MSG Via: SIP/2.0/UDP 9x.xx.xxx.13:5060;branch=z9hG4bK-1c1-6da03-33014e17
15:52:04.249 SIP.STACK MSG From: <sip:Softswitch.net:5060;transport=UDP>;tag=24b6770-7f000001-13c4-1c1-d2d40655-1c1
15:52:04.250 SIP.STACK MSG To: <sip:248766xxxx@Softswitch.net:5060>;tag=767bafbb96
15:52:04.250 SIP.STACK MSG Call-ID: 24d6420-7f000001-13c4-1c1-e82689ba-1c1@Softswitch.net
15:52:04.251 SIP.STACK MSG CSeq: 1 INVITE
15:52:04.251 SIP.STACK MSG Content-Length: 0
15:52:04.252 SIP.STACK MSG
15:52:04.255 SIP.CLDU Incoming message received from 1xx.xx.xxx.139:5060 via UDP
15:52:04.256 TM.T01 42 SipTM_Delivering rcvd SIP call-leg response: 100 Trying
15:52:04.256 TM.T01 42 SipTM_Delivering No Supported header in message
15:52:04.257 TM.T01 42 SipTM_Delivering rcvd: Provisional Response 100 Trying
15:52:04.257 SIP.CLDU Cldu::CallLegStateChangedEv: (0x24d6420)->Proceeding
15:52:04.258 TM.T01 42 SipTM_Delivering call-leg -> Proceeding
15:52:04.259 SIP.STACK MSG Rx: UDP src=1xx.xx.xxx.139:5060 dst=9x.xx.xxx.13:5060
15:52:04.260 SIP.STACK MSGSUM Rx: SIP/2.0 403 Forbidden
15:52:04.260 SIP.STACK MSG SIP/2.0 403 Forbidden
15:52:04.261 SIP.STACK MSG Via: SIP/2.0/UDP 9x.xx.xxx.13:5060;branch=z9hG4bK-1c1-6da03-33014e17
15:52:04.261 SIP.STACK MSG From: <sip:Softswitch.net:5060;transport=UDP>;tag=24b6770-7f000001-13c4-1c1-d2d40655-1c1
15:52:04.262 SIP.STACK MSG To: <sip:248766xxxx@Softswitch.net:5060>;tag=767bafbb96
15:52:04.263 SIP.STACK MSG Call================
2nd attempt
15:52:31.709 SIP.STACK MSG Tx: UDP src=9x.xx.xxx.13:5060 dst=1xx.xx.xxx.139:5060
15:52:31.710 SIP.STACK MSGSUM Tx: INVITE sip:248766xxxx@Softswitch.net:5060 SIP/2.0 (with SDP)
15:52:31.711 SIP.STACK MSG INVITE sip:248766xxxx@Softswitch.net:5060 SIP/2.0
15:52:31.711 SIP.STACK MSG From: <sip:customer.com.livering->SipTM_Closing
15:52:31.801 TM.T01 41 SipTM_Closing sent: TA->Clear
15:52:31.802 SIP.CLDU Cldu::CallLegStateChangedEv: (0x24d6600)->Terminated
15:52:31.803 TM.T01 41 SipTM_Closing call-leg -> Terminated
15:52:31.804 TA.T01 41 TAOutGoing rcvd: clear from TM
15:52:31.804 TA.T01 41 State change >> TAOutGoing->TATrunkClearing (TAS_Clearing)
15:52:31.805 TM.T01 41 SipTM_Closing tachg -> TATrunkClearing
15:52:31.806 TM.T01 41 SipTM_Closing State change >> SipTM_Closing->SipTM_Terminated
15:52:31.806 TM.T01 41 SipTM_Terminated sent: TA->AppearanceOff
15:52:31.807 TM.T01 41 SipTM_Terminated State change >> SipTM_Terminated->SipTM_Idle
15:52:31.807 VOICE.SUMMARY Call from T02 to T01 (1248766xxxx) ended by T01: call rejected
You're dealing with two different issues.
On calls to the PBX, the PBX is returning a user busy response. You're sending only three digits, "201". Is the PBX expecting to see 3-digit extensions and is 201 a valid extension? This seems to be a conflict between the dialed extension sent to the PBX and what the PBX expects.
On calls outbound, your SIP provider is rejecting the call as forbidden. Is your device registered successfully? Type "show sip trunk-registration" to be sure. Reach out to your SIP provider for help.