SOLVED Setting up Twilio on FusionPBX

i3ioi-iazard · Mar 14, 2018

Hi,

Newbie here.

I am trying to set up Twilio to work with FusionPBX but the gateway state stays at TRYING and in logs I get Timeout Registering.
Under Gateway I have filled the below:

Gateway: Twilio

Username; myusernamefortwilio
Password: mypwfortwilio

From User: left empty
From Domain: left empty

Proxy: something.pstn.twilio.com
Realm: left empty
Expire Seconds: 800
Register: True
Retry Seconds: 30

Context: public
Hostname: left empty

Enabled: True
Description: left empty

Any idea what I did wrong?

Help greatly appreciated!

DigitalDaz · Mar 14, 2018

In the freeswitch cli do a:

Code:

sofia global siptrace on

Then stop and restart the gateway and paste the log out of the cli.

Also, always remember, when making any changes to a gateway you must stop and start it.

i3ioi-iazard · Mar 14, 2018

Ran that command in under the advanced section and then command. When I go to start the gateway, nothing happens now.

DigitalDaz said:
In the freeswitch cli do a:

Code:

sofia global siptrace on

Then stop and restart the gateway and paste the log out of the cli.

Also, always remember, when making any changes to a gateway you must stop and start it.

DigitalDaz · Mar 14, 2018

Nah, you need to do it in an ssh session on the linux box but inside freeswitch

i3ioi-iazard · Mar 14, 2018

Okay done - Still not able to start it. Every time I click start the screen refreshes but the state is blank even if I refresh. I rebooted the server and I still get the same thing.

DigitalDaz said:
Nah, you need to do it in an ssh session on the linux box but inside freeswitch

DigitalDaz · Mar 14, 2018

That would indicate a misconfiguration, I would have hought there would be something in the log though

i3ioi-iazard · Mar 14, 2018

I get this in the log from the status section. I ended up reinstalling Fusionpbx on a clean install. I have not configured anything other than this gateway and also turning on TLS/SSL. Would not having the certificate part cause an issue with the gateway?

2018-03-14 20:54:32.512622 [NOTICE] sofia_reg.c:448 Registering 38f4704b-cfba-4c77-aa89-b79ea4895e5a
2018-03-14 20:55:33.592674 [WARNING] sofia_reg.c:484 Timeout Registering 38f4704b-cfba-4c77-aa89-b79ea4895e5a
2018-03-14 20:55:34.592605 [WARNING] sofia_reg.c:505 38f4704b-cfba-4c77-aa89-b79ea4895e5a Failed Registration [908], setting retry to 30 seconds.
2018-03-14 20:56:05.632665 [NOTICE] sofia_reg.c:448 Registering 38f4704b-cfba-4c77-aa89-b79ea4895e5a
2018-03-14 20:57:06.732602 [WARNING] sofia_reg.c:484 Timeout Registering 38f4704b-cfba-4c77-aa89-b79ea4895e5a
2018-03-14 20:57:07.732602 [WARNING] sofia_reg.c:505 38f4704b-cfba-4c77-aa89-b79ea4895e5a Failed Registration [908], setting retry to 30 seconds.

DigitalDaz · Mar 14, 2018

You need that sip log but it looks like its not making it to and from the twilio,

Is this on a LAN by any chance?

phonesimon · Mar 14, 2018

Are you sure you're supposed to be registering? Last I used Twilio, I set up ACLs for outbound and provided Twilio an IP address for sending calls to my server.

i3ioi-iazard · Mar 14, 2018

Nope - Server is located in Vultr
------------------------------------------------------------------------
send 668 bytes to udp/[54.172.60.1]:5060 at 21:08:05.643290:
------------------------------------------------------------------------
REGISTER sip:dsfgsgsd.pstn.twilio.com;transport=udp SIP/2.0
Via: SIP/2.0/UDP 1.2.3.4:5080;rport;branch=z9hG4bKrvZUy6tr32e3j
Max-Forwards: 70
From: <sip:dsfgsgsd@dsfgsgsd.pstn.twilio.com>;tag=re8tpXeHX4t6K
To: <sip:dsfgsgsd@dsfgsgsd.pstn.twilio.com>
Call-ID: e5059359-901c-42d7-8890-57665b1516c5
CSeq: 120194777 REGISTER
Contact: <sip:gw+38f4704b-cfba-4c77-aa89-b79ea4895e5a@1.2.3.4:5080;transport=udp;gw=38f4704b-cfba-4c77-aa89-b79ea4895e5a>
Expires: 800
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
Supported: timer, path, replaces
Content-Length: 0

------------------------------------------------------------------------
send 668 bytes to udp/[54.172.60.3]:5060 at 21:08:06.271446:
------------------------------------------------------------------------
REGISTER sip:dsfgsgsd.pstn.twilio.com;transport=udp SIP/2.0
Via: SIP/2.0/UDP 1.2.3.4:5080;rport;branch=z9hG4bKQK62vBaN6SrgQ
Max-Forwards: 70
From: <sip:dsfgsgsd@dsfgsgsd.pstn.twilio.com>;tag=Q5e2m2XD0U4Kr
To: <sip:dsfgsgsd@dsfgsgsd.pstn.twilio.com>
Call-ID: e5059359-901c-42d7-8890-57665b1516c5
CSeq: 120194730 REGISTER
Contact: <sip:gw+38f4704b-cfba-4c77-aa89-b79ea4895e5a@1.2.3.4:5080;transport=udp;gw=38f4704b-cfba-4c77-aa89-b79ea4895e5a>
Expires: 800
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
Supported: timer, path, replaces
Content-Length: 0

