+OK Global siptrace off
2018-05-30 19:23:47.183102 [NOTICE] switch_channel.c:1104 New Channel sofia/external/1000@139.59.19.72 [bda6fc64-b947-42a7-b9b2-3d520a221368]
2018-05-30 19:23:47.183102 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1000@139.59.19.72) Running State Change CS_NEW (Cur 1 Tot 11)
2018-05-30 19:23:47.183102 [DEBUG] sofia.c:10078 sofia/external/1000@139.59.19.72 receiving invite from 139.59.19.72:5060 version: 1.9.0 git ed4920e 2018-05-04 14:37:06Z 64bit
2018-05-30 19:23:47.183102 [DEBUG] sofia.c:7291 Channel sofia/external/1000@139.59.19.72 entering state [received][100]
2018-05-30 19:23:47.183102 [DEBUG] sofia.c:7301 Remote SDP:
v=0
o=Shashi-switch-sdp 1527691809 1527691810 IN IP4 139.59.19.72
s=Shashi-switch-sdp
c=IN IP4 139.59.19.72
t=0 0
m=audio 16416 RTP/AVP 102 9 0 8 103 101
a=rtpmap:102 opus/48000/2
a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40; stereo=1
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:103 telephone-event/48000
a=fmtp:103 0-16
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20

