Link to home
Start Free TrialLog in
Avatar of bevege
bevegeFlag for United States of America

asked on

Asterisk hangs up when call is forwarded to it but works when dialed

I have a Freepbx box running Asterisk 1.8.20.1 on Centos 6.3.

When I forward a call to my box from anywhere ie cell phone, another voip provider analog pbx, it almost immediately hangs up. If I call the number directly it works just fine. Not sure what the issue is. I've added copies of the log when it works and when it doesn't work.

I really want to get this working. I have live people that answer the phone during business hours but I want the calls forwarded to my box after hours.

Logs from a call made directly to the number (it works)

 [2013-07-01 17:57:04] VERBOSE[5516] netsock2.c:   == Using SIP RTP TOS bits 184
[2013-07-01 17:57:04] VERBOSE[5516] netsock2.c:   == Using SIP RTP CoS mark 5
[2013-07-01 17:57:04] VERBOSE[982] pbx.c:     -- Executing [xxxxxxxxxx@from-trunk:1] Set("SIP/vitel-inbound-00000447", "__FROM_DID=xxxxxxxxxx") in new stack
[2013-07-01 17:57:04] VERBOSE[982] pbx.c:     -- Executing [xxxxxxxxxx@from-trunk:2] Gosub("SIP/vitel-inbound-00000447", "app-blacklist-check,s,1()") in new stack
[2013-07-01 17:57:04] VERBOSE[982] pbx.c:     -- Executing [s@app-blacklist-check:1] GotoIf("SIP/vitel-inbound-00000447", "0?blacklisted") in new stack
[2013-07-01 17:57:04] VERBOSE[982] pbx.c:     -- Executing [s@app-blacklist-check:2] Set("SIP/vitel-inbound-00000447", "CALLED_BLACKLIST=1") in new stack
[2013-07-01 17:57:04] VERBOSE[982] pbx.c:     -- Executing [s@app-blacklist-check:3] Return("SIP/vitel-inbound-00000447", "") in new stack
[2013-07-01 17:57:04] VERBOSE[982] pbx.c:     -- Executing [xxxxxxxxxx@from-trunk:3] Set("SIP/vitel-inbound-00000447", "CDR(did)=xxxxxxxxxx") in new stack
[2013-07-01 17:57:04] VERBOSE[982] pbx.c:     -- Executing [xxxxxxxxxx@from-trunk:4] ExecIf("SIP/vitel-inbound-00000447", "0 ?Set(CALLERID(name)=7203846501)") in new stack
[2013-07-01 17:57:04] VERBOSE[982] pbx.c:     -- Executing [xxxxxxxxxx@from-trunk:5] Set("SIP/vitel-inbound-00000447", "__CALLINGPRES_SV=allowed_not_screened") in new stack
[2013-07-01 17:57:04] VERBOSE[982] pbx.c:     -- Executing [xxxxxxxxxx@from-trunk:6] Set("SIP/vitel-inbound-00000447", "CALLERPRES()=allowed_not_screened") in new stack
[2013-07-01 17:57:04] VERBOSE[982] pbx.c:     -- Executing [xxxxxxxxxx@from-trunk:7] Goto("SIP/vitel-inbound-00000447", "ivr-2,s,1") in new stack
[2013-07-01 17:57:04] VERBOSE[982] pbx.c:     -- Goto (ivr-2,s,1)
[2013-07-01 17:57:04] VERBOSE[982] pbx.c:     -- Executing [s@ivr-2:1] Set("SIP/vitel-inbound-00000447", "TIMEOUT_LOOPCOUNT=0") in new stack
[2013-07-01 17:57:04] VERBOSE[982] pbx.c:     -- Executing [s@ivr-2:2] Set("SIP/vitel-inbound-00000447", "INVALID_LOOPCOUNT=0") in new stack
[2013-07-01 17:57:04] VERBOSE[982] pbx.c:     -- Executing [s@ivr-2:3] Set("SIP/vitel-inbound-00000447", "_IVR_CONTEXT_ivr-2=") in new stack
[2013-07-01 17:57:04] VERBOSE[982] pbx.c:     -- Executing [s@ivr-2:4] Set("SIP/vitel-inbound-00000447", "_IVR_CONTEXT=ivr-2") in new stack
[2013-07-01 17:57:04] VERBOSE[982] pbx.c:     -- Executing [s@ivr-2:5] Set("SIP/vitel-inbound-00000447", "__IVR_RETVM=") in new stack
[2013-07-01 17:57:04] VERBOSE[982] pbx.c:     -- Executing [s@ivr-2:6] GotoIf("SIP/vitel-inbound-00000447", "0?skip") in new stack
[2013-07-01 17:57:04] VERBOSE[982] pbx.c:     -- Executing [s@ivr-2:7] Answer("SIP/vitel-inbound-00000447", "") in new stack
[2013-07-01 17:57:04] VERBOSE[982] pbx.c:     -- Executing [s@ivr-2:8] Wait("SIP/vitel-inbound-00000447", "1") in new stack
[2013-07-01 17:57:05] VERBOSE[982] pbx.c:     -- Executing [s@ivr-2:9] Set("SIP/vitel-inbound-00000447", "IVR_MSG=custom/Main_IVR_Recording") in new stack
[2013-07-01 17:57:05] VERBOSE[982] pbx.c:     -- Executing [s@ivr-2:10] Set("SIP/vitel-inbound-00000447", "TIMEOUT(digit)=3") in new stack
[2013-07-01 17:57:05] VERBOSE[982] func_timeout.c:     -- Digit timeout set to 3.000
[2013-07-01 17:57:05] VERBOSE[982] pbx.c:     -- Executing [s@ivr-2:11] ExecIf("SIP/vitel-inbound-00000447", "1?Background(custom/Main_IVR_Recording)") in new stack
[2013-07-01 17:57:05] VERBOSE[982] res_rtp_asterisk.c: Sent RTP packet to      xxxxxxxxxx:16900 (type 00, seq 006867, ts 000160, len 000160)
[2013-07-01 17:57:06] VERBOSE[982] file.c:     -- <SIP/vitel-inbound-00000447> Playing 'custom/Main_IVR_Recording.slin' (language 'en')
[2013-07-01 17:57:06] VERBOSE[982] res_rtp_asterisk.c: Sent RTP packet to      xxxxxxxxxx:16900 (type 00, seq 006868, ts 000320, len 000160) 