------------------------------------------------------------------------
send 668 bytes to udp/[54.172.60.3]:5060 at 21:08:07.273287:
------------------------------------------------------------------------
REGISTER sip:dsfgsgsd.pstn.twilio.com;transport=udp SIP/2.0
Via: SIP/2.0/UDP 1.2.3.4:5080;rport;branch=z9hG4bKQK62vBaN6SrgQ
Max-Forwards: 70
From: <sip:dsfgsgsd@dsfgsgsd.pstn.twilio.com>;tag=Q5e2m2XD0U4Kr
To: <sip:dsfgsgsd@dsfgsgsd.pstn.twilio.com>
Call-ID: e5059359-901c-42d7-8890-57665b1516c5
CSeq: 120194730 REGISTER
Contact: <sip:gw+38f4704b-cfba-4c77-aa89-b79ea4895e5a@1.2.3.4:5080;transport=udp;gw=38f4704b-cfba-4c77-aa89-b79ea4895e5a>
Expires: 800
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
Supported: timer, path, replaces
Content-Length: 0

------------------------------------------------------------------------
freeswitch@vursify.com>

DigitalDaz said:
You need that sip log but it looks like its not making it to and from the twilio,

Is this on a LAN by any chance?

DigitalDaz · Mar 14, 2018

As @phonesimon said, do you need to register?? You are definitely not getting replies.

i3ioi-iazard · Mar 14, 2018

This might sound really dumb but dont I need that so I can call to external numbers? Right now, when I call from extension 100 (which i configured) to *9664 i get the hold music and logs are happy. When I call the DID from my cell, the DID rings but the extension 100 which is supposed to doesn't. Logs state that NO_ROUTE_DESTINATION

DigitalDaz said:
As @phonesimon said, do you need to register?? You are definitely not getting replies.

i3ioi-iazard · Mar 15, 2018

I have gotten inbound calling to work flawlessly but now I am having issues with outbound calling... Logs shown below:

SIP/2.0 100 Trying
Via: SIP/2.0/UDP 1.2.3.4:43326;branch=z9hG4bK973963959
From: "100" <sip:100@100.100.100.100:5060>;tag=166424428
To: <sip:1234567891@100.100.100.100:5060>
Call-ID: 2_2724983192@192.168.1.6
CSeq: 2 INVITE
User-Agent: FreeSWITCH
Content-Length: 0

------------------------------------------------------------------------
2018-03-15 16:05:56.072617 [DEBUG] sofia.c:2442 Re-attaching to session fbdb2b82-5044-4755-9344-7df6c0290421
2018-03-15 16:05:56.072617 [DEBUG] sofia.c:9873 sofia/internal/100@100.100.100.100:5060 receiving invite from 1.2.3.4:43326 version: 1.6.20 -37-987c9b9 64bit
2018-03-15 16:05:56.072617 [DEBUG] sofia.c:10044 IP 1.2.3.4 Rejected by acl "domains". Falling back to Digest auth.
2018-03-15 16:05:56.072617 [DEBUG] sofia.c:7084 Channel sofia/internal/100@100.100.100.100:5060 entering state [received][100]
2018-03-15 16:05:56.072617 [DEBUG] sofia.c:7094 Remote SDP:
v=0
o=- 20131 20131 IN IP4 1.2.3.4
s=SDP data
c=IN IP4 1.2.3.4
b=AS:1310
t=0 0
m=audio 50082 RTP/AVP 121 122 123 124 9 0 8 18 101
a=rtpmap:121 G7221/32000
a=fmtp:121 bitrate=48000
a=rtpmap:122 G7221/32000
a=fmtp:122 bitrate=32000
a=rtpmap:123 G7221/32000
a=fmtp:123 bitrate=24000
a=rtpmap:124 G7221/16000
a=fmtp:124 bitrate=24000
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
m=video 50084 RTP/AVP 97 98 99 34 117
b=TIAS:1310720
a=rtpmap:97 H264/90000
a=fmtp:97 profile-level-id=640028; packetization-mode=1
a=rtpmap:98 H264/90000
a=fmtp:98 profile-level-id=428028
a=rtpmap:99 H264/90000
a=fmtp:99 profile-level-id=428028; packetization-mode=1
a=rtpmap:34 H263/90000
a=fmtp:34 CIF4=1; CIF=1; QCIF=1
a=rtpmap:117 YL-FPR/90000
a=fmtp:117 yl-capset=7;yl-ver=1;yl-ext=19
a=ptime:20
a=rtcp-fb:* ccm fir

