freeswitch@freeswitch2>
recv 1277 bytes from udp/[54.172.60.0]:5060 at 23:39:06.922168:
------------------------------------------------------------------------
INVITE sip:+12105552600@host.domain.xyz:5080 SIP/2.0
Record-Route: <sip:54.172.60.0:5060;lr;ftag=77969553_6772d868_a2d2abaa-ec5c-486d-9f51-36cca6acecc2>
From: <sip:+19185555555@xyz.pstn.twilio.com;pstn-params=808482808882;cpc=ordinary>;tag=77969553_6772d868_a2d2abaa-ec5c-486d-9f51-36cca6acecc2
To: <sip:+12105552600@host.domain.xyz:5080;user=phone>
CSeq: 24644 INVITE
Max-Forwards: 8
Diversion: <sip:+12105552600@public-vip.us1.twilio.com>;reason=unconditional
Call-ID: 1abc80bf6ecb7fd8fe56f8121c5d4fde@0.0.0.0
Via: SIP/2.0/UDP 54.172.60.0:5060;branch=z9hG4bKd173.db254ea.0
Via: SIP/2.0/UDP 172.18.17.96:5060;rport=5060;received=172.18.17.96;branch=z9hG4bKa2d2abaa-ec5c-486d-9f51-36cca6acecc2_6772d868_290-1797581531681190546
Contact: <sip:+19185555555@172.18.17.96:5060;transport=udp>
Allow: INVITE,ACK,CANCEL,BYE,OPTIONS
User-Agent: Twilio Gateway
X-Twilio-AccountSid: AC8b53e1937b9b71f1398aa93b989acc65
Content-Type: application/sdp
X-Twilio-CallSid: CA89fc4d397b25af1c13acc087fdbd4f24
Content-Length: 238
v=0
o=root 825736281 825736281 IN IP4 34.203.251.170
s=Twilio Media Gateway
c=IN IP4 34.203.251.170
t=0 0
m=audio 14984 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
------------------------------------------------------------------------
2017-07-20 23:39:06.910608 [NOTICE] switch_channel.c:1104 New Channel sofia/external/+19185555555@xyz.pstn.twilio.com [4b75ed5c-6ddf-11e7-a95c-9ba6c317ee11]
2017-07-20 23:39:06.910608 [DEBUG] switch_core_state_machine.c:584 (sofia/external/+19185555555@xyz.pstn.twilio.com) Running State Change CS_NEW (Cur 1 Tot 10)
2017-07-20 23:39:06.910608 [DEBUG] sofia.c:10067 sofia/external/+19185555555@xyz.pstn.twilio.com receiving invite from 54.172.60.0:5060 version: 1.9.0 git 13f2f2a 2017-07-14 20:15:19Z 32bit
2017-07-20 23:39:06.910608 [DEBUG] sofia.c:7283 Channel sofia/external/+19185555555@xyz.pstn.twilio.com entering state [received][100]
2017-07-20 23:39:06.910608 [DEBUG] sofia.c:7293 Remote SDP:
v=0
o=root 825736281 825736281 IN IP4 34.203.251.170
s=Twilio Media Gateway
c=IN IP4 34.203.251.170
t=0 0
m=audio 14984 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
2017-07-20 23:39:06.910608 [DEBUG] sofia.c:7685 (sofia/external/+19185555555@xyz.pstn.twilio.com) State Change CS_NEW -> CS_INIT
2017-07-20 23:39:06.910608 [DEBUG] switch_core_state_machine.c:603 (sofia/external/+19185555555@xyz.pstn.twilio.com) State NEW
2017-07-20 23:39:06.910608 [DEBUG] switch_core_state_machine.c:584 (sofia/external/+19185555555@xyz.pstn.twilio.com) Running State Change CS_INIT (Cur 1 Tot 10)
2017-07-20 23:39:06.910608 [DEBUG] switch_core_state_machine.c:627 (sofia/external/+19185555555@xyz.pstn.twilio.com) State INIT
2017-07-20 23:39:06.910608 [DEBUG] mod_sofia.c:93 sofia/external/+19185555555@xyz.pstn.twilio.com SOFIA INIT
2017-07-20 23:39:06.910608 [DEBUG] switch_core_state_machine.c:40 sofia/external/+19185555555@xyz.pstn.twilio.com Standard INIT
2017-07-20 23:39:06.910608 [DEBUG] switch_core_state_machine.c:48 (sofia/external/+19185555555@xyz.pstn.twilio.com) State Change CS_INIT -> CS_ROUTING
2017-07-20 23:39:06.910608 [DEBUG] switch_core_state_machine.c:627 (sofia/external/+19185555555@xyz.pstn.twilio.com) State INIT going to sleep
2017-07-20 23:39:06.910608 [DEBUG] switch_core_state_machine.c:584 (sofia/external/+19185555555@xyz.pstn.twilio.com) Running State Change CS_ROUTING (Cur 1 Tot 10)
2017-07-20 23:39:06.910608 [DEBUG] switch_channel.c:2249 (sofia/external/+19185555555@xyz.pstn.twilio.com) Callstate Change DOWN -> RINGING
2017-07-20 23:39:06.910608 [DEBUG] switch_core_state_machine.c:643 (sofia/external/+19185555555@xyz.pstn.twilio.com) State ROUTING
2017-07-20 23:39:06.930644 [DEBUG] mod_sofia.c:154 sofia/external/+19185555555@xyz.pstn.twilio.com SOFIA ROUTING
2017-07-20 23:39:06.930644 [DEBUG] switch_core_state_machine.c:236 sofia/external/+19185555555@xyz.pstn.twilio.com Standard ROUTING
2017-07-20 23:39:06.930644 [INFO] mod_dialplan_xml.c:637 Processing +19185555555 <+19185555555>->+12105552600 in context public
send 460 bytes to udp/[54.172.60.0]:5060 at 23:39:06.931040:
------------------------------------------------------------------------
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 54.172.60.0:5060;branch=z9hG4bKd173.db254ea.0
From: <sip:+19185555555@xyz.pstn.twilio.com;pstn-params=808482808882;cpc=ordinary>;tag=77969553_6772d868_a2d2abaa-ec5c-486d-9f51-36cca6acecc2
To: <sip:+12105552600@host.domain.xyz:5080;user=phone>
Call-ID: 1abc80bf6ecb7fd8fe56f8121c5d4fde@0.0.0.0
CSeq: 24644 INVITE
User-Agent: FreeSWITCH-mod_sofia/1.9.0+git~20170714T201519Z~13f2f2a056~32bit
Content-Length: 0
------------------------------------------------------------------------
Dialplan: sofia/external/+19185555555@xyz.pstn.twilio.com parsing [public->unloop] continue=false
Dialplan: sofia/external/+19185555555@xyz.pstn.twilio.com Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/external/+19185555555@xyz.pstn.twilio.com Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/external/+19185555555@xyz.pstn.twilio.com parsing [public->outside_call] continue=true
Dialplan: sofia/external/+19185555555@xyz.pstn.twilio.com Absolute Condition [outside_call]
Dialplan: sofia/external/+19185555555@xyz.pstn.twilio.com Action set(outside_call=true)
Dialplan: sofia/external/+19185555555@xyz.pstn.twilio.com Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
Dialplan: sofia/external/+19185555555@xyz.pstn.twilio.com parsing [public->call_debug] continue=true
Dialplan: sofia/external/+19185555555@xyz.pstn.twilio.com Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never
Dialplan: sofia/external/+19185555555@xyz.pstn.twilio.com parsing [public->public_extensions] continue=false
Dialplan: sofia/external/+19185555555@xyz.pstn.twilio.com Regex (FAIL) [public_extensions] destination_number(+12105552600) =~ /^(10[01][0-9])$/ break=on-false
Dialplan: sofia/external/+19185555555@xyz.pstn.twilio.com parsing [public->public_did] continue=false
Dialplan: sofia/external/+19185555555@xyz.pstn.twilio.com Regex (FAIL) [public_did] destination_number(+12105552600) =~ /^15123330880$/ break=on-false
Dialplan: sofia/external/+19185555555@xyz.pstn.twilio.com parsing [public->public_did] continue=false
Dialplan: sofia/external/+19185555555@xyz.pstn.twilio.com Regex (FAIL) [public_did] destination_number(+12105552600) =~ /^17023024016$/ break=on-false
Dialplan: sofia/external/+19185555555@xyz.pstn.twilio.com parsing [public->public_did] continue=false
Dialplan: sofia/external/+19185555555@xyz.pstn.twilio.com Regex (FAIL) [public_did] destination_number(+12105552600) =~ /^883510009027723$/ break=on-false
Dialplan: sofia/external/+19185555555@xyz.pstn.twilio.com parsing [public->public_did] continue=false
Dialplan: sofia/external/+19185555555@xyz.pstn.twilio.com Regex (FAIL) [public_did] destination_number(+12105552600) =~ /^12105552600$/ break=on-false
Dialplan: sofia/external/+19185555555@xyz.pstn.twilio.com parsing [public->outbound_sip] continue=false
Dialplan: sofia/external/+19185555555@xyz.pstn.twilio.com Regex (FAIL) [outbound_sip] ${sip_to_uri}(+12105552600@host.domain.xyz:5080) =~ /^([a-z][0-9a-z-]*\@[0-9a-z.-]+)$/ break=on-false
2017-07-20 23:39:06.930644 [DEBUG] switch_core_state_machine.c:286 (sofia/external/+19185555555@xyz.pstn.twilio.com) State Change CS_ROUTING -> CS_EXECUTE
2017-07-20 23:39:06.930644 [DEBUG] switch_core_state_machine.c:643 (sofia/external/+19185555555@xyz.pstn.twilio.com) State ROUTING going to sleep
2017-07-20 23:39:06.930644 [DEBUG] switch_core_state_machine.c:584 (sofia/external/+19185555555@xyz.pstn.twilio.com) Running State Change CS_EXECUTE (Cur 1 Tot 10)
2017-07-20 23:39:06.930644 [DEBUG] switch_core_state_machine.c:650 (sofia/external/+19185555555@xyz.pstn.twilio.com) State EXECUTE
2017-07-20 23:39:06.930644 [DEBUG] mod_sofia.c:209 sofia/external/+19185555555@xyz.pstn.twilio.com SOFIA EXECUTE
2017-07-20 23:39:06.930644 [DEBUG] switch_core_state_machine.c:328 sofia/external/+19185555555@xyz.pstn.twilio.com Standard EXECUTE
EXECUTE sofia/external/+19185555555@xyz.pstn.twilio.com set(outside_call=true)
2017-07-20 23:39:06.930644 [DEBUG] mod_dptools.c:1588 SET sofia/external/+19185555555@xyz.pstn.twilio.com [outside_call]=[true]
EXECUTE sofia/external/+19185555555@xyz.pstn.twilio.com export(RFC2822_DATE=Thu, 20 Jul 2017 23:39:06 -0700)
2017-07-20 23:39:06.930644 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Thu, 20 Jul 2017 23:39:06 -0700]
2017-07-20 23:39:06.930644 [NOTICE] switch_core_state_machine.c:385 sofia/external/+19185555555@xyz.pstn.twilio.com has executed the last dialplan instruction, hanging up.
2017-07-20 23:39:06.930644 [NOTICE] switch_core_state_machine.c:387 Hangup sofia/external/+19185555555@xyz.pstn.twilio.com [CS_EXECUTE] [NORMAL_CLEARING]
2017-07-20 23:39:06.930644 [DEBUG] switch_core_state_machine.c:650 (sofia/external/+19185555555@xyz.pstn.twilio.com) State EXECUTE going to sleep
2017-07-20 23:39:06.930644 [DEBUG] switch_core_state_machine.c:584 (sofia/external/+19185555555@xyz.pstn.twilio.com) Running State Change CS_HANGUP (Cur 1 Tot 10)
2017-07-20 23:39:06.930644 [DEBUG] switch_core_state_machine.c:850 (sofia/external/+19185555555@xyz.pstn.twilio.com) Callstate Change RINGING -> HANGUP
2017-07-20 23:39:06.930644 [DEBUG] switch_core_state_machine.c:852 (sofia/external/+19185555555@xyz.pstn.twilio.com) State HANGUP
2017-07-20 23:39:06.930644 [DEBUG] mod_sofia.c:449 Channel sofia/external/+19185555555@xyz.pstn.twilio.com hanging up, cause: NORMAL_CLEARING
2017-07-20 23:39:06.930644 [DEBUG] mod_sofia.c:588 Responding to INVITE with: 480
2017-07-20 23:39:06.930644 [DEBUG] switch_core_state_machine.c:60 sofia/external/+19185555555@xyz.pstn.twilio.com Standard HANGUP, cause: NORMAL_CLEARING
2017-07-20 23:39:06.930644 [DEBUG] switch_core_state_machine.c:852 (sofia/external/+19185555555@xyz.pstn.twilio.com) State HANGUP going to sleep
2017-07-20 23:39:06.930644 [DEBUG] switch_core_state_machine.c:619 (sofia/external/+19185555555@xyz.pstn.twilio.com) State Change CS_HANGUP -> CS_REPORTING
2017-07-20 23:39:06.930644 [DEBUG] switch_core_state_machine.c:584 (sofia/external/+19185555555@xyz.pstn.twilio.com) Running State Change CS_REPORTING (Cur 1 Tot 10)
send 1013 bytes to udp/[54.172.60.0]:5060 at 23:39:06.941589:
------------------------------------------------------------------------
SIP/2.0 480 Temporarily Unavailable
Via: SIP/2.0/UDP 54.172.60.0:5060;branch=z9hG4bKd173.db254ea.0
Via: SIP/2.0/UDP 172.18.17.96:5060;rport=5060;received=172.18.17.96;branch=z9hG4bKa2d2abaa-ec5c-486d-9f51-36cca6acecc2_6772d868_290-1797581531681190546
2017-07-20 23:39:06.930644 [DEBUG] switch_core_state_machine.c:938 (sofia/external/+19185555555@xyz.pstn.twilio.com) State REPORTING
Max-Forwards: 8
From: <sip:+19185555555@xyz.pstn.twilio.com;pstn-params=808482808882;cpc=ordinary>;tag=77969553_6772d868_a2d2abaa-ec5c-486d-9f51-36cca6acecc2
To: <sip:+12105552600@host.domain.xyz:5080;user=phone>;tag=cDHpDD7r1gUZg
Call-ID: 1abc80bf6ecb7fd8fe56f8121c5d4fde@0.0.0.0
CSeq: 24644 INVITE
User-Agent: FreeSWITCH-mod_sofia/1.9.0+git~20170714T201519Z~13f2f2a056~32bit
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
Supported: timer, path, replaces
Allow-Events: talk, hold, conference, refer
Reason: Q.850;cause=16;text="NORMAL_CLEARING"
Content-Length: 0
Remote-Party-ID: "+12105552600" <sip:+12105552600@host.domain.xyz>;party=calling;privacy=off;screen=no
------------------------------------------------------------------------
2017-07-20 23:39:06.950648 [DEBUG] mod_cdr_sqlite.c:102 Writing SQL to DB: INSERT INTO cdr VALUES ("+19185555555","+19185555555","+12105552600","public","2017-07-20 23:39:06","",
"2017-07-20 23:39:06",0, 0, 0,"NORMAL_CLEARING","4b75ed5c-6ddf-11e7-a95c-9ba6c317ee11","","","","",
"send_refuse","+19185555555","","DELAYED NEGOTIATION")
2017-07-20 23:39:06.950648 [DEBUG] switch_core_state_machine.c:174 sofia/external/+19185555555@xyz.pstn.twilio.com Standard REPORTING, cause: NORMAL_CLEARING
2017-07-20 23:39:06.950648 [DEBUG] switch_core_state_machine.c:938 (sofia/external/+19185555555@xyz.pstn.twilio.com) State REPORTING going to sleep
2017-07-20 23:39:06.950648 [DEBUG] switch_core_state_machine.c:610 (sofia/external/+19185555555@xyz.pstn.twilio.com) State Change CS_REPORTING -> CS_DESTROY
2017-07-20 23:39:06.950648 [DEBUG] switch_core_session.c:1713 Session 10 (sofia/external/+19185555555@xyz.pstn.twilio.com) Locked, Waiting on external entities
2017-07-20 23:39:06.950648 [NOTICE] switch_core_session.c:1731 Session 10 (sofia/external/+19185555555@xyz.pstn.twilio.com) Ended
2017-07-20 23:39:06.950648 [NOTICE] switch_core_session.c:1735 Close Channel sofia/external/+19185555555@xyz.pstn.twilio.com [CS_DESTROY]
2017-07-20 23:39:06.970637 [DEBUG] switch_core_state_machine.c:741 (sofia/external/+19185555555@xyz.pstn.twilio.com) Running State Change CS_DESTROY (Cur 0 Tot 10)
2017-07-20 23:39:06.970637 [DEBUG] switch_core_state_machine.c:751 (sofia/external/+19185555555@xyz.pstn.twilio.com) State DESTROY
2017-07-20 23:39:06.970637 [DEBUG] mod_sofia.c:354 sofia/external/+19185555555@xyz.pstn.twilio.com SOFIA DESTROY
2017-07-20 23:39:06.970637 [DEBUG] switch_core_state_machine.c:181 sofia/external/+19185555555@xyz.pstn.twilio.com Standard DESTROY
2017-07-20 23:39:06.970637 [DEBUG] switch_core_state_machine.c:751 (sofia/external/+19185555555@xyz.pstn.twilio.com) State DESTROY going to sleep
recv 477 bytes from udp/[54.172.60.0]:5060 at 23:39:07.020009:
------------------------------------------------------------------------
ACK sip:+12105552600@host.domain.xyz:5080 SIP/2.0
Via: SIP/2.0/UDP 54.172.60.0:5060;branch=z9hG4bKd173.db254ea.0
From: <sip:+19185555555@xyz.pstn.twilio.com;pstn-params=808482808882;cpc=ordinary>;tag=77969553_6772d868_a2d2abaa-ec5c-486d-9f51-36cca6acecc2
Call-ID: 1abc80bf6ecb7fd8fe56f8121c5d4fde@0.0.0.0
To: <sip:+12105552600@host.domain.xyz:5080;user=phone>;tag=cDHpDD7r1gUZg
CSeq: 24644 ACK
Max-Forwards: 70
User-Agent: Twilio Gateway
Content-Length: 0
------------------------------------------------------------------------
recv 1283 bytes from udp/[54.172.60.0]:5060 at 23:39:07.035432:
------------------------------------------------------------------------
INVITE sip:+12105552600@host.domain.xyz:5080 SIP/2.0
Record-Route: <sip:54.172.60.0:5060;lr;ftag=77188176_6772d868_4a885fd6-1513-4d88-8a23-05da680426b5>
From: <sip:+19185555555@xyz.pstn.twilio.com;pstn-params=808482808882;cpc=ordinary>;tag=77188176_6772d868_4a885fd6-1513-4d88-8a23-05da680426b5
To: <sip:+12105552600@host.domain.xyz:5080;user=phone>
CSeq: 24644 INVITE
Max-Forwards: 8
Diversion: <sip:+12105552600@public-vip.us1.twilio.com>;reason=unconditional
Call-ID: 43f08cd2aee9448fd1ddda464824a4f7@0.0.0.0
Via: SIP/2.0/UDP 54.172.60.0:5060;branch=z9hG4bKa89.728c7cf5.0
Via: SIP/2.0/UDP 172.18.12.229:5060;rport=5060;received=172.18.12.229;branch=z9hG4bK4a885fd6-1513-4d88-8a23-05da680426b5_6772d868_258-10557194566233067374
Contact: <sip:+19185555555@172.18.12.229:5060;transport=udp>
Allow: INVITE,ACK,CANCEL,BYE,OPTIONS
User-Agent: Twilio Gateway
X-Twilio-AccountSid: AC8b53e1937b9b71f1398aa93b989acc65
Content-Type: application/sdp
X-Twilio-CallSid: CA89fc4d397b25af1c13acc087fdbd4f24
Content-Length: 240
v=0
o=root 1209756446 1209756446 IN IP4 34.203.251.183
s=Twilio Media Gateway
c=IN IP4 34.203.251.183
t=0 0
m=audio 19538 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
------------------------------------------------------------------------
2017-07-20 23:39:07.030619 [NOTICE] switch_channel.c:1104 New Channel sofia/external/+19185555555@xyz.pstn.twilio.com [4b8736ac-6ddf-11e7-a960-9ba6c317ee11]
2017-07-20 23:39:07.030619 [DEBUG] switch_core_state_machine.c:584 (sofia/external/+19185555555@xyz.pstn.twilio.com) Running State Change CS_NEW (Cur 1 Tot 11)
2017-07-20 23:39:07.030619 [DEBUG] sofia.c:10067 sofia/external/+19185555555@xyz.pstn.twilio.com receiving invite from 54.172.60.0:5060 version: 1.9.0 git 13f2f2a 2017-07-14 20:15:19Z 32bit
2017-07-20 23:39:07.030619 [DEBUG] sofia.c:7283 Channel sofia/external/+19185555555@xyz.pstn.twilio.com entering state [received][100]
2017-07-20 23:39:07.030619 [DEBUG] sofia.c:7293 Remote SDP:
v=0
o=root 1209756446 1209756446 IN IP4 34.203.251.183
s=Twilio Media Gateway
c=IN IP4 34.203.251.183
t=0 0
m=audio 19538 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
2017-07-20 23:39:07.030619 [DEBUG] sofia.c:7685 (sofia/external/+19185555555@xyz.pstn.twilio.com) State Change CS_NEW -> CS_INIT
2017-07-20 23:39:07.030619 [DEBUG] switch_core_state_machine.c:603 (sofia/external/+19185555555@xyz.pstn.twilio.com) State NEW
2017-07-20 23:39:07.030619 [DEBUG] switch_core_state_machine.c:584 (sofia/external/+19185555555@xyz.pstn.twilio.com) Running State Change CS_INIT (Cur 1 Tot 11)
2017-07-20 23:39:07.030619 [DEBUG] switch_core_state_machine.c:627 (sofia/external/+19185555555@xyz.pstn.twilio.com) State INIT
2017-07-20 23:39:07.030619 [DEBUG] mod_sofia.c:93 sofia/external/+19185555555@xyz.pstn.twilio.com SOFIA INIT
2017-07-20 23:39:07.030619 [DEBUG] switch_core_state_machine.c:40 sofia/external/+19185555555@xyz.pstn.twilio.com Standard INIT
2017-07-20 23:39:07.030619 [DEBUG] switch_core_state_machine.c:48 (sofia/external/+19185555555@xyz.pstn.twilio.com) State Change CS_INIT -> CS_ROUTING
2017-07-20 23:39:07.030619 [DEBUG] switch_core_state_machine.c:627 (sofia/external/+19185555555@xyz.pstn.twilio.com) State INIT going to sleep
2017-07-20 23:39:07.030619 [DEBUG] switch_core_state_machine.c:584 (sofia/external/+19185555555@xyz.pstn.twilio.com) Running State Change CS_ROUTING (Cur 1 Tot 11)
2017-07-20 23:39:07.030619 [DEBUG] switch_channel.c:2249 (sofia/external/+19185555555@xyz.pstn.twilio.com) Callstate Change DOWN -> RINGING
2017-07-20 23:39:07.030619 [DEBUG] switch_core_state_machine.c:643 (sofia/external/+19185555555@xyz.pstn.twilio.com) State ROUTING
2017-07-20 23:39:07.030619 [DEBUG] mod_sofia.c:154 sofia/external/+19185555555@xyz.pstn.twilio.com SOFIA ROUTING
2017-07-20 23:39:07.030619 [DEBUG] switch_core_state_machine.c:236 sofia/external/+19185555555@xyz.pstn.twilio.com Standard ROUTING
2017-07-20 23:39:07.030619 [INFO] mod_dialplan_xml.c:637 Processing +19185555555 <+19185555555>->+12105552600 in context public
send 460 bytes to udp/[54.172.60.0]:5060 at 23:39:07.044121:
------------------------------------------------------------------------
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 54.172.60.0:5060;branch=z9hG4bKa89.728c7cf5.0
From: <sip:+19185555555@xyz.pstn.twilio.com;pstn-params=808482808882;cpc=ordinary>;tag=77188176_6772d868_4a885fd6-1513-4d88-8a23-05da680426b5
To: <sip:+12105552600@host.domain.xyz:5080;user=phone>
Call-ID: 43f08cd2aee9448fd1ddda464824a4f7@0.0.0.0
CSeq: 24644 INVITE
User-Agent: FreeSWITCH-mod_sofia/1.9.0+git~20170714T201519Z~13f2f2a056~32bit
Content-Length: 0
------------------------------------------------------------------------
Dialplan: sofia/external/+19185555555@xyz.pstn.twilio.com parsing [public->unloop] continue=false
Dialplan: sofia/external/+19185555555@xyz.pstn.twilio.com Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/external/+19185555555@xyz.pstn.twilio.com Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/external/+19185555555@xyz.pstn.twilio.com parsing [public->outside_call] continue=true
Dialplan: sofia/external/+19185555555@xyz.pstn.twilio.com Absolute Condition [outside_call]
Dialplan: sofia/external/+19185555555@xyz.pstn.twilio.com Action set(outside_call=true)
Dialplan: sofia/external/+19185555555@xyz.pstn.twilio.com Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
Dialplan: sofia/external/+19185555555@xyz.pstn.twilio.com parsing [public->call_debug] continue=true
Dialplan: sofia/external/+19185555555@xyz.pstn.twilio.com Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never
Dialplan: sofia/external/+19185555555@xyz.pstn.twilio.com parsing [public->public_extensions] continue=false
Dialplan: sofia/external/+19185555555@xyz.pstn.twilio.com Regex (FAIL) [public_extensions] destination_number(+12105552600) =~ /^(10[01][0-9])$/ break=on-false
Dialplan: sofia/external/+19185555555@xyz.pstn.twilio.com parsing [public->public_did] continue=false
Dialplan: sofia/external/+19185555555@xyz.pstn.twilio.com Regex (FAIL) [public_did] destination_number(+12105552600) =~ /^15123330880$/ break=on-false
Dialplan: sofia/external/+19185555555@xyz.pstn.twilio.com parsing [public->public_did] continue=false
Dialplan: sofia/external/+19185555555@xyz.pstn.twilio.com Regex (FAIL) [public_did] destination_number(+12105552600) =~ /^17023024016$/ break=on-false
Dialplan: sofia/external/+19185555555@xyz.pstn.twilio.com parsing [public->public_did] continue=false
Dialplan: sofia/external/+19185555555@xyz.pstn.twilio.com Regex (FAIL) [public_did] destination_number(+12105552600) =~ /^883510009027723$/ break=on-false
Dialplan: sofia/external/+19185555555@xyz.pstn.twilio.com parsing [public->public_did] continue=false
Dialplan: sofia/external/+19185555555@xyz.pstn.twilio.com Regex (FAIL) [public_did] destination_number(+12105552600) =~ /^12105552600$/ break=on-false
Dialplan: sofia/external/+19185555555@xyz.pstn.twilio.com parsing [public->outbound_sip] continue=false
Dialplan: sofia/external/+19185555555@xyz.pstn.twilio.com Regex (FAIL) [outbound_sip] ${sip_to_uri}(+12105552600@host.domain.xyz:5080) =~ /^([a-z][0-9a-z-]*\@[0-9a-z.-]+)$/ break=on-false
2017-07-20 23:39:07.030619 [DEBUG] switch_core_state_machine.c:286 (sofia/external/+19185555555@xyz.pstn.twilio.com) State Change CS_ROUTING -> CS_EXECUTE
2017-07-20 23:39:07.030619 [DEBUG] switch_core_state_machine.c:643 (sofia/external/+19185555555@xyz.pstn.twilio.com) State ROUTING going to sleep
2017-07-20 23:39:07.030619 [DEBUG] switch_core_state_machine.c:584 (sofia/external/+19185555555@xyz.pstn.twilio.com) Running State Change CS_EXECUTE (Cur 1 Tot 11)
2017-07-20 23:39:07.030619 [DEBUG] switch_core_state_machine.c:650 (sofia/external/+19185555555@xyz.pstn.twilio.com) State EXECUTE
2017-07-20 23:39:07.030619 [DEBUG] mod_sofia.c:209 sofia/external/+19185555555@xyz.pstn.twilio.com SOFIA EXECUTE
2017-07-20 23:39:07.030619 [DEBUG] switch_core_state_machine.c:328 sofia/external/+19185555555@xyz.pstn.twilio.com Standard EXECUTE
EXECUTE sofia/external/+19185555555@xyz.pstn.twilio.com set(outside_call=true)
2017-07-20 23:39:07.030619 [DEBUG] mod_dptools.c:1588 SET sofia/external/+19185555555@xyz.pstn.twilio.com [outside_call]=[true]
EXECUTE sofia/external/+19185555555@xyz.pstn.twilio.com export(RFC2822_DATE=Thu, 20 Jul 2017 23:39:07 -0700)
2017-07-20 23:39:07.050651 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Thu, 20 Jul 2017 23:39:07 -0700]
2017-07-20 23:39:07.050651 [NOTICE] switch_core_state_machine.c:385 sofia/external/+19185555555@xyz.pstn.twilio.com has executed the last dialplan instruction, hanging up.
2017-07-20 23:39:07.050651 [NOTICE] switch_core_state_machine.c:387 Hangup sofia/external/+19185555555@xyz.pstn.twilio.com [CS_EXECUTE] [NORMAL_CLEARING]
2017-07-20 23:39:07.050651 [DEBUG] switch_core_state_machine.c:650 (sofia/external/+19185555555@xyz.pstn.twilio.com) State EXECUTE going to sleep
2017-07-20 23:39:07.050651 [DEBUG] switch_core_state_machine.c:584 (sofia/external/+19185555555@xyz.pstn.twilio.com) Running State Change CS_HANGUP (Cur 1 Tot 11)
2017-07-20 23:39:07.050651 [DEBUG] switch_core_state_machine.c:850 (sofia/external/+19185555555@xyz.pstn.twilio.com) Callstate Change RINGING -> HANGUP
2017-07-20 23:39:07.050651 [DEBUG] switch_core_state_machine.c:852 (sofia/external/+19185555555@xyz.pstn.twilio.com) State HANGUP
2017-07-20 23:39:07.050651 [DEBUG] mod_sofia.c:449 Channel sofia/external/+19185555555@xyz.pstn.twilio.com hanging up, cause: NORMAL_CLEARING
2017-07-20 23:39:07.050651 [DEBUG] mod_sofia.c:588 Responding to INVITE with: 480
2017-07-20 23:39:07.050651 [DEBUG] switch_core_state_machine.c:60 sofia/external/+19185555555@xyz.pstn.twilio.com Standard HANGUP, cause: NORMAL_CLEARING
2017-07-20 23:39:07.050651 [DEBUG] switch_core_state_machine.c:852 (sofia/external/+19185555555@xyz.pstn.twilio.com) State HANGUP going to sleep
2017-07-20 23:39:07.050651 [DEBUG] switch_core_state_machine.c:619 (sofia/external/+19185555555@xyz.pstn.twilio.com) State Change CS_HANGUP -> CS_REPORTING
2017-07-20 23:39:07.050651 [DEBUG] switch_core_state_machine.c:584 (sofia/external/+19185555555@xyz.pstn.twilio.com) Running State Change CS_REPORTING (Cur 1 Tot 11)
send 1016 bytes to udp/[54.172.60.0]:5060 at 23:39:07.056140:
------------------------------------------------------------------------
SIP/2.0 480 Temporarily Unavailable
Via: SIP/2.0/UDP 54.172.60.0:5060;branch=z9hG4bKa89.728c7cf5.0
Via: SIP/2.0/UDP 172.18.12.229:5060;rport=5060;received=172.18.12.229;branch=z9hG4bK4a885fd6-1513-4d88-8a23-05da680426b5_6772d868_258-10557194566233067374
Max-Forwards: 8
From: <sip:+19185555555@xyz.pstn.twilio.com;pstn-params=808482808882;cpc=ordinary>;tag=77188176_6772d868_4a885fd6-1513-4d88-8a23-05da680426b5
2017-07-20 23:39:07.050651 [DEBUG] switch_core_state_machine.c:938 (sofia/external/+19185555555@xyz.pstn.twilio.com) State REPORTING
To: <sip:+12105552600@host.domain.xyz:5080;user=phone>;tag=DpaFF8QvySHjc
Call-ID: 43f08cd2aee9448fd1ddda464824a4f7@0.0.0.0
CSeq: 24644 INVITE
User-Agent: FreeSWITCH-mod_sofia/1.9.0+git~20170714T201519Z~13f2f2a056~32bit
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
Supported: timer, path, replaces
Allow-Events: talk, hold, conference, refer
Reason: Q.850;cause=16;text="NORMAL_CLEARING"
Content-Length: 0
Remote-Party-ID: "+12105552600" <sip:+12105552600@host.domain.xyz>;party=calling;privacy=off;screen=no
------------------------------------------------------------------------
2017-07-20 23:39:07.070649 [DEBUG] mod_cdr_sqlite.c:102 Writing SQL to DB: INSERT INTO cdr VALUES ("+19185555555","+19185555555","+12105552600","public","2017-07-20 23:39:07","",
"2017-07-20 23:39:07",0, 0, 0,"NORMAL_CLEARING","4b8736ac-6ddf-11e7-a960-9ba6c317ee11","","","","",
"send_refuse","+19185555555","","DELAYED NEGOTIATION")
2017-07-20 23:39:07.070649 [DEBUG] switch_core_state_machine.c:174 sofia/external/+19185555555@xyz.pstn.twilio.com Standard REPORTING, cause: NORMAL_CLEARING
2017-07-20 23:39:07.070649 [DEBUG] switch_core_state_machine.c:938 (sofia/external/+19185555555@xyz.pstn.twilio.com) State REPORTING going to sleep
2017-07-20 23:39:07.070649 [DEBUG] switch_core_state_machine.c:610 (sofia/external/+19185555555@xyz.pstn.twilio.com) State Change CS_REPORTING -> CS_DESTROY
2017-07-20 23:39:07.070649 [DEBUG] switch_core_session.c:1713 Session 11 (sofia/external/+19185555555@xyz.pstn.twilio.com) Locked, Waiting on external entities
2017-07-20 23:39:07.070649 [NOTICE] switch_core_session.c:1731 Session 11 (sofia/external/+19185555555@xyz.pstn.twilio.com) Ended
2017-07-20 23:39:07.070649 [NOTICE] switch_core_session.c:1735 Close Channel sofia/external/+19185555555@xyz.pstn.twilio.com [CS_DESTROY]
2017-07-20 23:39:07.070649 [DEBUG] switch_core_state_machine.c:741 (sofia/external/+19185555555@xyz.pstn.twilio.com) Running State Change CS_DESTROY (Cur 0 Tot 11)
2017-07-20 23:39:07.070649 [DEBUG] switch_core_state_machine.c:751 (sofia/external/+19185555555@xyz.pstn.twilio.com) State DESTROY
2017-07-20 23:39:07.070649 [DEBUG] mod_sofia.c:354 sofia/external/+19185555555@xyz.pstn.twilio.com SOFIA DESTROY
2017-07-20 23:39:07.070649 [DEBUG] switch_core_state_machine.c:181 sofia/external/+19185555555@xyz.pstn.twilio.com Standard DESTROY
2017-07-20 23:39:07.070649 [DEBUG] switch_core_state_machine.c:751 (sofia/external/+19185555555@xyz.pstn.twilio.com) State DESTROY going to sleep
recv 477 bytes from udp/[54.172.60.0]:5060 at 23:39:07.134629:
------------------------------------------------------------------------
ACK sip:+12105552600@host.domain.xyz:5080 SIP/2.0
Via: SIP/2.0/UDP 54.172.60.0:5060;branch=z9hG4bKa89.728c7cf5.0
From: <sip:+19185555555@xyz.pstn.twilio.com;pstn-params=808482808882;cpc=ordinary>;tag=77188176_6772d868_4a885fd6-1513-4d88-8a23-05da680426b5
Call-ID: 43f08cd2aee9448fd1ddda464824a4f7@0.0.0.0
To: <sip:+12105552600@host.domain.xyz:5080;user=phone>;tag=DpaFF8QvySHjc
CSeq: 24644 ACK
Max-Forwards: 70
User-Agent: Twilio Gateway
Content-Length: 0
------------------------------------------------------------------------
recv 561 bytes from tcp/[216.115.69.144]:5060 at 23:39:08.190560:
------------------------------------------------------------------------
OPTIONS sip:70.170.169.54:52255;transport=tcp SIP/2.0
Max-Forwards: 10
Record-Route: <sip:216.115.69.144;transport=tcp;r2=on;lr>
Record-Route: <sip:216.115.69.144;r2=on;lr>
Via: SIP/2.0/TCP 216.115.69.144;branch=z9hG4bK9bce.6a02dcb223963f2ad9d9a7df269e5104.0
Via: SIP/2.0/UDP 70.167.153.136:5060;branch=0
Route: <sip:216.115.69.144;lr;received='sip:70.170.169.54:52255;transport=tcp'>
From: sip:ping@invalid;tag=4d0b04d5
To: sip:70.170.169.54:52255;transport=tcp
Call-ID: 85612d53-24090897-158b232@70.167.153.136
CSeq: 1 OPTIONS
Content-Length: 0
------------------------------------------------------------------------
send 801 bytes to tcp/[216.115.69.144]:5060 at 23:39:08.192162:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/TCP 216.115.69.144;branch=z9hG4bK9bce.6a02dcb223963f2ad9d9a7df269e5104.0;rport=5060
Via: SIP/2.0/UDP 70.167.153.136:5060;branch=0
Record-Route: <sip:216.115.69.144;transport=tcp;r2=on;lr>
Record-Route: <sip:216.115.69.144;r2=on;lr>
From: sip:ping@invalid;tag=4d0b04d5
To: <sip:70.170.169.54:52255>;transport=tcp;tag=eZ37g38ZU274Q
Call-ID: 85612d53-24090897-158b232@70.167.153.136
CSeq: 1 OPTIONS
Contact: <sip:gw+flowroute@70.170.169.54:5080;transport=tcp;gw=flowroute>
User-Agent: FreeSWITCH-mod_sofia/1.9.0+git~20170714T201519Z~13f2f2a056~32bit
Accept: application/sdp
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
Supported: timer, path, replaces
Allow-Events: talk, hold, conference, refer
Content-Length: 0
------------------------------------------------------------------------