Open in new window


Logs from a call forwarded to the number (doesn't work)

[2013-07-01 17:59:17] VERBOSE[5516] netsock2.c:   == Using SIP RTP TOS bits 184
[2013-07-01 17:59:17] VERBOSE[5516] netsock2.c:   == Using SIP RTP CoS mark 5
[2013-07-01 17:59:17] VERBOSE[983] pbx.c:     -- Executing [xxxxxxxxxx@from-trunk:1] Set("SIP/vitel-inbound-00000448", "__FROM_DID=xxxxxxxxxx") in new stack
[2013-07-01 17:59:17] VERBOSE[983] pbx.c:     -- Executing [xxxxxxxxxx@from-trunk:2] Gosub("SIP/vitel-inbound-00000448", "app-blacklist-check,s,1()") in new stack
[2013-07-01 17:59:17] VERBOSE[983] pbx.c:     -- Executing [s@app-blacklist-check:1] GotoIf("SIP/vitel-inbound-00000448", "0?blacklisted") in new stack
[2013-07-01 17:59:17] VERBOSE[983] pbx.c:     -- Executing [s@app-blacklist-check:2] Set("SIP/vitel-inbound-00000448", "CALLED_BLACKLIST=1") in new stack
[2013-07-01 17:59:17] VERBOSE[983] pbx.c:     -- Executing [s@app-blacklist-check:3] Return("SIP/vitel-inbound-00000448", "") in new stack
[2013-07-01 17:59:17] VERBOSE[983] pbx.c:     -- Executing [xxxxxxxxxx@from-trunk:3] Set("SIP/vitel-inbound-00000448", "CDR(did)=xxxxxxxxxx") in new stack
[2013-07-01 17:59:17] VERBOSE[983] pbx.c:     -- Executing [xxxxxxxxxx@from-trunk:4] ExecIf("SIP/vitel-inbound-00000448", "0 ?Set(CALLERID(name)=7203846501)") in new stack
[2013-07-01 17:59:17] VERBOSE[983] pbx.c:     -- Executing [xxxxxxxxxx@from-trunk:5] Set("SIP/vitel-inbound-00000448", "__CALLINGPRES_SV=allowed_not_screened") in new stack
[2013-07-01 17:59:17] VERBOSE[983] pbx.c:     -- Executing [xxxxxxxxxx@from-trunk:6] Set("SIP/vitel-inbound-00000448", "CALLERPRES()=allowed_not_screened") in new stack
[2013-07-01 17:59:17] VERBOSE[983] pbx.c:     -- Executing [xxxxxxxxxx@from-trunk:7] Goto("SIP/vitel-inbound-00000448", "ivr-2,s,1") in new stack
[2013-07-01 17:59:17] VERBOSE[983] pbx.c:     -- Goto (ivr-2,s,1)
[2013-07-01 17:59:17] VERBOSE[983] pbx.c:     -- Executing [s@ivr-2:1] Set("SIP/vitel-inbound-00000448", "TIMEOUT_LOOPCOUNT=0") in new stack
[2013-07-01 17:59:17] VERBOSE[983] pbx.c:     -- Executing [s@ivr-2:2] Set("SIP/vitel-inbound-00000448", "INVALID_LOOPCOUNT=0") in new stack
[2013-07-01 17:59:17] VERBOSE[983] pbx.c:     -- Executing [s@ivr-2:3] Set("SIP/vitel-inbound-00000448", "_IVR_CONTEXT_ivr-2=") in new stack
[2013-07-01 17:59:17] VERBOSE[983] pbx.c:     -- Executing [s@ivr-2:4] Set("SIP/vitel-inbound-00000448", "_IVR_CONTEXT=ivr-2") in new stack
[2013-07-01 17:59:17] VERBOSE[983] pbx.c:     -- Executing [s@ivr-2:5] Set("SIP/vitel-inbound-00000448", "__IVR_RETVM=") in new stack
[2013-07-01 17:59:17] VERBOSE[983] pbx.c:     -- Executing [s@ivr-2:6] GotoIf("SIP/vitel-inbound-00000448", "0?skip") in new stack
[2013-07-01 17:59:17] VERBOSE[983] pbx.c:     -- Executing [s@ivr-2:7] Answer("SIP/vitel-inbound-00000448", "") in new stack
[2013-07-01 17:59:17] VERBOSE[983] pbx.c:     -- Executing [s@ivr-2:8] Wait("SIP/vitel-inbound-00000448", "1") in new stack
[2013-07-01 17:59:17] VERBOSE[983] pbx.c:   == Spawn extension (ivr-2, s, 8) exited non-zero on 'SIP/vitel-inbound-00000448'
[2013-07-01 17:59:17] VERBOSE[983] pbx.c:     -- Executing [h@ivr-2:1] Hangup("SIP/vitel-inbound-00000448", "") in new stack
[2013-07-01 17:59:17] VERBOSE[983] pbx.c:   == Spawn extension (ivr-2, h, 1) exited non-zero on 'SIP/vitel-inbound-00000448'

 

Open in new window

Avatar of Phonebuff
Phonebuff
Flag of United States of America image

??? Forwarded to your box --  

Please explain what it is you are attempting to do  --
Avatar of bevege

ASKER

I want my freepbx server to answer calls that are forwarded to it.

My answering service takes my calls until 5. After that they forward the calls to my PBX but it doesn't work. Neither does forwarding calls from my cell phone our Google voice. If i call the number that I'm forwarding to on my pbx directly it works fine.
Try moving your Verbosity level up and see why in Line 22 you exited the IVR on a Non-Zero return code.  

core set verbose 30
--------------------------
Avatar of bevege

ASKER

Ok, I'll do it in a few minutes.  I also forgot to mention that the DID I'm forwaring the numbers to on my Freepbx box is provided by vitelity. Not sure if that matters but might help. I called them and they weren't much help.
Avatar of bevege

ASKER

OK, here's a log with verbose 30. A couple things. I removed my IP's and phone numbers. I know this makes it harder but I don't like putting more than necessary on the net. I also removed a bunch of the RTP traffic. Anywhere you see "last two lines repeat a long time. removed to make shorter" the lines just repeated. This took the log from over 1500 lines to less than 500.

To be clear, I called my google voice number from my office phone. My google voice is set to ring on my Freepbx via the vitelity_DID. You can see in the logs that the call is being sent to FreePBX but it just hangs up at line 374. The exact same thing happens when my answering service forwards my calls to the vitelity_DID number. I can't test that until after 5 as they answer the phone until then. Again, if I call the vitelity_DID number directly it work just fine.

Vitelity_DID = the number that I'm forwarding calls to on my PBX.This number works fine when dialed directly but not when forwarded to.

my_firewall_IP = External address of my firewall (pfsense) in front of the freepbx box at our datacenter using a static public IP.

number_I_called_from = the phone I made the test call from

Thank you for your help.

<--- SIP read from UDP:66.241.99.28:5060 --->
INVITE sip:Vitelity_DID@my_firewall_IP:52967 SIP/2.0
Via: SIP/2.0/UDP 66.241.99.28:5060;branch=z9hG4bK6c214dd8;rport
From: "number_I_called_from" <sip:number_I_called_from@66.241.99.28>;tag=as52bc8ae1
To: <sip:Vitelity_DID@my_firewall_IP:52967>
Contact: <sip:number_I_called_from@66.241.99.28>
Call-ID: 3d14bdfe5e364f0c24485557204d636b@66.241.99.28
CSeq: 102 INVITE
User-Agent: packetrino
Max-Forwards: 70
Date: Wed, 03 Jul 2013 16:51:26 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces
Content-Type: application/sdp
Content-Length: 334

v=0
o=root 10114 10114 IN IP4 66.241.99.28
s=session
c=IN IP4 66.241.99.28
t=0 0
m=audio 18938 RTP/AVP 0 8 3 18 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:3 GSM/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv
<------------->
--- (14 headers 16 lines) ---
Sending to 66.241.99.28:5060 (NAT)
Using INVITE request as basis request - 3d14bdfe5e364f0c24485557204d636b@66.241.99.28
Found peer 'vitel-inbound' for 'number_I_called_from' from 66.241.99.28:5060
  == Using SIP RTP TOS bits 184
  == Using SIP RTP CoS mark 5
Found RTP audio format 0
Found RTP audio format 8
Found RTP audio format 3
Found RTP audio format 18
Found RTP audio format 101
Found audio description format PCMU for ID 0
Found audio description format PCMA for ID 8
Found audio description format GSM for ID 3
Found audio description format G729 for ID 18
Found audio description format telephone-event for ID 101
Capabilities: us - 0x4 (ulaw), peer - audio=0x10e (gsm|ulaw|alaw|g729)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0x4 (ulaw)
Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|)
Peer audio RTP is at port 66.241.99.28:18938
Looking for Vitelity_DID in from-trunk (domain my_firewall_IP)
list_route: hop: <sip:number_I_called_from@66.241.99.28>