2018-03-15 16:05:56.072617 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G7221:121:32000:20:0:1]/[G722:9:8000:20:64000:1]
2018-03-15 16:05:56.072617 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G7221:121:32000:20:0:1]/[PCMU:0:8000:20:64000:1]
2018-03-15 16:05:56.072617 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G7221:121:32000:20:0:1]/[PCMA:8:8000:20:64000:1]
2018-03-15 16:05:56.072617 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G7221:121:32000:20:0:1]/[GSM:3:8000:20:13200:1]
2018-03-15 16:05:56.072617 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G7221:122:32000:20:0:1]/[G722:9:8000:20:64000:1]
2018-03-15 16:05:56.072617 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G7221:122:32000:20:0:1]/[PCMU:0:8000:20:64000:1]
2018-03-15 16:05:56.072617 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G7221:122:32000:20:0:1]/[PCMA:8:8000:20:64000:1]
2018-03-15 16:05:56.072617 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G7221:122:32000:20:0:1]/[GSM:3:8000:20:13200:1]
2018-03-15 16:05:56.072617 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G7221:123:32000:20:0:1]/[G722:9:8000:20:64000:1]
2018-03-15 16:05:56.072617 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G7221:123:32000:20:0:1]/[PCMU:0:8000:20:64000:1]
2018-03-15 16:05:56.072617 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G7221:123:32000:20:0:1]/[PCMA:8:8000:20:64000:1]
2018-03-15 16:05:56.072617 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G7221:123:32000:20:0:1]/[GSM:3:8000:20:13200:1]
2018-03-15 16:05:56.072617 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G7221:124:16000:20:0:1]/[G722:9:8000:20:64000:1]
2018-03-15 16:05:56.072617 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G7221:124:16000:20:0:1]/[PCMU:0:8000:20:64000:1]
2018-03-15 16:05:56.072617 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G7221:124:16000:20:0:1]/[PCMA:8:8000:20:64000:1]
2018-03-15 16:05:56.072617 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G7221:124:16000:20:0:1]/[GSM:3:8000:20:13200:1]
2018-03-15 16:05:56.072617 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2018-03-15 16:05:56.072617 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
2018-03-15 16:05:56.072617 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-03-15 16:05:56.072617 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2018-03-15 16:05:56.072617 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
2018-03-15 16:05:56.072617 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2018-03-15 16:05:56.072617 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-03-15 16:05:56.072617 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2018-03-15 16:05:56.072617 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2018-03-15 16:05:56.072617 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
2018-03-15 16:05:56.072617 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2018-03-15 16:05:56.072617 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-03-15 16:05:56.072617 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2018-03-15 16:05:56.072617 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2018-03-15 16:05:56.072617 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
2018-03-15 16:05:56.072617 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1]
2018-03-15 16:05:56.072617 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
2018-03-15 16:05:56.072617 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
2018-03-15 16:05:56.072617 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[GSM:3:8000:20:13200:1]
2018-03-15 16:05:56.072617 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000
2018-03-15 16:05:56.072617 [DEBUG] switch_core_media.c:3061 Set Codec sofia/internal/100@100.100.100.100:5060 G722/8000 20 ms 160 samples 64000 bits 1 channels
2018-03-15 16:05:56.072617 [DEBUG] switch_core_codec.c:111 sofia/internal/100@100.100.100.100:5060 Original read codec set to G722:9
2018-03-15 16:05:56.072617 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000
2018-03-15 16:05:56.072617 [DEBUG] switch_core_media.c:4767 sofia/internal/100@100.100.100.100:5060 Set 2833 dtmf send payload to 101 recv payload to 101
2018-03-15 16:05:56.072617 [DEBUG] switch_core_media.c:4993 No matches with FTMP, fallback to ignoring FMTP
2018-03-15 16:05:56.072617 [DEBUG] switch_core_media.c:5001 No matches with inherit_codec, fallback to ignoring PT
2018-03-15 16:05:56.072617 [DEBUG] sofia.c:7507 (sofia/internal/100@100.100.100.100:5060) State Change CS_NEW -> CS_INIT
2018-03-15 16:05:56.072617 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/100@100.100.100.100:5060) Running State Change CS_INIT (Cur 1 Tot 119)
2018-03-15 16:05:56.072617 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/100@100.100.100.100:5060) State INIT
2018-03-15 16:05:56.072617 [DEBUG] mod_sofia.c:90 sofia/internal/100@100.100.100.100:5060 SOFIA INIT
2018-03-15 16:05:56.072617 [DEBUG] switch_core_state_machine.c:40 sofia/internal/100@100.100.100.100:5060 Standard INIT
2018-03-15 16:05:56.072617 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/100@100.100.100.100:5060) State Change CS_INIT -> CS_ROUTING
2018-03-15 16:05:56.072617 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/100@100.100.100.100:5060) State INIT going to sleep
2018-03-15 16:05:56.072617 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/100@100.100.100.100:5060) Running State Change CS_ROUTING (Cur 1 Tot 119)
2018-03-15 16:05:56.072617 [DEBUG] switch_channel.c:2249 (sofia/internal/100@100.100.100.100:5060) Callstate Change DOWN -> RINGING
2018-03-15 16:05:56.072617 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/100@100.100.100.100:5060) State ROUTING
2018-03-15 16:05:56.072617 [DEBUG] mod_sofia.c:143 sofia/internal/100@100.100.100.100:5060 SOFIA ROUTING
2018-03-15 16:05:56.072617 [DEBUG] switch_core_state_machine.c:236 sofia/internal/100@100.100.100.100:5060 Standard ROUTING
2018-03-15 16:05:56.072617 [INFO] mod_dialplan_xml.c:637 Processing 100 <100>->1234567891 in context 100.100.100.100
Dialplan: sofia/internal/100@100.100.100.100:5060 parsing [100.100.100.100->user_exists] continue=true
Dialplan: sofia/internal/100@100.100.100.100:5060 Regex (PASS) [user_exists] () =~ // break=on-false
Dialplan: sofia/internal/100@100.100.100.100:5060 Action set(user_exists=${user_exists id ${destination_number} ${domain_name}}) INLINE
2018-03-15 16:05:56.092603 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f069c188140 Connected.
2018-03-15 16:05:56.092603 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f069c188140 released.
EXECUTE sofia/internal/100@100.100.100.100:5060 set(user_exists=false)
2018-03-15 16:05:56.092603 [DEBUG] mod_dptools.c:1548 SET sofia/internal/100@100.100.100.100:5060 [user_exists]=[false]
Dialplan: sofia/internal/100@100.100.100.100:5060 Regex (FAIL) [user_exists] ${user_exists}(false) =~ /^true$/ break=on-false
Dialplan: sofia/internal/100@100.100.100.100:5060 parsing [100.100.100.100->call-direction] continue=true
Dialplan: sofia/internal/100@100.100.100.100:5060 Regex (FAIL) [call-direction] ${call_direction}() =~ /^(inbound|outbound|local)$/ break=never
Dialplan: sofia/internal/100@100.100.100.100:5060 ANTI-Action set(call_direction=local)
Dialplan: sofia/internal/100@100.100.100.100:5060 parsing [100.100.100.100->variables] continue=true
Dialplan: sofia/internal/100@100.100.100.100:5060 Regex (PASS) [variables] () =~ // break=on-false
Dialplan: sofia/internal/100@100.100.100.100:5060 Action export(origination_callee_id_name=${destination_number})
Dialplan: sofia/internal/100@100.100.100.100:5060 Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
Dialplan: sofia/internal/100@100.100.100.100:5060 parsing [100.100.100.100->user_record] continue=true
Dialplan: sofia/internal/100@100.100.100.100:5060 Regex (PASS) [user_record] () =~ // break=on-false
Dialplan: sofia/internal/100@100.100.100.100:5060 Action set(user_record=${user_data ${destination_number}@${domain_name} var user_record}) INLINE
2018-03-15 16:05:56.092603 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f069c188140 Connected.
2018-03-15 16:05:56.092603 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f069c188140 released.
2018-03-15 16:05:56.092603 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f069c188140 Connected.
2018-03-15 16:05:56.092603 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f069c188140 released.
EXECUTE sofia/internal/100@100.100.100.100:5060 set(user_record=)
2018-03-15 16:05:56.092603 [DEBUG] mod_dptools.c:1548 SET sofia/internal/100@100.100.100.100:5060 [user_record]=[UNDEF]
Dialplan: sofia/internal/100@100.100.100.100:5060 Action set(from_user_exists=${user_exists id ${sip_from_user} ${sip_from_host}}) INLINE
EXECUTE sofia/internal/100@100.100.100.100:5060 set(from_user_exists=true)
2018-03-15 16:05:56.092603 [DEBUG] mod_dptools.c:1548 SET sofia/internal/100@100.100.100.100:5060 [from_user_exists]=[true]
Dialplan: sofia/internal/100@100.100.100.100:5060 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/100@100.100.100.100:5060 Regex (FAIL) [user_record] ${user_record}() =~ /^all$/ break=never
Dialplan: sofia/internal/100@100.100.100.100:5060 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/100@100.100.100.100:5060 Regex (FAIL) [user_record] ${call_direction}() =~ /^inbound$/ break=never
Dialplan: sofia/internal/100@100.100.100.100:5060 Regex (FAIL) [user_record] ${user_record}() =~ /^inbound$/ break=never
Dialplan: sofia/internal/100@100.100.100.100:5060 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/100@100.100.100.100:5060 Regex (FAIL) [user_record] ${call_direction}() =~ /^outbound$/ break=never
Dialplan: sofia/internal/100@100.100.100.100:5060 Regex (FAIL) [user_record] ${user_record}() =~ /^outbound$/ break=never
Dialplan: sofia/internal/100@100.100.100.100:5060 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/100@100.100.100.100:5060 Regex (FAIL) [user_record] ${call_direction}() =~ /^local$/ break=never
Dialplan: sofia/internal/100@100.100.100.100:5060 Regex (FAIL) [user_record] ${user_record}() =~ /^local$/ break=never
Dialplan: sofia/internal/100@100.100.100.100:5060 Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/internal/100@100.100.100.100:5060 Action set(from_user_record=${user_data ${sip_from_user}@${sip_from_host} var user_record}) INLINE
EXECUTE sofia/internal/100@100.100.100.100:5060 set(from_user_record=)
2018-03-15 16:05:56.112605 [DEBUG] mod_dptools.c:1548 SET sofia/internal/100@100.100.100.100:5060 [from_user_record]=[UNDEF]
Dialplan: sofia/internal/100@100.100.100.100:5060 Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/internal/100@100.100.100.100:5060 Regex (FAIL) [user_record] ${from_user_record}() =~ /^all$/ break=never
Dialplan: sofia/internal/100@100.100.100.100:5060 Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/internal/100@100.100.100.100:5060 Regex (FAIL) [user_record] ${call_direction}() =~ /^inbound$/ break=never
Dialplan: sofia/internal/100@100.100.100.100:5060 Regex (FAIL) [user_record] ${from_user_record}() =~ /^inbound$/ break=never
Dialplan: sofia/internal/100@100.100.100.100:5060 Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/internal/100@100.100.100.100:5060 Regex (FAIL) [user_record] ${call_direction}() =~ /^outbound$/ break=never
Dialplan: sofia/internal/100@100.100.100.100:5060 Regex (FAIL) [user_record] ${from_user_record}() =~ /^outbound$/ break=never
Dialplan: sofia/internal/100@100.100.100.100:5060 Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/internal/100@100.100.100.100:5060 Regex (FAIL) [user_record] ${call_direction}() =~ /^local$/ break=never
Dialplan: sofia/internal/100@100.100.100.100:5060 Regex (FAIL) [user_record] ${from_user_record}() =~ /^local$/ break=never
Dialplan: sofia/internal/100@100.100.100.100:5060 Regex (FAIL) [user_record] ${record_session}() =~ /^true$/ break=on-false
Dialplan: sofia/internal/100@100.100.100.100:5060 parsing [100.100.100.100->redial] continue=true
Dialplan: sofia/internal/100@100.100.100.100:5060 Regex (FAIL) [redial] destination_number(1234567891) =~ /^(redial|\*870)$/ break=on-true
Dialplan: sofia/internal/100@100.100.100.100:5060 Regex (PASS) [redial] () =~ // break=never
Dialplan: sofia/internal/100@100.100.100.100:5060 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
Dialplan: sofia/internal/100@100.100.100.100:5060 parsing [100.100.100.100->speed_dial] continue=false
Dialplan: sofia/internal/100@100.100.100.100:5060 Regex (FAIL) [speed_dial] destination_number(1234567891) =~ /^\*0(.*)$/ break=on-false
Dialplan: sofia/internal/100@100.100.100.100:5060 parsing [100.100.100.100->Twilio.011.9-17d] continue=false
Dialplan: sofia/internal/100@100.100.100.100:5060 Regex (FAIL) [Twilio.011.9-17d] destination_number(1234567891) =~ /^(011\d{9,17})$/ break=on-false
Dialplan: sofia/internal/100@100.100.100.100:5060 parsing [100.100.100.100->Twilio.011.9-17d] continue=false
Dialplan: sofia/internal/100@100.100.100.100:5060 Regex (FAIL) [Twilio.011.9-17d] destination_number(1234567891) =~ /^(011\d{9,17})$/ break=on-false
Dialplan: sofia/internal/100@100.100.100.100:5060 parsing [100.100.100.100->Twilio.11d] continue=false
Dialplan: sofia/internal/100@100.100.100.100:5060 Regex (FAIL) [Twilio.11d] destination_number(1234567891) =~ /^\+?(\d{11})$/ break=on-false
Dialplan: sofia/internal/100@100.100.100.100:5060 parsing [100.100.100.100->Twilio.1d10] continue=false
Dialplan: sofia/internal/100@100.100.100.100:5060 Regex (PASS) [Twilio.1d10] destination_number(1234567891) =~ /^\+?1?(\d{10})$/ break=on-false
Dialplan: sofia/internal/100@100.100.100.100:5060 Action set(sip_h_X-accountcode=${accountcode})
Dialplan: sofia/internal/100@100.100.100.100:5060 Action set(call_direction=outbound)
Dialplan: sofia/internal/100@100.100.100.100:5060 Action unset(call_timeout)
Dialplan: sofia/internal/100@100.100.100.100:5060 Action set(hangup_after_bridge=true)
Dialplan: sofia/internal/100@100.100.100.100:5060 Action set(effective_caller_id_name=${outbound_caller_id_name})
Dialplan: sofia/internal/100@100.100.100.100:5060 Action set(effective_caller_id_number=${outbound_caller_id_number})
Dialplan: sofia/internal/100@100.100.100.100:5060 Action set(inherit_codec=true)
Dialplan: sofia/internal/100@100.100.100.100:5060 Action set(ignore_display_updates=true)
Dialplan: sofia/internal/100@100.100.100.100:5060 Action set(callee_id_number=1234567891)
Dialplan: sofia/internal/100@100.100.100.100:5060 Action set(continue_on_fail=true)
Dialplan: sofia/internal/100@100.100.100.100:5060 Action bridge(sofia/gateway/a2b2bcd6-8977-49d7-a207-36b7b7fc8b61/1234567891)
2018-03-15 16:05:56.112605 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/100@100.100.100.100:5060) State Change CS_ROUTING -> CS_EXECUTE
2018-03-15 16:05:56.112605 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/100@100.100.100.100:5060) State ROUTING going to sleep
2018-03-15 16:05:56.112605 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/100@100.100.100.100:5060) Running State Change CS_EXECUTE (Cur 1 Tot 119)
2018-03-15 16:05:56.112605 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/100@100.100.100.100:5060) State EXECUTE
2018-03-15 16:05:56.112605 [DEBUG] mod_sofia.c:198 sofia/internal/100@100.100.100.100:5060 SOFIA EXECUTE
2018-03-15 16:05:56.112605 [DEBUG] switch_core_state_machine.c:328 sofia/internal/100@100.100.100.100:5060 Standard EXECUTE
EXECUTE sofia/internal/100@100.100.100.100:5060 set(call_direction=local)
2018-03-15 16:05:56.112605 [DEBUG] mod_dptools.c:1548 SET sofia/internal/100@100.100.100.100:5060 [call_direction]=[local]
EXECUTE sofia/internal/100@100.100.100.100:5060 export(origination_callee_id_name=1234567891)
2018-03-15 16:05:56.112605 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [origination_callee_id_name]=[1234567891]
EXECUTE sofia/internal/100@100.100.100.100:5060 set(RFC2822_DATE=Thu, 15 Mar 2018 16:05:56 +0000)
2018-03-15 16:05:56.112605 [DEBUG] mod_dptools.c:1548 SET sofia/internal/100@100.100.100.100:5060 [RFC2822_DATE]=[Thu, 15 Mar 2018 16:05:56 +0000]
EXECUTE sofia/internal/100@100.100.100.100:5060 hash(insert/100.100.100.100-last_dial/100/1234567891)
EXECUTE sofia/internal/100@100.100.100.100:5060 set(sip_h_X-accountcode=100.100.100.100)
2018-03-15 16:05:56.112605 [DEBUG] mod_dptools.c:1548 SET sofia/internal/100@100.100.100.100:5060 [sip_h_X-accountcode]=[100.100.100.100]
EXECUTE sofia/internal/100@100.100.100.100:5060 set(call_direction=outbound)
2018-03-15 16:05:56.112605 [DEBUG] mod_dptools.c:1548 SET sofia/internal/100@100.100.100.100:5060 [call_direction]=[outbound]
EXECUTE sofia/internal/100@100.100.100.100:5060 unset(call_timeout)
2018-03-15 16:05:56.112605 [DEBUG] mod_dptools.c:1693 UNSET [call_timeout]
EXECUTE sofia/internal/100@100.100.100.100:5060 set(hangup_after_bridge=true)
2018-03-15 16:05:56.112605 [DEBUG] mod_dptools.c:1548 SET sofia/internal/100@100.100.100.100:5060 [hangup_after_bridge]=[true]
EXECUTE sofia/internal/100@100.100.100.100:5060 set(effective_caller_id_name=asdfr)
2018-03-15 16:05:56.112605 [DEBUG] mod_dptools.c:1548 SET sofia/internal/100@100.100.100.100:5060 [effective_caller_id_name]=[asdf]
EXECUTE sofia/internal/100@100.100.100.100:5060 set(effective_caller_id_number=5876021009)
2018-03-15 16:05:56.112605 [DEBUG] mod_dptools.c:1548 SET sofia/internal/100@100.100.100.100:5060 [effective_caller_id_number]=[5876021009]
EXECUTE sofia/internal/100@100.100.100.100:5060 set(inherit_codec=true)
2018-03-15 16:05:56.112605 [DEBUG] mod_dptools.c:1548 SET sofia/internal/100@100.100.100.100:5060 [inherit_codec]=[true]
EXECUTE sofia/internal/100@100.100.100.100:5060 set(ignore_display_updates=true)
2018-03-15 16:05:56.112605 [DEBUG] mod_dptools.c:1548 SET sofia/internal/100@100.100.100.100:5060 [ignore_display_updates]=[true]
EXECUTE sofia/internal/100@100.100.100.100:5060 set(callee_id_number=1234567891)
2018-03-15 16:05:56.112605 [DEBUG] mod_dptools.c:1548 SET sofia/internal/100@100.100.100.100:5060 [callee_id_number]=[1234567891]
EXECUTE sofia/internal/100@100.100.100.100:5060 set(continue_on_fail=true)
2018-03-15 16:05:56.112605 [DEBUG] mod_dptools.c:1548 SET sofia/internal/100@100.100.100.100:5060 [continue_on_fail]=[true]
EXECUTE sofia/internal/100@100.100.100.100:5060 bridge(sofia/gateway/a2b2bcd6-8977-49d7-a207-36b7b7fc8b61/1234567891)
2018-03-15 16:05:56.112605 [DEBUG] switch_channel.c:1250 sofia/internal/100@100.100.100.100:5060 EXPORTING[export_vars] [domain_name]=[100.100.100.100] to event
2018-03-15 16:05:56.112605 [DEBUG] switch_channel.c:1250 sofia/internal/100@100.100.100.100:5060 EXPORTING[export_vars] [origination_callee_id_name]=[1234567891] to event
2018-03-15 16:05:56.112605 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
2018-03-15 16:05:56.112605 [NOTICE] switch_channel.c:1104 New Channel sofia/external/1234567891 [f7b3cea5-f511-46d4-970e-aee496701d46]
2018-03-15 16:05:56.112605 [DEBUG] mod_sofia.c:4819 (sofia/external/1234567891) State Change CS_NEW -> CS_INIT
2018-03-15 16:05:56.112605 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1234567891) Running State Change CS_INIT (Cur 2 Tot 120)
2018-03-15 16:05:56.112605 [DEBUG] switch_core_state_machine.c:627 (sofia/external/1234567891) State INIT
2018-03-15 16:05:56.112605 [DEBUG] mod_sofia.c:90 sofia/external/1234567891 SOFIA INIT
2018-03-15 16:05:56.112605 [DEBUG] sofia_glue.c:1295 sofia/external/1234567891 sending invite version: 1.6.20 -37-987c9b9 64bit
Local SDP:
v=0
o=FreeSWITCH15211118141521111815 IN IP4 100.100.100.100
s=FreeSWITCH
c=IN IP4 100.100.100.100
t=0 0
m=audio 18142 RTP/AVP 9 0 8 3 101 13
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:3 GSM/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=ptime:20
a=sendrecv