2018-05-30 19:23:47.183102 [DEBUG] sofia.c:7693 (sofia/external/1000@139.59.19.72) State Change CS_NEW -> CS_INIT
2018-05-30 19:23:47.183102 [DEBUG] switch_core_state_machine.c:603 (sofia/external/1000@139.59.19.72) State NEW
2018-05-30 19:23:47.183102 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1000@139.59.19.72) Running State Change CS_INIT (Cur 1 Tot 11)
2018-05-30 19:23:47.183102 [DEBUG] switch_core_state_machine.c:627 (sofia/external/1000@139.59.19.72) State INIT
2018-05-30 19:23:47.183102 [DEBUG] mod_sofia.c:93 sofia/external/1000@139.59.19.72 SOFIA INIT
2018-05-30 19:23:47.183102 [DEBUG] switch_core_state_machine.c:40 sofia/external/1000@139.59.19.72 Standard INIT
2018-05-30 19:23:47.183102 [DEBUG] switch_core_state_machine.c:48 (sofia/external/1000@139.59.19.72) State Change CS_INIT -> CS_ROUTING
2018-05-30 19:23:47.183102 [DEBUG] switch_core_state_machine.c:627 (sofia/external/1000@139.59.19.72) State INIT going to sleep
2018-05-30 19:23:47.183102 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1000@139.59.19.72) Running State Change CS_ROUTING (Cur 1 Tot 11)
2018-05-30 19:23:47.183102 [DEBUG] switch_channel.c:2249 (sofia/external/1000@139.59.19.72) Callstate Change DOWN -> RINGING
2018-05-30 19:23:47.183102 [DEBUG] switch_core_state_machine.c:643 (sofia/external/1000@139.59.19.72) State ROUTING
2018-05-30 19:23:47.183102 [DEBUG] mod_sofia.c:154 sofia/external/1000@139.59.19.72 SOFIA ROUTING
2018-05-30 19:23:47.183102 [DEBUG] switch_core_state_machine.c:236 sofia/external/1000@139.59.19.72 Standard ROUTING
2018-05-30 19:23:47.183102 [INFO] mod_dialplan_xml.c:637 Processing Extension 1000 <1000>->1001 in context public
Dialplan: sofia/external/1000@139.59.19.72 parsing [public->record_rest] continue=false
Dialplan: sofia/external/1000@139.59.19.72 Regex (PASS) [record_rest] ${destination_number}(1001) =~ /1001/ break=on-false
Dialplan: sofia/external/1000@139.59.19.72 Action answer()
Dialplan: sofia/external/1000@139.59.19.72 Action set(playback_terminators=#)
Dialplan: sofia/external/1000@139.59.19.72 Action record(/tmp/data.wav)
2018-05-30 19:23:47.183102 [DEBUG] switch_core_state_machine.c:286 (sofia/external/1000@139.59.19.72) State Change CS_ROUTING -> CS_EXECUTE
2018-05-30 19:23:47.183102 [DEBUG] switch_core_state_machine.c:643 (sofia/external/1000@139.59.19.72) State ROUTING going to sleep
2018-05-30 19:23:47.183102 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1000@139.59.19.72) Running State Change CS_EXECUTE (Cur 1 Tot 11)
2018-05-30 19:23:47.183102 [DEBUG] switch_core_state_machine.c:650 (sofia/external/1000@139.59.19.72) State EXECUTE
2018-05-30 19:23:47.183102 [DEBUG] mod_sofia.c:209 sofia/external/1000@139.59.19.72 SOFIA EXECUTE
2018-05-30 19:23:47.183102 [DEBUG] switch_core_state_machine.c:328 sofia/external/1000@139.59.19.72 Standard EXECUTE
EXECUTE sofia/external/1000@139.59.19.72 answer()
2018-05-30 19:23:47.183102 [DEBUG] switch_core_media.c:5131 Audio Codec Compare [opus:102:48000:20:0:2]/[opus:116:48000:20:0:1]
2018-05-30 19:23:47.183102 [DEBUG] switch_core_media.c:5186 Audio Codec Compare [opus:116:48000:20:0:1] ++++ is saved as a match
2018-05-30 19:23:47.183102 [DEBUG] switch_core_media.c:5131 Audio Codec Compare [opus:102:48000:20:0:2]/[G722:9:8000:20:64000:1]
2018-05-30 19:23:47.183102 [DEBUG] switch_core_media.c:5131 Audio Codec Compare [opus:102:48000:20:0:2]/[PCMU:0:8000:20:64000:1]
2018-05-30 19:23:47.183102 [DEBUG] switch_core_media.c:5131 Audio Codec Compare [opus:102:48000:20:0:2]/[PCMA:8:8000:20:64000:1]
2018-05-30 19:23:47.183102 [DEBUG] switch_core_media.c:5131 Audio Codec Compare [G722:9:8000:20:64000:1]/[opus:116:48000:20:0:1]
2018-05-30 19:23:47.183102 [DEBUG] switch_core_media.c:5131 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2018-05-30 19:23:47.183102 [DEBUG] switch_core_media.c:5186 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
2018-05-30 19:23:47.183102 [DEBUG] switch_core_media.c:5131 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-05-30 19:23:47.183102 [DEBUG] switch_core_media.c:5131 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2018-05-30 19:23:47.183102 [DEBUG] switch_core_media.c:5131 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
2018-05-30 19:23:47.183102 [DEBUG] switch_core_media.c:5131 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2018-05-30 19:23:47.183102 [DEBUG] switch_core_media.c:5131 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-05-30 19:23:47.183102 [DEBUG] switch_core_media.c:5186 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2018-05-30 19:23:47.183102 [DEBUG] switch_core_media.c:5131 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2018-05-30 19:23:47.183102 [DEBUG] switch_core_media.c:5131 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1]
2018-05-30 19:23:47.183102 [DEBUG] switch_core_media.c:5131 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2018-05-30 19:23:47.183102 [DEBUG] switch_core_media.c:5131 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-05-30 19:23:47.183102 [DEBUG] switch_core_media.c:5131 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2018-05-30 19:23:47.183102 [DEBUG] switch_core_media.c:5186 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2018-05-30 19:23:47.183102 [DEBUG] switch_core_media.c:5047 Set telephone-event payload to 103@48000
2018-05-30 19:23:47.183102 [DEBUG] mod_opus.c:617 Opus encoder: set bitrate to local settings [120000bps]
2018-05-30 19:23:47.183102 [DEBUG] mod_opus.c:617 Opus encoder: set bitrate to local settings [120000bps]
2018-05-30 19:23:47.183102 [DEBUG] switch_core_media.c:3446 Set Codec sofia/external/1000@139.59.19.72 opus/48000 20 ms 960 samples 0 bits 2 channels
2018-05-30 19:23:47.183102 [DEBUG] switch_core_codec.c:111 sofia/external/1000@139.59.19.72 Original read codec set to opus:116
2018-05-30 19:23:47.183102 [DEBUG] switch_core_media.c:5390 Set telephone-event payload to 103@48000
2018-05-30 19:23:47.183102 [DEBUG] switch_core_media.c:5448 sofia/external/1000@139.59.19.72 Set 2833 dtmf send payload to 103 recv payload to 103
2018-05-30 19:23:47.183102 [DEBUG] switch_core_media.c:8164 AUDIO RTP [sofia/external/1000@139.59.19.72] 159.89.163.195 port 19228 -> 139.59.19.72 port 16416 codec: 102 ms: 20
2018-05-30 19:23:47.183102 [DEBUG] switch_rtp.c:4189 Starting timer [soft] 960 bytes per 20ms
2018-05-30 19:23:47.183102 [DEBUG] switch_core_media.c:8468 sofia/external/1000@139.59.19.72 Set 2833 dtmf send payload to 103
2018-05-30 19:23:47.183102 [DEBUG] switch_core_media.c:8475 sofia/external/1000@139.59.19.72 Set 2833 dtmf receive payload to 103
2018-05-30 19:23:47.183102 [DEBUG] switch_core_media.c:8498 sofia/external/1000@139.59.19.72 Set rtp dtmf delay to 40
2018-05-30 19:23:47.183102 [NOTICE] sofia_media.c:92 Pre-Answer sofia/external/1000@139.59.19.72!
2018-05-30 19:23:47.193063 [DEBUG] switch_channel.c:3482 (sofia/external/1000@139.59.19.72) Callstate Change RINGING -> EARLY
2018-05-30 19:23:47.193063 [DEBUG] switch_core_media.c:8147 Audio params are unchanged for sofia/external/1000@139.59.19.72.
2018-05-30 19:23:47.193063 [DEBUG] mod_sofia.c:881 Local SDP sofia/external/1000@139.59.19.72:
v=0
o=FreeSWITCH 1527688999 1527689000 IN IP4 159.89.163.195
s=FreeSWITCH
c=IN IP4 159.89.163.195
t=0 0
m=audio 19228 RTP/AVP 102 103
a=rtpmap:102 opus/48000/2
a=fmtp:102 useinbandfec=1; ptime=20; minptime=10; maxptime=40; stereo=1
a=rtpmap:103 telephone-event/48000
a=fmtp:103 0-16
a=ptime:20
a=sendrecv