<--- Transmitting (NAT) to 66.241.99.28:5060 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 66.241.99.28:5060;branch=z9hG4bK6c214dd8;received=66.241.99.28;rport=5060
From: "number_I_called_from" <sip:number_I_called_from@66.241.99.28>;tag=as52bc8ae1
To: <sip:Vitelity_DID@my_firewall_IP:52967>
Call-ID: 3d14bdfe5e364f0c24485557204d636b@66.241.99.28
CSeq: 102 INVITE
Server: FPBX-2.10.0(1.8.20.1)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: <sip:Vitelity_DID@my_firewall_IP:5060>
Content-Length: 0


<------------>
    -- Executing [Vitelity_DID@from-trunk:1] Set("SIP/vitel-inbound-0000045e", "__FROM_DID=Vitelity_DID") in new stack
    -- Executing [Vitelity_DID@from-trunk:2] Gosub("SIP/vitel-inbound-0000045e", "app-blacklist-check,s,1()") in new stack
    -- Executing [s@app-blacklist-check:1] GotoIf("SIP/vitel-inbound-0000045e", "0?blacklisted") in new stack
    -- Executing [s@app-blacklist-check:2] Set("SIP/vitel-inbound-0000045e", "CALLED_BLACKLIST=1") in new stack
    -- Executing [s@app-blacklist-check:3] Return("SIP/vitel-inbound-0000045e", "") in new stack
    -- Executing [Vitelity_DID@from-trunk:3] Set("SIP/vitel-inbound-0000045e", "CDR(did)=Vitelity_DID") in new stack
    -- Executing [Vitelity_DID@from-trunk:4] ExecIf("SIP/vitel-inbound-0000045e", "0 ?Set(CALLERID(name)=number_I_called_from)") in new stack
    -- Executing [Vitelity_DID@from-trunk:5] Set("SIP/vitel-inbound-0000045e", "__CALLINGPRES_SV=allowed_not_screened") in new stack
    -- Executing [Vitelity_DID@from-trunk:6] Set("SIP/vitel-inbound-0000045e", "CALLERPRES()=allowed_not_screened") in new stack
    -- Executing [Vitelity_DID@from-trunk:7] Goto("SIP/vitel-inbound-0000045e", "ivr-2,s,1") in new stack
    -- Goto (ivr-2,s,1)
    -- Executing [s@ivr-2:1] Set("SIP/vitel-inbound-0000045e", "TIMEOUT_LOOPCOUNT=0") in new stack
    -- Executing [s@ivr-2:2] Set("SIP/vitel-inbound-0000045e", "INVALID_LOOPCOUNT=0") in new stack
    -- Executing [s@ivr-2:3] Set("SIP/vitel-inbound-0000045e", "_IVR_CONTEXT_ivr-2=") in new stack
    -- Executing [s@ivr-2:4] Set("SIP/vitel-inbound-0000045e", "_IVR_CONTEXT=ivr-2") in new stack
    -- Executing [s@ivr-2:5] Set("SIP/vitel-inbound-0000045e", "__IVR_RETVM=") in new stack
    -- Executing [s@ivr-2:6] GotoIf("SIP/vitel-inbound-0000045e", "0?skip") in new stack
    -- Executing [s@ivr-2:7] Answer("SIP/vitel-inbound-0000045e", "") in new stack