2018-03-15 16:05:56.112605 [DEBUG] switch_core_state_machine.c:40 sofia/external/1234567891 Standard INIT
2018-03-15 16:05:56.112605 [DEBUG] switch_core_state_machine.c:48 (sofia/external/1234567891) State Change CS_INIT -> CS_ROUTING
2018-03-15 16:05:56.112605 [DEBUG] switch_core_state_machine.c:627 (sofia/external/1234567891) State INIT going to sleep
2018-03-15 16:05:56.112605 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1234567891) Running State Change CS_ROUTING (Cur 2 Tot 120)
2018-03-15 16:05:56.112605 [DEBUG] switch_core_state_machine.c:643 (sofia/external/1234567891) State ROUTING
2018-03-15 16:05:56.112605 [DEBUG] mod_sofia.c:143 sofia/external/1234567891 SOFIA ROUTING
2018-03-15 16:05:56.112605 [DEBUG] switch_ivr_originate.c:67 (sofia/external/1234567891) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2018-03-15 16:05:56.112605 [DEBUG] switch_core_state_machine.c:643 (sofia/external/1234567891) State ROUTING going to sleep
2018-03-15 16:05:56.112605 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1234567891) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 120)
2018-03-15 16:05:56.112605 [DEBUG] sofia.c:7084 Channel sofia/external/1234567891 entering state [calling][0]
2018-03-15 16:05:56.112605 [DEBUG] switch_core_state_machine.c:662 (sofia/external/1234567891) State CONSUME_MEDIA
2018-03-15 16:05:56.112605 [DEBUG] switch_core_state_machine.c:662 (sofia/external/1234567891) State CONSUME_MEDIA going to sleep
send 1261 bytes to udp/[54.172.60.1]:5060 at 16:05:58.513804:
------------------------------------------------------------------------
INVITE sip:1234567891@vursify.pstn.twilio.com SIP/2.0
Via: SIP/2.0/UDP 100.100.100.100:5080;rport;branch=z9hG4bK2Q5c9pycaSpmS
Max-Forwards: 69
From: "asdf" <sip:someguy@gmail.com@vursify.pstn.twilio.com>;tag=mDy3SpvNKrvyD
To: <sip:1234567891@vursify.pstn.twilio.com>
Call-ID: 95ca3ee0-a30d-1236-eab1-56000168b138
CSeq: 120228914 INVITE
Contact: <sip:gw+a2b2bcd6-8977-49d7-a207-36b7b7fc8b61@100.100.100.100:5080;transport=udp;gw=a2b2bcd6-8977-49d7-a207-36b7b7fc8b61>
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
Supported: timer, path, replaces
Allow-Events: talk, hold, conference, refer
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 321
X-accountcode: 100.100.100.100
X-FS-Support: update_display,send_info
Remote-Party-ID: "asdf" <sip:5876021009@vursify.pstn.twilio.com>;party=calling;screen=yes;privacy=off

