New to Free PBX - cannot make outgoing calls via trunk

12 posts / 0 new
Last post
mirage03
mirage03's picture
New to Free PBX - cannot make outgoing calls via trunk

Hi

I got a FreePbx 2.8.1 with Asterisk 1.6.2.18 running on a server (Centos
5 with Virtualmin), both installed using the repro's. I have made entries for extensions, trunk (inbound/outbound), and outgoing route (with dial patterns and connected to the trunk) in FreePBX.

Now I can receive internal and external calls and can also make calls to extensions on the PBX. Got a few DID's forwarded via a trunk from my provider.

But when I want to make outgoing calls to the world as well (yes, provider account is set up for this and funds available) I noticed whenever I try to call a number not a DID on my server (an external number) I receive the message "The number you have dialled is not in service, please check the number and try again" from FreePBX.

As I suspected that my Free PBX might not know what to do with a call to
the outer world I have created an Any DID / Any CID inbound rule which
sends the call to the trunk (just for testing of course, I think it's
not save that way).

Result is, the "not in service message" is gone, but now I get the
congestion tone when I try to make a call.

Am I missing something important in my configuration and where would I need to tell FreePBX to send an outgoing call to a trunk instead of in the outbound route?

Below a copy of my Asterisk log (I have replaced <> with ((( ))) as I could not post code.

[Aug 7 02:02:12] VERBOSE[59249] chan_sip.c:
(((--- SIP read from UDP:(((MY DSL IP ADDRESS))):35940 ---)))
INVITE sip:(((NUMBER DIALED)))@(((MY FREEPBX IP ADDRESS))):5060 SIP/2.0
Via: SIP/2.0/UDP
(((MY DSL IP ADDRESS))):35940;branch=z9hG4bK-d8754z-d8ea26d5c282bb86-1---d8754z-;rport
Max-Forwards: 70
Contact: (((sip:1020@(((MY DSL IP ADDRESS))):35940)))
To: "(((NUMBER DIALED)))"(((sip:(((NUMBER DIALED)))@(((MY FREEPBX IP ADDRESS))):5060)))
From: "1020"(((sip:1020@(((MY FREEPBX IP ADDRESS))):5060)));tag=e9bd76e6
Call-ID: ZDdhOTFlMDFjMzM1OTA1MmIzYzUyNDk1YjA0NzAxZDA.
CSeq: 1 INVITE
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE,
SUBSCRIBE, INFO
Content-Type: application/sdp
Supported: replaces
User-Agent: X-Lite 4 release 4.0 stamp 58832
Content-Length: 383

v=0
o=- 12957145327968750 1 IN IP4 (((MY DSL IP ADDRESS)))
s=CounterPath X-Lite 4.0
c=IN IP4 (((MY DSL IP ADDRESS)))
t=0 0
a=ice-ufrag:79b534
a=ice-pwd:32d999db3b26fb93c0313a4ac7700abd
m=audio 51208 RTP/AVP 0 8 101
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sendrecv
a=candidate:1 1 UDP 659136 192.168.254.190 51208 typ host
a=candidate:1 2 UDP 659134 192.168.254.190 51209 typ host

(((-------------)))
[Aug 7 02:02:12] VERBOSE[59249] chan_sip.c: --- (13 headers 13 lines) ---
[Aug 7 02:02:12] VERBOSE[59249] netsock.c: == Using SIP RTP TOS bits 184
[Aug 7 02:02:12] VERBOSE[59249] netsock.c: == Using SIP RTP CoS mark 5
[Aug 7 02:02:12] VERBOSE[59249] netsock.c: == Using UDPTL TOS bits 184
[Aug 7 02:02:12] VERBOSE[59249] netsock.c: == Using UDPTL CoS mark 5
[Aug 7 02:02:12] VERBOSE[59249] chan_sip.c: Sending to (((MY DSL IP ADDRESS))) :
35940 (NAT)
[Aug 7 02:02:12] VERBOSE[59249] chan_sip.c: Using INVITE request as
basis request - ZDdhOTFlMDFjMzM1OTA1MmIzYzUyNDk1YjA0NzAxZDA.
[Aug 7 02:02:12] VERBOSE[59249] chan_sip.c: Found peer '1020' for '1020'
from (((MY DSL IP ADDRESS))):35940
[Aug 7 02:02:12] VERBOSE[59249] chan_sip.c:
(((--- Reliably Transmitting (NAT) to (((MY DSL IP ADDRESS))):35940 ---)))
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP
(((MY DSL IP ADDRESS))):35940;branch=z9hG4bK-d8754z-d8ea26d5c282bb86-1---d8754z-;received=(((MY DSL IP ADDRESS)));rport=35940
From: "1020"(((sip:1020@(((MY FREEPBX IP ADDRESS))):5060)));tag=e9bd76e6
To: "(((NUMBER DIALED)))"(((sip:(((NUMBER DIALED)))@(((MY FREEPBX IP ADDRESS))):5060)));tag=as69b6d619
Call-ID: ZDdhOTFlMDFjMzM1OTA1MmIzYzUyNDk1YjA0NzAxZDA.
CSeq: 1 INVITE
Server: FPBX-2.8.1(1.6.2.18)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="5cb70702"
Content-Length: 0

(((------------)))
[Aug 7 02:02:12] VERBOSE[59249] chan_sip.c: Scheduling destruction of
SIP dialog 'ZDdhOTFlMDFjMzM1OTA1MmIzYzUyNDk1YjA0NzAxZDA.' in 6400 ms
(Method: INVITE)
[Aug 7 02:02:12] VERBOSE[59249] chan_sip.c:
(((--- SIP read from UDP:(((MY DSL IP ADDRESS))):35940 ---)))
ACK sip:(((NUMBER DIALED)))@(((MY FREEPBX IP ADDRESS))):5060 SIP/2.0
Via: SIP/2.0/UDP
(((MY DSL IP ADDRESS))):35940;branch=z9hG4bK-d8754z-d8ea26d5c282bb86-1---d8754z-;rport
Max-Forwards: 70
To: "(((NUMBER DIALED)))"(((sip:(((NUMBER DIALED)))@(((MY FREEPBX IP ADDRESS))):5060)));tag=as69b6d619
From: "1020"(((sip:1020@(((MY FREEPBX IP ADDRESS))):5060)));tag=e9bd76e6
Call-ID: ZDdhOTFlMDFjMzM1OTA1MmIzYzUyNDk1YjA0NzAxZDA.
CSeq: 1 ACK
Content-Length: 0

(((-------------)))
[Aug 7 02:02:12] VERBOSE[59249] chan_sip.c: --- (8 headers 0 lines) ---
[Aug 7 02:02:12] VERBOSE[59249] chan_sip.c:
(((--- SIP read from UDP:(((MY DSL IP ADDRESS))):35940 ---)))
INVITE sip:(((NUMBER DIALED)))@(((MY FREEPBX IP ADDRESS))):5060 SIP/2.0
Via: SIP/2.0/UDP
(((MY DSL IP ADDRESS))):35940;branch=z9hG4bK-d8754z-1a8545a523081812-1---d8754z-;rport
Max-Forwards: 70
Contact: (((sip:1020@(((MY DSL IP ADDRESS))):35940)))
To: "(((NUMBER DIALED)))"(((sip:(((NUMBER DIALED)))@(((MY FREEPBX IP ADDRESS))):5060)))
From: "1020"(((sip:1020@(((MY FREEPBX IP ADDRESS))):5060)));tag=e9bd76e6
Call-ID: ZDdhOTFlMDFjMzM1OTA1MmIzYzUyNDk1YjA0NzAxZDA.
CSeq: 2 INVITE
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE,
SUBSCRIBE, INFO
Content-Type: application/sdp
Supported: replaces
User-Agent: X-Lite 4 release 4.0 stamp 58832
Authorization: Digest
username="1020",realm="asterisk",nonce="5cb70702",uri="sip:(((NUMBER DIALED)))@(((MY FREEPBX IP ADDRESS)))",response="5dc88384c187efc48a59b421df5ec225",algorithm=MD5
Content-Length: 383

v=0
o=- 12957145327968750 1 IN IP4 (((MY DSL IP ADDRESS)))
s=CounterPath X-Lite 4.0
c=IN IP4 (((MY DSL IP ADDRESS)))
t=0 0
a=ice-ufrag:79b534
a=ice-pwd:32d999db3b26fb93c0313a4ac7700abd
m=audio 51208 RTP/AVP 0 8 101
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sendrecv
a=candidate:1 1 UDP 659136 192.168.254.190 51208 typ host
a=candidate:1 2 UDP 659134 192.168.254.190 51209 typ host

(((-------------)))
[Aug 7 02:02:12] VERBOSE[59249] chan_sip.c: --- (14 headers 13 lines) ---
[Aug 7 02:02:12] VERBOSE[59249] chan_sip.c: Sending to (((MY DSL IP ADDRESS))) :
35940 (NAT)
[Aug 7 02:02:12] VERBOSE[59249] chan_sip.c: Using INVITE request as
basis request - ZDdhOTFlMDFjMzM1OTA1MmIzYzUyNDk1YjA0NzAxZDA.
[Aug 7 02:02:12] VERBOSE[59249] chan_sip.c: Found peer '1020' for '1020'
from (((MY DSL IP ADDRESS))):35940
[Aug 7 02:02:12] VERBOSE[59249] chan_sip.c: Found RTP audio format 0
[Aug 7 02:02:12] VERBOSE[59249] chan_sip.c: Found RTP audio format 8
[Aug 7 02:02:12] VERBOSE[59249] chan_sip.c: Found RTP audio format 101
[Aug 7 02:02:12] VERBOSE[59249] chan_sip.c: Found audio description
format telephone-event for ID 101
[Aug 7 02:02:12] VERBOSE[59249] chan_sip.c: Capabilities: us - 0xc
(ulaw|alaw), peer - audio=0xc (ulaw|alaw)/video=0x0 (nothing)/text=0x0
(nothing), combined - 0xc (ulaw|alaw)
[Aug 7 02:02:12] VERBOSE[59249] chan_sip.c: Non-codec capabilities
(dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event),
combined - 0x1 (telephone-event)
[Aug 7 02:02:12] VERBOSE[59249] chan_sip.c: Peer audio RTP is at port
(((MY DSL IP ADDRESS))):51208
[Aug 7 02:02:12] VERBOSE[59249] chan_sip.c: Looking for (((NUMBER DIALED)))
in from-trunk (domain (((MY FREEPBX IP ADDRESS))))
[Aug 7 02:02:12] VERBOSE[59249] chan_sip.c: list_route: hop:
(((sip:1020@(((MY DSL IP ADDRESS))):35940)))
[Aug 7 02:02:12] VERBOSE[59249] chan_sip.c:
(((--- Transmitting (NAT) to (((MY DSL IP ADDRESS))):35940 ---)))
SIP/2.0 100 Trying
Via: SIP/2.0/UDP
(((MY DSL IP ADDRESS))):35940;branch=z9hG4bK-d8754z-1a8545a523081812-1---d8754z-;received=(((MY DSL IP ADDRESS)));rport=35940
From: "1020"(((sip:1020@(((MY FREEPBX IP ADDRESS))):5060)));tag=e9bd76e6
To: "(((NUMBER DIALED)))"(((sip:(((NUMBER DIALED)))@(((MY FREEPBX IP ADDRESS))):5060)))
Call-ID: ZDdhOTFlMDFjMzM1OTA1MmIzYzUyNDk1YjA0NzAxZDA.
CSeq: 2 INVITE
Server: FPBX-2.8.1(1.6.2.18)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Contact: (((sip:(((NUMBER DIALED)))@(((MY FREEPBX IP ADDRESS))))))
Content-Length: 0

(((------------)))
[Aug 7 02:02:12] VERBOSE[48951] pbx.c: -- Executing
[(((NUMBER DIALED)))@from-trunk:1] NoOp("SIP/1020-00000005", "Catch-All DID
Match - Found (((NUMBER DIALED))) - You probably want a DID for this.") in
new stack
[Aug 7 02:02:12] VERBOSE[48951] pbx.c: -- Executing
[(((NUMBER DIALED)))@from-trunk:2] Goto("SIP/1020-00000005", "ext-did,s,1")
in new stack
[Aug 7 02:02:12] VERBOSE[48951] pbx.c: -- Goto (ext-did,s,1)
[Aug 7 02:02:12] VERBOSE[48951] pbx.c: -- Executing [s@ext-did:1]
Set("SIP/1020-00000005", "__FROM_DID=s") in new stack
[Aug 7 02:02:12] VERBOSE[48951] pbx.c: -- Executing [s@ext-did:2]
Gosub("SIP/1020-00000005", "app-blacklist-check,s,1") in new stack
[Aug 7 02:02:12] VERBOSE[48951] pbx.c: -- Executing
[s@app-blacklist-check:1] GotoIf("SIP/1020-00000005", "0?blacklisted")
in new stack
[Aug 7 02:02:12] VERBOSE[48951] pbx.c: -- Executing
[s@app-blacklist-check:2] Set("SIP/1020-00000005", "CALLED_BLACKLIST=1")
in new stack
[Aug 7 02:02:12] VERBOSE[48951] pbx.c: -- Executing
[s@app-blacklist-check:3] Return("SIP/1020-00000005", "") in new stack
[Aug 7 02:02:12] VERBOSE[48951] pbx.c: -- Executing [s@ext-did:3]
ExecIf("SIP/1020-00000005", "0 ?Set(CALLERID(name)=1020)") in new stack
[Aug 7 02:02:12] VERBOSE[48951] pbx.c: -- Executing [s@ext-did:4]
Set("SIP/1020-00000005", "__CALLINGPRES_SV=allowed_not_screened") in new
stack
[Aug 7 02:02:12] VERBOSE[48951] pbx.c: -- Executing [s@ext-did:5]
Set("SIP/1020-00000005", "CALLERPRES()=allowed_not_screened") in new stack
[Aug 7 02:02:12] VERBOSE[48951] pbx.c: -- Executing [s@ext-did:6]
Goto("SIP/1020-00000005", "ext-trunk,2,1") in new stack
[Aug 7 02:02:12] VERBOSE[48951] pbx.c: -- Goto (ext-trunk,2,1)
[Aug 7 02:02:12] VERBOSE[48951] pbx.c: -- Executing [2@ext-trunk:1]
Set("SIP/1020-00000005", "TDIAL_STRING=SIP/(((MY TRUNK PROVIDERS DOMAIN)))") in
new stack
[Aug 7 02:02:12] VERBOSE[48951] pbx.c: -- Executing [2@ext-trunk:2]
Set("SIP/1020-00000005", "DIAL_TRUNK=2") in new stack
[Aug 7 02:02:12] VERBOSE[48951] pbx.c: -- Executing [2@ext-trunk:3]
Goto("SIP/1020-00000005", "ext-trunk,tdial,1") in new stack
[Aug 7 02:02:12] VERBOSE[48951] pbx.c: -- Goto (ext-trunk,tdial,1)
[Aug 7 02:02:12] VERBOSE[48951] pbx.c: -- Executing [tdial@ext-trunk:1]
Set("SIP/1020-00000005", "OUTBOUND_GROUP=OUT_2") in new stack
[Aug 7 02:02:12] VERBOSE[48951] pbx.c: -- Executing [tdial@ext-trunk:2]
GotoIf("SIP/1020-00000005", "0?nomax") in new stack
[Aug 7 02:02:12] VERBOSE[48951] pbx.c: -- Executing [tdial@ext-trunk:3]
GotoIf("SIP/1020-00000005", "0?hangit") in new stack
[Aug 7 02:02:12] VERBOSE[48951] pbx.c: -- Executing [tdial@ext-trunk:4]
ExecIf("SIP/1020-00000005", "1?Set(CALLERPRES()=allowed_not_screened)")
in new stack
[Aug 7 02:02:12] VERBOSE[48951] pbx.c: -- Executing [tdial@ext-trunk:5]
Set("SIP/1020-00000005", "DIAL_NUMBER=s") in new stack
[Aug 7 02:02:12] VERBOSE[48951] pbx.c: -- Executing [tdial@ext-trunk:6]
GosubIf("SIP/1020-00000005", "0?sub-flp-2,s,1") in new stack
[Aug 7 02:02:12] VERBOSE[48951] pbx.c: -- Executing [tdial@ext-trunk:7]
Set("SIP/1020-00000005", "OUTNUM=s") in new stack
[Aug 7 02:02:12] VERBOSE[48951] pbx.c: -- Executing [tdial@ext-trunk:8]
Dial("SIP/1020-00000005", "SIP/(((MY TRUNK PROVIDERS DOMAIN)))/s,300,") in new stack
[Aug 7 02:02:12] VERBOSE[48951] netsock.c: == Using SIP RTP TOS bits 184
[Aug 7 02:02:12] VERBOSE[48951] netsock.c: == Using SIP RTP CoS mark 5
[Aug 7 02:02:12] VERBOSE[48951] netsock.c: == Using UDPTL TOS bits 184
[Aug 7 02:02:12] VERBOSE[48951] netsock.c: == Using UDPTL CoS mark 5
[Aug 7 02:02:12] VERBOSE[48951] chan_sip.c: Audio is at (((MY FREEPBX IP ADDRESS)))
port 12636
[Aug 7 02:02:12] VERBOSE[48951] chan_sip.c: Adding codec 0x4 (ulaw) to SDP
[Aug 7 02:02:12] VERBOSE[48951] chan_sip.c: Adding codec 0x8 (alaw) to SDP
[Aug 7 02:02:12] VERBOSE[48951] chan_sip.c: Adding non-codec 0x1
(telephone-event) to SDP
[Aug 7 02:02:12] VERBOSE[48951] chan_sip.c: Reliably Transmitting (no
NAT) to (((MY TRUNK PROVIDERS IP ADDRESS))):5060:
INVITE sip:s@(((MY TRUNK PROVIDERS DOMAIN))):5060 SIP/2.0
Via: SIP/2.0/UDP (((MY FREEPBX IP ADDRESS))):5060;branch=z9hG4bK4cc78f6b
Max-Forwards: 70
From: "device" (((sip:(((MY TRUNK PROVIDER USERNAME)))@(((MY TRUNK PROVIDERS DOMAIN))))));tag=as7f80f6cb
To: (((sip:s@(((MY TRUNK PROVIDERS DOMAIN))):5060)))
Contact: (((sip:(((MY TRUNK PROVIDER USERNAME)))@(((MY FREEPBX IP ADDRESS))))))
Call-ID: 3368f96d5e185eaf4bbefef07745287e@(((MY TRUNK PROVIDERS DOMAIN)))
CSeq: 102 INVITE
User-Agent: FPBX-2.8.1(1.6.2.18)
Date: Sun, 07 Aug 2011 00:02:12 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Type: application/sdp
Content-Length: 288

v=0
o=root 607280493 607280493 IN IP4 (((MY FREEPBX IP ADDRESS)))
s=Asterisk PBX 1.6.2.18
c=IN IP4 (((MY FREEPBX IP ADDRESS)))
t=0 0
m=audio 12636 RTP/AVP 0 8 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv

---
[Aug 7 02:02:12] VERBOSE[48951] app_dial.c: -- Called
(((MY TRUNK PROVIDERS DOMAIN)))/s
[Aug 7 02:02:12] VERBOSE[59249] chan_sip.c:
(((--- SIP read from UDP:(((MY TRUNK PROVIDERS IP ADDRESS))):5060 ---)))
SIP/2.0 404 Not found (no match)
Via: SIP/2.0/UDP (((MY FREEPBX IP ADDRESS))):5060;branch=z9hG4bK4cc78f6b
From: "device" (((sip:(((MY TRUNK PROVIDER USERNAME)))@(((MY TRUNK PROVIDERS DOMAIN))))));tag=as7f80f6cb
To:
(((sip:s@(((MY TRUNK PROVIDERS DOMAIN))):5060)));tag=8905033d07430b3434f1d8712ca047af.9e5d
Call-ID: 3368f96d5e185eaf4bbefef07745287e@(((MY TRUNK PROVIDERS DOMAIN)))
CSeq: 102 INVITE
Content-Length: 0

(((-------------)))
[Aug 7 02:02:12] VERBOSE[59249] chan_sip.c: --- (7 headers 0 lines) ---
[Aug 7 02:02:12] VERBOSE[59249] chan_sip.c: Transmitting (no NAT) to
(((MY TRUNK PROVIDERS IP ADDRESS))):5060:
ACK sip:s@(((MY TRUNK PROVIDERS DOMAIN))):5060 SIP/2.0
Via: SIP/2.0/UDP (((MY FREEPBX IP ADDRESS))):5060;branch=z9hG4bK4cc78f6b
Max-Forwards: 70
From: "device" (((sip:(((MY TRUNK PROVIDER USERNAME)))@(((MY TRUNK PROVIDERS DOMAIN))))));tag=as7f80f6cb
To:
(((sip:s@(((MY TRUNK PROVIDERS DOMAIN))):5060)));tag=8905033d07430b3434f1d8712ca047af.9e5d
Contact: (((sip:(((MY TRUNK PROVIDER USERNAME)))@(((MY FREEPBX IP ADDRESS))))))
Call-ID: 3368f96d5e185eaf4bbefef07745287e@(((MY TRUNK PROVIDERS DOMAIN)))
CSeq: 102 ACK
User-Agent: FPBX-2.8.1(1.6.2.18)
Content-Length: 0

---
[Aug 7 02:02:12] VERBOSE[48951] app_dial.c: --
SIP/(((MY TRUNK PROVIDERS DOMAIN)))-00000006 is circuit-busy
[Aug 7 02:02:12] VERBOSE[48951] app_dial.c: == Everyone is
busy/congested at this time (1:0/1/0)
[Aug 7 02:02:12] VERBOSE[48951] pbx.c: -- Executing [tdial@ext-trunk:9]
Set("SIP/1020-00000005", "CALLERID(number)=1020") in new stack
[Aug 7 02:02:12] VERBOSE[48951] pbx.c: -- Executing [tdial@ext-trunk:10]
Set("SIP/1020-00000005", "CALLERID(name)=device") in new stack
[Aug 7 02:02:12] VERBOSE[48951] pbx.c: -- Executing [tdial@ext-trunk:11]
Hangup("SIP/1020-00000005", "") in new stack
[Aug 7 02:02:12] VERBOSE[48951] pbx.c: == Spawn extension (ext-trunk,
tdial, 11) exited non-zero on 'SIP/1020-00000005'
[Aug 7 02:02:12] VERBOSE[48951] chan_sip.c: Scheduling destruction of
SIP dialog 'ZDdhOTFlMDFjMzM1OTA1MmIzYzUyNDk1YjA0NzAxZDA.' in 6400 ms
(Method: INVITE)
[Aug 7 02:02:12] VERBOSE[48951] chan_sip.c:
(((--- Reliably Transmitting (NAT) to (((MY DSL IP ADDRESS))):35940 ---)))
SIP/2.0 404 Not Found
Via: SIP/2.0/UDP
(((MY DSL IP ADDRESS))):35940;branch=z9hG4bK-d8754z-1a8545a523081812-1---d8754z-;received=(((MY DSL IP ADDRESS)));rport=35940
From: "1020"(((sip:1020@(((MY FREEPBX IP ADDRESS))):5060)));tag=e9bd76e6
To: "(((NUMBER DIALED)))"(((sip:(((NUMBER DIALED)))@(((MY FREEPBX IP ADDRESS))):5060)));tag=as7a69ada6
Call-ID: ZDdhOTFlMDFjMzM1OTA1MmIzYzUyNDk1YjA0NzAxZDA.
CSeq: 2 INVITE
Server: FPBX-2.8.1(1.6.2.18)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces, timer
Content-Length: 0

(((------------)))
[Aug 7 02:02:12] VERBOSE[59249] chan_sip.c:
(((--- SIP read from UDP:(((MY DSL IP ADDRESS))):35940 ---)))
ACK sip:(((NUMBER DIALED)))@(((MY FREEPBX IP ADDRESS))):5060 SIP/2.0
Via: SIP/2.0/UDP
(((MY DSL IP ADDRESS))):35940;branch=z9hG4bK-d8754z-1a8545a523081812-1---d8754z-;rport
Max-Forwards: 70
To: "(((NUMBER DIALED)))"(((sip:(((NUMBER DIALED)))@(((MY FREEPBX IP ADDRESS))):5060)));tag=as7a69ada6
From: "1020"(((sip:1020@(((MY FREEPBX IP ADDRESS))):5060)));tag=e9bd76e6
Call-ID: ZDdhOTFlMDFjMzM1OTA1MmIzYzUyNDk1YjA0NzAxZDA.
CSeq: 2 ACK
Content-Length: 0

(((-------------)))
[Aug 7 02:02:12] VERBOSE[59249] chan_sip.c: --- (8 headers 0 lines) ---
[Aug 7 02:02:12] VERBOSE[59249] chan_sip.c: Really destroying SIP dialog
'3368f96d5e185eaf4bbefef07745287e@(((MY TRUNK PROVIDERS DOMAIN)))' Method: INVITE
[Aug 7 02:02:18] VERBOSE[59249] chan_sip.c: Really destroying SIP dialog
'ZDdhOTFlMDFjMzM1OTA1MmIzYzUyNDk1YjA0NzAxZDA.' Method: ACK
[Aug 7 02:02:29] VERBOSE[59249] chan_sip.c:
(((--- SIP read from UDP:(((MY DSL IP ADDRESS))):5060 ---)))

The Other Guy
The Other Guy's picture
It would be more helpful to

It would be more helpful to see a copy of the Asterisk CLI output. SSH into your Asterisk server and issue the command:

asterisk -RvvvvT

The number of v's indicates the level of verbosity.
Also, while at the CLI you can do commands like

sip show peers

and

sip show registry

which will help determine if you are actually registering with the provider.

mirage03
mirage03's picture
CLI Commands and SSH Logs

Hi

When I issue the command "sip show peers", it returns:

> 1020/1020 (((MY DSL IP))) D N A 5060 OK (53ms)
> (and all the other extensions I configured in FreePBX)
> (((MY SIPGATE USERNAME)))/(((MY SIPGATE USERNAME))) 217.10.68.150 N 5060 Unmonitored
> sipconnect.sipgate.de/131 217.10.68.150 5060 Unmonitored

and "sip show registry"

> Host dnsmgr Username Refresh State Reg.Time
> sipconnect.sipgate.de:5060 N (((MY SIPGATE USERNAME))) 105 Registered Mon, 08 Aug 2011 00:24:23
> 1 SIP registrations.

When I login via SSH with "asterisk -RvvvvT" and try to make a call it returns to log as below:

Regards
Christian

> <------------>
> -- Executing [(((EXTERNAL NUMBER I TRIED TO CALL)))@from-trunk:1] Set("SIP/1020-00000014", "__FROM_DID=(((EXTERNAL NUMBER I TRIED TO CALL)))") in new stack
> -- Executing [(((EXTERNAL NUMBER I TRIED TO CALL)))@from-trunk:2] NoOp("SIP/1020-00000014", "Received an unknown call with DID set to (((EXTERNAL NUMBER I TRIED TO CALL)))") in new stack
> -- Executing [(((EXTERNAL NUMBER I TRIED TO CALL)))@from-trunk:3] Goto("SIP/1020-00000014", "s,a2") in new stack
> -- Goto (from-trunk,s,2)
> -- Executing [s@from-trunk:2] Answer("SIP/1020-00000014", "") in new stack
> Audio is at (((MY FREEPBX IP))) port 13632
> Adding codec 0x4 (ulaw) to SDP
> Adding codec 0x8 (alaw) to SDP
> Adding non-codec 0x1 (telephone-event) to SDP
>
> <--- Reliably Transmitting (NAT) to (((MY DSL IP))):10124 --->
> SIP/2.0 200 OK
> Via: SIP/2.0/UDP (((MY DSL IP))):10124;branch=z9hG4bK-d8754z-219c1468ea60ded4-1---d8754z-;received=(((MY DSL IP)));rport=10124
> From: "1020";tag=a8b296e2
> To: "(((EXTERNAL NUMBER I TRIED TO CALL)))";tag=as78857830
> Call-ID: NWQ0Zjk4MTBkNDRkNjZjYmFlYWU3MWRmMWE2ODBhZjU.
> CSeq: 2 INVITE
> Server: FPBX-2.8.1(1.6.2.18)
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
> Supported: replaces, timer
> Contact:
> Content-Type: application/sdp
> Content-Length: 284
>
> v=0
> o=root 3921927 3921927 IN IP4 (((MY FREEPBX IP)))
> s=Asterisk PBX 1.6.2.18
> c=IN IP4 (((MY FREEPBX IP)))
> t=0 0
> m=audio 13632 RTP/AVP 0 8 101
> a=rtpmap:0 PCMU/8000
> a=rtpmap:8 PCMA/8000
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-16
> a=silenceSupp:off - - - -
> a=ptime:20
> a=sendrecv
>
> <------------>
> -- Executing [s@from-trunk:3] Wait("SIP/1020-00000014", "2") in new stack
>
> <--- SIP read from UDP:(((MY DSL IP))):10124 --->
> ACK sip:(((EXTERNAL NUMBER I TRIED TO CALL)))@(((MY FREEPBX IP))):5060 SIP/2.0
> Via: SIP/2.0/UDP (((MY DSL IP))):10124;branch=z9hG4bK-d8754z-f769b22e518dcea6-1---d8754z-;rport
> Max-Forwards: 70
> Contact:
> To: "(((EXTERNAL NUMBER I TRIED TO CALL)))";tag=as78857830
> From: "1020";tag=a8b296e2
> Call-ID: NWQ0Zjk4MTBkNDRkNjZjYmFlYWU3MWRmMWE2ODBhZjU.
> CSeq: 2 ACK
> User-Agent: X-Lite 4 release 4.0 stamp 58832
> Authorization: Digest username="1020",realm="asterisk",nonce="4b2c998f",uri="sip:(((EXTERNAL NUMBER I TRIED TO CALL)))@(((MY FREEPBX IP)))",response="a592678be638a9fc3fd876831f7273d6",algorithm=MD5
> Content-Length: 0
>
>
> <------------->
> --- (11 headers 0 lines) ---
> -- Executing [s@from-trunk:4] Playback("SIP/1020-00000014", "ss-noservice") in new stack
> -- Playing 'ss-noservice.gsm' (language 'en')
>
> <--- SIP read from UDP:(((MY DSL IP))):10124 --->
> BYE sip:(((EXTERNAL NUMBER I TRIED TO CALL)))@(((MY FREEPBX IP))):5060 SIP/2.0
> Via: SIP/2.0/UDP (((MY DSL IP))):10124;branch=z9hG4bK-d8754z-1b49724012b2017b-1---d8754z-;rport
> Max-Forwards: 70
> Contact:
> To: "(((EXTERNAL NUMBER I TRIED TO CALL)))";tag=as78857830
> From: "1020";tag=a8b296e2
> Call-ID: NWQ0Zjk4MTBkNDRkNjZjYmFlYWU3MWRmMWE2ODBhZjU.
> CSeq: 3 BYE
> User-Agent: X-Lite 4 release 4.0 stamp 58832
> Authorization: Digest username="1020",realm="asterisk",nonce="4b2c998f",uri="sip:(((EXTERNAL NUMBER I TRIED TO CALL)))@(((MY FREEPBX IP))):5060",response="29e8fc39f65514201e474e4b05ead0c0",algorithm=MD5
> Content-Length: 0
>
>
> <------------->
> --- (11 headers 0 lines) ---
> Sending to (((MY DSL IP))) : 10124 (NAT)
>
> <--- Transmitting (NAT) to (((MY DSL IP))):10124 --->
> SIP/2.0 200 OK
> Via: SIP/2.0/UDP (((MY DSL IP))):10124;branch=z9hG4bK-d8754z-1b49724012b2017b-1---d8754z-;received=(((MY DSL IP)));rport=10124
> From: "1020";tag=a8b296e2
> To: "(((EXTERNAL NUMBER I TRIED TO CALL)))";tag=as78857830
> Call-ID: NWQ0Zjk4MTBkNDRkNjZjYmFlYWU3MWRmMWE2ODBhZjU.
> CSeq: 3 BYE
> Server: FPBX-2.8.1(1.6.2.18)
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
> Supported: replaces, timer
> Content-Length: 0
>
>
> <------------>
> == Spawn extension (from-trunk, s, 4) exited non-zero on 'SIP/1020-00000014'
> -- Executing [h@from-trunk:1] Macro("SIP/1020-00000014", "hangupcall,") in new stack
> -- Executing [s@macro-hangupcall:1] GotoIf("SIP/1020-00000014", "1?skiprg") in new stack
> -- Goto (macro-hangupcall,s,4)
> -- Executing [s@macro-hangupcall:4] GotoIf("SIP/1020-00000014", "1?skipblkvm") in new stack
> -- Goto (macro-hangupcall,s,7)
> -- Executing [s@macro-hangupcall:7] GotoIf("SIP/1020-00000014", "1?theend") in new stack
> -- Goto (macro-hangupcall,s,9)
> -- Executing [s@macro-hangupcall:9] Hangup("SIP/1020-00000014", "") in new stack
> == Spawn extension (macro-hangupcall, s, 9) exited non-zero on 'SIP/1020-00000014' in macro 'hangupcall'
> == Spawn extension (from-trunk, h, 1) exited non-zero on 'SIP/1020-00000014'
> Really destroying SIP dialog 'NWQ0Zjk4MTBkNDRkNjZjYmFlYWU3MWRmMWE2ODBhZjU.' Method: BYE
>
> <--- SIP read from UDP:(((MY DSL IP))):10124 --->
>
>
>
> <------------->
> > doing dnsmgr_lookup for 'sipconnect.sipgate.de'
> > ast_get_srv: SRV lookup for '_sip._udp.sipconnect.sipgate.de' mapped to host sipconnect.sipgate.de, port 5060
> REGISTER 11 headers, 0 lines
> Reliably Transmitting (no NAT) to 217.10.68.150:5060:
> REGISTER sip:sipconnect.sipgate.de SIP/2.0
> Via: SIP/2.0/UDP (((MY FREEPBX IP))):5060;branch=z9hG4bK52e7e7ca
> Max-Forwards: 70
> From: ;tag=as3af809ab
> To:
> Call-ID:

> CSeq: 104 REGISTER
> User-Agent: FPBX-2.8.1(1.6.2.18)
> Authorization: Digest username="(((MY SIPGATE USER NAME)))", realm="sipconnect.sipgate.de", algorithm=MD5, uri="sip:sipconnect.sipgate.de", nonce="4e3f198b91ad21038de30211e5b5cbfe0ba32962", response="5991e06e347ac7c07ca8c09b4bf72ff5"
> Expires: 120
> Contact:
> Content-Length: 0
>
>
> ---
>
> <--- SIP read from UDP:217.10.68.150:5060 --->
> SIP/2.0 200 OK
> Via: SIP/2.0/UDP (((MY FREEPBX IP))):5060;branch=z9hG4bK52e7e7ca
> From: ;tag=as3af809ab
> To: ;tag=efae1b206a1df22b5fbc395b5a747d13.4c9b
> Call-ID:

> CSeq: 104 REGISTER
> Contact: ;expires=120
> Content-Length: 0
>
>
> <------------->
> --- (8 headers 0 lines) ---
> Scheduling destruction of SIP dialog '2d525a3717a7d374459371d579cd1576@sipconnect.sipgate.de' in 32000 ms (Method: REGISTER)
> Reliably Transmitting (NAT) to (((MY DSL IP))):10124:
> OPTIONS sip:1020@(((MY DSL IP))):10124;rinstance=69e56f8aa3c4644b SIP/2.0
> Via: SIP/2.0/UDP (((MY FREEPBX IP))):5060;branch=z9hG4bK1e092e95;rport
> Max-Forwards: 70
> From: "Unknown" ;tag=as1e4a33b3
> To:
> Contact:
> Call-ID: 60908b600f49db8970bb4fb1738217ac@(((MY FREEPBX IP)))
> CSeq: 102 OPTIONS
> User-Agent: FPBX-2.8.1(1.6.2.18)
> Date: Sun, 07 Aug 2011 22:59:36 GMT
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
> Supported: replaces, timer
> Content-Length: 0
>
>
> ---
>
> <--- SIP read from UDP:(((MY DSL IP))):10124 --->
> SIP/2.0 200 OK
> Via: SIP/2.0/UDP (((MY FREEPBX IP))):5060;branch=z9hG4bK1e092e95;rport=5060
> Contact:
> To: ;tag=8e5c2611
> From: "Unknown";tag=as1e4a33b3
> Call-ID: 60908b600f49db8970bb4fb1738217ac@(((MY FREEPBX IP)))
> CSeq: 102 OPTIONS
> Accept: application/sdp
> Accept-Language: en
> Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO
> Supported: replaces
> User-Agent: X-Lite 4 release 4.0 stamp 58832
> Content-Length: 0
>
>
> <------------->
> --- (13 headers 0 lines) ---
> Really destroying SIP dialog '60908b600f49db8970bb4fb1738217ac@(((MY FREEPBX IP)))' Method: OPTIONS
>
> <--- SIP read from UDP:(((MY DSL IP))):10124 --->
>
>
>
> <------------->
> Really destroying SIP dialog '2d525a3717a7d374459371d579cd1576@sipconnect.sipgate.de' Method: REGISTER

The Other Guy
The Other Guy's picture
Okay, so you are registering

Okay, so you are registering with the provider. The question then is, why is the call not going through?

It would be more helpful to see a copy of the Asterisk CLI output. SSH into your Asterisk server and issue the command:

asterisk -RvvvvT

The number of v's indicates the level of verbosity.

You are sending sections of log file output and that's not what I asked to see. I can't see anything useful by looking at that log file. I'm trying to figure out why the call is not going through, and the CLI output is what tells you that, not a log file.

Please do NOT send any more log file snippets unless I (or someone else) asks you to do so.

mirage03
mirage03's picture
Cli Output

Yes, I also find this strange, because nobody here seem to have similar problems.

Sorry, for posting the logs (I am quite new to FreePBX), but if I log on via SSH in Putty and type in "asterisk -RvvvvT" this is what it says:

> [Aug 8 01:41:01] Asterisk 1.6.2.18, Copyright (C) 1999 - 2010 Digium, Inc. and others.
> Created by Mark Spencer
> Asterisk comes with ABSOLUTELY NO WARRANTY; type 'core show warranty' for details.
> This is free software, with components licensed under the GNU General Public
> License version 2 and other licenses; you are welcome to redistribute it under
> certain conditions. Type 'core show license' for details.
> =========================================================================
> [Aug 8 01:41:01] == Parsing '/etc/asterisk/asterisk.conf': [Aug 8 01:41:01] == Found
> [Aug 8 01:41:01] == Parsing '/etc/asterisk/extconfig.conf': [Aug 8 01:41:01] == Found
> [Aug 8 01:41:01] Connected to Asterisk 1.6.2.18 currently running on freepbx (pid = 59236)
> Verbosity is at least 4
>
> <--- SIP read from UDP:(((MY DSL IP))):10124 --->
>
>
>
> <------------->
> > doing dnsmgr_lookup for 'sipconnect.sipgate.de'
> > ast_get_srv: SRV lookup for '_sip._udp.sipconnect.sipgate.de' mapped to host sipconnect.sipgate.de, port 5060
> REGISTER 11 headers, 0 lines
> Reliably Transmitting (no NAT) to 217.10.68.150:5060:

......

from there on it continues to write to the file with logs like previously posted, thought these entries would be required.

Regards
Christian

The Other Guy
The Other Guy's picture
Right, you do that and see

Right, you do that and see that output, and THEN you make a test call, and on that screen you should start seeing output from Asterisk as it tries to follow each step of the dial plan generated by FreePBX. It's that output we need to see, but you won't see anything more until you make a call. Don't navigate away from the Asterisk CLI or switch to another screen until you have made a call, and you should see what I'm talking about.

mirage03
mirage03's picture
Forgot to mention

In the FreePBX GUI --> Tools --> Asterisk CLI I had turned on "sip set debug on". Now, after I turned it off it stops at > ast_get_srv: SRV lookup for '_sip._udp.sipconnect.sipgate.de' mapped to host sipconnect.sipgate.de, port 5060

Understood now what you were looking for.

Regards
Christian

mirage03
mirage03's picture
Now I get (when I make a call)

> == Using SIP RTP TOS bits 184
> == Using SIP RTP CoS mark 5
> == Using UDPTL TOS bits 184
> == Using UDPTL CoS mark 5
> -- Executing [(((EXTERNAL NUMBER I TRIED TO CALL)))@from-trunk:1] Set("SIP/1020-00000016", "__FROM_DID=(((EXTERNAL NUMBER I TRIED TO CALL)))") in new stack
> -- Executing [(((EXTERNAL NUMBER I TRIED TO CALL)))@from-trunk:2] NoOp("SIP/1020-00000016", "Received an unknown call with DID set to (((EXTERNAL NUMBER I TRIED TO CALL)))") in new stack
> -- Executing [(((EXTERNAL NUMBER I TRIED TO CALL)))@from-trunk:3] Goto("SIP/1020-00000016", "s,a2") in new stack
> -- Goto (from-trunk,s,2)
> -- Executing [s@from-trunk:2] Answer("SIP/1020-00000016", "") in new stack
> -- Executing [s@from-trunk:3] Wait("SIP/1020-00000016", "2") in new stack
> -- Executing [s@from-trunk:4] Playback("SIP/1020-00000016", "ss-noservice") in new stack
> -- Playing 'ss-noservice.gsm' (language 'en')
> -- Executing [s@from-trunk:5] SayAlpha("SIP/1020-00000016", "(((EXTERNAL NUMBER I TRIED TO CALL)))") in new stack
> -- Playing 'digits/0.gsm' (language 'en')
> -- Playing 'digits/0.gsm' (language 'en')
> -- Playing 'digits/4.gsm' (language 'en')
> -- Playing 'digits/9.gsm' (language 'en')

(Says the number)

> == Spawn extension (from-trunk, s, 5) exited non-zero on 'SIP/1020-00000016'
> -- Executing [h@from-trunk:1] Macro("SIP/1020-00000016", "hangupcall,") in new stack
> -- Executing [s@macro-hangupcall:1] GotoIf("SIP/1020-00000016", "1?skiprg") in new stack
> -- Goto (macro-hangupcall,s,4)
> -- Executing [s@macro-hangupcall:4] GotoIf("SIP/1020-00000016", "1?skipblkvm") in new stack
> -- Goto (macro-hangupcall,s,7)
> -- Executing [s@macro-hangupcall:7] GotoIf("SIP/1020-00000016", "1?theend") in new stack
> -- Goto (macro-hangupcall,s,9)
> -- Executing [s@macro-hangupcall:9] Hangup("SIP/1020-00000016", "") in new stack
> == Spawn extension (macro-hangupcall, s, 9) exited non-zero on 'SIP/1020-00000016' in macro 'hangupcall'
> == Spawn extension (from-trunk, h, 1) exited non-zero on 'SIP/1020-00000016'
> > doing dnsmgr_lookup for 'sipconnect.sipgate.de'
> > ast_get_srv: SRV lookup for '_sip._udp.sipconnect.sipgate.de' mapped to host sipconnect.sipgate.de, port 5060

obelisk
obelisk's picture
Your extensions should have

Your extensions should have context from-internal, not from-trunk.
FreePBX should not allow users to shoot themselves in the foot so easily Wink

SkykingOH
SkykingOH's picture
Quote: Your extensions

Quote:
Your extensions should have context from-internal, not from-trunk.

He is not using FXS ports, these are FXO trunk ports. x-lite is on the client side.

from-dahdi is the correct context.

mirage03
mirage03's picture
context from-internal and disabling the Blacklist fixed it

A special thanks to obelisk and the othe guy. I had indeed context from-trunk in my extensions configuration because otherwise the incoming calls on numbers forwarded through the trunk did not reach the system.

I also disabled the blacklist addon from moduls and -surprise- all works fine now, incoming and outgoing calls!

You are a great forum, thanks a million again.

Regards
Christian

SkykingOH
SkykingOH's picture
I reread and retract my

I reread and retract my comment to Obelisk. I had never thought you would have put an extension in the from-trunk context, that would indeed cause lots of issues (and an inability to dial)

from-trunk
from-pstn
from-dahdi

are the three most common contexts for trunks. from-trunk and from-pstn do the same thing, the from-trunk is a legacy name. from-dahdi supports the functionality of the Zap DID module

from-internal is for extensions and other devices that need access to the dial plan.