Audio is at 17782
Adding codec 0x4 (ulaw) to SDP
Adding non-codec 0x1 (telephone-event) to SDP

<--- Reliably Transmitting (NAT) to 66.241.99.28:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 66.241.99.28:5060;branch=z9hG4bK6c214dd8;received=66.241.99.28;rport=5060
From: "number_I_called_from" <sip:number_I_called_from@66.241.99.28>;tag=as52bc8ae1
To: <sip:Vitelity_DID@my_firewall_IP:52967>;tag=as247edccd
Call-ID: 3d14bdfe5e364f0c24485557204d636b@66.241.99.28
CSeq: 102 INVITE
Server: FPBX-2.10.0(1.8.20.1)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: <sip:Vitelity_DID@my_firewall_IP:5060>
Content-Type: application/sdp
Content-Length: 262

v=0
o=root 164424957 164424957 IN IP4 my_firewall_IP
s=Asterisk PBX 1.8.20.1
c=IN IP4 my_firewall_IP
t=0 0
m=audio 17782 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv

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

<--- SIP read from UDP:66.241.99.28:5060 --->
ACK sip:Vitelity_DID@my_firewall_IP:5060 SIP/2.0
Via: SIP/2.0/UDP 66.241.99.28:5060;branch=z9hG4bK6cb06d43;rport
From: "number_I_called_from" <sip:number_I_called_from@66.241.99.28>;tag=as52bc8ae1
To: <sip:Vitelity_DID@my_firewall_IP:52967>;tag=as247edccd
Contact: <sip:number_I_called_from@66.241.99.28>
Call-ID: 3d14bdfe5e364f0c24485557204d636b@66.241.99.28
CSeq: 102 ACK
User-Agent: packetrino
Max-Forwards: 70
Content-Length: 0