v=0
o=FreeSWITCH15211118141521111815 IN IP4 100.100.100.100
s=FreeSWITCH
c=IN IP4 100.100.100.100
t=0 0
m=audio 18142 RTP/AVP 9 0 8 3 101 13
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:3 GSM/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=ptime:20
------------------------------------------------------------------------
recv 379 bytes from udp/[54.172.60.1]:5060 at 16:05:58.590510:
------------------------------------------------------------------------
SIP/2.0 100 Giving a try
Via: SIP/2.0/UDP 100.100.100.100:5080;received=100.100.100.100;rport=5080;branch=z9hG4bK2Q5c9pycaSpmS
From: "asdf" <sip:someguy@gmail.com@vursify.pstn.twilio.com>;tag=mDy3SpvNKrvyD
To: <sip:1234567891@vursify.pstn.twilio.com>
Call-ID: 95ca3ee0-a30d-1236-eab1-56000168b138
CSeq: 120228914 INVITE
Server: Twilio Gateway
Content-Length: 0

------------------------------------------------------------------------
recv 424 bytes from udp/[54.172.60.1]:5060 at 16:06:06.891917:
------------------------------------------------------------------------
SIP/2.0 408 Request Timeout
Via: SIP/2.0/UDP 100.100.100.100:5080;received=100.100.100.100;rport=5080;branch=z9hG4bK2Q5c9pycaSpmS
From: "asdf" <sip:someguy@gmail.com@vursify.pstn.twilio.com>;tag=mDy3SpvNKrvyD
To: <sip:1234567891@vursify.pstn.twilio.com>;tag=048bc9a6984fdbcd1de39c7c218aea19-3a73
Call-ID: 95ca3ee0-a30d-1236-eab1-56000168b138
CSeq: 120228914 INVITE
Server: Twilio Gateway
Content-Length: 0

