New ViciBox - No outbound calls - Any thoughts?

Support forum for the ViciBox ISO Server Install and ISO LiveCD Demo

Moderators: enjay, williamconley, Staydog, mflorell, MJCoate, mcargile, Kumba

New ViciBox - No outbound calls - Any thoughts?

Postby darryldale » Thu Dec 16, 2010 9:38 am

I have a new ViciBox in implementation phase right now. I have it setup (as far as I can tell) and have had a Vici consultant look at it quickly yesterday as well and he said everything looks good.

In testing last night I brought the system up and tried to make an outbound call but no go. Details of my system are in my sig line. The sip debug log I got via putty is kind of long but here is the relevent section (I think).

Any thoughts on what could be wrong?

Here is the sip debug:

[Kviciexp*CLI>
[Dec 16 08:18:35]
<--- SIP read from 66.51.127.173:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 216.###.###.###:5060;branch=z9hG4bK5b9639f4;rport=5060
From: "asterisk" <sip:asterisk@216.###.###.###>;tag=as7f839d1b
To: <sip:sip.ca1.link2voip.com;cpd=on>;tag=6da5cb3c58ecfc1b91772f44357856fa.8d3f
Call-ID: 306261ca2c9cb202326ac3463b035238@216.###.###.###
CSeq: 102 OPTIONS
Accept: */*
Accept-Encoding:
Accept-Language: en
Supported:
Content-Length: 0

<------------->

viciexp*CLI>
[Dec 16 08:18:35] --- (11 headers 0 lines) ---

viciexp*CLI>
[Dec 16 08:18:35] Really destroying SIP dialog '306261ca2c9cb202326ac3463b035238@216.###.###.###' Method: OPTIONS

viciexp*CLI>
[Dec 16 08:18:39]
<--- SIP read from 192.168.3.148:13624 --->
INVITE sip:91519#######@192.168.3.9 SIP/2.0
Via: SIP/2.0/UDP 192.168.3.148:13624;branch=z9hG4bK-d87543-3f6ac7599448ad53-1--d87543-;rport
Max-Forwards: 70
Contact: <sip:226@192.168.3.148:13624>
To: "91519#######"<sip:91519#######@192.168.3.9>
From: "Barb Thompson"<sip:226@192.168.3.9>;tag=0321500d
Call-ID: 4f0b227f0b0b965cM2FiM2E2ZDNiMmU5MTg3MmM0YjNjY2ZjMGY1YzQyZjg.
CSeq: 1 INVITE
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO
Content-Type: application/sdp
User-Agent: eyeBeam release 1003s stamp 31159
Content-Length: 546

v=0
o=- 9 2 IN IP4 192.168.3.148
s=CounterPath eyeBeam 1.5
c=IN IP4 192.168.3.148
t=0 0
m=audio 11604 RTP/AVP 107 100 106 6 0 105 18 3 5 101
a=alt:1 3 : mbHkWJwC hEL2+p/T 192.168.3.148 11604
a=alt:2 2 : nIZmOOtf 6KAUzHcL 192.168.75.1 11604
a=alt:3 1 : bFg1x43s 6LsuDJ9M 192.168.93.1 11604
a=fmtp:18 annexb=no
a=fmtp:101 0-15
a=rtpmap:107 BV32/16000
a=rtpmap:100 SPEEX/16000
a=rtpmap:106 SPEEX-FEC/16000
a=rtpmap:105 SPEEX-FEC/8000
a=rtpmap:101 telephone-event/8000
a=sendrecv
a=x-rtp-session-id:A6CFDDC8A920404D96B33964A0BF5DF2

<------------->

viciexp*CLI>
[Dec 16 08:18:39] --- (12 headers 18 lines) ---
[Dec 16 08:18:39] Sending to 192.168.3.148 : 13624 (NAT)

viciexp*CLI>
[Dec 16 08:18:39] Using INVITE request as basis request - 4f0b227f0b0b965cM2FiM2E2ZDNiMmU5MTg3MmM0YjNjY2ZjMGY1YzQyZjg.
[Dec 16 08:18:39]
<--- Reliably Transmitting (NAT) to 192.168.3.148:13624 --->
SIP/2.0 407 Proxy Authentication Required
Via: SIP/2.0/UDP 192.168.3.148:13624;branch=z9hG4bK-d87543-3f6ac7599448ad53-1--d87543-;received=192.168.3.148;rport=13624
From: "Barb Thompson"<sip:226@192.168.3.9>;tag=0321500d
To: "91519#######"<sip:91519#######@192.168.3.9>;tag=as783cdf10
Call-ID: 4f0b227f0b0b965cM2FiM2E2ZDNiMmU5MTg3MmM0YjNjY2ZjMGY1YzQyZjg.
CSeq: 1 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces
Proxy-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="0375589e"
Content-Length: 0

<------------>
[Dec 16 08:18:39] Scheduling destruction of SIP dialog '4f0b227f0b0b965cM2FiM2E2ZDNiMmU5MTg3MmM0YjNjY2ZjMGY1YzQyZjg.' in 32000 ms (Method: INVITE)
[Dec 16 08:18:39] Found user '226'

viciexp*CLI>
[Dec 16 08:18:39]
<--- SIP read from 192.168.3.148:13624 --->
ACK sip:91519#######@192.168.3.9 SIP/2.0
Via: SIP/2.0/UDP 192.168.3.148:13624;branch=z9hG4bK-d87543-3f6ac7599448ad53-1--d87543-;rport
To: "91519#######"<sip:91519#######@192.168.3.9>;tag=as783cdf10
From: "Barb Thompson"<sip:226@192.168.3.9>;tag=0321500d
Call-ID: 4f0b227f0b0b965cM2FiM2E2ZDNiMmU5MTg3MmM0YjNjY2ZjMGY1YzQyZjg.
CSeq: 1 ACK
Content-Length: 0

<------------->

viciexp*CLI>
[Dec 16 08:18:39] --- (7 headers 0 lines) ---

viciexp*CLI>
[Dec 16 08:18:40]
<--- SIP read from 192.168.3.148:13624 --->
INVITE sip:91519#######@192.168.3.9 SIP/2.0
Via: SIP/2.0/UDP 192.168.3.148:13624;branch=z9hG4bK-d87543-b10eb573282fd177-1--d87543-;rport
Max-Forwards: 70
Contact: <sip:226@192.168.3.148:13624>
To: "91519#######"<sip:91519#######@192.168.3.9>
From: "Barb Thompson"<sip:226@192.168.3.9>;tag=0321500d
Call-ID: 4f0b227f0b0b965cM2FiM2E2ZDNiMmU5MTg3MmM0YjNjY2ZjMGY1YzQyZjg.
CSeq: 2 INVITE
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO
Content-Type: application/sdp
Proxy-Authorization: Digest username="226",realm="asterisk",nonce="0375589e",uri="sip:91519#######@192.168.3.9",response="672c2e4f5ee49810f2edf8babd74e111",algorithm=MD5
User-Agent: eyeBeam release 1003s stamp 31159
Content-Length: 546

v=0
o=- 9 2 IN IP4 192.168.3.148
s=CounterPath eyeBeam 1.5
c=IN IP4 192.168.3.148
t=0 0
m=audio 11604 RTP/AVP 107 100 106 6 0 105 18 3 5 101
a=alt:1 3 : mbHkWJwC hEL2+p/T 192.168.3.148 11604
a=alt:2 2 : nIZmOOtf 6KAUzHcL 192.168.75.1 11604
a=alt:3 1 : bFg1x43s 6LsuDJ9M 192.168.93.1 11604
a=fmtp:18 annexb=no
a=fmtp:101 0-15
a=rtpmap:107 BV32/16000
a=rtpmap:100 SPEEX/16000
a=rtpmap:106 SPEEX-FEC/16000
a=rtpmap:105 SPEEX-FEC/8000
a=rtpmap:101 telephone-event/8000
a=sendrecv
a=x-rtp-session-id:A6CFDDC8A920404D96B33964A0BF5DF2

<------------->

viciexp*CLI>
[Dec 16 08:18:40] --- (13 headers 18 lines) ---
[Dec 16 08:18:40] Sending to 192.168.3.148 : 13624 (NAT)

viciexp*CLI>
[Dec 16 08:18:40] Using INVITE request as basis request - 4f0b227f0b0b965cM2FiM2E2ZDNiMmU5MTg3MmM0YjNjY2ZjMGY1YzQyZjg.
[Dec 16 08:18:40] Found user '226'
[Dec 16 08:18:40] Found RTP audio format 107

viciexp*CLI>
[Dec 16 08:18:40] Found RTP audio format 100
[Dec 16 08:18:40] Found RTP audio format 106
[Dec 16 08:18:40] Found RTP audio format 6
[Dec 16 08:18:40] Found RTP audio format 0
[Dec 16 08:18:40] Found RTP audio format 105
[Dec 16 08:18:40] Found RTP audio format 18
[Dec 16 08:18:40] Found RTP audio format 3
[Dec 16 08:18:40] Found RTP audio format 5
[Dec 16 08:18:40] Found RTP audio format 101
[Dec 16 08:18:40] Found unknown media description format BV32 for ID 107
[Dec 16 08:18:40] Found audio description format SPEEX for ID 100
[Dec 16 08:18:40] Found unknown media description format SPEEX-FEC for ID 106
[Dec 16 08:18:40] Found unknown media description format SPEEX-FEC for ID 105
[Dec 16 08:18:40] Found audio description format telephone-event for ID 101
[Dec 16 08:18:40] Capabilities: us - 0x6 (gsm|ulaw), peer - audio=0x326 (gsm|ulaw|adpcm|g729|speex)/video=0x0 (nothing), combined - 0x6 (gsm|ulaw)
[Dec 16 08:18:40] Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event)
[Dec 16 08:18:40] Peer audio RTP is at port 192.168.3.148:11604
[Dec 16 08:18:40] Looking for 91519####### in default (domain 192.168.3.9)
[Dec 16 08:18:40] list_route: hop: <sip:226@192.168.3.148:13624>
[Dec 16 08:18:40]
<--- Transmitting (NAT) to 192.168.3.148:13624 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.3.148:13624;branch=z9hG4bK-d87543-b10eb573282fd177-1--d87543-;received=192.168.3.148;rport=13624
From: "Barb Thompson"<sip:226@192.168.3.9>;tag=0321500d
To: "91519#######"<sip:91519#######@192.168.3.9>
Call-ID: 4f0b227f0b0b965cM2FiM2E2ZDNiMmU5MTg3MmM0YjNjY2ZjMGY1YzQyZjg.
CSeq: 2 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces
Contact: <sip:91519#######@192.168.3.9>
Content-Length: 0

<------------>

viciexp*CLI>
[Dec 16 08:18:40] -- Executing [91519#######@default:1] AGI("SIP/226-00000015", "agi://127.0.0.1:4577/call_log") in new stack

viciexp*CLI>
[Dec 16 08:18:40] -- AGI Script agi://127.0.0.1:4577/call_log completed, returning 0

viciexp*CLI>
[Dec 16 08:18:40] -- Executing [91519#######@default:2] Dial("SIP/226-00000015", "SIP/acelink2voip/$(EXTEN:1)||tTor") in new stack

viciexp*CLI>
[Dec 16 08:18:40] Audio is at 216.###.###.### port 17446

viciexp*CLI>
[Dec 16 08:18:40] Adding codec 0x4 (ulaw) to SDP

viciexp*CLI>
[Dec 16 08:18:40] Adding non-codec 0x1 (telephone-event) to SDP

viciexp*CLI>
[Dec 16 08:18:40] Reliably Transmitting (NAT) to 66.51.127.173:5060:
INVITE sip:$(EXTEN:1)@sip.ca1.link2voip.com;cpd=on SIP/2.0
Via: SIP/2.0/UDP 216.###.###.###:5060;branch=z9hG4bK04c52c59;rport
From: "BARB THOMPSON" <sip:5197726813@216.###.###.###>;tag=as1798b565
To: <sip:$(EXTEN:1)@sip.ca1.link2voip.com;cpd=on>
Contact: <sip:5197726813@216.###.###.###>
Call-ID: 33b0f89d497510fc7945c9951b790484@216.###.###.###
CSeq: 102 INVITE
User-Agent: Asterisk PBX
Max-Forwards: 70
Remote-Party-ID: "BARB THOMPSON" <sip:5197726813@216.###.###.###>;privacy=off;screen=no
Date: Thu, 16 Dec 2010 13:18:40 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces
Content-Type: application/sdp
Content-Length: 239

v=0
o=root 2543 2543 IN IP4 216.###.###.###
s=session
c=IN IP4 216.###.###.###
t=0 0
m=audio 17446 RTP/AVP 0 96
a=rtpmap:0 PCMU/8000
a=rtpmap:96 telephone-event/8000
a=fmtp:96 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv

---

viciexp*CLI>
[Dec 16 08:18:40] -- Called acelink2voip/$(EXTEN:1)

viciexp*CLI>
[Dec 16 08:18:40]
<--- Transmitting (NAT) to 192.168.3.148:13624 --->
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 192.168.3.148:13624;branch=z9hG4bK-d87543-b10eb573282fd177-1--d87543-;received=192.168.3.148;rport=13624
From: "Barb Thompson"<sip:226@192.168.3.9>;tag=0321500d
To: "91519#######"<sip:91519#######@192.168.3.9>;tag=as57de1692
Call-ID: 4f0b227f0b0b965cM2FiM2E2ZDNiMmU5MTg3MmM0YjNjY2ZjMGY1YzQyZjg.
CSeq: 2 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces
Contact: <sip:91519#######@192.168.3.9>
Content-Length: 0

<------------>

viciexp*CLI>
[Dec 16 08:18:40]
<--- SIP read from 66.51.127.173:5060 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 216.###.###.###:5060;branch=z9hG4bK04c52c59;rport=5060
From: "BARB THOMPSON" <sip:5197726813@216.###.###.###>;tag=as1798b565
To: <sip:$(EXTEN:1)@sip.ca1.link2voip.com;cpd=on>
Call-ID: 33b0f89d497510fc7945c9951b790484@216.###.###.###
CSeq: 102 INVITE
Content-Length: 0

<------------->

viciexp*CLI>
[Dec 16 08:18:40] --- (7 headers 0 lines) ---

viciexp*CLI>
[Dec 16 08:18:40]
<--- SIP read from 66.51.127.173:5060 --->
SIP/2.0 404 User Not Found
Via: SIP/2.0/UDP 216.###.###.###:5060;branch=z9hG4bK04c52c59;rport=5060
From: "BARB THOMPSON" <sip:5197726813@216.###.###.###>;tag=as1798b565
To: <sip:$(EXTEN:1)@sip.ca1.link2voip.com;cpd=on>;tag=6da5cb3c58ecfc1b91772f44357856fa.044f
Call-ID: 33b0f89d497510fc7945c9951b790484@216.###.###.###
CSeq: 102 INVITE
Content-Length: 0

<------------->

viciexp*CLI>
[Dec 16 08:18:40] --- (7 headers 0 lines) ---

viciexp*CLI>
[Dec 16 08:18:40] Transmitting (NAT) to 66.51.127.173:5060:
ACK sip:$(EXTEN:1)@sip.ca1.link2voip.com;cpd=on SIP/2.0
Via: SIP/2.0/UDP 216.###.###.###:5060;branch=z9hG4bK04c52c59;rport
From: "BARB THOMPSON" <sip:5197726813@216.###.###.###>;tag=as1798b565
To: <sip:$(EXTEN:1)@sip.ca1.link2voip.com;cpd=on>;tag=6da5cb3c58ecfc1b91772f44357856fa.044f
Contact: <sip:5197726813@216.###.###.###>
Call-ID: 33b0f89d497510fc7945c9951b790484@216.###.###.###
CSeq: 102 ACK
User-Agent: Asterisk PBX
Max-Forwards: 70
Remote-Party-ID: "BARB THOMPSON" <sip:5197726813@216.###.###.###>;privacy=off;screen=no
Content-Length: 0

---

viciexp*CLI>
[Dec 16 08:18:40] -- SIP/acelink2voip-00000016 is circuit-busy

viciexp*CLI>
[Dec 16 08:18:40] == Everyone is busy/congested at this time (1:0/1/0)
My system specifics:
"Vici Express Box" purchased from ViciDial

Came loaded with:
ViciBox Redux v3.0.5
ViciDial 2.4-283 build 100929-1203
Asterisk 1.4.27.1
OpenSuse 11.3
Kernal v2.6.34.7-0.3-pae
darryldale
 
Posts: 87
Joined: Mon Apr 28, 2008 8:17 am

Postby darryldale » Thu Dec 16, 2010 9:40 am

The lines that stand out to me are:

<--- SIP read from 66.51.127.173:5060 --->
SIP/2.0 404 User Not Found

and then further down:


viciexp*CLI>
[Dec 16 08:18:40] -- SIP/acelink2voip-00000016 is circuit-busy

viciexp*CLI>
[Dec 16 08:18:40] == Everyone is busy/congested at this time (1:0/1/0)


Darryl
My system specifics:
"Vici Express Box" purchased from ViciDial

Came loaded with:
ViciBox Redux v3.0.5
ViciDial 2.4-283 build 100929-1203
Asterisk 1.4.27.1
OpenSuse 11.3
Kernal v2.6.34.7-0.3-pae
darryldale
 
Posts: 87
Joined: Mon Apr 28, 2008 8:17 am

Postby darryldale » Thu Dec 16, 2010 11:44 am

I bounced the issue of of my SIP provider and here was his response:

---------------
This appears to be a problem with the INVITE you are sending. Your
system is not subbing in the macro replacement for the EXTEN:

INVITE sip:$(EXTEN:1)@sip.ca1.link2voip.com;cpd=on SIP/2.0

This should look something like:

INVITE sip:18005551212@sip.ca1.link2voip.com;cpd=on SIP/2.0
----------------

The only place I see the exten:1 configured is in my carrier dial plan which leads me to believe that is where the problem lies. Here is my carrier setup:

Registration string:
register => darryldale:xxxxxxxxxxx@sip.ca1.link2voip.com:5060

Account entry:
[acelink2voip]
disallow=all
allow=ulaw
type=friend
username=darryldale
secret=xxxxxxxxxx
host=sip.ca1.link2voip.com
dtmfmode=rfc2833
context=trunkinbound

Dialplan entry:
exten => _91NXXNXXXXXX,1,AGI(agi://127.0.0.1:4577/call_log)
exten => _91NXXNXXXXXX,2,Dial(SIP/acelink2voip/$(EXTEN:1),,tTor)
exten => _91NXXNXXXXXX,3,Hangup


Is the dialplan entry correct?

Darryl
My system specifics:
"Vici Express Box" purchased from ViciDial

Came loaded with:
ViciBox Redux v3.0.5
ViciDial 2.4-283 build 100929-1203
Asterisk 1.4.27.1
OpenSuse 11.3
Kernal v2.6.34.7-0.3-pae
darryldale
 
Posts: 87
Joined: Mon Apr 28, 2008 8:17 am

Postby darryldale » Thu Dec 16, 2010 12:11 pm

Making progress (I think).

Changed the dial plan in my Carrier from:
exten => _91NXXNXXXXXX,1,AGI(agi://127.0.0.1:4577/call_log)
exten => _91NXXNXXXXXX,2,Dial(SIP/acelink2voip/$(EXTEN:1),,tTor)
exten => _91NXXNXXXXXX,3,Hangup

to:
exten => _91NXXNXXXXXX,1,AGI(agi://127.0.0.1:4577/call_log)
exten => _91NXXNXXXXXX,2,Dial(SIP/acelink2voip/${EXTEN:2},,tTor)
exten => _91NXXNXXXXXX,3,Hangup

Now my invite request appears to be OK in the sip debug log but am now getting what you see below. Any thoughts on what 503 "PSTN Termination Currently Unavailable" is caused by?

Darryl

<------------->

viciexp*CLI>
[Dec 16 11:56:15] --- (7 headers 0 lines) ---

viciexp*CLI>
[Dec 16 11:56:15]
<--- SIP read from 66.51.127.173:5060 --->
SIP/2.0 503 PSTN Termination Currently Unavailable
Via: SIP/2.0/UDP 216.16.228.134:5060;branch=z9hG4bK3e48afae;rport=5060
From: "BARB THOMPSON" <sip:5197726813@216.16.228.134>;tag=as58db812b
To: <sip:2263384491@sip.ca1.link2voip.com;cpd=on>;tag=6da5cb3c58ecfc1b91772f44357856fa.6565
Call-ID: 26f4cdda58063c043a3882324c1d50cc@216.16.228.134
CSeq: 102 INVITE
Content-Length: 0

<------------->

viciexp*CLI>
[Dec 16 11:56:15] --- (7 headers 0 lines) ---

viciexp*CLI>
[Dec 16 11:56:15] -- Got SIP response 503 "PSTN Termination Currently Unavailable" back from 66.51.127.173

viciexp*CLI>
[Dec 16 11:56:15] Transmitting (NAT) to 66.51.127.173:5060:
ACK sip:2263384491@sip.ca1.link2voip.com;cpd=on SIP/2.0
Via: SIP/2.0/UDP 216.16.228.134:5060;branch=z9hG4bK3e48afae;rport
From: "BARB THOMPSON" <sip:5197726813@216.16.228.134>;tag=as58db812b
To: <sip:2263384491@sip.ca1.link2voip.com;cpd=on>;tag=6da5cb3c58ecfc1b91772f44357856fa.6565
Contact: <sip:5197726813@216.16.228.134>
Call-ID: 26f4cdda58063c043a3882324c1d50cc@216.16.228.134
CSeq: 102 ACK
User-Agent: Asterisk PBX
Max-Forwards: 70
Remote-Party-ID: "BARB THOMPSON" <sip:5197726813@216.16.228.134>;privacy=off;screen=no
Content-Length: 0

---

viciexp*CLI>
[Dec 16 11:56:15] -- SIP/acelink2voip-00000001 is circuit-busy

viciexp*CLI>
[Dec 16 11:56:15] == Everyone is busy/congested at this time (1:0/1/0)
My system specifics:
"Vici Express Box" purchased from ViciDial

Came loaded with:
ViciBox Redux v3.0.5
ViciDial 2.4-283 build 100929-1203
Asterisk 1.4.27.1
OpenSuse 11.3
Kernal v2.6.34.7-0.3-pae
darryldale
 
Posts: 87
Joined: Mon Apr 28, 2008 8:17 am

Postby darryldale » Thu Dec 16, 2010 1:05 pm

*** SUCCESS ***

The issue was with my dial plan and the whole issue was that I had round brackets () around the EXTEN:1 instead of curly brackets {}.

The 503 message is what link2voip was returning if you only sent the 10 digit number without a 1 on the front. EXTEN:2 apparently doesn't have the 1 and EXTEN:1 does.

So as soon as I changed my dial plan to have curly brackets around EXTEN:1 I was able to make an outbound call.

Darryl
My system specifics:
"Vici Express Box" purchased from ViciDial

Came loaded with:
ViciBox Redux v3.0.5
ViciDial 2.4-283 build 100929-1203
Asterisk 1.4.27.1
OpenSuse 11.3
Kernal v2.6.34.7-0.3-pae
darryldale
 
Posts: 87
Joined: Mon Apr 28, 2008 8:17 am


Return to ViciBox Server Install and Demo

Who is online

Users browsing this forum: No registered users and 298 guests