<------------->
--- (10 headers 0 lines) ---
    -- Executing [s@ivr-2:8] Wait("SIP/vitel-inbound-0000045e", "1") in new stack
    -- Executing [s@ivr-2:9] Set("SIP/vitel-inbound-0000045e", "IVR_MSG=custom/Main_IVR_Recording") in new stack
    -- Executing [s@ivr-2:10] Set("SIP/vitel-inbound-0000045e", "TIMEOUT(digit)=3") in new stack
    -- Digit timeout set to 3.000
    -- Executing [s@ivr-2:11] ExecIf("SIP/vitel-inbound-0000045e", "1?Background(custom/Main_IVR_Recording)") in new stack
Sent RTP packet to      66.241.99.28:18938 (type 00, seq 003266, ts 000160, len 000160)
    -- <SIP/vitel-inbound-0000045e> Playing 'custom/Main_IVR_Recording.slin' (language 'en')
Sent RTP packet to      66.241.99.28:18938 (type 00, seq 003267, ts 000320, len 000160)
Got  RTP packet from    66.241.99.28:18938 (type 00, seq 000065, ts 162742440, len 000160)
last two lines repeat a long time. removed to make shorter

<--- SIP read from UDP:192.168.100.189:5060 --->
NOTIFY sip:10.1.1.20 SIP/2.0
Via: SIP/2.0/UDP 192.168.100.189:5060;branch=z9hG4bK-70f3cb25
From: "xxxxxxx" <sip:2001@10.1.1.20>;tag=aa011a37c0c48e9co0
To: <sip:10.1.1.20>
Call-ID: 29272533-2caf9fd0@192.168.100.189
CSeq: 131053 NOTIFY
Max-Forwards: 70
Contact: "xxxxxxx" <sip:2001@192.168.100.189:5060>
Event: keep-alive
User-Agent: Cisco/SPA504G-7.1.3a
Content-Length: 0

<------------->
--- (11 headers 0 lines) ---

<--- Transmitting (NAT) to 192.168.100.189:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.100.189:5060;branch=z9hG4bK-70f3cb25;received=192.168.100.189;rport=5060
From: "xxxxxxx" <sip:2001@10.1.1.20>;tag=aa011a37c0c48e9co0
To: <sip:10.1.1.20>;tag=as6e514327
Call-ID: 29272533-2caf9fd0@192.168.100.189
CSeq: 131053 NOTIFY
Server: FPBX-2.10.0(1.8.20.1)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0


<------------>
Scheduling destruction of SIP dialog '29272533-2caf9fd0@192.168.100.189' in 32000 ms (Method: NOTIFY)
Sent RTP packet to      66.241.99.28:18938 (type 00, seq 003415, ts 024000, len 000160)
Got  RTP packet from    66.241.99.28:18938 (type 00, seq 000213, ts 162766120, len 000160)

last two lines repeat a long time. removed to make shorter

Reliably Transmitting (NAT) to 192.168.100.189:5060:
OPTIONS sip:2001@192.168.100.189:5060 SIP/2.0
Via: SIP/2.0/UDP 10.1.1.20:5060;branch=z9hG4bK073746aa;rport
Max-Forwards: 70
From: "Unknown" <sip:Unknown@10.1.1.20>;tag=as475e6d1d
To: <sip:2001@192.168.100.189:5060>
Contact: <sip:Unknown@10.1.1.20:5060>
Call-ID: 75105f4149fc833e523ffec421df3e69@10.1.1.20:5060
CSeq: 102 OPTIONS
User-Agent: FPBX-2.10.0(1.8.20.1)
Date: Wed, 03 Jul 2013 16:51:31 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0


---
Got  RTP packet from    66.241.99.28:18938 (type 00, seq 000221, ts 162767400, len 000160)
Sent RTP packet to      66.241.99.28:18938 (type 00, seq 003424, ts 025440, len 000160)

last two lines repeat a long time. removed to make shorter