------------------------------------------------------------------------
send 408 bytes to udp/[54.172.60.1]:5060 at 16:06:06.892081:
------------------------------------------------------------------------
ACK sip:1234567891@vursify.pstn.twilio.com SIP/2.0
Via: SIP/2.0/UDP 100.100.100.100:5080;rport;branch=z9hG4bK2Q5c9pycaSpmS
Max-Forwards: 69
From: "asdf" <sip:someguy@gmail.com@vursify.pstn.twilio.com>;tag=mDy3SpvNKrvyD
To: <sip:1234567891@vursify.pstn.twilio.com>;tag=048bc9a6984fdbcd1de39c7c218aea19-3a73
Call-ID: 95ca3ee0-a30d-1236-eab1-56000168b138
CSeq: 120228914 ACK
Content-Length: 0

------------------------------------------------------------------------
2018-03-15 16:06:06.872604 [DEBUG] sofia.c:7084 Channel sofia/external/1234567891 entering state [terminated][408]
2018-03-15 16:06:06.872604 [NOTICE] sofia.c:8273 Hangup sofia/external/1234567891 [CS_CONSUME_MEDIA] [RECOVERY_ON_TIMER_EXPIRE]
2018-03-15 16:06:06.892603 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1234567891) Running State Change CS_HANGUP (Cur 2 Tot 120)
2018-03-15 16:06:06.892603 [DEBUG] switch_core_state_machine.c:850 (sofia/external/1234567891) Callstate Change DOWN -> HANGUP
2018-03-15 16:06:06.892603 [DEBUG] switch_core_state_machine.c:852 (sofia/external/1234567891) State HANGUP
2018-03-15 16:06:06.892603 [DEBUG] mod_sofia.c:438 Channel sofia/external/1234567891 hanging up, cause: RECOVERY_ON_TIMER_EXPIRE
2018-03-15 16:06:06.892603 [DEBUG] switch_core_state_machine.c:60 sofia/external/1234567891 Standard HANGUP, cause: RECOVERY_ON_TIMER_EXPIRE
2018-03-15 16:06:06.892603 [DEBUG] switch_core_state_machine.c:852 (sofia/external/1234567891) State HANGUP going to sleep
2018-03-15 16:06:06.892603 [DEBUG] switch_core_state_machine.c:619 (sofia/external/1234567891) State Change CS_HANGUP -> CS_REPORTING
2018-03-15 16:06:06.892603 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1234567891) Running State Change CS_REPORTING (Cur 2 Tot 120)
2018-03-15 16:06:06.892603 [DEBUG] switch_core_state_machine.c:938 (sofia/external/1234567891) State REPORTING
2018-03-15 16:06:06.892603 [DEBUG] switch_core_state_machine.c:174 sofia/external/1234567891 Standard REPORTING, cause: RECOVERY_ON_TIMER_EXPIRE
2018-03-15 16:06:06.892603 [DEBUG] switch_core_state_machine.c:938 (sofia/external/1234567891) State REPORTING going to sleep
2018-03-15 16:06:06.892603 [DEBUG] switch_core_state_machine.c:610 (sofia/external/1234567891) State Change CS_REPORTING -> CS_DESTROY
2018-03-15 16:06:06.892603 [DEBUG] switch_core_session.c:1665 Session 120 (sofia/external/1234567891) Locked, Waiting on external entities
2018-03-15 16:06:06.892603 [DEBUG] switch_ivr_originate.c:3848 Originate Resulted in Error Cause: 102 [RECOVERY_ON_TIMER_EXPIRE]
2018-03-15 16:06:06.892603 [NOTICE] switch_core_session.c:1683 Session 120 (sofia/external/1234567891) Ended
2018-03-15 16:06:06.892603 [NOTICE] switch_core_session.c:1687 Close Channel sofia/external/1234567891 [CS_DESTROY]
2018-03-15 16:06:06.892603 [DEBUG] switch_core_state_machine.c:741 (sofia/external/1234567891) Running State Change CS_DESTROY (Cur 1 Tot 120)
2018-03-15 16:06:06.892603 [DEBUG] switch_core_state_machine.c:751 (sofia/external/1234567891) State DESTROY
2018-03-15 16:06:06.892603 [DEBUG] mod_sofia.c:343 sofia/external/1234567891 SOFIA DESTROY
2018-03-15 16:06:06.892603 [DEBUG] switch_core_state_machine.c:181 sofia/external/1234567891 Standard DESTROY
2018-03-15 16:06:06.892603 [DEBUG] switch_core_state_machine.c:751 (sofia/external/1234567891) State DESTROY going to sleep
2018-03-15 16:06:06.892603 [INFO] mod_dptools.c:3436 Originate Failed. Cause: RECOVERY_ON_TIMER_EXPIRE
2018-03-15 16:06:06.892603 [NOTICE] switch_core_state_machine.c:385 sofia/internal/100@100.100.100.100:5060 has executed the last dialplan instruction, hanging up.
2018-03-15 16:06:06.892603 [NOTICE] switch_core_state_machine.c:387 Hangup sofia/internal/100@100.100.100.100:5060 [CS_EXECUTE] [NORMAL_CLEARING]
2018-03-15 16:06:06.892603 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/100@100.100.100.100:5060) State EXECUTE going to sleep
2018-03-15 16:06:06.892603 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/100@100.100.100.100:5060) Running State Change CS_HANGUP (Cur 1 Tot 120)
2018-03-15 16:06:06.892603 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/100@100.100.100.100:5060) Callstate Change RINGING -> HANGUP
2018-03-15 16:06:06.892603 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/100@100.100.100.100:5060) State HANGUP
2018-03-15 16:06:06.892603 [DEBUG] mod_sofia.c:432 sofia/internal/100@100.100.100.100:5060 Overriding SIP cause 480 with 408 from the other leg
2018-03-15 16:06:06.892603 [DEBUG] mod_sofia.c:438 Channel sofia/internal/100@100.100.100.100:5060 hanging up, cause: NORMAL_CLEARING
2018-03-15 16:06:06.892603 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 408
2018-03-15 16:06:06.892603 [DEBUG] switch_core_state_machine.c:60 sofia/internal/100@100.100.100.100:5060 Standard HANGUP, cause: NORMAL_CLEARING
2018-03-15 16:06:06.892603 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/100@100.100.100.100:5060) State HANGUP going to sleep
2018-03-15 16:06:06.892603 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/100@100.100.100.100:5060) State Change CS_HANGUP -> CS_REPORTING
send 812 bytes to udp/[1.2.3.4]:43326 at 16:06:06.910233:
------------------------------------------------------------------------
SIP/2.0 408 Request Timeout
Via: SIP/2.0/UDP 1.2.3.4:43326;branch=z9hG4bK973963959
Max-Forwards: 70
From: "100" <sip:100@100.100.100.100:5060>;tag=166424428
To: <sip:1234567891@100.100.100.100:5060>;tag=SmUjZvmprcpFB
Call-ID: 2_2724983192@192.168.1.6
CSeq: 2 INVITE
User-Agent: FreeSWITCH
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
Reason: Q.850;cause=16;text="NORMAL_CLEARING"
Content-Length: 0
Remote-Party-ID: "1234567891" <sip:1234567891@100.100.100.100>;party=calling;privacy=off;screen=no

