2017-06-09 13:21:00.874588 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
2017-06-09 13:21:00.874588 [NOTICE] switch_channel.c:1104 New Channel sofia/external/8872 [f78c431e-3f59-4788-91f1-68156ec15a03]
2017-06-09 13:21:00.874588 [DEBUG] mod_sofia.c:4819 (sofia/external/8872) State Change CS_NEW -> CS_INIT
2017-06-09 13:21:00.874588 [DEBUG] switch_core_session.c:614 sofia/external/8872 set UUID=f78c431e-3f59-4788-91f1-68156ec15a03
2017-06-09 13:21:00.874588 [DEBUG] switch_core_state_machine.c:584 (sofia/external/8872) Running State Change CS_INIT (Cur 1 Tot 15)
2017-06-09 13:21:00.874588 [DEBUG] switch_core_state_machine.c:627 (sofia/external/8872) State INIT
2017-06-09 13:21:00.874588 [DEBUG] mod_sofia.c:90 sofia/external/8872 SOFIA INIT
2017-06-09 13:21:00.874588 [DEBUG] sofia_glue.c:1295 sofia/external/8872 sending invite version: 1.6.17 git 7f84782 2017-05-15 23:00:56Z 64bit
Local SDP:
v=0
o=FreeSWITCH 1496994206 1496994207 IN IP4 192.
s=FreeSWITCH
c=IN IP4 1removed
t=0 0
m=audio 16654 RTP/AVP 0 8 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

2017-06-09 13:21:00.874588 [DEBUG] switch_core_state_machine.c:40 sofia/external/8872 Standard INIT
2017-06-09 13:21:00.874588 [DEBUG] switch_core_state_machine.c:48 (sofia/external/8872) State Change CS_INIT -> CS_ROUTING
2017-06-09 13:21:00.874588 [DEBUG] switch_core_state_machine.c:627 (sofia/external/8872) State INIT going to sleep
2017-06-09 13:21:00.874588 [DEBUG] switch_core_state_machine.c:584 (sofia/external/8872) Running State Change CS_ROUTING (Cur 1 Tot 15)
2017-06-09 13:21:00.874588 [DEBUG] sofia.c:7048 Channel sofia/external/8872 entering state [calling][0]
2017-06-09 13:21:00.874588 [DEBUG] switch_core_state_machine.c:643 (sofia/external/8872) State ROUTING
2017-06-09 13:21:00.874588 [DEBUG] mod_sofia.c:143 sofia/external/8872 SOFIA ROUTING
2017-06-09 13:21:00.874588 [DEBUG] switch_ivr_originate.c:67 (sofia/external/8872) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2017-06-09 13:21:00.874588 [DEBUG] switch_core_state_machine.c:643 (sofia/external/8872) State ROUTING going to sleep
2017-06-09 13:21:00.874588 [DEBUG] switch_core_state_machine.c:584 (sofia/external/8872) Running State Change CS_CONSUME_MEDIA (Cur 1 Tot 15)
2017-06-09 13:21:00.874588 [DEBUG] switch_core_state_machine.c:662 (sofia/external/8872) State CONSUME_MEDIA
2017-06-09 13:21:00.874588 [DEBUG] switch_core_state_machine.c:662 (sofia/external/8872) State CONSUME_MEDIA going to sleep
2017-06-09 13:21:01.334589 [NOTICE] switch_channel.c:1104 New Channel sofia/external/8911@192.168.23.127 [5085ba13-5f58-43c4-b77e-c7d0d41cae66]
2017-06-09 13:21:01.334589 [DEBUG] switch_core_state_machine.c:584 (sofia/external/8911@192.168.23.127) Running State Change CS_NEW (Cur 2 Tot 16)
2017-06-09 13:21:01.334589 [DEBUG] sofia.c:9834 sofia/external/8911@192.168.23.127 receiving invite from removed 5060 version: 1.6.17 git 7f84782 2017-05-15 23:00:56Z 64bit
2017-06-09 13:21:01.334589 [DEBUG] sofia.c:7048 Channel sofia/external/8911@192.168.23.127 entering state [received][100]
2017-06-09 13:21:01.334589 [DEBUG] sofia.c:7058 Remote SDP:
v=0
o=- 1149254514 1149254515 IN IP4 removed
s=SBC call
c=IN IP4 removed
t=0 0
m=audio 51386 RTP/AVP 0 8 101 108 102 18 4
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=rtpmap:108 AMR/8000
a=fmtp:108 mode-change-neighbor=1;mode-change-period=2
a=rtpmap:102 AMR/8000
a=rtpmap:18 G729/8000
a=rtpmap:4 G723/8000
a=ptime:20
a=curr:qos local none
a=curr:qos remote none
a=des:qos mandatory local sendrecv
a=des:qos optional remote sendrecv
a=3gOoBTC

