No audio on inbound calls

General Help
1

FreePBX server [v:13.0.191.11] sits behind a firewall.
A public,static IP address [123.123.123.123] has been forwarded to the internal address of the server without NAT at the firewall.
All TCP and UDP ports are forwarded from the WAN interface of the static IP to the internal IP of the FreePBX server.
The external address in SIP settings is set to the public,static IP address that is being forwarded to the server.
The local networks are set to the subnet of the local networks - there are two (one is used by VPN exclusivly).
NAT on Chan SIP Settings is set to Yes
I have a Twilio SIP trunk and an inbound route pointed to an IVR.
When I call the inbound number, I cannot hear the message and the call is dropped after a little over 30 seconds.

I know this is some sort of NAT issues or external/internal address issue. I have checked the firewall and everything inbound is open on both TCP and UDP. I can’t see it. I am hoping another set of more experianced eyes can see what I am missing. Let me know if you need additional info. I tried to supply everything I could.

<--- Reliably Transmitting (NAT) to 54.172.60.3:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 54.172.60.3:5060;branch=z9hG4bK46a8.010b9755.0;received=54.172.60.3;rport=5060
Via: SIP/2.0/UDP 172.18.17.158:5060;rport=5060;received=172.18.17.158;branch=z9hG4bKd237926c-77af-4f1a-aa24-70439e93be0b_6772d868_245-1465169140678352228
Record-Route: <sip:54.172.60.3:5060;lr;ftag=81723374_6772d868_d237926c-77af-4f1a-aa24-70439e93be0b>
From: <sip:[email protected];isup-oli=61;pstn-params=808481808882>;tag=81723374_6772d868_d237926c-77af-4f1a-aa24-70439e93be0b
To: <sip:[email protected];user=phone>;tag=as33a30bf4
Call-ID: [email protected]
CSeq: 905299 INVITE
Server: FPBX-13.0.191.11(13.14.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:[email protected]:5060>
Content-Type: application/sdp
Content-Length: 252

v=0
o=root 290295314 290295314 IN IP4 123.123.123.123
s=Asterisk PBX 13.14.0
c=IN IP4 123.123.123.123
t=0 0
m=audio 15054 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=maxptime:150
a=sendrecv

<------------>
[2017-05-24 16:23:25] VERBOSE[1799] chan_sip.c: Retransmitting #1 (NAT) to 54.172.60.3:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 54.172.60.3:5060;branch=z9hG4bK46a8.010b9755.0;received=54.172.60.3;rport=5060
Via: SIP/2.0/UDP 172.18.17.158:5060;rport=5060;received=172.18.17.158;branch=z9hG4bKd237926c-77af-4f1a-aa24-70439e93be0b_6772d868_245-1465169140678352228
Record-Route: <sip:54.172.60.3:5060;lr;ftag=81723374_6772d868_d237926c-77af-4f1a-aa24-70439e93be0b>
From: <sip:[email protected];isup-oli=61;pstn-params=808481808882>;tag=81723374_6772d868_d237926c-77af-4f1a-aa24-70439e93be0b
To: <sip:[email protected];user=phone>;tag=as33a30bf4
Call-ID: [email protected]
CSeq: 905299 INVITE
Server: FPBX-13.0.191.11(13.14.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:[email protected]:5060>
Content-Type: application/sdp
Content-Length: 252

v=0
o=root 290295314 290295314 IN IP4 123.123.123.123
s=Asterisk PBX 13.14.0
c=IN IP4 123.123.123.123
t=0 0
m=audio 15054 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=maxptime:150
a=sendrecv

---
[2017-05-24 16:23:25] VERBOSE[17591][C-00000014] pbx.c: Executing [s@ivr-1:8] Wait("SIP/Twilio_Inbound_Trunk_3-0000001b", "1") in new stack
[2017-05-24 16:23:26] VERBOSE[1799] chan_sip.c: Retransmitting #2 (NAT) to 54.172.60.3:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 54.172.60.3:5060;branch=z9hG4bK46a8.010b9755.0;received=54.172.60.3;rport=5060
Via: SIP/2.0/UDP 172.18.17.158:5060;rport=5060;received=172.18.17.158;branch=z9hG4bKd237926c-77af-4f1a-aa24-70439e93be0b_6772d868_245-1465169140678352228
Record-Route: <sip:54.172.60.3:5060;lr;ftag=81723374_6772d868_d237926c-77af-4f1a-aa24-70439e93be0b>
From: <sip:[email protected];isup-oli=61;pstn-params=808481808882>;tag=81723374_6772d868_d237926c-77af-4f1a-aa24-70439e93be0b
To: <sip:[email protected];user=phone>;tag=as33a30bf4
Call-ID: [email protected]
CSeq: 905299 INVITE
Server: FPBX-13.0.191.11(13.14.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:[email protected]:5060>
Content-Type: application/sdp
Content-Length: 252

v=0
o=root 290295314 290295314 IN IP4 123.123.123.123
s=Asterisk PBX 13.14.0
c=IN IP4 123.123.123.123
t=0 0
m=audio 15054 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=maxptime:150
a=sendrecv

---
[2017-05-24 16:23:26] VERBOSE[17591][C-00000014] pbx.c: Executing [s@ivr-1:9] Set("SIP/Twilio_Inbound_Trunk_3-0000001b", "IVR_MSG=custom/test") in new stack
[2017-05-24 16:23:26] VERBOSE[17591][C-00000014] pbx.c: Executing [s@ivr-1:10] Set("SIP/Twilio_Inbound_Trunk_3-0000001b", "TIMEOUT(digit)=3") in new stack
[2017-05-24 16:23:26] VERBOSE[17591][C-00000014] func_timeout.c: Digit timeout set to 3.000
[2017-05-24 16:23:26] VERBOSE[17591][C-00000014] pbx.c: Executing [s@ivr-1:11] ExecIf("SIP/Twilio_Inbound_Trunk_3-0000001b", "1?Background(custom/test)") in new stack
[2017-05-24 16:23:26] VERBOSE[17591][C-00000014] file.c: <SIP/Twilio_Inbound_Trunk_3-0000001b> Playing 'custom/test.slin' (language 'en')
[2017-05-24 16:23:28] VERBOSE[1799] chan_sip.c: Retransmitting #3 (NAT) to 54.172.60.3:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 54.172.60.3:5060;branch=z9hG4bK46a8.010b9755.0;received=54.172.60.3;rport=5060
Via: SIP/2.0/UDP 172.18.17.158:5060;rport=5060;received=172.18.17.158;branch=z9hG4bKd237926c-77af-4f1a-aa24-70439e93be0b_6772d868_245-1465169140678352228
Record-Route: <sip:54.172.60.3:5060;lr;ftag=81723374_6772d868_d237926c-77af-4f1a-aa24-70439e93be0b>
From: <sip:[email protected];isup-oli=61;pstn-params=808481808882>;tag=81723374_6772d868_d237926c-77af-4f1a-aa24-70439e93be0b
To: <sip:[email protected];user=phone>;tag=as33a30bf4
Call-ID: [email protected]
CSeq: 905299 INVITE
Server: FPBX-13.0.191.11(13.14.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:[email protected]:5060>
Content-Type: application/sdp
Content-Length: 252

v=0
o=root 290295314 290295314 IN IP4 123.123.123.123
s=Asterisk PBX 13.14.0
c=IN IP4 123.123.123.123
t=0 0
m=audio 15054 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=maxptime:150
a=sendrecv

---
[2017-05-24 16:23:32] VERBOSE[1799] chan_sip.c: Retransmitting #4 (NAT) to 54.172.60.3:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 54.172.60.3:5060;branch=z9hG4bK46a8.010b9755.0;received=54.172.60.3;rport=5060
Via: SIP/2.0/UDP 172.18.17.158:5060;rport=5060;received=172.18.17.158;branch=z9hG4bKd237926c-77af-4f1a-aa24-70439e93be0b_6772d868_245-1465169140678352228
Record-Route: <sip:54.172.60.3:5060;lr;ftag=81723374_6772d868_d237926c-77af-4f1a-aa24-70439e93be0b>
From: <sip:[email protected];isup-oli=61;pstn-params=808481808882>;tag=81723374_6772d868_d237926c-77af-4f1a-aa24-70439e93be0b
To: <sip:[email protected];user=phone>;tag=as33a30bf4
Call-ID: [email protected]
CSeq: 905299 INVITE
Server: FPBX-13.0.191.11(13.14.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:[email protected]:5060>
Content-Type: application/sdp
Content-Length: 252

v=0
o=root 290295314 290295314 IN IP4 123.123.123.123
s=Asterisk PBX 13.14.0
c=IN IP4 123.123.123.123
t=0 0
m=audio 15054 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=maxptime:150
a=sendrecv

---
[2017-05-24 16:23:33] VERBOSE[17591][C-00000014] pbx.c: Executing [s@ivr-1:12] WaitExten("SIP/Twilio_Inbound_Trunk_3-0000001b", "10,") in new stack
[2017-05-24 16:23:36] VERBOSE[1799] chan_sip.c: Retransmitting #5 (NAT) to 54.172.60.3:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 54.172.60.3:5060;branch=z9hG4bK46a8.010b9755.0;received=54.172.60.3;rport=5060
Via: SIP/2.0/UDP 172.18.17.158:5060;rport=5060;received=172.18.17.158;branch=z9hG4bKd237926c-77af-4f1a-aa24-70439e93be0b_6772d868_245-1465169140678352228
Record-Route: <sip:54.172.60.3:5060;lr;ftag=81723374_6772d868_d237926c-77af-4f1a-aa24-70439e93be0b>
From: <sip:[email protected];isup-oli=61;pstn-params=808481808882>;tag=81723374_6772d868_d237926c-77af-4f1a-aa24-70439e93be0b
To: <sip:[email protected];user=phone>;tag=as33a30bf4
Call-ID: [email protected]
CSeq: 905299 INVITE
Server: FPBX-13.0.191.11(13.14.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:[email protected]:5060>
Content-Type: application/sdp
Content-Length: 252

v=0
o=root 290295314 290295314 IN IP4 123.123.123.123
s=Asterisk PBX 13.14.0
c=IN IP4 123.123.123.123
t=0 0
m=audio 15054 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=maxptime:150
a=sendrecv

---
[2017-05-24 16:23:40] VERBOSE[1799] chan_sip.c: Retransmitting #6 (NAT) to 54.172.60.3:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 54.172.60.3:5060;branch=z9hG4bK46a8.010b9755.0;received=54.172.60.3;rport=5060
Via: SIP/2.0/UDP 172.18.17.158:5060;rport=5060;received=172.18.17.158;branch=z9hG4bKd237926c-77af-4f1a-aa24-70439e93be0b_6772d868_245-1465169140678352228
Record-Route: <sip:54.172.60.3:5060;lr;ftag=81723374_6772d868_d237926c-77af-4f1a-aa24-70439e93be0b>
From: <sip:[email protected];isup-oli=61;pstn-params=808481808882>;tag=81723374_6772d868_d237926c-77af-4f1a-aa24-70439e93be0b
To: <sip:[email protected];user=phone>;tag=as33a30bf4
Call-ID: [email protected]
CSeq: 905299 INVITE
Server: FPBX-13.0.191.11(13.14.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:[email protected]:5060>
Content-Type: application/sdp
Content-Length: 252

v=0
o=root 290295314 290295314 IN IP4 123.123.123.123
s=Asterisk PBX 13.14.0
c=IN IP4 123.123.123.123
t=0 0
m=audio 15054 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=maxptime:150
a=sendrecv

---
[2017-05-24 16:23:43] VERBOSE[17591][C-00000014] pbx_builtins.c: Timeout on SIP/Twilio_Inbound_Trunk_3-0000001b, going to 't'
[2017-05-24 16:23:43] VERBOSE[17591][C-00000014] pbx.c: Executing [t@ivr-1:1] Set("SIP/Twilio_Inbound_Trunk_3-0000001b", "TIMEOUT_LOOPCOUNT=1") in new stack
[2017-05-24 16:23:43] VERBOSE[17591][C-00000014] pbx.c: Executing [t@ivr-1:2] GotoIf("SIP/Twilio_Inbound_Trunk_3-0000001b", "0?final") in new stack
[2017-05-24 16:23:43] VERBOSE[17591][C-00000014] pbx.c: Executing [t@ivr-1:3] Set("SIP/Twilio_Inbound_Trunk_3-0000001b", "IVR_MSG=no-valid-responce-pls-try-again") in new stack
[2017-05-24 16:23:43] VERBOSE[17591][C-00000014] pbx.c: Executing [t@ivr-1:4] Goto("SIP/Twilio_Inbound_Trunk_3-0000001b", "s,start") in new stack
[2017-05-24 16:23:43] VERBOSE[17591][C-00000014] pbx_builtins.c: Goto (ivr-1,s,10)
[2017-05-24 16:23:43] VERBOSE[17591][C-00000014] pbx.c: Executing [s@ivr-1:10] Set("SIP/Twilio_Inbound_Trunk_3-0000001b", "TIMEOUT(digit)=3") in new stack
[2017-05-24 16:23:43] VERBOSE[17591][C-00000014] func_timeout.c: Digit timeout set to 3.000
[2017-05-24 16:23:43] VERBOSE[17591][C-00000014] pbx.c: Executing [s@ivr-1:11] ExecIf("SIP/Twilio_Inbound_Trunk_3-0000001b", "1?Background(no-valid-responce-pls-try-again)") in new stack
[2017-05-24 16:23:43] VERBOSE[17591][C-00000014] file.c: <SIP/Twilio_Inbound_Trunk_3-0000001b> Playing 'no-valid-responce-pls-try-again.slin' (language 'en')
[2017-05-24 16:23:44] VERBOSE[1799] chan_sip.c: Retransmitting #7 (NAT) to 54.172.60.3:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 54.172.60.3:5060;branch=z9hG4bK46a8.010b9755.0;received=54.172.60.3;rport=5060
Via: SIP/2.0/UDP 172.18.17.158:5060;rport=5060;received=172.18.17.158;branch=z9hG4bKd237926c-77af-4f1a-aa24-70439e93be0b_6772d868_245-1465169140678352228
Record-Route: <sip:54.172.60.3:5060;lr;ftag=81723374_6772d868_d237926c-77af-4f1a-aa24-70439e93be0b>
From: <sip:[email protected];isup-oli=61;pstn-params=808481808882>;tag=81723374_6772d868_d237926c-77af-4f1a-aa24-70439e93be0b
To: <sip:[email protected];user=phone>;tag=as33a30bf4
Call-ID: [email protected]
CSeq: 905299 INVITE
Server: FPBX-13.0.191.11(13.14.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:[email protected]:5060>
Content-Type: application/sdp
Content-Length: 252

v=0
o=root 290295314 290295314 IN IP4 123.123.123.123
s=Asterisk PBX 13.14.0
c=IN IP4 123.123.123.123
t=0 0
m=audio 15054 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=maxptime:150
a=sendrecv

---
[2017-05-24 16:23:45] VERBOSE[1799][C-00000015] netsock2.c: Using SIP RTP TOS bits 184
[2017-05-24 16:23:45] VERBOSE[1799][C-00000015] netsock2.c: Using SIP RTP CoS mark 5
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [+14056738457@from-trunk:1] NoOp("SIP/Twilio_Inbound_Trunk_1-0000001c", "Catch-All DID Match - Found +14056738457 - You probably want a DID for this.") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [+14056738457@from-trunk:2] Log("SIP/Twilio_Inbound_Trunk_1-0000001c", "WARNING,Friendly Scanner from 54.172.60.1") in new stack
[2017-05-24 16:23:45] WARNING[17592][C-00000015] Ext. +14056738457: Friendly Scanner from 54.172.60.1
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [+14056738457@from-trunk:3] Set("SIP/Twilio_Inbound_Trunk_1-0000001c", "__FROM_DID=+14056738457") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [+14056738457@from-trunk:4] Goto("SIP/Twilio_Inbound_Trunk_1-0000001c", "ext-did,s,1") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx_builtins.c: Goto (ext-did,s,1)
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [s@ext-did:1] Set("SIP/Twilio_Inbound_Trunk_1-0000001c", "__DIRECTION=INBOUND") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [s@ext-did:2] Gosub("SIP/Twilio_Inbound_Trunk_1-0000001c", "sub-record-check,s,1(in,s,dontcare)") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [s@sub-record-check:1] GotoIf("SIP/Twilio_Inbound_Trunk_1-0000001c", "0?initialized") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [s@sub-record-check:2] Set("SIP/Twilio_Inbound_Trunk_1-0000001c", "__REC_STATUS=INITIALIZED") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [s@sub-record-check:3] Set("SIP/Twilio_Inbound_Trunk_1-0000001c", "NOW=1495661025") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [s@sub-record-check:4] Set("SIP/Twilio_Inbound_Trunk_1-0000001c", "__DAY=24") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [s@sub-record-check:5] Set("SIP/Twilio_Inbound_Trunk_1-0000001c", "__MONTH=05") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [s@sub-record-check:6] Set("SIP/Twilio_Inbound_Trunk_1-0000001c", "__YEAR=2017") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [s@sub-record-check:7] Set("SIP/Twilio_Inbound_Trunk_1-0000001c", "__TIMESTR=20170524-162345") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [s@sub-record-check:8] Set("SIP/Twilio_Inbound_Trunk_1-0000001c", "__FROMEXTEN=unknown") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [s@sub-record-check:9] Set("SIP/Twilio_Inbound_Trunk_1-0000001c", "__MON_FMT=wav") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [s@sub-record-check:10] NoOp("SIP/Twilio_Inbound_Trunk_1-0000001c", "Recordings initialized") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [s@sub-record-check:11] ExecIf("SIP/Twilio_Inbound_Trunk_1-0000001c", "0?Set(ARG3=dontcare)") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [s@sub-record-check:12] Set("SIP/Twilio_Inbound_Trunk_1-0000001c", "REC_POLICY_MODE_SAVE=") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [s@sub-record-check:13] ExecIf("SIP/Twilio_Inbound_Trunk_1-0000001c", "0?Set(REC_STATUS=NO)") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [s@sub-record-check:14] GotoIf("SIP/Twilio_Inbound_Trunk_1-0000001c", "2?checkaction") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx_builtins.c: Goto (sub-record-check,s,17)
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [s@sub-record-check:17] GotoIf("SIP/Twilio_Inbound_Trunk_1-0000001c", "1?sub-record-check,in,1") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx_builtins.c: Goto (sub-record-check,in,1)
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [in@sub-record-check:1] NoOp("SIP/Twilio_Inbound_Trunk_1-0000001c", "Inbound Recording Check to s") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [in@sub-record-check:2] Set("SIP/Twilio_Inbound_Trunk_1-0000001c", "FROMEXTEN=unknown") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [in@sub-record-check:3] ExecIf("SIP/Twilio_Inbound_Trunk_1-0000001c", "12?Set(FROMEXTEN=+14054066291)") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [in@sub-record-check:4] Gosub("SIP/Twilio_Inbound_Trunk_1-0000001c", "recordcheck,1(dontcare,in,s)") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [recordcheck@sub-record-check:1] NoOp("SIP/Twilio_Inbound_Trunk_1-0000001c", "Starting recording check against dontcare") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [recordcheck@sub-record-check:2] Goto("SIP/Twilio_Inbound_Trunk_1-0000001c", "dontcare") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx_builtins.c: Goto (sub-record-check,recordcheck,3)
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [recordcheck@sub-record-check:3] Return("SIP/Twilio_Inbound_Trunk_1-0000001c", "") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [in@sub-record-check:5] Return("SIP/Twilio_Inbound_Trunk_1-0000001c", "") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [s@ext-did:3] Gosub("SIP/Twilio_Inbound_Trunk_1-0000001c", "app-blacklist-check,s,1()") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [s@app-blacklist-check:1] GotoIf("SIP/Twilio_Inbound_Trunk_1-0000001c", "0?blacklisted") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [s@app-blacklist-check:2] Set("SIP/Twilio_Inbound_Trunk_1-0000001c", "CALLED_BLACKLIST=1") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [s@app-blacklist-check:3] Return("SIP/Twilio_Inbound_Trunk_1-0000001c", "") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [s@ext-did:4] ExecIf("SIP/Twilio_Inbound_Trunk_1-0000001c", "0?Set(__FROM_DID=s)") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [s@ext-did:5] Set("SIP/Twilio_Inbound_Trunk_1-0000001c", "CDR(did)=+14056738457") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [s@ext-did:6] ExecIf("SIP/Twilio_Inbound_Trunk_1-0000001c", "1 ?Set(CALLERID(name)=+14054066291)") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [s@ext-did:7] Set("SIP/Twilio_Inbound_Trunk_1-0000001c", "__MOHCLASS=") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [s@ext-did:8] Set("SIP/Twilio_Inbound_Trunk_1-0000001c", "__REVERSAL_REJECT=FALSE") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [s@ext-did:9] GotoIf("SIP/Twilio_Inbound_Trunk_1-0000001c", "1?post-reverse-charge") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx_builtins.c: Goto (ext-did,s,11)
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [s@ext-did:11] NoOp("SIP/Twilio_Inbound_Trunk_1-0000001c", "") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [s@ext-did:12] Set("SIP/Twilio_Inbound_Trunk_1-0000001c", "__CALLINGNAMEPRES_SV=allowed_not_screened") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [s@ext-did:13] Set("SIP/Twilio_Inbound_Trunk_1-0000001c", "__CALLINGNUMPRES_SV=allowed_not_screened") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [s@ext-did:14] Set("SIP/Twilio_Inbound_Trunk_1-0000001c", "CALLERID(name-pres)=allowed_not_screened") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [s@ext-did:15] Set("SIP/Twilio_Inbound_Trunk_1-0000001c", "CALLERID(num-pres)=allowed_not_screened") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [s@ext-did:16] NoOp("SIP/Twilio_Inbound_Trunk_1-0000001c", "CallerID Entry Point") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [s@ext-did:17] Goto("SIP/Twilio_Inbound_Trunk_1-0000001c", "ivr-1,s,1") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx_builtins.c: Goto (ivr-1,s,1)
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [s@ivr-1:1] Set("SIP/Twilio_Inbound_Trunk_1-0000001c", "TIMEOUT_LOOPCOUNT=0") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [s@ivr-1:2] Set("SIP/Twilio_Inbound_Trunk_1-0000001c", "INVALID_LOOPCOUNT=0") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [s@ivr-1:3] Set("SIP/Twilio_Inbound_Trunk_1-0000001c", "_IVR_CONTEXT_ivr-1=") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [s@ivr-1:4] Set("SIP/Twilio_Inbound_Trunk_1-0000001c", "_IVR_CONTEXT=ivr-1") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [s@ivr-1:5] Set("SIP/Twilio_Inbound_Trunk_1-0000001c", "__IVR_RETVM=") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [s@ivr-1:6] GotoIf("SIP/Twilio_Inbound_Trunk_1-0000001c", "0?skip") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [s@ivr-1:7] Answer("SIP/Twilio_Inbound_Trunk_1-0000001c", "") in new stack
[2017-05-24 16:23:45] VERBOSE[17592][C-00000015] pbx.c: Executing [s@ivr-1:8] Wait("SIP/Twilio_Inbound_Trunk_1-0000001c", "1") in new stack
[2017-05-24 16:23:46] VERBOSE[17592][C-00000015] pbx.c: Executing [s@ivr-1:9] Set("SIP/Twilio_Inbound_Trunk_1-0000001c", "IVR_MSG=custom/test") in new stack
[2017-05-24 16:23:46] VERBOSE[17592][C-00000015] pbx.c: Executing [s@ivr-1:10] Set("SIP/Twilio_Inbound_Trunk_1-0000001c", "TIMEOUT(digit)=3") in new stack
[2017-05-24 16:23:46] VERBOSE[17592][C-00000015] func_timeout.c: Digit timeout set to 3.000
[2017-05-24 16:23:46] VERBOSE[17592][C-00000015] pbx.c: Executing [s@ivr-1:11] ExecIf("SIP/Twilio_Inbound_Trunk_1-0000001c", "1?Background(custom/test)") in new stack
[2017-05-24 16:23:46] VERBOSE[17592][C-00000015] file.c: <SIP/Twilio_Inbound_Trunk_1-0000001c> Playing 'custom/test.slin' (language 'en')
[2017-05-24 16:23:47] VERBOSE[17591][C-00000014] pbx.c: Executing [s@ivr-1:12] WaitExten("SIP/Twilio_Inbound_Trunk_3-0000001b", "10,") in new stack
[2017-05-24 16:23:48] VERBOSE[1799] chan_sip.c: Retransmitting #8 (NAT) to 54.172.60.3:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 54.172.60.3:5060;branch=z9hG4bK46a8.010b9755.0;received=54.172.60.3;rport=5060
Via: SIP/2.0/UDP 172.18.17.158:5060;rport=5060;received=172.18.17.158;branch=z9hG4bKd237926c-77af-4f1a-aa24-70439e93be0b_6772d868_245-1465169140678352228
Record-Route: <sip:54.172.60.3:5060;lr;ftag=81723374_6772d868_d237926c-77af-4f1a-aa24-70439e93be0b>
From: <sip:[email protected];isup-oli=61;pstn-params=808481808882>;tag=81723374_6772d868_d237926c-77af-4f1a-aa24-70439e93be0b
To: <sip:[email protected];user=phone>;tag=as33a30bf4
Call-ID: [email protected]
CSeq: 905299 INVITE
Server: FPBX-13.0.191.11(13.14.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:[email protected]:5060>
Content-Type: application/sdp
Content-Length: 252

v=0
o=root 290295314 290295314 IN IP4 123.123.123.123
s=Asterisk PBX 13.14.0
c=IN IP4 123.123.123.123
t=0 0
m=audio 15054 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=maxptime:150
a=sendrecv

---
[2017-05-24 16:23:52] VERBOSE[1799] chan_sip.c: Retransmitting #9 (NAT) to 54.172.60.3:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 54.172.60.3:5060;branch=z9hG4bK46a8.010b9755.0;received=54.172.60.3;rport=5060
Via: SIP/2.0/UDP 172.18.17.158:5060;rport=5060;received=172.18.17.158;branch=z9hG4bKd237926c-77af-4f1a-aa24-70439e93be0b_6772d868_245-1465169140678352228
Record-Route: <sip:54.172.60.3:5060;lr;ftag=81723374_6772d868_d237926c-77af-4f1a-aa24-70439e93be0b>
From: <sip:[email protected];isup-oli=61;pstn-params=808481808882>;tag=81723374_6772d868_d237926c-77af-4f1a-aa24-70439e93be0b
To: <sip:[email protected];user=phone>;tag=as33a30bf4
Call-ID: [email protected]
CSeq: 905299 INVITE
Server: FPBX-13.0.191.11(13.14.0)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:[email protected]:5060>
Content-Type: application/sdp
Content-Length: 252

v=0
o=root 290295314 290295314 IN IP4 123.123.123.123
s=Asterisk PBX 13.14.0
c=IN IP4 123.123.123.123
t=0 0
m=audio 15054 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=maxptime:150
a=sendrecv

---
[2017-05-24 16:23:54] VERBOSE[17592][C-00000015] pbx.c: Executing [s@ivr-1:12] WaitExten("SIP/Twilio_Inbound_Trunk_1-0000001c", "10,") in new stack
[2017-05-24 16:23:56] NOTICE[1799] chan_sip.c: Disconnecting call 'SIP/Twilio_Inbound_Trunk_3-0000001b' for lack of RTP activity in 31 seconds
2

I’m pretty sure your problem is right there. Tell us more about how you are routing traffic from the Internet to your “local” server without NAT.

3

I have added a forward policy on my firewall to forward (without NAT) all traffic to this specific IP address [123.123.123.123] to the local IP of the FreePBX server. Do you think I should enable NAT on the inbound traffic?

4

From the rest of your description, I think so.

The incoming calls are not able to connect to your system through RTP, which indicates a problem with the UDP 10000-20000 ports on the external interface. Unless you are sending the external address to the server (which it doesn’t sound like you are doing), you will have to translate the address to get the traffic to communicate with the server inside your Local LAN.

5

I changed the router to forward with NAT. That seems to have resolved that problem. I have another one, but will post it in separate post.