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: From: ;tag=77969553_6772d868_a2d2abaa-ec5c-486d-9f51-36cca6acecc2 To: CSeq: 24644 INVITE Max-Forwards: 8 Diversion: ;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: 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: ;tag=77969553_6772d868_a2d2abaa-ec5c-486d-9f51-36cca6acecc2 To: 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: ;tag=77969553_6772d868_a2d2abaa-ec5c-486d-9f51-36cca6acecc2 To: ;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" ;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: ;tag=77969553_6772d868_a2d2abaa-ec5c-486d-9f51-36cca6acecc2 Call-ID: 1abc80bf6ecb7fd8fe56f8121c5d4fde@0.0.0.0 To: ;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: From: ;tag=77188176_6772d868_4a885fd6-1513-4d88-8a23-05da680426b5 To: CSeq: 24644 INVITE Max-Forwards: 8 Diversion: ;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: 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: ;tag=77188176_6772d868_4a885fd6-1513-4d88-8a23-05da680426b5 To: 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: ;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: ;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" ;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: ;tag=77188176_6772d868_4a885fd6-1513-4d88-8a23-05da680426b5 Call-ID: 43f08cd2aee9448fd1ddda464824a4f7@0.0.0.0 To: ;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: Record-Route: 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: 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: Record-Route: From: sip:ping@invalid;tag=4d0b04d5 To: ;transport=tcp;tag=eZ37g38ZU274Q Call-ID: 85612d53-24090897-158b232@70.167.153.136 CSeq: 1 OPTIONS Contact: 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 ------------------------------------------------------------------------