2017-06-09 13:21:01.334589 [DEBUG] sofia.c:7450 (sofia/external/8911@192.168.23.127) State Change CS_NEW -> CS_INIT
2017-06-09 13:21:01.334589 [DEBUG] switch_core_state_machine.c:603 (sofia/external/8911@192.168.23.127) State NEW
2017-06-09 13:21:01.334589 [DEBUG] switch_core_state_machine.c:584 (sofia/external/8911@192.168.23.127) Running State Change CS_INIT (Cur 2 Tot 16)
2017-06-09 13:21:01.334589 [DEBUG] switch_core_state_machine.c:627 (sofia/external/8911@192.168.23.127) State INIT
2017-06-09 13:21:01.334589 [DEBUG] mod_sofia.c:90 sofia/external/8911@192.168.23.127 SOFIA INIT
2017-06-09 13:21:01.334589 [DEBUG] switch_core_state_machine.c:40 sofia/external/8911@192.168.23.127 Standard INIT
2017-06-09 13:21:01.334589 [DEBUG] switch_core_state_machine.c:48 (sofia/external/8911@192.168.23.127) State Change CS_INIT -> CS_ROUTING
2017-06-09 13:21:01.334589 [DEBUG] switch_core_state_machine.c:627 (sofia/external/8911@192.168.23.127) State INIT going to sleep
2017-06-09 13:21:01.334589 [DEBUG] switch_core_state_machine.c:584 (sofia/external/8911@192.168.23.127) Running State Change CS_ROUTING (Cur 2 Tot 16)
2017-06-09 13:21:01.334589 [DEBUG] switch_channel.c:2249 (sofia/external/8911@192.168.23.127) Callstate Change DOWN -> RINGING
2017-06-09 13:21:01.334589 [DEBUG] switch_core_state_machine.c:643 (sofia/external/8911@192.168.23.127) State ROUTING
2017-06-09 13:21:01.334589 [DEBUG] mod_sofia.c:143 sofia/external/8911@192.168.23.127 SOFIA ROUTING
2017-06-09 13:21:01.334589 [DEBUG] switch_core_state_machine.c:236 sofia/external/8911@192.168.23.127 Standard ROUTING
2017-06-09 13:21:01.334589 [INFO] mod_dialplan_xml.c:637 Processing 8911 <8911>->+8872 in context public
Dialplan: sofia/external/8911@192.168.23.127 parsing [public->unloop] continue=false
Dialplan: sofia/external/8911@192.168.23.127 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/external/8911@192.168.23.127 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/external/8911@192.168.23.127 parsing [public->outside_call] continue=true
Dialplan: sofia/external/8911@192.168.23.127 Absolute Condition [outside_call]
Dialplan: sofia/external/8911@192.168.23.127 Action set(outside_call=true) 
Dialplan: sofia/external/8911@192.168.23.127 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) 
Dialplan: sofia/external/8911@192.168.23.127 parsing [public->call_debug] continue=true
Dialplan: sofia/external/8911@192.168.23.127 Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never
Dialplan: sofia/external/8911@192.168.23.127 parsing [public->public_extensions] continue=false
Dialplan: sofia/external/8911@192.168.23.127 Regex (FAIL) [public_extensions] destination_number(+8872) =~ /^(10[01][0-9])$/ break=on-false
Dialplan: sofia/external/8911@192.168.23.127 parsing [public->public_did] continue=false
Dialplan: sofia/external/8911@192.168.23.127 Regex (PASS) [public_did] destination_number(+8872) =~ /^\+?(.*)$/ break=on-false
Dialplan: sofia/external/8911@192.168.23.127 Action set(bypass_media=true) 
Dialplan: sofia/external/8911@192.168.23.127 Action answer() 
Dialplan: sofia/external/8911@192.168.23.127 Action playback({loops=10}tone_stream://path=${conf_dir}/tetris.ttml) 
Dialplan: sofia/external/8911@192.168.23.127 Action playback(/usr/local/freeswitch/sounds/en/us/callie/conference/conf-enter_conf_number.wav) 
Dialplan: sofia/external/8911@192.168.23.127 Action sleep(280000) 
Dialplan: sofia/external/8911@192.168.23.127 Action playback({loops=10}tone_stream://path=${conf_dir}/tetris.ttml) 
Dialplan: sofia/external/8911@192.168.23.127 Action playback(/usr/local/freeswitch/sounds/en/us/callie/conference/conf-enter_conf_number.wav) 
Dialplan: sofia/external/8911@192.168.23.127 Action sleep(280000) 
2017-06-09 13:21:01.334589 [DEBUG] switch_core_state_machine.c:286 (sofia/external/8911@192.168.23.127) State Change CS_ROUTING -> CS_EXECUTE
2017-06-09 13:21:01.334589 [DEBUG] switch_core_state_machine.c:643 (sofia/external/8911@192.168.23.127) State ROUTING going to sleep
2017-06-09 13:21:01.334589 [DEBUG] switch_core_state_machine.c:584 (sofia/external/8911@192.168.23.127) Running State Change CS_EXECUTE (Cur 2 Tot 16)
2017-06-09 13:21:01.334589 [DEBUG] switch_core_state_machine.c:650 (sofia/external/8911@192.168.23.127) State EXECUTE
2017-06-09 13:21:01.334589 [DEBUG] mod_sofia.c:198 sofia/external/8911@192.168.23.127 SOFIA EXECUTE
2017-06-09 13:21:01.334589 [DEBUG] switch_core_state_machine.c:328 sofia/external/8911@192.168.23.127 Standard EXECUTE
EXECUTE sofia/external/8911@192.168.23.127 set(outside_call=true)
2017-06-09 13:21:01.334589 [DEBUG] mod_dptools.c:1530 SET sofia/external/8911@192.168.23.127 [outside_call]=[true]
EXECUTE sofia/external/8911@192.168.23.127 export(RFC2822_DATE=Fri, 09 Jun 2017 13:21:01 +0100)
2017-06-09 13:21:01.334589 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Fri, 09 Jun 2017 13:21:01 +0100]
EXECUTE sofia/external/8911@192.168.23.127 set(bypass_media=true)
2017-06-09 13:21:01.334589 [DEBUG] mod_dptools.c:1530 SET sofia/external/8911@192.168.23.127 [bypass_media]=[true]
EXECUTE sofia/external/8911@192.168.23.127 answer()
2017-06-09 13:21:01.334589 [DEBUG] switch_core_media.c:4432 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2017-06-09 13:21:01.334589 [DEBUG] switch_core_media.c:4487 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2017-06-09 13:21:01.334589 [DEBUG] switch_core_media.c:4432 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2017-06-09 13:21:01.334589 [DEBUG] switch_core_media.c:4432 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2017-06-09 13:21:01.334589 [DEBUG] switch_core_media.c:4432 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2017-06-09 13:21:01.334589 [DEBUG] switch_core_media.c:4487 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2017-06-09 13:21:01.334589 [DEBUG] switch_core_media.c:4348 Set telephone-event payload to 101@8000
2017-06-09 13:21:01.334589 [DEBUG] switch_core_media.c:4432 Audio Codec Compare [AMR:108:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
2017-06-09 13:21:01.334589 [DEBUG] switch_core_media.c:4432 Audio Codec Compare [AMR:108:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
2017-06-09 13:21:01.334589 [DEBUG] switch_core_media.c:4432 Audio Codec Compare [AMR:102:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
2017-06-09 13:21:01.334589 [DEBUG] switch_core_media.c:4432 Audio Codec Compare [AMR:102:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
2017-06-09 13:21:01.334589 [DEBUG] switch_core_media.c:4432 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
2017-06-09 13:21:01.334589 [DEBUG] switch_core_media.c:4432 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
2017-06-09 13:21:01.334589 [DEBUG] switch_core_media.c:4432 Audio Codec Compare [G723:4:8000:20:6300:1]/[PCMU:0:8000:20:64000:1]
2017-06-09 13:21:01.334589 [DEBUG] switch_core_media.c:4432 Audio Codec Compare [G723:4:8000:20:6300:1]/[PCMA:8:8000:20:64000:1]
2017-06-09 13:21:01.334589 [DEBUG] switch_core_media.c:3056 Set Codec sofia/external/8911@192.168.23.127 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2017-06-09 13:21:01.334589 [DEBUG] switch_core_codec.c:111 sofia/external/8911@192.168.23.127 Original read codec set to PCMU:0
2017-06-09 13:21:01.334589 [DEBUG] switch_core_media.c:4691 Set telephone-event payload to 101@8000
2017-06-09 13:21:01.334589 [DEBUG] switch_core_media.c:4750 sofia/external/8911@192.168.23.127 Set 2833 dtmf send payload to 101 recv payload to 101
2017-06-09 13:21:01.334589 [DEBUG] switch_core_media.c:6861 AUDIO RTP [sofia/external/8911@192.168.23.127] 192.168.23.127 port 26338 -> rmeoved port 51386 codec: 0 ms: 20
2017-06-09 13:21:01.334589 [DEBUG] switch_rtp.c:4107 Starting timer [soft] 160 bytes per 20ms
2017-06-09 13:21:01.334589 [DEBUG] switch_core_media.c:7162 sofia/external/8911@192.168.23.127 Set 2833 dtmf send payload to 101
2017-06-09 13:21:01.334589 [DEBUG] switch_core_media.c:7169 sofia/external/8911@192.168.23.127 Set 2833 dtmf receive payload to 101
2017-06-09 13:21:01.334589 [DEBUG] switch_core_media.c:7192 sofia/external/8911@192.168.23.127 Set rtp dtmf delay to 40
2017-06-09 13:21:01.334589 [NOTICE] sofia_media.c:92 Pre-Answer sofia/external/8911@192.168.23.127!
2017-06-09 13:21:01.334589 [DEBUG] switch_channel.c:3473 (sofia/external/8911@192.168.23.127) Callstate Change RINGING -> EARLY
2017-06-09 13:21:01.334589 [DEBUG] switch_core_media.c:6844 Audio params are unchanged for sofia/external/8911@192.168.23.127.
2017-06-09 13:21:01.334589 [DEBUG] mod_sofia.c:850 Local SDP sofia/external/8911@192.168.23.127:
v=0
o=FreeSWITCH 1496984523 1496984524 IN IP4 removed
s=FreeSWITCH
c=IN IP4 removed
t=0 0
m=audio 26338 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-06-09 13:21:01.334589 [NOTICE] mod_dptools.c:1312 Channel [sofia/external/8911@192.168.23.127] has been answered
2017-06-09 13:21:01.334589 [DEBUG] switch_channel.c:3772 (sofia/external/8911@192.168.23.127) Callstate Change EARLY -> ACTIVE
2017-06-09 13:21:01.334589 [DEBUG] sofia.c:7048 Channel sofia/external/8911@192.168.23.127 entering state [completed][200]
EXECUTE sofia/external/8911@192.168.23.127 playback({loops=10}tone_stream://path=/usr/local/freeswitch/conf/tetris.ttml)
2017-06-09 13:21:01.334589 [DEBUG] switch_ivr_play_say.c:1498 Codec Activated L16@8000hz 1 channels 20ms
2017-06-09 13:21:01.634595 [INFO] sofia.c:1279 sofia/external/8872 Update Callee ID to "Outbound Call" <+8872>
2017-06-09 13:21:01.634595 [DEBUG] sofia.c:7048 Channel sofia/external/8872 entering state [completing][200]
2017-06-09 13:21:01.634595 [DEBUG] sofia.c:7058 Remote SDP:
v=0
o=- 1149254513 1149254513 IN IP4 7removed
s=SBC call
c=IN IP4 removed
t=0 0
m=audio 49430 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=ptime:20

2017-06-09 13:21:01.634595 [DEBUG] sofia.c:7048 Channel sofia/external/8872 entering state [ready][200]
2017-06-09 13:21:01.634595 [DEBUG] switch_core_media.c:4432 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2017-06-09 13:21:01.634595 [DEBUG] switch_core_media.c:4487 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2017-06-09 13:21:01.634595 [DEBUG] switch_core_media.c:4432 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2017-06-09 13:21:01.634595 [DEBUG] switch_core_media.c:4348 Set telephone-event payload to 101@8000
2017-06-09 13:21:01.634595 [DEBUG] switch_core_media.c:3056 Set Codec sofia/external/8872 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2017-06-09 13:21:01.634595 [DEBUG] switch_core_codec.c:111 sofia/external/8872 Original read codec set to PCMU:0
2017-06-09 13:21:01.634595 [DEBUG] switch_core_media.c:4691 Set telephone-event payload to 101@8000
2017-06-09 13:21:01.634595 [DEBUG] switch_core_media.c:4750 sofia/external/8872 Set 2833 dtmf send payload to 101 recv payload to 101
2017-06-09 13:21:01.634595 [DEBUG] switch_core_media.c:6861 AUDIO RTP [sofia/external/8872] 192.168.23.127 port 16654 -> removed port 49430 codec: 0 ms: 20
2017-06-09 13:21:01.634595 [DEBUG] switch_rtp.c:4107 Starting timer [soft] 160 bytes per 20ms
2017-06-09 13:21:01.634595 [DEBUG] switch_core_media.c:7162 sofia/external/8872 Set 2833 dtmf send payload to 101
2017-06-09 13:21:01.634595 [DEBUG] switch_core_media.c:7169 sofia/external/8872 Set 2833 dtmf receive payload to 101
2017-06-09 13:21:01.634595 [DEBUG] switch_core_media.c:7192 sofia/external/8872 Set rtp dtmf delay to 40
2017-06-09 13:21:01.634595 [NOTICE] sofia.c:8182 Channel [sofia/external/8872] has been answered
2017-06-09 13:21:01.634595 [DEBUG] switch_channel.c:3772 (sofia/external/8872) Callstate Change DOWN -> ACTIVE
2017-06-09 13:21:01.634595 [DEBUG] switch_ivr_originate.c:3690 Originate Resulted in Success: [sofia/external/8872]
2017-06-09 13:21:01.634595 [INFO] switch_channel.c:3129 sofia/external/8872 Flipping CID from "" <8911> to "Outbound Call" <+8872>
2017-06-09 13:21:01.634595 [DEBUG] mod_commands.c:4809 (sofia/external/8872) State Change CS_CONSUME_MEDIA -> CS_EXECUTE
2017-06-09 13:21:01.654587 [DEBUG] switch_core_state_machine.c:584 (sofia/external/8872) Running State Change CS_EXECUTE (Cur 2 Tot 16)
2017-06-09 13:21:01.654587 [DEBUG] switch_core_state_machine.c:650 (sofia/external/8872) State EXECUTE
2017-06-09 13:21:01.654587 [DEBUG] mod_sofia.c:198 sofia/external/8872 SOFIA EXECUTE
2017-06-09 13:21:01.654587 [DEBUG] switch_core_state_machine.c:328 sofia/external/8872 Standard EXECUTE
EXECUTE sofia/external/8872 sleep(700000)
2017-06-09 13:21:01.814583 [DEBUG] sofia.c:7048 Channel sofia/external/8911@192.168.23.127 entering state [ready][200]
2017-06-09 13:25:16.134584 [DEBUG] switch_ivr_play_say.c:1942 done playing file {loops=10}tone_stream://path=/usr/local/freeswitch/conf/tetris.ttml
EXECUTE sofia/external/8911@192.168.23.127 playback(/usr/local/freeswitch/sounds/en/us/callie/conference/conf-enter_conf_number.wav)
2017-06-09 13:25:16.134584 [DEBUG] switch_ivr_play_say.c:1498 Codec Activated L16@8000hz 1 channels 20ms
2017-06-09 13:25:19.034589 [DEBUG] switch_ivr_play_say.c:1942 done playing file /usr/local/freeswitch/sounds/en/us/callie/conference/conf-enter_conf_number.wav
EXECUTE sofia/external/8911@192.168.23.127 sleep(280000)
2017-06-09 13:26:01.334585 [NOTICE] switch_core_media.c:2228 Hangup sofia/external/8911@192.168.23.127 [CS_EXECUTE] [MEDIA_TIMEOUT]
2017-06-09 13:26:01.334585 [DEBUG] switch_core_session.c:2814 sofia/external/8911@192.168.23.127 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2017-06-09 13:26:01.334585 [DEBUG] switch_core_state_machine.c:650 (sofia/external/8911@192.168.23.127) State EXECUTE going to sleep
2017-06-09 13:26:01.334585 [DEBUG] switch_core_state_machine.c:584 (sofia/external/8911@192.168.23.127) Running State Change CS_HANGUP (Cur 2 Tot 16)
2017-06-09 13:26:01.334585 [DEBUG] switch_core_state_machine.c:850 (sofia/external/8911@192.168.23.127) Callstate Change ACTIVE -> HANGUP
2017-06-09 13:26:01.334585 [DEBUG] switch_core_state_machine.c:852 (sofia/external/8911@192.168.23.127) State HANGUP
2017-06-09 13:26:01.334585 [DEBUG] mod_sofia.c:438 Channel sofia/external/8911@192.168.23.127 hanging up, cause: MEDIA_TIMEOUT
2017-06-09 13:26:01.334585 [DEBUG] mod_sofia.c:491 Sending BYE to sofia/external/8911@192.168.23.127
2017-06-09 13:26:01.334585 [DEBUG] switch_core_state_machine.c:60 sofia/external/8911@192.168.23.127 Standard HANGUP, cause: MEDIA_TIMEOUT
2017-06-09 13:26:01.334585 [DEBUG] switch_core_state_machine.c:852 (sofia/external/8911@192.168.23.127) State HANGUP going to sleep
2017-06-09 13:26:01.334585 [DEBUG] switch_core_state_machine.c:619 (sofia/external/8911@192.168.23.127) State Change CS_HANGUP -> CS_REPORTING
2017-06-09 13:26:01.334585 [DEBUG] switch_core_state_machine.c:584 (sofia/external/8911@192.168.23.127) Running State Change CS_REPORTING (Cur 2 Tot 16)
2017-06-09 13:26:01.334585 [DEBUG] switch_core_state_machine.c:938 (sofia/external/8911@192.168.23.127) State REPORTING
2017-06-09 13:26:01.334585 [DEBUG] switch_core_state_machine.c:174 sofia/external/8911@192.168.23.127 Standard REPORTING, cause: MEDIA_TIMEOUT
2017-06-09 13:26:01.334585 [DEBUG] switch_core_state_machine.c:938 (sofia/external/8911@192.168.23.127) State REPORTING going to sleep
2017-06-09 13:26:01.334585 [DEBUG] switch_core_state_machine.c:610 (sofia/external/8911@192.168.23.127) State Change CS_REPORTING -> CS_DESTROY
2017-06-09 13:26:01.334585 [DEBUG] switch_core_session.c:1664 Session 16 (sofia/external/8911@192.168.23.127) Locked, Waiting on external entities
2017-06-09 13:26:01.334585 [NOTICE] switch_core_session.c:1682 Session 16 (sofia/external/8911@192.168.23.127) Ended
2017-06-09 13:26:01.334585 [NOTICE] switch_core_session.c:1686 Close Channel sofia/external/8911@192.168.23.127 [CS_DESTROY]
2017-06-09 13:26:01.334585 [DEBUG] switch_core_state_machine.c:741 (sofia/external/8911@192.168.23.127) Running State Change CS_DESTROY (Cur 1 Tot 16)
2017-06-09 13:26:01.334585 [DEBUG] switch_core_state_machine.c:751 (sofia/external/8911@192.168.23.127) State DESTROY
2017-06-09 13:26:01.334585 [DEBUG] mod_sofia.c:343 sofia/external/8911@192.168.23.127 SOFIA DESTROY
2017-06-09 13:26:01.334585 [DEBUG] switch_core_state_machine.c:181 sofia/external/8911@192.168.23.127 Standard DESTROY
2017-06-09 13:26:01.334585 [DEBUG] switch_core_state_machine.c:751 (sofia/external/8911@192.168.23.127) State DESTROY going to sleep
2017-06-09 13:26:01.514583 [NOTICE] sofia.c:1012 Hangup sofia/external/8872 [CS_EXECUTE] [UNALLOCATED_NUMBER]
2017-06-09 13:26:01.514583 [DEBUG] switch_core_session.c:2814 sofia/external/8872 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2017-06-09 13:26:01.514583 [DEBUG] switch_core_state_machine.c:650 (sofia/external/8872) State EXECUTE going to sleep
2017-06-09 13:26:01.514583 [DEBUG] switch_core_state_machine.c:584 (sofia/external/8872) Running State Change CS_HANGUP (Cur 1 Tot 16)
2017-06-09 13:26:01.514583 [DEBUG] switch_core_state_machine.c:850 (sofia/external/8872) Callstate Change ACTIVE -> HANGUP
2017-06-09 13:26:01.514583 [DEBUG] switch_core_state_machine.c:852 (sofia/external/8872) State HANGUP
2017-06-09 13:26:01.514583 [DEBUG] mod_sofia.c:438 Channel sofia/external/8872 hanging up, cause: UNALLOCATED_NUMBER
2017-06-09 13:26:01.514583 [DEBUG] switch_core_state_machine.c:60 sofia/external/8872 Standard HANGUP, cause: UNALLOCATED_NUMBER
2017-06-09 13:26:01.514583 [DEBUG] switch_core_state_machine.c:852 (sofia/external/8872) State HANGUP going to sleep
2017-06-09 13:26:01.514583 [DEBUG] switch_core_state_machine.c:619 (sofia/external/8872) State Change CS_HANGUP -> CS_REPORTING
2017-06-09 13:26:01.514583 [DEBUG] switch_core_state_machine.c:584 (sofia/external/8872) Running State Change CS_REPORTING (Cur 1 Tot 16)
2017-06-09 13:26:01.514583 [DEBUG] switch_core_state_machine.c:938 (sofia/external/8872) State REPORTING
2017-06-09 13:26:01.514583 [DEBUG] switch_core_state_machine.c:174 sofia/external/8872 Standard REPORTING, cause: UNALLOCATED_NUMBER
2017-06-09 13:26:01.514583 [DEBUG] switch_core_state_machine.c:938 (sofia/external/8872) State REPORTING going to sleep
2017-06-09 13:26:01.514583 [DEBUG] switch_core_state_machine.c:610 (sofia/external/8872) State Change CS_REPORTING -> CS_DESTROY
2017-06-09 13:26:01.514583 [DEBUG] switch_core_session.c:1664 Session 15 (sofia/external/8872) Locked, Waiting on external entities
2017-06-09 13:26:01.514583 [NOTICE] switch_core_session.c:1682 Session 15 (sofia/external/8872) Ended
2017-06-09 13:26:01.514583 [NOTICE] switch_core_session.c:1686 Close Channel sofia/external/8872 [CS_DESTROY]
2017-06-09 13:26:01.514583 [DEBUG] switch_core_state_machine.c:741 (sofia/external/8872) Running State Change CS_DESTROY (Cur 0 Tot 16)
2017-06-09 13:26:01.514583 [DEBUG] switch_core_state_machine.c:751 (sofia/external/8872) State DESTROY
2017-06-09 13:26:01.514583 [DEBUG] mod_sofia.c:343 sofia/external/8872 SOFIA DESTROY
2017-06-09 13:26:01.514583 [DEBUG] switch_core_state_machine.c:181 sofia/external/8872 Standard DESTROY
2017-06-09 13:26:01.514583 [DEBUG] switch_core_state_machine.c:751 (sofia/external/8872) State DESTROY going to sleep