New to Free PBX - cannot make outgoing calls via trunk

mirage03 · August 7, 2011, 2:37pm

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 · August 7, 2011, 3:26pm

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 · August 7, 2011, 11:18pm

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”<sip:1020@(((MY FREEPBX IP))):5060>;tag=a8b296e2
To: “(((EXTERNAL NUMBER I TRIED TO CALL)))”<sip:(((EXTERNAL NUMBER I TRIED TO CALL)))@(((MY FREEPBX IP))):5060>;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: <sip:(((EXTERNAL NUMBER I TRIED TO CALL)))@(((MY FREEPBX IP)))>
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: <sip:1020@(((MY DSL IP))):10124>
To: “(((EXTERNAL NUMBER I TRIED TO CALL)))”<sip:(((EXTERNAL NUMBER I TRIED TO CALL)))@(((MY FREEPBX IP))):5060>;tag=as78857830
From: “1020”<sip:1020@(((MY FREEPBX IP))):5060>;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
– <SIP/1020-00000014> 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: <sip:1020@(((MY DSL IP))):10124>
To: “(((EXTERNAL NUMBER I TRIED TO CALL)))”<sip:(((EXTERNAL NUMBER I TRIED TO CALL)))@(((MY FREEPBX IP))):5060>;tag=as78857830
From: “1020”<sip:1020@(((MY FREEPBX IP))):5060>;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”<sip:1020@(((MY FREEPBX IP))):5060>;tag=a8b296e2
To: “(((EXTERNAL NUMBER I TRIED TO CALL)))”<sip:(((EXTERNAL NUMBER I TRIED TO CALL)))@(((MY FREEPBX IP))):5060>;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: <sip:(((MY SIPGATE USER NAME)))@sipconnect.sipgate.de>;tag=as3af809ab
To: <sip:(((MY SIPGATE USER NAME)))@sipconnect.sipgate.de>
Call-ID: [email protected]
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: <sip:(((MY SIPGATE USER NAME)))@(((MY FREEPBX IP)))>
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: <sip:(((MY SIPGATE USER NAME)))@sipconnect.sipgate.de>;tag=as3af809ab
To: <sip:(((MY SIPGATE USER NAME)))@sipconnect.sipgate.de>;tag=efae1b206a1df22b5fbc395b5a747d13.4c9b
Call-ID: [email protected]
CSeq: 104 REGISTER
Contact: <sip:(((MY SIPGATE USER NAME)))@(((MY FREEPBX IP)))>;expires=120
Content-Length: 0

<------------->
— (8 headers 0 lines) —
Scheduling destruction of SIP dialog ‘[email protected]’ 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” <sip:Unknown@(((MY FREEPBX IP)))>;tag=as1e4a33b3
To: <sip:1020@(((MY DSL IP))):10124;rinstance=69e56f8aa3c4644b>
Contact: <sip:Unknown@(((MY FREEPBX IP)))>
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: <sip:(((MY DSL IP))):10124>
To: <sip:1020@(((MY DSL IP))):10124;rinstance=69e56f8aa3c4644b>;tag=8e5c2611
From: “Unknown”<sip:Unknown@(((MY FREEPBX IP))):5060>;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 ‘[email protected]’ Method: REGISTER

The_Other_Guy · August 7, 2011, 11:33pm

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 · August 7, 2011, 11:51pm

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 [email protected]
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 · August 8, 2011, 12:08am

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 · August 8, 2011, 12:10am

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 · August 8, 2011, 12:29am

== 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
– <SIP/1020-00000016> Playing ‘ss-noservice.gsm’ (language ‘en’)
– Executing [s@from-trunk:5] SayAlpha(“SIP/1020-00000016”, “(((EXTERNAL NUMBER I TRIED TO CALL)))”) in new stack
– <SIP/1020-00000016> Playing ‘digits/0.gsm’ (language ‘en’)
– <SIP/1020-00000016> Playing ‘digits/0.gsm’ (language ‘en’)
– <SIP/1020-00000016> Playing ‘digits/4.gsm’ (language ‘en’)
– <SIP/1020-00000016> 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 · August 9, 2011, 9:54am

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

SkykingOH · August 9, 2011, 1:36pm

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 · August 9, 2011, 10:16pm

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 · August 9, 2011, 10:45pm

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.