<--- SIP read from UDP:192.168.100.189:5060 --->
SIP/2.0 200 OK
To: <sip:2001@192.168.100.189:5060>;tag=e6a79a9359faa9f0i0
From: "Unknown" <sip:Unknown@10.1.1.20>;tag=as475e6d1d
Call-ID: 75105f4149fc833e523ffec421df3e69@10.1.1.20:5060
CSeq: 102 OPTIONS
Via: SIP/2.0/UDP 10.1.1.20:5060;branch=z9hG4bK073746aa
Server: Cisco/SPA504G-7.1.3a
Content-Length: 0
Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER
Supported: replaces

<------------->
--- (10 headers 0 lines) ---
Really destroying SIP dialog '75105f4149fc833e523ffec421df3e69@10.1.1.20:5060' Method: OPTIONS
Got  RTP packet from    66.241.99.28:18938 (type 00, seq 000225, ts 162768040, len 000160)
Sent RTP packet to      66.241.99.28:18938 (type 00, seq 003428, ts 026080, len 000160)

last two lines repeat a long time. removed to make shorter

* Sent RTCP SR to 66.241.99.28:18939
  Our SSRC: 1627841618
  Sent(NTP): 1372870293.1637236736
  Sent(RTP): 40000
  Sent packets: 250
  Sent octets: 40000
  Report block:
  Fraction lost: 0
  Cumulative loss: 0
  IA jitter: 0.0003
  Their last SR: 0
  DLSR: 22165.3990 (sec)

Sent RTP packet to      66.241.99.28:18938 (type 00, seq 003516, ts 040160, len 000160)
Got  RTP packet from    66.241.99.28:18938 (type 00, seq 000314, ts 162782280, len 000160)

last two lines repeat a long time. removed to make shorter

* Sent RTCP SR to 66.241.99.28:18939
  Our SSRC: 1627841618
  Sent(NTP): 1372870298.1639473152
  Sent(RTP): 80160
  Sent packets: 501
  Sent octets: 80160
  Report block:
  Fraction lost: 0
  Cumulative loss: 0
  IA jitter: 0.0002
  Their last SR: 0
  DLSR: 22170.4000 (sec)

Got  RTP packet from    66.241.99.28:18938 (type 00, seq 000564, ts 162822280, len 000160)
Sent RTP packet to      66.241.99.28:18938 (type 00, seq 003767, ts 080320, len 000160)

last two lines repeat a long time. removed to make shorter

       > doing dnsmgr_lookup for 'inbound29.vitelity.net'
REGISTER 11 headers, 0 lines
Reliably Transmitting (NAT) to 66.241.99.28:5060:
REGISTER sip:inbound29.vitelity.net SIP/2.0
Via: SIP/2.0/UDP my_firewall_IP:5060;branch=z9hG4bK7e312c7e;rport
Max-Forwards: 70
From: <sip:xxxxxxx@inbound29.vitelity.net>;tag=as72a4b494
To: <sip:xxxxxxx@inbound29.vitelity.net>
Call-ID: 1dc1721a58d6f8ea698d9ed4744479e2@10.1.1.20
CSeq: 3896 REGISTER
User-Agent: FPBX-2.10.0(1.8.20.1)
Authorization: Digest username="xxxxxxx", realm="asterisk", algorithm=MD5, uri="sip:inbound29.vitelity.net", nonce="014baed9", response="c19a0aad1ce3ed8ea911ea23b31fc874"
Expires: 120
Contact: <sip:s@my_firewall_IP:5060>
Content-Length: 0


---
Sent RTP packet to      66.241.99.28:18938 (type 00, seq 003807, ts 086720, len 000160)
Got  RTP packet from    66.241.99.28:18938 (type 00, seq 000605, ts 162828840, len 000160)
Sent RTP packet to      66.241.99.28:18938 (type 00, seq 003808, ts 086880, len 000160)

<--- SIP read from UDP:66.241.99.28:5060 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP my_firewall_IP:5060;branch=z9hG4bK7e312c7e;received=my_firewall_IP;rport=52967
From: <sip:xxxxxxx@inbound29.vitelity.net>;tag=as72a4b494
To: <sip:xxxxxxx@inbound29.vitelity.net>
Call-ID: 1dc1721a58d6f8ea698d9ed4744479e2@10.1.1.20
CSeq: 3896 REGISTER
User-Agent: packetrino
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces
Content-Length: 0

<------------->
--- (10 headers 0 lines) ---

<--- SIP read from UDP:66.241.99.28:5060 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP my_firewall_IP:5060;branch=z9hG4bK7e312c7e;received=my_firewall_IP;rport=52967
From: <sip:xxxxxxx@inbound29.vitelity.net>;tag=as72a4b494
To: <sip:xxxxxxx@inbound29.vitelity.net>;tag=as5c39ce5f
Call-ID: 1dc1721a58d6f8ea698d9ed4744479e2@10.1.1.20
CSeq: 3896 REGISTER
User-Agent: packetrino
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces
WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="028739f2"
Content-Length: 0

<------------->
--- (11 headers 0 lines) ---
Responding to challenge, registration to domain/host name inbound29.vitelity.net
       > doing dnsmgr_lookup for 'inbound29.vitelity.net'