------------------------------------------------------------------------
2018-03-15 16:06:06.892603 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/100@100.100.100.100:5060) Running State Change CS_REPORTING (Cur 1 Tot 120)
2018-03-15 16:06:06.892603 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/100@100.100.100.100:5060) State REPORTING
2018-03-15 16:06:06.932587 [DEBUG] switch_core_state_machine.c:174 sofia/internal/100@100.100.100.100:5060 Standard REPORTING, cause: NORMAL_CLEARING
2018-03-15 16:06:06.932587 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/100@100.100.100.100:5060) State REPORTING going to sleep
2018-03-15 16:06:06.932587 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/100@100.100.100.100:5060) State Change CS_REPORTING -> CS_DESTROY
2018-03-15 16:06:06.932587 [DEBUG] switch_core_session.c:1665 Session 119 (sofia/internal/100@100.100.100.100:5060) Locked, Waiting on external entities
2018-03-15 16:06:06.932587 [NOTICE] switch_core_session.c:1683 Session 119 (sofia/internal/100@100.100.100.100:5060) Ended
2018-03-15 16:06:06.932587 [NOTICE] switch_core_session.c:1687 Close Channel sofia/internal/100@100.100.100.100:5060 [CS_DESTROY]
2018-03-15 16:06:06.932587 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/100@100.100.100.100:5060) Running State Change CS_DESTROY (Cur 0 Tot 120)
2018-03-15 16:06:06.932587 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/100@100.100.100.100:5060) State DESTROY
2018-03-15 16:06:06.932587 [DEBUG] mod_sofia.c:343 sofia/internal/100@100.100.100.100:5060 SOFIA DESTROY
2018-03-15 16:06:06.932587 [DEBUG] switch_core_state_machine.c:181 sofia/internal/100@100.100.100.100:5060 Standard DESTROY
2018-03-15 16:06:06.932587 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/100@100.100.100.100:5060) State DESTROY going to sleep
recv 300 bytes from udp/[1.2.3.4]:43326 at 16:06:06.947464:
------------------------------------------------------------------------
ACK sip:1234567891@100.100.100.100:5060 SIP/2.0
Via: SIP/2.0/UDP 1.2.3.4:43326;branch=z9hG4bK973963959
From: "100" <sip:100@100.100.100.100:5060>;tag=166424428
To: <sip:1234567891@100.100.100.100:5060>;tag=SmUjZvmprcpFB
Call-ID: 2_2724983192@192.168.1.6
CSeq: 2 ACK
Content-Length: 0