2018-05-30 19:23:47.193063 [DEBUG] sofia.c:7291 Channel sofia/external/1000@139.59.19.72 entering state [completed][200]
2018-05-30 19:23:47.193063 [NOTICE] mod_dptools.c:1357 Channel [sofia/external/1000@139.59.19.72] has been answered
2018-05-30 19:23:47.193063 [DEBUG] switch_channel.c:3781 (sofia/external/1000@139.59.19.72) Callstate Change EARLY -> ACTIVE
EXECUTE sofia/external/1000@139.59.19.72 set(playback_terminators=#)
2018-05-30 19:23:47.193063 [DEBUG] mod_dptools.c:1593 SET sofia/external/1000@139.59.19.72 [playback_terminators]=[#]
EXECUTE sofia/external/1000@139.59.19.72 record(/tmp/data.wav)
2018-05-30 19:23:47.193063 [DEBUG] switch_ivr_play_say.c:560 Raw Codec Activated, ready to waste resources!
2018-05-30 19:23:47.193063 [DEBUG] switch_ivr_play_say.c:674 Raw Codec Activated
2018-05-30 19:23:47.193063 [DEBUG] switch_core_codec.c:223 sofia/external/1000@139.59.19.72 Push codec L16:100
2018-05-30 19:23:47.193063 [DEBUG] sofia.c:7291 Channel sofia/external/1000@139.59.19.72 entering state [ready][200]
2018-05-30 19:23:47.543096 [DEBUG] switch_rtp.c:7373 Correct audio ip/port confirmed.
freeswitch@debian-s-1vcpu-1gb-blr1-01>
freeswitch@debian-s-1vcpu-1gb-blr1-01>
freeswitch@debian-s-1vcpu-1gb-blr1-01>
freeswitch@debian-s-1vcpu-1gb-blr1-01>
freeswitch@debian-s-1vcpu-1gb-blr1-01>
freeswitch@debian-s-1vcpu-1gb-blr1-01>
freeswitch@debian-s-1vcpu-1gb-blr1-01>
freeswitch@debian-s-1vcpu-1gb-blr1-01>
2018-05-30 19:24:50.163080 [DEBUG] sofia.c:7291 Channel sofia/external/1000@139.59.19.72 entering state [received][100]
2018-05-30 19:24:50.163080 [DEBUG] sofia.c:7301 Remote SDP:
v=0
o=Shashi-switch-sdp 1527691809 1527691810 IN IP4 139.59.19.72
s=Shashi-switch-sdp
c=IN IP4 139.59.19.72
t=0 0
m=audio 16416 RTP/AVP 102 103 9 0 8 101
a=rtpmap:102 opus/48000/2
a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40; stereo=1
a=rtpmap:103 telephone-event/48000
a=fmtp:103 0-16
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20

2018-05-30 19:24:50.163080 [DEBUG] switch_core_media.c:5131 Audio Codec Compare [opus:102:48000:20:0:2]/[opus:116:48000:20:0:1]
2018-05-30 19:24:50.163080 [DEBUG] switch_core_media.c:5186 Audio Codec Compare [opus:116:48000:20:0:1] ++++ is saved as a match
2018-05-30 19:24:50.163080 [DEBUG] switch_core_media.c:5131 Audio Codec Compare [opus:102:48000:20:0:2]/[G722:9:8000:20:64000:1]
2018-05-30 19:24:50.163080 [DEBUG] switch_core_media.c:5131 Audio Codec Compare [opus:102:48000:20:0:2]/[PCMU:0:8000:20:64000:1]
2018-05-30 19:24:50.163080 [DEBUG] switch_core_media.c:5131 Audio Codec Compare [opus:102:48000:20:0:2]/[PCMA:8:8000:20:64000:1]
2018-05-30 19:24:50.163080 [DEBUG] switch_core_media.c:5047 Set telephone-event payload to 103@48000
2018-05-30 19:24:50.163080 [DEBUG] switch_core_media.c:5131 Audio Codec Compare [G722:9:8000:20:64000:1]/[opus:116:48000:20:0:1]
2018-05-30 19:24:50.163080 [DEBUG] switch_core_media.c:5131 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2018-05-30 19:24:50.163080 [DEBUG] switch_core_media.c:5186 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
2018-05-30 19:24:50.163080 [DEBUG] switch_core_media.c:5131 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-05-30 19:24:50.163080 [DEBUG] switch_core_media.c:5131 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2018-05-30 19:24:50.163080 [DEBUG] switch_core_media.c:5131 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
2018-05-30 19:24:50.163080 [DEBUG] switch_core_media.c:5131 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2018-05-30 19:24:50.163080 [DEBUG] switch_core_media.c:5131 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-05-30 19:24:50.163080 [DEBUG] switch_core_media.c:5186 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2018-05-30 19:24:50.163080 [DEBUG] switch_core_media.c:5131 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2018-05-30 19:24:50.163080 [DEBUG] switch_core_media.c:5131 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1]
2018-05-30 19:24:50.163080 [DEBUG] switch_core_media.c:5131 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2018-05-30 19:24:50.163080 [DEBUG] switch_core_media.c:5131 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-05-30 19:24:50.163080 [DEBUG] switch_core_media.c:5131 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2018-05-30 19:24:50.163080 [DEBUG] switch_core_media.c:5186 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2018-05-30 19:24:50.163080 [DEBUG] switch_core_media.c:5390 Set telephone-event payload to 103@48000
2018-05-30 19:24:50.163080 [DEBUG] switch_core_media.c:5448 sofia/external/1000@139.59.19.72 Set 2833 dtmf send payload to 103 recv payload to 103
2018-05-30 19:24:50.163080 [DEBUG] switch_core_media.c:8147 Audio params are unchanged for sofia/external/1000@139.59.19.72.
2018-05-30 19:24:50.163080 [DEBUG] sofia.c:8206 Processing updated SDP
2018-05-30 19:24:50.173063 [DEBUG] sofia.c:7291 Channel sofia/external/1000@139.59.19.72 entering state [completed][200]
2018-05-30 19:24:50.183080 [DEBUG] sofia.c:7291 Channel sofia/external/1000@139.59.19.72 entering state [ready][200]
2018-05-30 19:25:18.903071 [NOTICE] sofia.c:1079 Hangup sofia/external/1000@139.59.19.72 [CS_EXECUTE] [NORMAL_CLEARING]
2018-05-30 19:25:18.913064 [DEBUG] switch_core_codec.c:248 sofia/external/1000@139.59.19.72 Restore previous codec opus:116.
2018-05-30 19:25:18.913064 [DEBUG] switch_core_session.c:2885 sofia/external/1000@139.59.19.72 skip receive message [PHONE_EVENT] (channel is hungup already)
2018-05-30 19:25:18.913064 [DEBUG] switch_core_state_machine.c:650 (sofia/external/1000@139.59.19.72) State EXECUTE going to sleep
2018-05-30 19:25:18.913064 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1000@139.59.19.72) Running State Change CS_HANGUP (Cur 1 Tot 11)
2018-05-30 19:25:18.913064 [DEBUG] switch_core_state_machine.c:850 (sofia/external/1000@139.59.19.72) Callstate Change ACTIVE -> HANGUP
2018-05-30 19:25:18.913064 [DEBUG] switch_core_state_machine.c:852 (sofia/external/1000@139.59.19.72) State HANGUP
2018-05-30 19:25:18.913064 [DEBUG] mod_sofia.c:449 Channel sofia/external/1000@139.59.19.72 hanging up, cause: NORMAL_CLEARING
2018-05-30 19:25:18.913064 [DEBUG] switch_core_state_machine.c:60 sofia/external/1000@139.59.19.72 Standard HANGUP, cause: NORMAL_CLEARING
2018-05-30 19:25:18.913064 [DEBUG] switch_core_state_machine.c:852 (sofia/external/1000@139.59.19.72) State HANGUP going to sleep
2018-05-30 19:25:18.913064 [DEBUG] switch_core_state_machine.c:619 (sofia/external/1000@139.59.19.72) State Change CS_HANGUP -> CS_REPORTING
2018-05-30 19:25:18.913064 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1000@139.59.19.72) Running State Change CS_REPORTING (Cur 1 Tot 11)
2018-05-30 19:25:18.913064 [DEBUG] switch_core_state_machine.c:938 (sofia/external/1000@139.59.19.72) State REPORTING
2018-05-30 19:25:18.913064 [DEBUG] switch_core_state_machine.c:174 sofia/external/1000@139.59.19.72 Standard REPORTING, cause: NORMAL_CLEARING
2018-05-30 19:25:18.913064 [DEBUG] switch_core_state_machine.c:938 (sofia/external/1000@139.59.19.72) State REPORTING going to sleep
2018-05-30 19:25:18.913064 [DEBUG] switch_core_state_machine.c:610 (sofia/external/1000@139.59.19.72) State Change CS_REPORTING -> CS_DESTROY
2018-05-30 19:25:18.913064 [DEBUG] switch_core_session.c:1713 Session 11 (sofia/external/1000@139.59.19.72) Locked, Waiting on external entities
2018-05-30 19:25:18.913064 [NOTICE] switch_core_session.c:1731 Session 11 (sofia/external/1000@139.59.19.72) Ended
2018-05-30 19:25:18.913064 [NOTICE] switch_core_session.c:1735 Close Channel sofia/external/1000@139.59.19.72 [CS_DESTROY]
2018-05-30 19:25:18.913064 [DEBUG] switch_core_state_machine.c:741 (sofia/external/1000@139.59.19.72) Running State Change CS_DESTROY (Cur 0 Tot 11)
2018-05-30 19:25:18.913064 [DEBUG] switch_core_state_machine.c:751 (sofia/external/1000@139.59.19.72) State DESTROY
2018-05-30 19:25:18.913064 [DEBUG] mod_sofia.c:354 sofia/external/1000@139.59.19.72 SOFIA DESTROY
2018-05-30 19:25:18.913064 [DEBUG] mod_opus.c:725 Opus decoder stats: Frames[4488] PLC[0] FEC[0]
2018-05-30 19:25:18.913064 [DEBUG] mod_opus.c:740 Opus encoder stats: Frames[0] Bytes encoded[0] Encoded length ms[0] Average encoded bitrate bps[0]
2018-05-30 19:25:18.913064 [DEBUG] mod_opus.c:725 Opus decoder stats: Frames[0] PLC[0] FEC[0]
2018-05-30 19:25:18.913064 [DEBUG] mod_opus.c:740 Opus encoder stats: Frames[4585] Bytes encoded[710568] Encoded length ms[91700] Average encoded bitrate bps[62467]
2018-05-30 19:25:18.913064 [DEBUG] switch_core_state_machine.c:181 sofia/external/1000@139.59.19.72 Standard DESTROY
2018-05-30 19:25:18.913064 [DEBUG] switch_core_state_machine.c:751 (sofia/external/1000@139.59.19.72) State DESTROY going to sleep