REGISTER 11 headers, 0 lines
Reliably Transmitting (NAT) to 66.241.99.28:5060:
REGISTER sip:inbound29.vitelity.net SIP/2.0
Via: SIP/2.0/UDP my_firewall_IP:5060;branch=z9hG4bK6ca24d9f;rport
Max-Forwards: 70
From: <sip:xxxxxxx@inbound29.vitelity.net>;tag=as775b8495
To: <sip:xxxxxxx@inbound29.vitelity.net>
Call-ID: 1dc1721a58d6f8ea698d9ed4744479e2@10.1.1.20
CSeq: 3897 REGISTER
User-Agent: FPBX-2.10.0(1.8.20.1)
Authorization: Digest username="xxxxxxx", realm="asterisk", algorithm=MD5, uri="sip:inbound29.vitelity.net", nonce="028739f2", response="d27f4055d940ade040638bfb9ccf9dbb"
Expires: 120
Contact: <sip:s@my_firewall_IP:5060>
Content-Length: 0


---
Got  RTP packet from    66.241.99.28:18938 (type 00, seq 000606, ts 162829000, len 000160)
Sent RTP packet to      66.241.99.28:18938 (type 00, seq 003809, ts 087040, len 000160)

<--- SIP read from UDP:66.241.99.28:5060 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP my_firewall_IP:5060;branch=z9hG4bK6ca24d9f;received=my_firewall_IP;rport=52967
From: <sip:xxxxxxx@inbound29.vitelity.net>;tag=as775b8495
To: <sip:xxxxxxx@inbound29.vitelity.net>
Call-ID: 1dc1721a58d6f8ea698d9ed4744479e2@10.1.1.20
CSeq: 3897 REGISTER
User-Agent: packetrino
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces
Content-Length: 0

<------------->
--- (10 headers 0 lines) ---
Got  RTP packet from    66.241.99.28:18938 (type 00, seq 000607, ts 162829160, len 000160)

<--- SIP read from UDP:66.241.99.28:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP my_firewall_IP:5060;branch=z9hG4bK6ca24d9f;received=my_firewall_IP;rport=52967
From: <sip:xxxxxxx@inbound29.vitelity.net>;tag=as775b8495
To: <sip:xxxxxxx@inbound29.vitelity.net>;tag=as5c39ce5f
Call-ID: 1dc1721a58d6f8ea698d9ed4744479e2@10.1.1.20
CSeq: 3897 REGISTER
User-Agent: packetrino
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO
Supported: replaces
Expires: 60
Contact: <sip:s@my_firewall_IP:5060>;expires=60
Date: Wed, 03 Jul 2013 16:51:38 GMT
Content-Length: 0

<------------->
--- (13 headers 0 lines) ---
Scheduling destruction of SIP dialog '1dc1721a58d6f8ea698d9ed4744479e2@10.1.1.20' in 32000 ms (Method: REGISTER)
Sent RTP packet to      66.241.99.28:18938 (type 00, seq 003810, ts 087200, len 000160)
Got  RTP packet from    66.241.99.28:18938 (type 00, seq 000608, ts 162829320, len 000160)

last two lines repeat a long time. removed to make shorter

<--- SIP read from UDP:66.241.99.28:5060 --->
BYE sip:Vitelity_DID@my_firewall_IP:5060 SIP/2.0
Via: SIP/2.0/UDP 66.241.99.28:5060;branch=z9hG4bK20235870;rport
From: "number_I_called_from" <sip:number_I_called_from@66.241.99.28>;tag=as52bc8ae1
To: <sip:Vitelity_DID@my_firewall_IP:52967>;tag=as247edccd
Call-ID: 3d14bdfe5e364f0c24485557204d636b@66.241.99.28
CSeq: 103 BYE
User-Agent: packetrino
Max-Forwards: 70
X-Asterisk-HangupCause: Normal Clearing
X-Asterisk-HangupCauseCode: 16
Content-Length: 0

<------------->
--- (11 headers 0 lines) ---
Sending to 66.241.99.28:5060 (NAT)
Scheduling destruction of SIP dialog '3d14bdfe5e364f0c24485557204d636b@66.241.99.28' in 32000 ms (Method: BYE)

<--- Transmitting (NAT) to 66.241.99.28:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 66.241.99.28:5060;branch=z9hG4bK20235870;received=66.241.99.28;rport=5060
From: "number_I_called_from" <sip:number_I_called_from@66.241.99.28>;tag=as52bc8ae1
To: <sip:Vitelity_DID@my_firewall_IP:52967>;tag=as247edccd
Call-ID: 3d14bdfe5e364f0c24485557204d636b@66.241.99.28
CSeq: 103 BYE
Server: FPBX-2.10.0(1.8.20.1)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0


