2016-05-23 11:13:40.149854 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/3000@10.30.80.37 [6976d8d1-c952-40cf-9963-eb00f4256bd8] 2016-05-23 11:13:40.149854 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/3000@10.30.80.37) Running State Change CS_NEW 2016-05-23 11:13:40.149854 [DEBUG] sofia.c:9376 sofia/internal/3000@10.30.80.37 receiving invite from 10.2.250.73:63361 version: 1.6.8 git 99de0ad 2016-05-05 15:38:32Z 64bit 2016-05-23 11:13:40.149854 [DEBUG] sofia.c:9488 IP 10.2.250.73 Approved by acl "domains[]". Access Granted. 2016-05-23 11:13:40.149854 [DEBUG] sofia.c:6858 Channel sofia/internal/3000@10.30.80.37 entering state [received][100] 2016-05-23 11:13:40.149854 [DEBUG] sofia.c:6868 Remote SDP: v=0 o=- 13108472028284007 1 IN IP4 10.2.251.5 s=X-Lite release 4.9.3 stamp 79961 c=IN IP4 10.2.251.5 t=0 0 m=audio 51114 RTP/AVP 9 8 120 0 84 101 a=rtpmap:120 opus/48000/2 a=fmtp:120 useinbandfec=1; usedtx=1; maxaveragebitrate=64000 a=rtpmap:84 speex/16000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 2016-05-23 11:13:40.149854 [DEBUG] sofia.c:7227 (sofia/internal/3000@10.30.80.37) State Change CS_NEW -> CS_INIT 2016-05-23 11:13:40.149854 [DEBUG] switch_core_state_machine.c:562 (sofia/internal/3000@10.30.80.37) State NEW 2016-05-23 11:13:40.149854 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/3000@10.30.80.37) Running State Change CS_INIT 2016-05-23 11:13:40.149854 [DEBUG] switch_core_state_machine.c:586 (sofia/internal/3000@10.30.80.37) State INIT 2016-05-23 11:13:40.149854 [DEBUG] mod_sofia.c:89 sofia/internal/3000@10.30.80.37 SOFIA INIT 2016-05-23 11:13:40.149854 [DEBUG] switch_core_state_machine.c:40 sofia/internal/3000@10.30.80.37 Standard INIT 2016-05-23 11:13:40.149854 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/3000@10.30.80.37) State Change CS_INIT -> CS_ROUTING 2016-05-23 11:13:40.149854 [DEBUG] switch_core_state_machine.c:586 (sofia/internal/3000@10.30.80.37) State INIT going to sleep 2016-05-23 11:13:40.149854 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/3000@10.30.80.37) Running State Change CS_ROUTING 2016-05-23 11:13:40.149854 [DEBUG] switch_channel.c:2249 (sofia/internal/3000@10.30.80.37) Callstate Change DOWN -> RINGING 2016-05-23 11:13:40.149854 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/3000@10.30.80.37) State ROUTING 2016-05-23 11:13:40.149854 [DEBUG] mod_sofia.c:142 sofia/internal/3000@10.30.80.37 SOFIA ROUTING 2016-05-23 11:13:40.149854 [DEBUG] switch_core_state_machine.c:236 sofia/internal/3000@10.30.80.37 Standard ROUTING 2016-05-23 11:13:40.149854 [INFO] mod_dialplan_xml.c:637 Processing 3000 <3000>->2000 in context public Dialplan: sofia/internal/3000@10.30.80.37 parsing [public->unloop] continue=false Dialplan: sofia/internal/3000@10.30.80.37 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: sofia/internal/3000@10.30.80.37 parsing [public->outside_call] continue=true Dialplan: sofia/internal/3000@10.30.80.37 Absolute Condition [outside_call] Dialplan: sofia/internal/3000@10.30.80.37 Action set(outside_call=true) Dialplan: sofia/internal/3000@10.30.80.37 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) Dialplan: sofia/internal/3000@10.30.80.37 parsing [public->call_debug] continue=true Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never Dialplan: sofia/internal/3000@10.30.80.37 parsing [public->public_extensions] continue=false Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [public_extensions] destination_number(2000) =~ /^(10[01][0-9])$/ break=on-false Dialplan: sofia/internal/3000@10.30.80.37 parsing [public->public_did] continue=false Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [public_did] destination_number(2000) =~ /^(5551212)$/ break=on-false Dialplan: sofia/internal/3000@10.30.80.37 parsing [public->Calls from Charlotte Freeswitch-TEST] continue=false Dialplan: sofia/internal/3000@10.30.80.37 Regex (FAIL) [Calls from Charlotte Freeswitch-TEST] destination_number(2000) =~ /^(300[0-9])$/ break=on-false 2016-05-23 11:13:40.149854 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/3000@10.30.80.37) State Change CS_ROUTING -> CS_EXECUTE 2016-05-23 11:13:40.149854 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/3000@10.30.80.37) State ROUTING going to sleep 2016-05-23 11:13:40.149854 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/3000@10.30.80.37) Running State Change CS_EXECUTE 2016-05-23 11:13:40.149854 [DEBUG] switch_core_state_machine.c:609 (sofia/internal/3000@10.30.80.37) State EXECUTE 2016-05-23 11:13:40.149854 [DEBUG] mod_sofia.c:197 sofia/internal/3000@10.30.80.37 SOFIA EXECUTE 2016-05-23 11:13:40.149854 [DEBUG] switch_core_state_machine.c:328 sofia/internal/3000@10.30.80.37 Standard EXECUTE EXECUTE sofia/internal/3000@10.30.80.37 set(outside_call=true) 2016-05-23 11:13:40.149854 [DEBUG] mod_dptools.c:1519 SET sofia/internal/3000@10.30.80.37 [outside_call]=[true] EXECUTE sofia/internal/3000@10.30.80.37 export(RFC2822_DATE=Mon, 23 May 2016 11:13:40 +0100) 2016-05-23 11:13:40.149854 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Mon, 23 May 2016 11:13:40 +0100] 2016-05-23 11:13:40.149854 [NOTICE] switch_core_state_machine.c:385 sofia/internal/3000@10.30.80.37 has executed the last dialplan instruction, hanging up. 2016-05-23 11:13:40.149854 [NOTICE] switch_core_state_machine.c:387 Hangup sofia/internal/3000@10.30.80.37 [CS_EXECUTE] [NORMAL_CLEARING] 2016-05-23 11:13:40.149854 [DEBUG] switch_core_state_machine.c:609 (sofia/internal/3000@10.30.80.37) State EXECUTE going to sleep 2016-05-23 11:13:40.149854 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/3000@10.30.80.37) Running State Change CS_HANGUP 2016-05-23 11:13:40.149854 [DEBUG] switch_core_state_machine.c:809 (sofia/internal/3000@10.30.80.37) Callstate Change RINGING -> HANGUP 2016-05-23 11:13:40.149854 [DEBUG] switch_core_state_machine.c:811 (sofia/internal/3000@10.30.80.37) State HANGUP 2016-05-23 11:13:40.149854 [DEBUG] mod_sofia.c:437 Channel sofia/internal/3000@10.30.80.37 hanging up, cause: NORMAL_CLEARING 2016-05-23 11:13:40.149854 [DEBUG] mod_sofia.c:574 Responding to INVITE with: 480 2016-05-23 11:13:40.149854 [DEBUG] switch_core_state_machine.c:60 sofia/internal/3000@10.30.80.37 Standard HANGUP, cause: NORMAL_CLEARING 2016-05-23 11:13:40.149854 [DEBUG] switch_core_state_machine.c:811 (sofia/internal/3000@10.30.80.37) State HANGUP going to sleep 2016-05-23 11:13:40.149854 [DEBUG] switch_core_state_machine.c:578 (sofia/internal/3000@10.30.80.37) State Change CS_HANGUP -> CS_REPORTING 2016-05-23 11:13:40.149854 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/3000@10.30.80.37) Running State Change CS_REPORTING 2016-05-23 11:13:40.149854 [DEBUG] switch_core_state_machine.c:897 (sofia/internal/3000@10.30.80.37) State REPORTING 2016-05-23 11:13:40.149854 [DEBUG] switch_core_state_machine.c:174 sofia/internal/3000@10.30.80.37 Standard REPORTING, cause: NORMAL_CLEARING 2016-05-23 11:13:40.149854 [DEBUG] switch_core_state_machine.c:897 (sofia/internal/3000@10.30.80.37) State REPORTING going to sleep 2016-05-23 11:13:40.149854 [DEBUG] switch_core_state_machine.c:569 (sofia/internal/3000@10.30.80.37) State Change CS_REPORTING -> CS_DESTROY 2016-05-23 11:13:40.149854 [DEBUG] switch_core_session.c:1646 Session 165 (sofia/internal/3000@10.30.80.37) Locked, Waiting on external entities 2016-05-23 11:13:40.149854 [NOTICE] switch_core_session.c:1664 Session 165 (sofia/internal/3000@10.30.80.37) Ended 2016-05-23 11:13:40.149854 [NOTICE] switch_core_session.c:1668 Close Channel sofia/internal/3000@10.30.80.37 [CS_DESTROY] 2016-05-23 11:13:40.149854 [DEBUG] switch_core_state_machine.c:700 (sofia/internal/3000@10.30.80.37) Running State Change CS_DESTROY 2016-05-23 11:13:40.149854 [DEBUG] switch_core_state_machine.c:710 (sofia/internal/3000@10.30.80.37) State DESTROY 2016-05-23 11:13:40.149854 [DEBUG] mod_sofia.c:342 sofia/internal/3000@10.30.80.37 SOFIA DESTROY 2016-05-23 11:13:40.149854 [DEBUG] switch_core_state_machine.c:181 sofia/internal/3000@10.30.80.37 Standard DESTROY 2016-05-23 11:13:40.149854 [DEBUG] switch_core_state_machine.c:710 (sofia/internal/3000@10.30.80.37) State DESTROY going to sleep