phonesimon · Mar 15, 2018

You need to set up an ACL at Twilio to allow calls from your IP address.

i3ioi-iazard · Mar 15, 2018

how does that work if a user has a dynamic IP?

phonesimon said:
You need to set up an ACL at Twilio to allow calls from your IP address.

i3ioi-iazard · Mar 15, 2018

I have my PBX IP address added to Twilio in the form of 1.2.3.4 but I still cant make an outbound call.

phonesimon · Mar 15, 2018

My mistake. It looks like you can set up user/pass auth alone without specifying an ACL. https://www.twilio.com/docs/api/sip-trunking/getting-started#termination

phonesimon · Mar 15, 2018

Get the logs from the Twilio console to see what's going on... they even let you download pcaps so you can review it thoroughly.

phonesimon · Mar 15, 2018

i3ioi-iazard said:
100.100.100.100:5080;

Are you actually using this IP address for your pbx? If you're using it in a NAT it's not going to work. You need to use RFC1918 addresses.

i3ioi-iazard · Mar 15, 2018

They arent reaching Twilio. The incoming is all in the logs but nothing gets recorded for outbound.

phonesimon said:
Get the logs from the Twilio console to see what's going on... they even let you download pcaps so you can review it thoroughly.

That is not my actual IP

phonesimon said:
Are you actually using this IP address for your pbx? If you're using it in a NAT it's not going to work. You need to use RFC1918 addresses.

SOLVED Setting up Twilio on FusionPBX

Member

Administrator

Member

Administrator

Member

Administrator

Member

Administrator

Member

Member

Administrator

Member

Member

Member

Member

Member

Member

Member

Member

Member