<------------>
  == Spawn extension (ivr-2, s, 11) exited non-zero on 'SIP/vitel-inbound-0000045e'
    -- Executing [h@ivr-2:1] Hangup("SIP/vitel-inbound-0000045e", "") in new stack
  == Spawn extension (ivr-2, h, 1) exited non-zero on 'SIP/vitel-inbound-0000045e'

<--- SIP read from UDP:192.168.100.189:5060 --->
NOTIFY sip:10.1.1.20 SIP/2.0
Via: SIP/2.0/UDP 192.168.100.189:5060;branch=z9hG4bK-c43f9f9b
From: "xxxxxxx" <sip:2001@10.1.1.20>;tag=aa011a37c0c48e9co0
To: <sip:10.1.1.20>
Call-ID: 29272533-2caf9fd0@192.168.100.189
CSeq: 131054 NOTIFY
Max-Forwards: 70
Contact: "xxxxxxx" <sip:2001@192.168.100.189:5060>
Event: keep-alive
User-Agent: Cisco/SPA504G-7.1.3a
Content-Length: 0

<------------->
--- (11 headers 0 lines) ---

<--- Transmitting (NAT) to 192.168.100.189:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.100.189:5060;branch=z9hG4bK-c43f9f9b;received=192.168.100.189;rport=5060
From: "xxxxxxx" <sip:2001@10.1.1.20>;tag=aa011a37c0c48e9co0
To: <sip:10.1.1.20>;tag=as6e514327
Call-ID: 29272533-2caf9fd0@192.168.100.189
CSeq: 131054 NOTIFY
Server: FPBX-2.10.0(1.8.20.1)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0


<------------>
Scheduling destruction of SIP dialog '29272533-2caf9fd0@192.168.100.189' in 32000 ms (Method: NOTIFY)

Open in new window

Avatar of bevege

ASKER

I'm learning how to read the logs but want to make sure I have it right in my head. I'm trying to figure out where the bye is being sent. From Vitelity or from the number being called from.

Line 374: Does "Read From" mean my PBX is reading the information sent from vitelity (66.241.99.28)?  
Line 375: is this the information being sent from vitelity which is a BYE
Line 376: does VIA mean how it's being transmitted accross the wire, ie udp
Line 377: does from mean where the info in line 375 is coming from or where the call is coming from
Line 378 - 385: makes sense to me, it's to my did on my freepbx and then what my freepbx box does with the information, which is hang up the call.

If so that means that vitelity is actually the one who  is hanging up the call correct?
SOLUTION
Avatar of Phonebuff
Phonebuff
Flag of United States of America image

Link to home
membership
This solution is only available to members.
To access this solution, you must be a member of Experts Exchange.
Start Free Trial
Avatar of bevege

ASKER

I am not sure. It's from google voice. I've read lots of posts from people saying their google voice works fine on freepbx.

Maybe there is a setting on google voice I can change. It's like google voice doesn't see it when Freepbx picks up the call. Right now I have it going to a IVR but I tried everything with the same result, direct to extension, directory etc. Same result.
Avatar of bevege

ASKER

Since calls directly to my DID seem to work just fine, maybe I can do this another way. Is there a way to set call routing using a schedule in Freepbx? So instead of having calls go directly to my Answering service I can have the calls go to my Freepbx box directly during the day but forward the calls to my answering service. After 5 I can then have my freepbx box answer the calls. At 7:00am forward the calls back to the answering service.  

Basically reversing the way I'm doing it now. My main goal is to have live people answering the calls during the day.
Well,

     I do not have a Google Voice Line ringing to my Asterisk box --  Just my Cell .

     But doesn't GV have some feature / option to screen the call and require a DTMF input to say that you excepted the call.  Be sure that's not turned on in your GV account.  Also, check that your Asterisk box is the only # being called, if someone / something else picks up then you would see the disconnect.  

     ===================
SOLUTION
Link to home
membership
This solution is only available to members.
To access this solution, you must be a member of Experts Exchange.
Start Free Trial
ASKER CERTIFIED SOLUTION
Link to home
membership
This solution is only available to members.
To access this solution, you must be a member of Experts Exchange.
Start Free Trial
Do you mean that all calls that come in to my Freepbx via the main DID I want to use will stay connected through the PBX until the call is hung up even though it is forwarded to another number?

YES !   Unless you have an advanced service called "Take Back and Transfer" ---  

Remember to factor Holidays in unless you do that manually --

New Years -- Jan 1st --  
MLK Day - 3RD Monday Jan. Monday - Jan 15/21
Washington's Birthday 3rd Monday Feb  15/21
Memorial Day - Last Monday - May  Monday 25/31
Independance Day - July 4th -  
Labor Day - 1st Monday September Monday - 1/7
Columbus Day - 2nd Monday in October  Monday 8/14
Veterns Day - Nov 11th - Nov 11th
ThanksGiving - 4th Thursday Nov.
Xmas - Dec 25th --

-------------------------------------------------------------------------------------
Avatar of bevege

ASKER

I eventually removed google from the picture and it all works perfectly now. Thank you all for your help.