recv 1411 bytes from tls/[180.151.83.178]:63093 at 10:05:21.510513: ------------------------------------------------------------------------ INVITE sip:1010@x.x.x.x SIP/2.0 Via: SIP/2.0/TLS 192.168.93.102:45556;branch=z9hG4bK.AFYnEJtkz;rport From: ;tag=hKZC8L27Q To: sip:1010@x.x.x.x CSeq: 20 INVITE Call-ID: BbPYZv5Bca Max-Forwards: 70 Supported: outbound Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO, UPDATE Content-Type: application/sdp Content-Length: 824 Contact: ;+sip.instance="" User-Agent: LinphoneAndroid/2.4.1-28-g98516d9 (belle-sip/1.4.1) v=0 o=1003 3566 1099 IN IP4 192.168.93.102 s=Talk c=IN IP4 192.168.93.102 b=AS:380 t=0 0 a=rtcp-xr:rcvr-rtt=all:10000 stat-summary=loss,dup,jitt,TTL voip-metrics m=audio 7076 RTP/SAVP 96 97 98 99 0 8 101 100 102 a=rtpmap:96 opus/48000/2 a=fmtp:96 useinbandfec=1 a=rtpmap:97 SILK/16000 a=rtpmap:98 speex/16000 a=fmtp:98 vbr=on a=rtpmap:99 speex/8000 a=fmtp:99 vbr=on a=rtpmap:101 telephone-event/48000 a=rtpmap:100 telephone-event/16000 a=rtpmap:102 telephone-event/8000 a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:a+yoBUtbPKBYtrMBfjzZsMCYiql5SOxoYUbDFZc3 a=crypto:2 AES_CM_128_HMAC_SHA1_32 inline:gRAgLfg3vCRKDA5gbaNfpHcGDrwH/GWyy6dnzQe2 a=crypto:3 AES_CM_256_HMAC_SHA1_80 inline:dn9M35kOLue0i/aclkHZGjBFmz6A/GACewZnkf5I a=crypto:4 AES_CM_256_HMAC_SHA1_32 inline:nbX7w1uUBZShXI5Oui6Otfyw/NHWodUw0kOH2d3f ------------------------------------------------------------------------ send 330 bytes to tls/[180.151.83.178]:63093 at 10:05:21.510915: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/TLS 192.168.93.102:45556;branch=z9hG4bK.AFYnEJtkz;rport=63093;received=180.151.83.178 From: ;tag=hKZC8L27Q To: sip:1010@x.x.x.x Call-ID: BbPYZv5Bca CSeq: 20 INVITE User-Agent: FreeSWITCH-mod_sofia/1.4.21+git~20150901T202622Z~a223dd0236~64bit Content-Length: 0 ------------------------------------------------------------------------ 2015-09-09 10:05:21.500444 [NOTICE] switch_channel.c:1075 New Channel sofia/internal/1003@x.x.x.x [47fa445c-56da-11e5-abf5-a53fe62ce2f9] 2015-09-09 10:05:21.500444 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/1003@x.x.x.x [BREAK] 2015-09-09 10:05:21.500444 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/1003@x.x.x.x [BREAK] 2015-09-09 10:05:21.500444 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/1003@x.x.x.x) Running State Change CS_NEW 2015-09-09 10:05:21.500444 [DEBUG] sofia.c:8925 sofia/internal/1003@x.x.x.x receiving invite from 180.151.83.178:63093 version: 1.4.21 git a223dd0 2015-09-01 20:26:22Z 64bit 2015-09-09 10:05:21.500444 [DEBUG] sofia.c:9092 IP 180.151.83.178 Rejected by acl "domains". Falling back to Digest auth. 2015-09-09 10:05:21.500444 [DEBUG] switch_core_state_machine.c:491 (sofia/internal/1003@x.x.x.x) State NEW send 835 bytes to tls/[180.151.83.178]:63093 at 10:05:21.513879: ------------------------------------------------------------------------ SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/TLS 192.168.93.102:45556;branch=z9hG4bK.AFYnEJtkz;rport=63093;received=180.151.83.178 From: ;tag=hKZC8L27Q To: ;tag=696jg19a5rZvj Call-ID: BbPYZv5Bca CSeq: 20 INVITE User-Agent: FreeSWITCH-mod_sofia/1.4.21+git~20150901T202622Z~a223dd0236~64bit Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Proxy-Authenticate: Digest realm="x.x.x.x", nonce="47fa5ad2-56da-11e5-abf6-a53fe62ce2f9", algorithm=MD5, qop="auth" Content-Length: 0 ------------------------------------------------------------------------ 2015-09-09 10:05:21.500444 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/1003@x.x.x.x [BREAK] 2015-09-09 10:05:21.500444 [DEBUG] sofia.c:2065 detaching session 47fa445c-56da-11e5-abf5-a53fe62ce2f9 recv 391 bytes from tls/[180.151.83.178]:63093 at 10:05:22.125670: ------------------------------------------------------------------------ ACK sip:1010@x.x.x.x SIP/2.0 Via: SIP/2.0/TLS 192.168.93.102:45556;branch=z9hG4bK.AFYnEJtkz;rport Call-ID: BbPYZv5Bca From: ;tag=hKZC8L27Q To: ;tag=696jg19a5rZvj Contact: ;+sip.instance="" Max-Forwards: 70 CSeq: 20 ACK Content-Length: 0 ------------------------------------------------------------------------ recv 1657 bytes from tls/[180.151.83.178]:63093 at 10:05:22.128844: ------------------------------------------------------------------------ INVITE sip:1010@x.x.x.x SIP/2.0 Via: SIP/2.0/TLS 192.168.93.102:45556;branch=z9hG4bK.cZ3vY0uWP;rport From: ;tag=hKZC8L27Q To: sip:1010@x.x.x.x CSeq: 21 INVITE Call-ID: BbPYZv5Bca Max-Forwards: 70 Supported: outbound Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO, UPDATE Content-Type: application/sdp Content-Length: 824 Contact: ;+sip.instance="" User-Agent: LinphoneAndroid/2.4.1-28-g98516d9 (belle-sip/1.4.1) Proxy-Authorization: Digest realm="x.x.x.x", nonce="47fa5ad2-56da-11e5-abf6-a53fe62ce2f9", algorithm=MD5, username="1003", uri="sip:1010@x.x.x.x", response="7051af6f556408074ede39d53ff582c2", cnonce="faaa8515", nc=00000001, qop=auth v=0 o=1003 3566 1099 IN IP4 192.168.93.102 s=Talk c=IN IP4 192.168.93.102 b=AS:380 t=0 0 a=rtcp-xr:rcvr-rtt=all:10000 stat-summary=loss,dup,jitt,TTL voip-metrics m=audio 7076 RTP/SAVP 96 97 98 99 0 8 101 100 102 a=rtpmap:96 opus/48000/2 a=fmtp:96 useinbandfec=1 a=rtpmap:97 SILK/16000 a=rtpmap:98 speex/16000 a=fmtp:98 vbr=on a=rtpmap:99 speex/8000 a=fmtp:99 vbr=on a=rtpmap:101 telephone-event/48000 a=rtpmap:100 telephone-event/16000 a=rtpmap:102 telephone-event/8000 a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:a+yoBUtbPKBYtrMBfjzZsMCYiql5SOxoYUbDFZc3 a=crypto:2 AES_CM_128_HMAC_SHA1_32 inline:gRAgLfg3vCRKDA5gbaNfpHcGDrwH/GWyy6dnzQe2 a=crypto:3 AES_CM_256_HMAC_SHA1_80 inline:dn9M35kOLue0i/aclkHZGjBFmz6A/GACewZnkf5I a=crypto:4 AES_CM_256_HMAC_SHA1_32 inline:nbX7w1uUBZShXI5Oui6Otfyw/NHWodUw0kOH2d3f ------------------------------------------------------------------------ send 330 bytes to tls/[180.151.83.178]:63093 at 10:05:22.129118: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/TLS 192.168.93.102:45556;branch=z9hG4bK.cZ3vY0uWP;rport=63093;received=180.151.83.178 From: ;tag=hKZC8L27Q To: sip:1010@x.x.x.x Call-ID: BbPYZv5Bca CSeq: 21 INVITE User-Agent: FreeSWITCH-mod_sofia/1.4.21+git~20150901T202622Z~a223dd0236~64bit Content-Length: 0 ------------------------------------------------------------------------ 2015-09-09 10:05:22.120462 [DEBUG] sofia.c:2173 Re-attaching to session 47fa445c-56da-11e5-abf5-a53fe62ce2f9 2015-09-09 10:05:22.120462 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/1003@x.x.x.x [BREAK] 2015-09-09 10:05:22.120462 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/1003@x.x.x.x [BREAK] 2015-09-09 10:05:22.120462 [DEBUG] sofia.c:8925 sofia/internal/1003@x.x.x.x receiving invite from 180.151.83.178:63093 version: 1.4.21 git a223dd0 2015-09-01 20:26:22Z 64bit 2015-09-09 10:05:22.120462 [DEBUG] sofia.c:9092 IP 180.151.83.178 Rejected by acl "domains". Falling back to Digest auth. 2015-09-09 10:05:22.140647 [DEBUG] sofia.c:6634 Channel sofia/internal/1003@x.x.x.x entering state [received][100] 2015-09-09 10:05:22.140647 [DEBUG] sofia.c:6644 Remote SDP: v=0 o=1003 3566 1099 IN IP4 192.168.93.102 s=Talk c=IN IP4 192.168.93.102 b=AS:380 t=0 0 a=rtcp-xr:rcvr-rtt=all:10000 stat-summary=loss,dup,jitt,TTL voip-metrics m=audio 7076 RTP/SAVP 96 97 98 99 0 8 101 100 102 a=rtpmap:96 opus/48000/2 a=fmtp:96 useinbandfec=1 a=rtpmap:97 SILK/16000 a=rtpmap:98 speex/16000 a=fmtp:98 vbr=on a=rtpmap:99 speex/8000 a=fmtp:99 vbr=on a=rtpmap:101 telephone-event/48000 a=rtpmap:100 telephone-event/16000 a=rtpmap:102 telephone-event/8000 a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:a+yoBUtbPKBYtrMBfjzZsMCYiql5SOxoYUbDFZc3 a=crypto:2 AES_CM_128_HMAC_SHA1_32 inline:gRAgLfg3vCRKDA5gbaNfpHcGDrwH/GWyy6dnzQe2 a=crypto:3 AES_CM_256_HMAC_SHA1_80 inline:dn9M35kOLue0i/aclkHZGjBFmz6A/GACewZnkf5I a=crypto:4 AES_CM_256_HMAC_SHA1_32 inline:nbX7w1uUBZShXI5Oui6Otfyw/NHWodUw0kOH2d3f 2015-09-09 10:05:22.140647 [DEBUG] sofia.c:6910 (sofia/internal/1003@x.x.x.x) State Change CS_NEW -> CS_INIT 2015-09-09 10:05:22.140647 [DEBUG] switch_core_session.c:1397 Send signal sofia/internal/1003@x.x.x.x [BREAK] 2015-09-09 10:05:22.140647 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/1003@x.x.x.x) Running State Change CS_INIT 2015-09-09 10:05:22.140647 [DEBUG] switch_core_state_machine.c:512 (sofia/internal/1003@x.x.x.x) State INIT 2015-09-09 10:05:22.140647 [DEBUG] mod_sofia.c:87 sofia/internal/1003@x.x.x.x SOFIA INIT 2015-09-09 10:05:22.140647 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1003@x.x.x.x Standard INIT 2015-09-09 10:05:22.140647 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1003@x.x.x.x) State Change CS_INIT -> CS_ROUTING 2015-09-09 10:05:22.140647 [DEBUG] switch_core_session.c:1397 Send signal sofia/internal/1003@x.x.x.x [BREAK] 2015-09-09 10:05:22.140647 [DEBUG] switch_core_state_machine.c:512 (sofia/internal/1003@x.x.x.x) State INIT going to sleep 2015-09-09 10:05:22.140647 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/1003@x.x.x.x) Running State Change CS_ROUTING 2015-09-09 10:05:22.140647 [DEBUG] switch_channel.c:2204 (sofia/internal/1003@x.x.x.x) Callstate Change DOWN -> RINGING 2015-09-09 10:05:22.140647 [DEBUG] switch_core_state_machine.c:528 (sofia/internal/1003@x.x.x.x) State ROUTING 2015-09-09 10:05:22.140647 [DEBUG] mod_sofia.c:123 sofia/internal/1003@x.x.x.x SOFIA ROUTING 2015-09-09 10:05:22.140647 [DEBUG] switch_core_state_machine.c:166 sofia/internal/1003@x.x.x.x Standard ROUTING 2015-09-09 10:05:22.140647 [INFO] mod_dialplan_xml.c:635 Processing 1003 <1003>->1010 in context default Dialplan: sofia/internal/1003@x.x.x.x parsing [default->unloop] continue=false Dialplan: sofia/internal/1003@x.x.x.x Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/internal/1003@x.x.x.x Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: sofia/internal/1003@x.x.x.x parsing [default->tod_example] continue=true Dialplan: sofia/internal/1003@x.x.x.x Date/Time Match (PASS) [tod_example] break=on-false Dialplan: sofia/internal/1003@x.x.x.x Action set(open=true) Dialplan: sofia/internal/1003@x.x.x.x parsing [default->holiday_example] continue=true Dialplan: sofia/internal/1003@x.x.x.x Date/TimeMatch (FAIL) [holiday_example] break=on-false Dialplan: sofia/internal/1003@x.x.x.x parsing [default->global-intercept] continue=false Dialplan: sofia/internal/1003@x.x.x.x Regex (FAIL) [global-intercept] destination_number(1010) =~ /^886$/ break=on-false Dialplan: sofia/internal/1003@x.x.x.x parsing [default->group-intercept] continue=false Dialplan: sofia/internal/1003@x.x.x.x Regex (FAIL) [group-intercept] destination_number(1010) =~ /^\*8$/ break=on-false Dialplan: sofia/internal/1003@x.x.x.x parsing [default->intercept-ext] continue=false Dialplan: sofia/internal/1003@x.x.x.x Regex (FAIL) [intercept-ext] destination_number(1010) =~ /^\*\*(\d+)$/ break=on-false Dialplan: sofia/internal/1003@x.x.x.x parsing [default->redial] continue=false Dialplan: sofia/internal/1003@x.x.x.x Regex (FAIL) [redial] destination_number(1010) =~ /^(redial|870)$/ break=on-false Dialplan: sofia/internal/1003@x.x.x.x parsing [default->global] continue=true Dialplan: sofia/internal/1003@x.x.x.x Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never Dialplan: sofia/internal/1003@x.x.x.x Regex (PASS) [global] ${default_password}(1234) =~ /^1234$/ break=never Dialplan: sofia/internal/1003@x.x.x.x Action log(CRIT WARNING WARNING WARNING WARNING WARNING WARNING WARNING WARNING WARNING ) Dialplan: sofia/internal/1003@x.x.x.x Action log(CRIT Open /usr/local/freeswitch/conf/vars.xml and change the default_password.) Dialplan: sofia/internal/1003@x.x.x.x Action log(CRIT Once changed type 'reloadxml' at the console.) Dialplan: sofia/internal/1003@x.x.x.x Action log(CRIT WARNING WARNING WARNING WARNING WARNING WARNING WARNING WARNING WARNING ) Dialplan: sofia/internal/1003@x.x.x.x Regex (FAIL) [global] ${rtp_has_crypto}() =~ /^(AEAD_AES_256_GCM_8|AEAD_AES_128_GCM_8|AES_CM_256_HMAC_SHA1_80|AES_CM_192_HMAC_SHA1_80|AES_CM_128_HMAC_SHA1_80|AES_CM_256_HMAC_SHA1_32|AES_CM_192_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_32|AES_CM_128_NULL_AUTH)$/ break=never Dialplan: sofia/internal/1003@x.x.x.x Regex (PASS) [global] ${endpoint_disposition}(DELAYED NEGOTIATION) =~ /^(DELAYED NEGOTIATION)/ break=on-false Dialplan: sofia/internal/1003@x.x.x.x Regex (PASS) [global] ${switch_r_sdp}(v=0 o=1003 3566 1099 IN IP4 192.168.93.102 s=Talk c=IN IP4 192.168.93.102 b=AS:380 t=0 0 a=rtcp-xr:rcvr-rtt=all:10000 stat-summary=loss,dup,jitt,TTL voip-metrics m=audio 7076 RTP/SAVP 96 97 98 99 0 8 101 100 102 a=rtpmap:96 opus/48000/2 a=fmtp:96 useinbandfec=1 a=rtpmap:97 SILK/16000 a=rtpmap:98 speex/16000 a=fmtp:98 vbr=on a=rtpmap:99 speex/8000 a=fmtp:99 vbr=on a=rtpmap:101 telephone-event/48000 a=rtpmap:100 telephone-event/16000 a=rtpmap:102 telephone-event/8000 a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:a+yoBUtbPKBYtrMBfjzZsMCYiql5SOxoYUbDFZc3 a=crypto:2 AES_CM_128_HMAC_SHA1_32 inline:gRAgLfg3vCRKDA5gbaNfpHcGDrwH/GWyy6dnzQe2 a=crypto:3 AES_CM_256_HMAC_SHA1_80 inline:dn9M35kOLue0i/aclkHZGjBFmz6A/GACewZnkf5I a=crypto:4 AES_CM_256_HMAC_SHA1_32 inline:nbX7w1uUBZShXI5Oui6Otfyw/NHWodUw0kOH2d3f ) =~ /(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)/ break=never Dialplan: sofia/internal/1003@x.x.x.x Action set(rtp_secure_media=true) Dialplan: sofia/internal/1003@x.x.x.x Action export(rtp_secure_media=true) Dialplan: sofia/internal/1003@x.x.x.x Absolute Condition [global] Dialplan: sofia/internal/1003@x.x.x.x Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid}) Dialplan: sofia/internal/1003@x.x.x.x Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number}) Dialplan: sofia/internal/1003@x.x.x.x Action hash(insert/${domain_name}-last_dial/global/${uuid}) Dialplan: sofia/internal/1003@x.x.x.x Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) Dialplan: sofia/internal/1003@x.x.x.x parsing [default->snom-demo-2] continue=false Dialplan: sofia/internal/1003@x.x.x.x Regex (FAIL) [snom-demo-2] destination_number(1010) =~ /^9001$/ break=on-false Dialplan: sofia/internal/1003@x.x.x.x parsing [default->snom-demo-1] continue=false Dialplan: sofia/internal/1003@x.x.x.x Regex (FAIL) [snom-demo-1] destination_number(1010) =~ /^9000$/ break=on-false Dialplan: sofia/internal/1003@x.x.x.x parsing [default->eavesdrop] continue=false Dialplan: sofia/internal/1003@x.x.x.x Regex (FAIL) [eavesdrop] destination_number(1010) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false Dialplan: sofia/internal/1003@x.x.x.x parsing [default->eavesdrop] continue=false Dialplan: sofia/internal/1003@x.x.x.x Regex (FAIL) [eavesdrop] destination_number(1010) =~ /^779$/ break=on-false Dialplan: sofia/internal/1003@x.x.x.x parsing [default->call_return] continue=false Dialplan: sofia/internal/1003@x.x.x.x Regex (FAIL) [call_return] destination_number(1010) =~ /^\*69$|^869$|^lcr$/ break=on-false Dialplan: sofia/internal/1003@x.x.x.x parsing [default->del-group] continue=false Dialplan: sofia/internal/1003@x.x.x.x Regex (FAIL) [del-group] destination_number(1010) =~ /^80(\d{2})$/ break=on-false Dialplan: sofia/internal/1003@x.x.x.x parsing [default->add-group] continue=false Dialplan: sofia/internal/1003@x.x.x.x Regex (FAIL) [add-group] destination_number(1010) =~ /^81(\d{2})$/ break=on-false Dialplan: sofia/internal/1003@x.x.x.x parsing [default->call-group-simo] continue=false Dialplan: sofia/internal/1003@x.x.x.x Regex (FAIL) [call-group-simo] destination_number(1010) =~ /^82(\d{2})$/ break=on-false Dialplan: sofia/internal/1003@x.x.x.x parsing [default->call-group-order] continue=false Dialplan: sofia/internal/1003@x.x.x.x Regex (FAIL) [call-group-order] destination_number(1010) =~ /^83(\d{2})$/ break=on-false Dialplan: sofia/internal/1003@x.x.x.x parsing [default->extension-intercom] continue=false Dialplan: sofia/internal/1003@x.x.x.x Regex (FAIL) [extension-intercom] destination_number(1010) =~ /^8(10[01][0-9])$/ break=on-false Dialplan: sofia/internal/1003@x.x.x.x parsing [default->Local_Extension] continue=false Dialplan: sofia/internal/1003@x.x.x.x Regex (PASS) [Local_Extension] destination_number(1010) =~ /^(10[01][0-9])$/ break=on-false Dialplan: sofia/internal/1003@x.x.x.x Action export(dialed_extension=1010) Dialplan: sofia/internal/1003@x.x.x.x Action bind_meta_app(1 b s execute_extension::dx XML features) Dialplan: sofia/internal/1003@x.x.x.x Action bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/${caller_id_number}.${strftime(%Y-%m-%d-%H-%M-%S)}.wav) Dialplan: sofia/internal/1003@x.x.x.x Action bind_meta_app(3 b s execute_extension::cf XML features) Dialplan: sofia/internal/1003@x.x.x.x Action bind_meta_app(4 b s execute_extension::att_xfer XML features) Dialplan: sofia/internal/1003@x.x.x.x Action set(ringback=${us-ring}) Dialplan: sofia/internal/1003@x.x.x.x Action set(transfer_ringback=local_stream://moh) Dialplan: sofia/internal/1003@x.x.x.x Action set(call_timeout=30) Dialplan: sofia/internal/1003@x.x.x.x Action set(hangup_after_bridge=true) Dialplan: sofia/internal/1003@x.x.x.x Action set(continue_on_fail=true) Dialplan: sofia/internal/1003@x.x.x.x Action hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number}) Dialplan: sofia/internal/1003@x.x.x.x Action hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid}) Dialplan: sofia/internal/1003@x.x.x.x Action set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name} var callgroup)}) Dialplan: sofia/internal/1003@x.x.x.x Action hash(insert/${domain_name}-last_dial_ext/${called_party_callgroup}/${uuid}) Dialplan: sofia/internal/1003@x.x.x.x Action hash(insert/${domain_name}-last_dial_ext/global/${uuid}) Dialplan: sofia/internal/1003@x.x.x.x Action hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid}) Dialplan: sofia/internal/1003@x.x.x.x Action bridge(user/${dialed_extension}@${domain_name}) Dialplan: sofia/internal/1003@x.x.x.x Action answer() Dialplan: sofia/internal/1003@x.x.x.x Action sleep(1000) Dialplan: sofia/internal/1003@x.x.x.x Action bridge(loopback/app=voicemail:default ${domain_name} ${dialed_extension}) 2015-09-09 10:05:22.140647 [DEBUG] switch_core_state_machine.c:216 (sofia/internal/1003@x.x.x.x) State Change CS_ROUTING -> CS_EXECUTE 2015-09-09 10:05:22.140647 [DEBUG] switch_core_session.c:1397 Send signal sofia/internal/1003@x.x.x.x [BREAK] 2015-09-09 10:05:22.140647 [DEBUG] switch_core_state_machine.c:528 (sofia/internal/1003@x.x.x.x) State ROUTING going to sleep 2015-09-09 10:05:22.140647 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/1003@x.x.x.x) Running State Change CS_EXECUTE 2015-09-09 10:05:22.140647 [DEBUG] switch_core_state_machine.c:535 (sofia/internal/1003@x.x.x.x) State EXECUTE 2015-09-09 10:05:22.140647 [DEBUG] mod_sofia.c:178 sofia/internal/1003@x.x.x.x SOFIA EXECUTE 2015-09-09 10:05:22.140647 [DEBUG] switch_core_state_machine.c:258 sofia/internal/1003@x.x.x.x Standard EXECUTE EXECUTE sofia/internal/1003@x.x.x.x set(open=true) 2015-09-09 10:05:22.140647 [DEBUG] mod_dptools.c:1477 sofia/internal/1003@x.x.x.x SET [open]=[true] EXECUTE sofia/internal/1003@x.x.x.x log(CRIT WARNING WARNING WARNING WARNING WARNING WARNING WARNING WARNING WARNING ) 2015-09-09 10:05:22.140647 [CRIT] mod_dptools.c:1670 WARNING WARNING WARNING WARNING WARNING WARNING WARNING WARNING WARNING EXECUTE sofia/internal/1003@x.x.x.x log(CRIT Open /usr/local/freeswitch/conf/vars.xml and change the default_password.) 2015-09-09 10:05:22.140647 [CRIT] mod_dptools.c:1670 Open /usr/local/freeswitch/conf/vars.xml and change the default_password. EXECUTE sofia/internal/1003@x.x.x.x log(CRIT Once changed type 'reloadxml' at the console.) 2015-09-09 10:05:22.140647 [CRIT] mod_dptools.c:1670 Once changed type 'reloadxml' at the console. EXECUTE sofia/internal/1003@x.x.x.x log(CRIT WARNING WARNING WARNING WARNING WARNING WARNING WARNING WARNING WARNING ) 2015-09-09 10:05:22.140647 [CRIT] mod_dptools.c:1670 WARNING WARNING WARNING WARNING WARNING WARNING WARNING WARNING WARNING EXECUTE sofia/internal/1003@x.x.x.x set(rtp_secure_media=true) 2015-09-09 10:05:22.140647 [DEBUG] mod_dptools.c:1477 sofia/internal/1003@x.x.x.x SET [rtp_secure_media]=[true] EXECUTE sofia/internal/1003@x.x.x.x export(rtp_secure_media=true) 2015-09-09 10:05:22.140647 [DEBUG] switch_channel.c:1267 EXPORT (export_vars) [rtp_secure_media]=[true] EXECUTE sofia/internal/1003@x.x.x.x hash(insert/x.x.x.x-spymap/1003/47fa445c-56da-11e5-abf5-a53fe62ce2f9) EXECUTE sofia/internal/1003@x.x.x.x hash(insert/x.x.x.x-last_dial/1003/1010) EXECUTE sofia/internal/1003@x.x.x.x hash(insert/x.x.x.x-last_dial/global/47fa445c-56da-11e5-abf5-a53fe62ce2f9) EXECUTE sofia/internal/1003@x.x.x.x export(RFC2822_DATE=Wed, 09 Sep 2015 10:05:22 +0000) 2015-09-09 10:05:22.140647 [DEBUG] switch_channel.c:1267 EXPORT (export_vars) [RFC2822_DATE]=[Wed, 09 Sep 2015 10:05:22 +0000] EXECUTE sofia/internal/1003@x.x.x.x export(dialed_extension=1010) 2015-09-09 10:05:22.140647 [DEBUG] switch_channel.c:1267 EXPORT (export_vars) [dialed_extension]=[1010] EXECUTE sofia/internal/1003@x.x.x.x bind_meta_app(1 b s execute_extension::dx XML features) 2015-09-09 10:05:22.140647 [INFO] switch_ivr_async.c:3932 Bound B-Leg: *1 execute_extension::dx XML features EXECUTE sofia/internal/1003@x.x.x.x bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/1003.2015-09-09-10-05-22.wav) 2015-09-09 10:05:22.140647 [INFO] switch_ivr_async.c:3932 Bound B-Leg: *2 record_session::/usr/local/freeswitch/recordings/1003.2015-09-09-10-05-22.wav EXECUTE sofia/internal/1003@x.x.x.x bind_meta_app(3 b s execute_extension::cf XML features) 2015-09-09 10:05:22.140647 [INFO] switch_ivr_async.c:3932 Bound B-Leg: *3 execute_extension::cf XML features EXECUTE sofia/internal/1003@x.x.x.x bind_meta_app(4 b s execute_extension::att_xfer XML features) 2015-09-09 10:05:22.140647 [INFO] switch_ivr_async.c:3932 Bound B-Leg: *4 execute_extension::att_xfer XML features EXECUTE sofia/internal/1003@x.x.x.x set(ringback=%(2000,4000,440,480)) 2015-09-09 10:05:22.140647 [DEBUG] mod_dptools.c:1477 sofia/internal/1003@x.x.x.x SET [ringback]=[%(2000,4000,440,480)] EXECUTE sofia/internal/1003@x.x.x.x set(transfer_ringback=local_stream://moh) 2015-09-09 10:05:22.140647 [DEBUG] mod_dptools.c:1477 sofia/internal/1003@x.x.x.x SET [transfer_ringback]=[local_stream://moh] EXECUTE sofia/internal/1003@x.x.x.x set(call_timeout=30) 2015-09-09 10:05:22.140647 [DEBUG] mod_dptools.c:1477 sofia/internal/1003@x.x.x.x SET [call_timeout]=[30] EXECUTE sofia/internal/1003@x.x.x.x set(hangup_after_bridge=true) 2015-09-09 10:05:22.140647 [DEBUG] mod_dptools.c:1477 sofia/internal/1003@x.x.x.x SET [hangup_after_bridge]=[true] EXECUTE sofia/internal/1003@x.x.x.x set(continue_on_fail=true) 2015-09-09 10:05:22.140647 [DEBUG] mod_dptools.c:1477 sofia/internal/1003@x.x.x.x SET [continue_on_fail]=[true] EXECUTE sofia/internal/1003@x.x.x.x hash(insert/x.x.x.x-call_return/1010/1003) EXECUTE sofia/internal/1003@x.x.x.x hash(insert/x.x.x.x-last_dial_ext/1010/47fa445c-56da-11e5-abf5-a53fe62ce2f9) EXECUTE sofia/internal/1003@x.x.x.x set(called_party_callgroup=techsupport) 2015-09-09 10:05:22.140647 [DEBUG] mod_dptools.c:1477 sofia/internal/1003@x.x.x.x SET [called_party_callgroup]=[techsupport] EXECUTE sofia/internal/1003@x.x.x.x hash(insert/x.x.x.x-last_dial_ext/techsupport/47fa445c-56da-11e5-abf5-a53fe62ce2f9) EXECUTE sofia/internal/1003@x.x.x.x hash(insert/x.x.x.x-last_dial_ext/global/47fa445c-56da-11e5-abf5-a53fe62ce2f9) EXECUTE sofia/internal/1003@x.x.x.x hash(insert/x.x.x.x-last_dial/techsupport/47fa445c-56da-11e5-abf5-a53fe62ce2f9) EXECUTE sofia/internal/1003@x.x.x.x bridge(user/1010@x.x.x.x) 2015-09-09 10:05:22.140647 [DEBUG] switch_channel.c:1221 sofia/internal/1003@x.x.x.x EXPORTING[export_vars] [rtp_secure_media]=[true] to event 2015-09-09 10:05:22.140647 [DEBUG] switch_channel.c:1221 sofia/internal/1003@x.x.x.x EXPORTING[export_vars] [RFC2822_DATE]=[Wed, 09 Sep 2015 10:05:22 +0000] to event 2015-09-09 10:05:22.140647 [DEBUG] switch_channel.c:1221 sofia/internal/1003@x.x.x.x EXPORTING[export_vars] [dialed_extension]=[1010] to event 2015-09-09 10:05:22.140647 [DEBUG] switch_ivr_originate.c:2101 Parsing global variables 2015-09-09 10:05:22.140647 [DEBUG] switch_channel.c:1221 sofia/internal/1003@x.x.x.x EXPORTING[export_vars] [rtp_secure_media]=[true] to event 2015-09-09 10:05:22.140647 [DEBUG] switch_channel.c:1221 sofia/internal/1003@x.x.x.x EXPORTING[export_vars] [RFC2822_DATE]=[Wed, 09 Sep 2015 10:05:22 +0000] to event 2015-09-09 10:05:22.140647 [DEBUG] switch_channel.c:1221 sofia/internal/1003@x.x.x.x EXPORTING[export_vars] [dialed_extension]=[1010] to event 2015-09-09 10:05:22.140647 [DEBUG] switch_ivr_originate.c:2101 Parsing global variables 2015-09-09 10:05:22.140647 [DEBUG] switch_event.c:1698 Parsing variable [sip_invite_domain]=[x.x.x.x] 2015-09-09 10:05:22.140647 [DEBUG] switch_event.c:1698 Parsing variable [presence_id]=[1010@x.x.x.x] 2015-09-09 10:05:22.140647 [NOTICE] switch_channel.c:1075 New Channel sofia/internal/1010@180.151.83.178:13916 [485d07d6-56da-11e5-ac1a-a53fe62ce2f9] 2015-09-09 10:05:22.140647 [DEBUG] mod_sofia.c:4701 (sofia/internal/1010@180.151.83.178:13916) State Change CS_NEW -> CS_INIT 2015-09-09 10:05:22.140647 [DEBUG] switch_core_session.c:1397 Send signal sofia/internal/1010@180.151.83.178:13916 [BREAK] 2015-09-09 10:05:22.140647 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/1010@180.151.83.178:13916) Running State Change CS_INIT 2015-09-09 10:05:22.140647 [DEBUG] switch_core_state_machine.c:512 (sofia/internal/1010@180.151.83.178:13916) State INIT 2015-09-09 10:05:22.140647 [DEBUG] mod_sofia.c:87 sofia/internal/1010@180.151.83.178:13916 SOFIA INIT 2015-09-09 10:05:22.140647 [DEBUG] switch_core_media.c:965 Set Local audio crypto Key [1 AEAD_AES_256_GCM_8 inline:NZxdLH9gzfkhVqwVhH5vNsKCqr2ZL2q9zmm58qlSlItToqVbwaDneilU+js] 2015-09-09 10:05:22.140647 [DEBUG] switch_core_media.c:965 Set Local video crypto Key [1 AEAD_AES_256_GCM_8 inline:7uw9HXkoT5LbBdJAIx6mvnWdy/gANmdQ1rdhGblSftKOJ7XmmqKXwcLZG2k] 2015-09-09 10:05:22.140647 [DEBUG] switch_core_media.c:965 Set Local audio crypto Key [2 AEAD_AES_128_GCM_8 inline:ua7aHtrGSUTtDiXrZ0GGBQV788KjFiuLmZTH8g] 2015-09-09 10:05:22.140647 [DEBUG] switch_core_media.c:965 Set Local video crypto Key [2 AEAD_AES_128_GCM_8 inline:7eAg8CQyKxxalD3DOHhyw5RhXN3KcBvgDMLckA] 2015-09-09 10:05:22.140647 [DEBUG] switch_core_media.c:965 Set Local audio crypto Key [3 AES_CM_256_HMAC_SHA1_80 inline:Z1uAXxMyRlMCgn5nLEN4V/2CKFQpu7WR+2jSAhcUrFEFjCntDm/xtGjKlCYs6g] 2015-09-09 10:05:22.140647 [DEBUG] switch_core_media.c:965 Set Local video crypto Key [3 AES_CM_256_HMAC_SHA1_80 inline:VexGkXR2HPxslnQmALYSBgGbvtJyO6LQ+QZzd5SGNabAwuFGF8gvKPMUK4S32Q] 2015-09-09 10:05:22.140647 [DEBUG] switch_core_media.c:965 Set Local audio crypto Key [4 AES_CM_192_HMAC_SHA1_80 inline:cW6ndzHiiplj8y8BFe6tlaJWC3F9jApWWJOXZ6lyatZAFGPbAqI] 2015-09-09 10:05:22.140647 [DEBUG] switch_core_media.c:965 Set Local video crypto Key [4 AES_CM_192_HMAC_SHA1_80 inline:MOsMk92cXU3us99+4guLRK1aWk5UoveM/hp4eY8Y4ieml3l/oQc] 2015-09-09 10:05:22.140647 [DEBUG] switch_core_media.c:965 Set Local audio crypto Key [5 AES_CM_128_HMAC_SHA1_80 inline:yDum29SwW09CG0fKGoM3G4JCWyKC5GoCrpPAPAZG] 2015-09-09 10:05:22.140647 [DEBUG] switch_core_media.c:965 Set Local video crypto Key [5 AES_CM_128_HMAC_SHA1_80 inline:4CAf5XYrvryfmUETnCt+/vdoHTCf2Oyon8kjh8yV] 2015-09-09 10:05:22.140647 [DEBUG] switch_core_media.c:965 Set Local audio crypto Key [6 AES_CM_256_HMAC_SHA1_32 inline:IktDcfIz+fhT77Pq/H1zHZwOZt/e9wYyFbDxeqhLws8ZJVLB60Y5Cxwhuall7w] 2015-09-09 10:05:22.140647 [DEBUG] switch_core_media.c:965 Set Local video crypto Key [6 AES_CM_256_HMAC_SHA1_32 inline:ASCE4Um7ly3qHgmBsV8U826feUJfrIv8cqyR/TMGMbQt7m77I1oO17xbcTRahA] 2015-09-09 10:05:22.140647 [DEBUG] switch_core_media.c:965 Set Local audio crypto Key [7 AES_CM_192_HMAC_SHA1_32 inline:cITD1AHsn0mlXOeRNLpdhC+raMZNQ7JOd2ntLdvJDY7hD+5gnOY] 2015-09-09 10:05:22.140647 [DEBUG] switch_core_media.c:965 Set Local video crypto Key [7 AES_CM_192_HMAC_SHA1_32 inline:AFzQEnxOGYB9FhMWeMXAiRLB63BcjMl7wdj17oTJuAh87QyeM8E] 2015-09-09 10:05:22.140647 [DEBUG] switch_core_media.c:965 Set Local audio crypto Key [8 AES_CM_128_HMAC_SHA1_32 inline:k2mJfkfFoSI57S0wRldCaqJ5o+zEDxI/gn/GoGYz] 2015-09-09 10:05:22.140647 [DEBUG] switch_core_media.c:965 Set Local video crypto Key [8 AES_CM_128_HMAC_SHA1_32 inline:w5Qg47gCQyv44qDVkQSdSzvOEr2UuoiLXK7tBTKB] 2015-09-09 10:05:22.140647 [DEBUG] switch_core_media.c:965 Set Local audio crypto Key [9 AES_CM_128_NULL_AUTH inline:746pNswmg35Pt7hBimQhSlhCFG97FGfQ1GxXpMgN] 2015-09-09 10:05:22.140647 [DEBUG] switch_core_media.c:965 Set Local video crypto Key [9 AES_CM_128_NULL_AUTH inline:1wY0sYq5HRdoAe9SH+qglTRSGML8o50CmJIwWvpZ] 2015-09-09 10:05:22.140647 [DEBUG] sofia_glue.c:1241 sofia/internal/1010@180.151.83.178:13916 sending invite version: 1.4.21 git a223dd0 2015-09-01 20:26:22Z 64bit Local SDP: v=0 o=FreeSWITCH 1441764576 1441764577 IN IP4 x.x.x.x s=FreeSWITCH c=IN IP4 x.x.x.x t=0 0 m=audio 28546 RTP/SAVP 96 0 8 9 3 101 13 a=rtpmap:96 opus/48000/2 a=fmtp:96 useinbandfec=1 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:9 G722/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=crypto:1 AEAD_AES_256_GCM_8 inline:NZxdLH9gzfkhVqwVhH5vNsKCqr2ZL2q9zmm58qlSlItToqVbwaDneilU+js a=crypto:2 AEAD_AES_128_GCM_8 inline:ua7aHtrGSUTtDiXrZ0GGBQV788KjFiuLmZTH8g a=crypto:3 AES_CM_256_HMAC_SHA1_80 inline:Z1uAXxMyRlMCgn5nLEN4V/2CKFQpu7WR+2jSAhcUrFEFjCntDm/xtGjKlCYs6g a=crypto:4 AES_CM_192_HMAC_SHA1_80 inline:cW6ndzHiiplj8y8BFe6tlaJWC3F9jApWWJOXZ6lyatZAFGPbAqI a=crypto:5 AES_CM_128_HMAC_SHA1_80 inline:yDum29SwW09CG0fKGoM3G4JCWyKC5GoCrpPAPAZG a=crypto:6 AES_CM_256_HMAC_SHA1_32 inline:IktDcfIz+fhT77Pq/H1zHZwOZt/e9wYyFbDxeqhLws8ZJVLB60Y5Cxwhuall7w a=crypto:7 AES_CM_192_HMAC_SHA1_32 inline:cITD1AHsn0mlXOeRNLpdhC+raMZNQ7JOd2ntLdvJDY7hD+5gnOY a=crypto:8 AES_CM_128_HMAC_SHA1_32 inline:k2mJfkfFoSI57S0wRldCaqJ5o+zEDxI/gn/GoGYz a=crypto:9 AES_CM_128_NULL_AUTH inline:746pNswmg35Pt7hBimQhSlhCFG97FGfQ1GxXpMgN a=ptime:20 a=sendrecv 2015-09-09 10:05:22.140647 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1010@180.151.83.178:13916 Standard INIT 2015-09-09 10:05:22.140647 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1010@180.151.83.178:13916) State Change CS_INIT -> CS_ROUTING 2015-09-09 10:05:22.140647 [DEBUG] switch_core_session.c:1397 Send signal sofia/internal/1010@180.151.83.178:13916 [BREAK] 2015-09-09 10:05:22.140647 [DEBUG] switch_core_state_machine.c:512 (sofia/internal/1010@180.151.83.178:13916) State INIT going to sleep 2015-09-09 10:05:22.140647 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/1010@180.151.83.178:13916) Running State Change CS_ROUTING 2015-09-09 10:05:22.140647 [DEBUG] switch_core_state_machine.c:528 (sofia/internal/1010@180.151.83.178:13916) State ROUTING 2015-09-09 10:05:22.140647 [DEBUG] mod_sofia.c:123 sofia/internal/1010@180.151.83.178:13916 SOFIA ROUTING 2015-09-09 10:05:22.140647 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/1010@180.151.83.178:13916) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2015-09-09 10:05:22.140647 [DEBUG] switch_core_session.c:1397 Send signal sofia/internal/1010@180.151.83.178:13916 [BREAK] 2015-09-09 10:05:22.140647 [DEBUG] switch_core_state_machine.c:528 (sofia/internal/1010@180.151.83.178:13916) State ROUTING going to sleep 2015-09-09 10:05:22.140647 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/1010@180.151.83.178:13916) Running State Change CS_CONSUME_MEDIA 2015-09-09 10:05:22.140647 [DEBUG] switch_core_state_machine.c:547 (sofia/internal/1010@180.151.83.178:13916) State CONSUME_MEDIA 2015-09-09 10:05:22.140647 [DEBUG] switch_core_state_machine.c:547 (sofia/internal/1010@180.151.83.178:13916) State CONSUME_MEDIA going to sleep send 2508 bytes to tls/[180.151.83.178]:13916 at 10:05:22.161388: ------------------------------------------------------------------------ INVITE sip:1010@180.151.83.178:13916;app-id=622464153529;pn-type=google;pn-tok=APA91bFqivAK_KIDpU_6PM0pf0U8rx9DOKm0vhyNRqjE1Dpq_uPRbTbT-BMwxNP5NmEyCMfnKxa-fjEhI2J-lzLkCcfFphO1hL39cE4VNqAnnfDbVeQbvmQ;transport=tls SIP/2.0 Via: SIP/2.0/TLS x.x.x.x:5061;rport;branch=z9hG4bKmHD6cSZUSjtmS Max-Forwards: 69 From: "Extension 1003" ;tag=8US4KQBjZac2S To: Call-ID: 1fbbb0c5-d17d-1233-c292-1293c2c31053 CSeq: 80560497 INVITE Contact: User-Agent: FreeSWITCH-mod_sofia/1.4.21+git~20150901T202622Z~a223dd0236~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 1176 X-FS-Support: update_display,send_info Remote-Party-ID: "Extension 1003" ;party=calling;screen=yes;privacy=off v=0 o=FreeSWITCH 1441764576 1441764577 IN IP4 x.x.x.x s=FreeSWITCH c=IN IP4 x.x.x.x t=0 0 m=audio 28546 RTP/SAVP 96 0 8 9 3 101 13 a=rtpmap:96 opus/48000/2 a=fmtp:96 useinbandfec=1 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:9 G722/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=crypto:1 AEAD_AES_256_GCM_8 inline:NZxdLH9gzfkhVqwVhH5vNsKCqr2ZL2q9zmm58qlSlItToqVbwaDneilU+js a=crypto:2 AEAD_AES_128_GCM_8 inline:ua7aHtrGSUTtDiXrZ0GGBQV788KjFiuLmZTH8g a=crypto:3 AES_CM_256_HMAC_SHA1_80 inline:Z1uAXxMyRlMCgn5nLEN4V/2CKFQpu7WR+2jSAhcUrFEFjCntDm/xtGjKlCYs6g a=crypto:4 AES_CM_192_HMAC_SHA1_80 inline:cW6ndzHiiplj8y8BFe6tlaJWC3F9jApWWJOXZ6lyatZAFGPbAqI a=crypto:5 AES_CM_128_HMAC_SHA1_80 inline:yDum29SwW09CG0fKGoM3G4JCWyKC5GoCrpPAPAZG a=crypto:6 AES_CM_256_HMAC_SHA1_32 inline:IktDcfIz+fhT77Pq/H1zHZwOZt/e9wYyFbDxeqhLws8ZJVLB60Y5Cxwhuall7w a=crypto:7 AES_CM_192_HMAC_SHA1_32 inline:cITD1AHsn0mlXOeRNLpdhC+raMZNQ7JOd2ntLdvJDY7hD+5gnOY a=crypto:8 AES_CM_128_HMAC_SHA1_32 inline:k2mJfkfFoSI57S0wRldCaqJ5o+zEDxI/gn/GoGYz a=crypto:9 AES_CM_128_NULL_AUTH inline:746pNswmg35Pt7hBimQhSlhCFG97FGfQ1GxXpMgN a=ptime:20 ------------------------------------------------------------------------ 2015-09-09 10:05:22.160525 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/1010@180.151.83.178:13916 [BREAK] 2015-09-09 10:05:22.160525 [DEBUG] sofia.c:6634 Channel sofia/internal/1010@180.151.83.178:13916 entering state [calling][0] recv 460 bytes from tls/[180.151.83.178]:13916 at 10:05:22.522342: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/TLS x.x.x.x:5061;rport;branch=z9hG4bKmHD6cSZUSjtmS From: "Extension 1003" ;tag=8US4KQBjZac2S To: Call-ID: 1fbbb0c5-d17d-1233-c292-1293c2c31053 CSeq: 80560497 INVITE Content-Length: 0 ------------------------------------------------------------------------ recv 559 bytes from tls/[180.151.83.178]:13916 at 10:05:23.464035: ------------------------------------------------------------------------ SIP/2.0 180 Ringing Via: SIP/2.0/TLS x.x.x.x:5061;rport;branch=z9hG4bKmHD6cSZUSjtmS From: "Extension 1003" ;tag=8US4KQBjZac2S To: ;tag=ezLC2Tx Call-ID: 1fbbb0c5-d17d-1233-c292-1293c2c31053 CSeq: 80560497 INVITE User-Agent: LinphoneAndroid/2.4.1-28-g98516d9 (belle-sip/1.4.1) Supported: outbound Content-Length: 0 ------------------------------------------------------------------------ 2015-09-09 10:05:23.460465 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/1010@180.151.83.178:13916 [BREAK] 2015-09-09 10:05:23.460465 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/1010@180.151.83.178:13916 [BREAK] 2015-09-09 10:05:23.460465 [DEBUG] sofia.c:6634 Channel sofia/internal/1010@180.151.83.178:13916 entering state [proceeding][180] 2015-09-09 10:05:23.460465 [NOTICE] sofia.c:6736 Ring-Ready sofia/internal/1010@180.151.83.178:13916! 2015-09-09 10:05:23.460465 [DEBUG] switch_channel.c:3297 (sofia/internal/1010@180.151.83.178:13916) Callstate Change DOWN -> RINGING 2015-09-09 10:05:23.480461 [INFO] switch_ivr_originate.c:1193 Sending early media 2015-09-09 10:05:23.480461 [DEBUG] switch_core_media.c:1228 looking for crypto suite [AEAD_AES_256_GCM_8] in [1 AES_CM_128_HMAC_SHA1_80 inline:a+yoBUtbPKBYtrMBfjzZsMCYiql5SOxoYUbDFZc3] 2015-09-09 10:05:23.480461 [DEBUG] switch_core_media.c:1228 looking for crypto suite [AEAD_AES_128_GCM_8] in [1 AES_CM_128_HMAC_SHA1_80 inline:a+yoBUtbPKBYtrMBfjzZsMCYiql5SOxoYUbDFZc3] 2015-09-09 10:05:23.480461 [DEBUG] switch_core_media.c:1228 looking for crypto suite [AES_CM_256_HMAC_SHA1_80] in [1 AES_CM_128_HMAC_SHA1_80 inline:a+yoBUtbPKBYtrMBfjzZsMCYiql5SOxoYUbDFZc3] 2015-09-09 10:05:23.480461 [DEBUG] switch_core_media.c:1228 looking for crypto suite [AES_CM_192_HMAC_SHA1_80] in [1 AES_CM_128_HMAC_SHA1_80 inline:a+yoBUtbPKBYtrMBfjzZsMCYiql5SOxoYUbDFZc3] 2015-09-09 10:05:23.480461 [DEBUG] switch_core_media.c:1228 looking for crypto suite [AES_CM_128_HMAC_SHA1_80] in [1 AES_CM_128_HMAC_SHA1_80 inline:a+yoBUtbPKBYtrMBfjzZsMCYiql5SOxoYUbDFZc3] 2015-09-09 10:05:23.480461 [DEBUG] switch_core_media.c:1233 Found suite AES_CM_128_HMAC_SHA1_80 2015-09-09 10:05:23.480461 [DEBUG] switch_core_media.c:1299 Set Remote Key [1 AES_CM_128_HMAC_SHA1_80 inline:a+yoBUtbPKBYtrMBfjzZsMCYiql5SOxoYUbDFZc3] 2015-09-09 10:05:23.480461 [DEBUG] switch_core_media.c:965 Set Local audio crypto Key [1 AES_CM_128_HMAC_SHA1_80 inline:44c6ZMEyLHkmecAZKJf7Nf8hAPMQhA4rubdYPr2/] 2015-09-09 10:05:23.480461 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [opus:96:48000:20:0:1]/[opus:116:48000:20:0:1] 2015-09-09 10:05:23.480461 [DEBUG] switch_core_media.c:3734 Audio Codec Compare [opus:116:48000:20:0:1] ++++ is saved as a match 2015-09-09 10:05:23.480461 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [opus:96:48000:20:0:1]/[G722:9:8000:20:64000:1] 2015-09-09 10:05:23.480461 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [opus:96:48000:20:0:1]/[PCMU:0:8000:20:64000:1] 2015-09-09 10:05:23.480461 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [opus:96:48000:20:0:1]/[PCMA:8:8000:20:64000:1] 2015-09-09 10:05:23.480461 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [opus:96:48000:20:0:1]/[GSM:3:8000:20:13200:1] 2015-09-09 10:05:23.480461 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [SILK:97:16000:20:0:1]/[opus:116:48000:20:0:1] 2015-09-09 10:05:23.480461 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [SILK:97:16000:20:0:1]/[G722:9:8000:20:64000:1] 2015-09-09 10:05:23.480461 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [SILK:97:16000:20:0:1]/[PCMU:0:8000:20:64000:1] 2015-09-09 10:05:23.480461 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [SILK:97:16000:20:0:1]/[PCMA:8:8000:20:64000:1] 2015-09-09 10:05:23.480461 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [SILK:97:16000:20:0:1]/[GSM:3:8000:20:13200:1] 2015-09-09 10:05:23.480461 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [speex:98:16000:20:0:1]/[opus:116:48000:20:0:1] 2015-09-09 10:05:23.480461 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [speex:98:16000:20:0:1]/[G722:9:8000:20:64000:1] 2015-09-09 10:05:23.480461 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [speex:98:16000:20:0:1]/[PCMU:0:8000:20:64000:1] 2015-09-09 10:05:23.480461 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [speex:98:16000:20:0:1]/[PCMA:8:8000:20:64000:1] 2015-09-09 10:05:23.480461 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [speex:98:16000:20:0:1]/[GSM:3:8000:20:13200:1] 2015-09-09 10:05:23.480461 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [speex:99:8000:20:0:1]/[opus:116:48000:20:0:1] 2015-09-09 10:05:23.480461 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [speex:99:8000:20:0:1]/[G722:9:8000:20:64000:1] 2015-09-09 10:05:23.480461 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [speex:99:8000:20:0:1]/[PCMU:0:8000:20:64000:1] 2015-09-09 10:05:23.480461 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [speex:99:8000:20:0:1]/[PCMA:8:8000:20:64000:1] 2015-09-09 10:05:23.480461 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [speex:99:8000:20:0:1]/[GSM:3:8000:20:13200:1] 2015-09-09 10:05:23.480461 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1] 2015-09-09 10:05:23.480461 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1] 2015-09-09 10:05:23.480461 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2015-09-09 10:05:23.480461 [DEBUG] switch_core_media.c:3734 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match 2015-09-09 10:05:23.480461 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2015-09-09 10:05:23.480461 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[GSM:3:8000:20:13200:1] 2015-09-09 10:05:23.480461 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1] 2015-09-09 10:05:23.480461 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1] 2015-09-09 10:05:23.480461 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2015-09-09 10:05:23.480461 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2015-09-09 10:05:23.480461 [DEBUG] switch_core_media.c:3734 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match 2015-09-09 10:05:23.480461 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[GSM:3:8000:20:13200:1] 2015-09-09 10:05:23.480461 [DEBUG] switch_core_media.c:3595 Set telephone-event payload to 101 2015-09-09 10:05:23.480461 [DEBUG] mod_opus.c:289 Opus encoder set bitrate to local settings [-1000bps] 2015-09-09 10:05:23.480461 [DEBUG] mod_opus.c:289 Opus encoder set bitrate to local settings [-1000bps] 2015-09-09 10:05:23.480461 [DEBUG] switch_core_media.c:2506 Set Codec sofia/internal/1003@x.x.x.x opus/48000 20 ms 960 samples 0 bits 1 channels 2015-09-09 10:05:23.480461 [DEBUG] switch_core_codec.c:111 sofia/internal/1003@x.x.x.x Original read codec set to opus:116 2015-09-09 10:05:23.480461 [DEBUG] switch_core_media.c:3942 Set 2833 dtmf send/recv payload to 101 2015-09-09 10:05:23.480461 [DEBUG] switch_core_media.c:5178 AUDIO RTP [sofia/internal/1003@x.x.x.x] y.y.y.y port 18344 -> 192.168.93.102 port 7076 codec: 96 ms: 20 2015-09-09 10:05:23.480461 [DEBUG] switch_rtp.c:3579 Starting timer [soft] 960 bytes per 20ms 2015-09-09 10:05:23.480461 [DEBUG] switch_core_media.c:5476 Set 2833 dtmf send payload to 101 2015-09-09 10:05:23.480461 [DEBUG] switch_core_media.c:5482 Set 2833 dtmf receive payload to 101 2015-09-09 10:05:23.480461 [DEBUG] switch_core_media.c:5504 sofia/internal/1003@x.x.x.x Set rtp dtmf delay to 40 2015-09-09 10:05:23.480461 [INFO] switch_rtp.c:3394 Activating Audio Secure RTP SEND 2015-09-09 10:05:23.480461 [INFO] switch_rtp.c:3372 Activating Audio Secure RTP RECV 2015-09-09 10:05:23.480461 [DEBUG] switch_core_sqldb.c:2599 Secure Type: srtp:sdes:AES_CM_128_HMAC_SHA1_80 2015-09-09 10:05:23.480461 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/1003@x.x.x.x! 2015-09-09 10:05:23.480461 [DEBUG] switch_core_sqldb.c:2599 Secure Type: srtp:sdes:AES_CM_128_HMAC_SHA1_80 2015-09-09 10:05:23.480461 [DEBUG] switch_channel.c:3419 (sofia/internal/1003@x.x.x.x) Callstate Change RINGING -> EARLY 2015-09-09 10:05:23.480461 [DEBUG] mod_sofia.c:2268 Ring SDP: v=0 o=FreeSWITCH 1441774779 1441774780 IN IP4 x.x.x.x s=FreeSWITCH c=IN IP4 x.x.x.x t=0 0 m=audio 18344 RTP/SAVP 96 101 a=rtpmap:96 opus/48000/2 a=fmtp:96 useinbandfec=1 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:44c6ZMEyLHkmecAZKJf7Nf8hAPMQhA4rubdYPr2/ 2015-09-09 10:05:23.480461 [DEBUG] switch_core_session.c:913 Send signal sofia/internal/1003@x.x.x.x [BREAK] 2015-09-09 10:05:23.480461 [DEBUG] switch_ivr_originate.c:1250 Raw Codec Activation Success L16@48000hz 1 channel 20ms 2015-09-09 10:05:23.480461 [DEBUG] switch_core_codec.c:221 sofia/internal/1003@x.x.x.x Push codec L16:100 2015-09-09 10:05:23.480461 [DEBUG] switch_ivr_originate.c:1318 Play Ringback Tone [%(2000,4000,440,480)] send 1237 bytes to tls/[180.151.83.178]:63093 at 10:05:23.495220: ------------------------------------------------------------------------ SIP/2.0 183 Session Progress Via: SIP/2.0/TLS 192.168.93.102:45556;branch=z9hG4bK.cZ3vY0uWP;rport=63093;received=180.151.83.178 From: ;tag=hKZC8L27Q To: ;tag=7j0Bjvte21NFe Call-ID: BbPYZv5Bca CSeq: 21 INVITE Contact: User-Agent: FreeSWITCH-mod_sofia/1.4.21+git~20150901T202622Z~a223dd0236~64bit Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 336 Remote-Party-ID: "1010" ;party=calling;privacy=off;screen=no v=0 o=FreeSWITCH 1441774779 1441774780 IN IP4 x.x.x.x s=FreeSWITCH c=IN IP4 x.x.x.x t=0 0 m=audio 18344 RTP/SAVP 96 101 a=rtpmap:96 opus/48000/2 a=fmtp:96 useinbandfec=1 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:44c6ZMEyLHkmecAZKJf7Nf8hAPMQhA4rubdYPr2/ ------------------------------------------------------------------------ 2015-09-09 10:05:23.480461 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/1003@x.x.x.x [BREAK] 2015-09-09 10:05:23.500460 [DEBUG] sofia.c:6634 Channel sofia/internal/1003@x.x.x.x entering state [early][183] 2015-09-09 10:05:25.080465 [INFO] switch_rtp.c:5867 Auto Changing port from 192.168.93.102:7076 to 180.151.83.178:41804 recv 1098 bytes from tls/[180.151.83.178]:13916 at 10:05:25.857085: ------------------------------------------------------------------------ SIP/2.0 200 Ok Via: SIP/2.0/TLS x.x.x.x:5061;rport;branch=z9hG4bKmHD6cSZUSjtmS From: "Extension 1003" ;tag=8US4KQBjZac2S To: ;tag=ezLC2Tx Call-ID: 1fbbb0c5-d17d-1233-c292-1293c2c31053 CSeq: 80560497 INVITE User-Agent: LinphoneAndroid/2.4.1-28-g98516d9 (belle-sip/1.4.1) Supported: outbound Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO, UPDATE Contact: ;+sip.instance="" Content-Type: application/sdp Content-Length: 300 v=0 o=1010 2282 1220 IN IP4 192.168.93.111 s=Talk c=IN IP4 192.168.93.111 b=AS:380 t=0 0 m=audio 7076 RTP/SAVP 96 0 8 101 a=rtpmap:96 opus/48000/2 a=fmtp:96 useinbandfec=1 a=rtpmap:101 telephone-event/8000 a=crypto:3 AES_CM_256_HMAC_SHA1_80 inline:7xYnuvUnDG18O3SS73sJH0aTo5Tpa4jyiTH40x0U ------------------------------------------------------------------------ 2015-09-09 10:05:25.840464 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/1010@180.151.83.178:13916 [BREAK] 2015-09-09 10:05:25.840464 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/1010@180.151.83.178:13916 [BREAK] 2015-09-09 10:05:25.860464 [DEBUG] sofia.c:6634 Channel sofia/internal/1010@180.151.83.178:13916 entering state [completing][200] 2015-09-09 10:05:25.860464 [DEBUG] sofia.c:6644 Remote SDP: v=0 o=1010 2282 1220 IN IP4 192.168.93.111 s=Talk c=IN IP4 192.168.93.111 b=AS:380 t=0 0 m=audio 7076 RTP/SAVP 96 0 8 101 a=rtpmap:96 opus/48000/2 a=fmtp:96 useinbandfec=1 a=rtpmap:101 telephone-event/8000 a=crypto:3 AES_CM_256_HMAC_SHA1_80 inline:7xYnuvUnDG18O3SS73sJH0aTo5Tpa4jyiTH40x0U send 582 bytes to tls/[180.151.83.178]:13916 at 10:05:25.861580: ------------------------------------------------------------------------ ACK sip:1010@180.151.83.178:13916;transport=tls SIP/2.0 Via: SIP/2.0/TLS x.x.x.x:5061;rport;branch=z9hG4bKNt6yemgZpUg7m Max-Forwards: 70 From: "Extension 1003" ;tag=8US4KQBjZac2S To: ;tag=ezLC2Tx Call-ID: 1fbbb0c5-d17d-1233-c292-1293c2c31053 CSeq: 80560497 ACK Contact: Content-Length: 0 ------------------------------------------------------------------------ 2015-09-09 10:05:25.860464 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/1010@180.151.83.178:13916 [BREAK] 2015-09-09 10:05:25.860464 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/1010@180.151.83.178:13916 [BREAK] 2015-09-09 10:05:25.860464 [DEBUG] sofia.c:6634 Channel sofia/internal/1010@180.151.83.178:13916 entering state [ready][200] 2015-09-09 10:05:25.860464 [DEBUG] switch_core_media.c:1228 looking for crypto suite [AEAD_AES_256_GCM_8] in [3 AES_CM_256_HMAC_SHA1_80 inline:7xYnuvUnDG18O3SS73sJH0aTo5Tpa4jyiTH40x0U] 2015-09-09 10:05:25.860464 [DEBUG] switch_core_media.c:1228 looking for crypto suite [AEAD_AES_128_GCM_8] in [3 AES_CM_256_HMAC_SHA1_80 inline:7xYnuvUnDG18O3SS73sJH0aTo5Tpa4jyiTH40x0U] 2015-09-09 10:05:25.860464 [DEBUG] switch_core_media.c:1228 looking for crypto suite [AES_CM_256_HMAC_SHA1_80] in [3 AES_CM_256_HMAC_SHA1_80 inline:7xYnuvUnDG18O3SS73sJH0aTo5Tpa4jyiTH40x0U] 2015-09-09 10:05:25.860464 [DEBUG] switch_core_media.c:1233 Found suite AES_CM_256_HMAC_SHA1_80 2015-09-09 10:05:25.860464 [DEBUG] switch_core_media.c:1299 Set Remote Key [3 AES_CM_256_HMAC_SHA1_80 inline:7xYnuvUnDG18O3SS73sJH0aTo5Tpa4jyiTH40x0U] 2015-09-09 10:05:25.860464 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [opus:96:48000:20:0:1]/[opus:116:48000:20:0:2] 2015-09-09 10:05:25.860464 [DEBUG] switch_core_media.c:3734 Audio Codec Compare [opus:116:48000:20:0:2] ++++ is saved as a match 2015-09-09 10:05:25.860464 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [opus:96:48000:20:0:1]/[PCMU:0:8000:20:64000:1] 2015-09-09 10:05:25.860464 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [opus:96:48000:20:0:1]/[PCMA:8:8000:20:64000:1] 2015-09-09 10:05:25.860464 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [opus:96:48000:20:0:1]/[opus:116:48000:20:0:1] 2015-09-09 10:05:25.860464 [DEBUG] switch_core_media.c:3734 Audio Codec Compare [opus:116:48000:20:0:1] ++++ is saved as a match 2015-09-09 10:05:25.860464 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [opus:96:48000:20:0:1]/[G722:9:8000:20:64000:1] 2015-09-09 10:05:25.860464 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [opus:96:48000:20:0:1]/[GSM:3:8000:20:13200:1] 2015-09-09 10:05:25.860464 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:2] 2015-09-09 10:05:25.860464 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2015-09-09 10:05:25.860464 [DEBUG] switch_core_media.c:3734 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match 2015-09-09 10:05:25.860464 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2015-09-09 10:05:25.860464 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1] 2015-09-09 10:05:25.860464 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1] 2015-09-09 10:05:25.860464 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[GSM:3:8000:20:13200:1] 2015-09-09 10:05:25.860464 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:2] 2015-09-09 10:05:25.860464 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2015-09-09 10:05:25.860464 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2015-09-09 10:05:25.860464 [DEBUG] switch_core_media.c:3734 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match 2015-09-09 10:05:25.860464 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1] 2015-09-09 10:05:25.860464 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1] 2015-09-09 10:05:25.860464 [DEBUG] switch_core_media.c:3679 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[GSM:3:8000:20:13200:1] 2015-09-09 10:05:25.860464 [DEBUG] switch_core_media.c:3595 Set telephone-event payload to 101 2015-09-09 10:05:25.860464 [DEBUG] mod_opus.c:289 Opus encoder set bitrate to local settings [-1000bps] 2015-09-09 10:05:25.860464 [DEBUG] mod_opus.c:289 Opus encoder set bitrate to local settings [-1000bps] 2015-09-09 10:05:25.860464 [DEBUG] switch_core_media.c:2506 Set Codec sofia/internal/1010@180.151.83.178:13916 opus/48000 20 ms 960 samples 0 bits 1 channels 2015-09-09 10:05:25.860464 [DEBUG] switch_core_codec.c:111 sofia/internal/1010@180.151.83.178:13916 Original read codec set to opus:116 2015-09-09 10:05:25.860464 [DEBUG] switch_core_media.c:3933 Set 2833 dtmf send payload to 101 2015-09-09 10:05:25.860464 [DEBUG] switch_core_media.c:5178 AUDIO RTP [sofia/internal/1010@180.151.83.178:13916] y.y.y.y port 28546 -> 192.168.93.111 port 7076 codec: 96 ms: 20 2015-09-09 10:05:25.860464 [DEBUG] switch_rtp.c:3579 Starting timer [soft] 960 bytes per 20ms 2015-09-09 10:05:25.860464 [DEBUG] switch_core_media.c:5476 Set 2833 dtmf send payload to 101 2015-09-09 10:05:25.860464 [DEBUG] switch_core_media.c:5482 Set 2833 dtmf receive payload to 101 2015-09-09 10:05:25.860464 [DEBUG] switch_core_media.c:5504 sofia/internal/1010@180.151.83.178:13916 Set rtp dtmf delay to 40 2015-09-09 10:05:25.860464 [INFO] switch_rtp.c:3394 Activating Audio Secure RTP SEND 2015-09-09 10:05:25.860464 [INFO] switch_rtp.c:3372 Activating Audio Secure RTP RECV 2015-09-09 10:05:25.860464 [DEBUG] switch_core_sqldb.c:2599 Secure Type: srtp:sdes:AES_CM_256_HMAC_SHA1_80 2015-09-09 10:05:25.860464 [DEBUG] switch_core_sqldb.c:2599 Secure Type: srtp:sdes:AES_CM_256_HMAC_SHA1_80 2015-09-09 10:05:25.860464 [DEBUG] switch_channel.c:3657 Send signal sofia/internal/1003@x.x.x.x [BREAK] 2015-09-09 10:05:25.860464 [NOTICE] sofia.c:7501 Channel [sofia/internal/1010@180.151.83.178:13916] has been answered 2015-09-09 10:05:25.860464 [DEBUG] switch_channel.c:3711 (sofia/internal/1010@180.151.83.178:13916) Callstate Change RINGING -> ACTIVE 2015-09-09 10:05:25.860464 [DEBUG] switch_core_codec.c:246 sofia/internal/1003@x.x.x.x Restore previous codec opus:116. 2015-09-09 10:05:25.860464 [DEBUG] mod_sofia.c:780 Local SDP sofia/internal/1003@x.x.x.x: v=0 o=FreeSWITCH 1441774779 1441774781 IN IP4 x.x.x.x s=FreeSWITCH c=IN IP4 x.x.x.x t=0 0 m=audio 18344 RTP/SAVP 96 101 a=rtpmap:96 opus/48000/2 a=fmtp:96 useinbandfec=1 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:44c6ZMEyLHkmecAZKJf7Nf8hAPMQhA4rubdYPr2/ 2015-09-09 10:05:25.860464 [DEBUG] switch_core_session.c:913 Send signal sofia/internal/1003@x.x.x.x [BREAK] send 1207 bytes to tls/[180.151.83.178]:63093 at 10:05:25.876054: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/TLS 192.168.93.102:45556;branch=z9hG4bK.cZ3vY0uWP;rport=63093;received=180.151.83.178 From: ;tag=hKZC8L27Q To: ;tag=7j0Bjvte21NFe Call-ID: BbPYZv5Bca CSeq: 21 INVITE Contact: User-Agent: FreeSWITCH-mod_sofia/1.4.21+git~20150901T202622Z~a223dd0236~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 336 Remote-Party-ID: "Outbound Call" ;party=calling;privacy=off;screen=no v=0 o=FreeSWITCH 1441774779 1441774780 IN IP4 x.x.x.x s=FreeSWITCH c=IN IP4 x.x.x.x t=0 0 m=audio 18344 RTP/SAVP 96 101 a=rtpmap:96 opus/48000/2 a=fmtp:96 useinbandfec=1 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:44c6ZMEyLHkmecAZKJf7Nf8hAPMQhA4rubdYPr2/ ------------------------------------------------------------------------ 2015-09-09 10:05:25.860464 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/1003@x.x.x.x [BREAK] 2015-09-09 10:05:25.860464 [NOTICE] switch_ivr_originate.c:3523 Channel [sofia/internal/1003@x.x.x.x] has been answered 2015-09-09 10:05:25.860464 [DEBUG] switch_channel.c:3711 (sofia/internal/1003@x.x.x.x) Callstate Change EARLY -> ACTIVE 2015-09-09 10:05:25.860464 [DEBUG] sofia.c:6634 Channel sofia/internal/1003@x.x.x.x entering state [completed][200] 2015-09-09 10:05:25.860464 [DEBUG] switch_ivr_originate.c:3581 Originate Resulted in Success: [sofia/internal/1010@180.151.83.178:13916] 2015-09-09 10:05:25.860464 [DEBUG] switch_ivr_originate.c:3581 Originate Resulted in Success: [sofia/internal/1010@180.151.83.178:13916] 2015-09-09 10:05:25.882975 [DEBUG] switch_core_session.c:913 Send signal sofia/internal/1010@180.151.83.178:13916 [BREAK] 2015-09-09 10:05:25.882975 [DEBUG] switch_core_session.c:913 Send signal sofia/internal/1003@x.x.x.x [BREAK] 2015-09-09 10:05:25.882975 [DEBUG] switch_ivr_bridge.c:1468 (sofia/internal/1010@180.151.83.178:13916) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA 2015-09-09 10:05:25.882975 [DEBUG] switch_core_session.c:1397 Send signal sofia/internal/1010@180.151.83.178:13916 [BREAK] 2015-09-09 10:05:25.882975 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/1010@180.151.83.178:13916) Running State Change CS_EXCHANGE_MEDIA 2015-09-09 10:05:25.882975 [DEBUG] switch_core_state_machine.c:538 (sofia/internal/1010@180.151.83.178:13916) State EXCHANGE_MEDIA 2015-09-09 10:05:25.882975 [DEBUG] mod_sofia.c:594 SOFIA EXCHANGE_MEDIA 2015-09-09 10:05:25.882975 [DEBUG] switch_rtp.c:5894 Correct ip/port confirmed. 2015-09-09 10:05:25.882975 [DEBUG] mod_opus.c:289 Opus encoder set bitrate to local settings [-1000bps] send 1207 bytes to tls/[180.151.83.178]:63093 at 10:05:26.379657: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/TLS 192.168.93.102:45556;branch=z9hG4bK.cZ3vY0uWP;rport=63093;received=180.151.83.178 From: ;tag=hKZC8L27Q To: ;tag=7j0Bjvte21NFe Call-ID: BbPYZv5Bca CSeq: 21 INVITE Contact: User-Agent: FreeSWITCH-mod_sofia/1.4.21+git~20150901T202622Z~a223dd0236~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 336 Remote-Party-ID: "Outbound Call" ;party=calling;privacy=off;screen=no v=0 o=FreeSWITCH 1441774779 1441774780 IN IP4 x.x.x.x s=FreeSWITCH c=IN IP4 x.x.x.x t=0 0 m=audio 18344 RTP/SAVP 96 101 a=rtpmap:96 opus/48000/2 a=fmtp:96 useinbandfec=1 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:44c6ZMEyLHkmecAZKJf7Nf8hAPMQhA4rubdYPr2/ ------------------------------------------------------------------------ recv 536 bytes from tls/[180.151.83.178]:63093 at 10:05:26.825971: ------------------------------------------------------------------------ ACK sip:1010@x.x.x.x:5061;transport=tls SIP/2.0 Via: SIP/2.0/TLS 192.168.93.102:45556;rport;branch=z9hG4bK.Tek3oSUVA From: ;tag=hKZC8L27Q To: ;tag=7j0Bjvte21NFe CSeq: 21 ACK Call-ID: BbPYZv5Bca Max-Forwards: 70 Proxy-Authorization: Digest realm="x.x.x.x", nonce="47fa5ad2-56da-11e5-abf6-a53fe62ce2f9", algorithm=MD5, username="1003", uri="sip:1010@x.x.x.x", response="7051af6f556408074ede39d53ff582c2", cnonce="faaa8515", nc=00000001, qop=auth Content-Length: 0 ------------------------------------------------------------------------ 2015-09-09 10:05:26.820469 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/1003@x.x.x.x [BREAK] 2015-09-09 10:05:26.820469 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/1003@x.x.x.x [BREAK] 2015-09-09 10:05:26.820469 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/1003@x.x.x.x [BREAK] 2015-09-09 10:05:26.820469 [DEBUG] sofia.c:6634 Channel sofia/internal/1003@x.x.x.x entering state [ready][200] 2015-09-09 10:05:26.820469 [DEBUG] switch_core_session.c:979 Send signal sofia/internal/1010@180.151.83.178:13916 [BREAK] 2015-09-09 10:05:26.820469 [DEBUG] switch_core_session.c:979 Send signal sofia/internal/1003@x.x.x.x [BREAK] recv 536 bytes from tls/[180.151.83.178]:63093 at 10:05:27.098382: ------------------------------------------------------------------------ ACK sip:1010@x.x.x.x:5061;transport=tls SIP/2.0 Via: SIP/2.0/TLS 192.168.93.102:45556;branch=z9hG4bK.Tek3oSUVA;rport From: ;tag=hKZC8L27Q To: ;tag=7j0Bjvte21NFe CSeq: 21 ACK Call-ID: BbPYZv5Bca Max-Forwards: 70 Proxy-Authorization: Digest realm="x.x.x.x", nonce="47fa5ad2-56da-11e5-abf6-a53fe62ce2f9", algorithm=MD5, username="1003", uri="sip:1010@x.x.x.x", response="7051af6f556408074ede39d53ff582c2", cnonce="faaa8515", nc=00000001, qop=auth Content-Length: 0 ------------------------------------------------------------------------ recv 566 bytes from tls/[180.151.83.178]:13916 at 10:05:56.602820: ------------------------------------------------------------------------ BYE sip:mod_sofia@x.x.x.x:5061;transport=tls SIP/2.0 Via: SIP/2.0/TLS 192.168.93.111:43713;branch=z9hG4bK.5hPjwbARP;rport From: ;tag=ezLC2Tx To: "Extension 1003" ;tag=8US4KQBjZac2S CSeq: 111 BYE Call-ID: 1fbbb0c5-d17d-1233-c292-1293c2c31053 Max-Forwards: 70 User-Agent: LinphoneAndroid/2.4.1-28-g98516d9 (belle-sip/1.4.1) Content-Length: 0 ------------------------------------------------------------------------ 2015-09-09 10:05:56.600460 [DEBUG] switch_core_session.c:1062 Send signal sofia/internal/1010@180.151.83.178:13916 [BREAK] 2015-09-09 10:05:56.600460 [NOTICE] sofia.c:952 Hangup sofia/internal/1010@180.151.83.178:13916 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING] 2015-09-09 10:05:56.600460 [DEBUG] switch_channel.c:3242 Send signal sofia/internal/1010@180.151.83.178:13916 [KILL] 2015-09-09 10:05:56.600460 [DEBUG] switch_core_session.c:1397 Send signal sofia/internal/1010@180.151.83.178:13916 [BREAK] send 693 bytes to tls/[180.151.83.178]:13916 at 10:05:56.606104: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/TLS 192.168.93.111:43713;branch=z9hG4bK.5hPjwbARP;rport=13916;received=180.151.83.178 From: ;tag=ezLC2Tx To: "Extension 1003" ;tag=8US4KQBjZac2S Call-ID: 1fbbb0c5-d17d-1233-c292-1293c2c31053 CSeq: 111 BYE User-Agent: FreeSWITCH-mod_sofia/1.4.21+git~20150901T202622Z~a223dd0236~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Content-Length: 0 ------------------------------------------------------------------------ 2015-09-09 10:05:56.600460 [DEBUG] switch_ivr_bridge.c:660 BRIDGE THREAD DONE [sofia/internal/1010@180.151.83.178:13916] 2015-09-09 10:05:56.600460 [DEBUG] switch_ivr_bridge.c:690 Send signal sofia/internal/1003@x.x.x.x [BREAK] 2015-09-09 10:05:56.600460 [DEBUG] switch_core_state_machine.c:538 (sofia/internal/1010@180.151.83.178:13916) State EXCHANGE_MEDIA going to sleep 2015-09-09 10:05:56.600460 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/1010@180.151.83.178:13916) Running State Change CS_HANGUP 2015-09-09 10:05:56.600460 [DEBUG] switch_core_state_machine.c:735 (sofia/internal/1010@180.151.83.178:13916) Callstate Change ACTIVE -> HANGUP 2015-09-09 10:05:56.600460 [DEBUG] switch_core_state_machine.c:737 (sofia/internal/1010@180.151.83.178:13916) State HANGUP 2015-09-09 10:05:56.600460 [DEBUG] mod_sofia.c:413 Channel sofia/internal/1010@180.151.83.178:13916 hanging up, cause: NORMAL_CLEARING 2015-09-09 10:05:56.600460 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1010@180.151.83.178:13916 Standard HANGUP, cause: NORMAL_CLEARING 2015-09-09 10:05:56.600460 [DEBUG] switch_core_state_machine.c:737 (sofia/internal/1010@180.151.83.178:13916) State HANGUP going to sleep 2015-09-09 10:05:56.600460 [DEBUG] switch_core_state_machine.c:504 (sofia/internal/1010@180.151.83.178:13916) State Change CS_HANGUP -> CS_REPORTING 2015-09-09 10:05:56.600460 [DEBUG] switch_core_session.c:1397 Send signal sofia/internal/1010@180.151.83.178:13916 [BREAK] 2015-09-09 10:05:56.600460 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/1010@180.151.83.178:13916) Running State Change CS_REPORTING 2015-09-09 10:05:56.600460 [DEBUG] switch_core_state_machine.c:823 (sofia/internal/1010@180.151.83.178:13916) State REPORTING 2015-09-09 10:05:56.600460 [DEBUG] switch_core_state_machine.c:104 sofia/internal/1010@180.151.83.178:13916 Standard REPORTING, cause: NORMAL_CLEARING 2015-09-09 10:05:56.600460 [DEBUG] switch_core_state_machine.c:823 (sofia/internal/1010@180.151.83.178:13916) State REPORTING going to sleep 2015-09-09 10:05:56.600460 [DEBUG] switch_core_state_machine.c:498 (sofia/internal/1010@180.151.83.178:13916) State Change CS_REPORTING -> CS_DESTROY 2015-09-09 10:05:56.600460 [DEBUG] switch_core_session.c:1397 Send signal sofia/internal/1010@180.151.83.178:13916 [BREAK] 2015-09-09 10:05:56.600460 [DEBUG] switch_core_session.c:1624 Session 2 (sofia/internal/1010@180.151.83.178:13916) Locked, Waiting on external entities 2015-09-09 10:05:56.600460 [DEBUG] switch_ivr_bridge.c:579 sofia/internal/1010@180.151.83.178:13916 ending bridge by request from write function 2015-09-09 10:05:56.600460 [DEBUG] switch_ivr_bridge.c:660 BRIDGE THREAD DONE [sofia/internal/1003@x.x.x.x] 2015-09-09 10:05:56.600460 [DEBUG] switch_ivr_bridge.c:690 Send signal sofia/internal/1010@180.151.83.178:13916 [BREAK] 2015-09-09 10:05:56.600460 [DEBUG] switch_core_session.c:913 Send signal sofia/internal/1003@x.x.x.x [BREAK] 2015-09-09 10:05:56.600460 [NOTICE] switch_ivr_bridge.c:1611 Hangup sofia/internal/1003@x.x.x.x [CS_EXECUTE] [NORMAL_CLEARING] 2015-09-09 10:05:56.600460 [DEBUG] switch_channel.c:3242 Send signal sofia/internal/1003@x.x.x.x [KILL] 2015-09-09 10:05:56.600460 [DEBUG] switch_core_session.c:1397 Send signal sofia/internal/1003@x.x.x.x [BREAK] 2015-09-09 10:05:56.600460 [NOTICE] switch_core_session.c:1642 Session 2 (sofia/internal/1010@180.151.83.178:13916) Ended 2015-09-09 10:05:56.600460 [NOTICE] switch_core_session.c:1646 Close Channel sofia/internal/1010@180.151.83.178:13916 [CS_DESTROY] 2015-09-09 10:05:56.600460 [DEBUG] switch_core_state_machine.c:626 (sofia/internal/1010@180.151.83.178:13916) Running State Change CS_DESTROY 2015-09-09 10:05:56.600460 [DEBUG] switch_core_state_machine.c:636 (sofia/internal/1010@180.151.83.178:13916) State DESTROY 2015-09-09 10:05:56.600460 [DEBUG] mod_sofia.c:323 sofia/internal/1010@180.151.83.178:13916 SOFIA DESTROY 2015-09-09 10:05:56.600460 [DEBUG] switch_core_state_machine.c:111 sofia/internal/1010@180.151.83.178:13916 Standard DESTROY 2015-09-09 10:05:56.600460 [DEBUG] switch_core_state_machine.c:636 (sofia/internal/1010@180.151.83.178:13916) State DESTROY going to sleep 2015-09-09 10:05:56.600460 [DEBUG] switch_core_session.c:2903 sofia/internal/1003@x.x.x.x skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2015-09-09 10:05:56.600460 [DEBUG] switch_core_state_machine.c:535 (sofia/internal/1003@x.x.x.x) State EXECUTE going to sleep 2015-09-09 10:05:56.600460 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/1003@x.x.x.x) Running State Change CS_HANGUP 2015-09-09 10:05:56.600460 [DEBUG] switch_core_state_machine.c:735 (sofia/internal/1003@x.x.x.x) Callstate Change ACTIVE -> HANGUP 2015-09-09 10:05:56.600460 [DEBUG] switch_core_state_machine.c:737 (sofia/internal/1003@x.x.x.x) State HANGUP 2015-09-09 10:05:56.600460 [DEBUG] mod_sofia.c:407 sofia/internal/1003@x.x.x.x Overriding SIP cause 480 with 200 from the other leg 2015-09-09 10:05:56.600460 [DEBUG] mod_sofia.c:413 Channel sofia/internal/1003@x.x.x.x hanging up, cause: NORMAL_CLEARING 2015-09-09 10:05:56.600460 [DEBUG] mod_sofia.c:465 Sending BYE to sofia/internal/1003@x.x.x.x 2015-09-09 10:05:56.600460 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1003@x.x.x.x Standard HANGUP, cause: NORMAL_CLEARING 2015-09-09 10:05:56.600460 [DEBUG] switch_core_state_machine.c:737 (sofia/internal/1003@x.x.x.x) State HANGUP going to sleep 2015-09-09 10:05:56.600460 [DEBUG] switch_core_state_machine.c:504 (sofia/internal/1003@x.x.x.x) State Change CS_HANGUP -> CS_REPORTING 2015-09-09 10:05:56.600460 [DEBUG] switch_core_session.c:1397 Send signal sofia/internal/1003@x.x.x.x [BREAK] 2015-09-09 10:05:56.600460 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/1003@x.x.x.x) Running State Change CS_REPORTING 2015-09-09 10:05:56.600460 [DEBUG] switch_core_state_machine.c:823 (sofia/internal/1003@x.x.x.x) State REPORTING 2015-09-09 10:05:56.600460 [DEBUG] switch_core_state_machine.c:104 sofia/internal/1003@x.x.x.x Standard REPORTING, cause: NORMAL_CLEARING 2015-09-09 10:05:56.600460 [DEBUG] switch_core_state_machine.c:823 (sofia/internal/1003@x.x.x.x) State REPORTING going to sleep 2015-09-09 10:05:56.600460 [DEBUG] switch_core_state_machine.c:498 (sofia/internal/1003@x.x.x.x) State Change CS_REPORTING -> CS_DESTROY 2015-09-09 10:05:56.600460 [DEBUG] switch_core_session.c:1397 Send signal sofia/internal/1003@x.x.x.x [BREAK] 2015-09-09 10:05:56.600460 [DEBUG] switch_core_session.c:1624 Session 1 (sofia/internal/1003@x.x.x.x) Locked, Waiting on external entities 2015-09-09 10:05:56.600460 [NOTICE] switch_core_session.c:1642 Session 1 (sofia/internal/1003@x.x.x.x) Ended 2015-09-09 10:05:56.600460 [NOTICE] switch_core_session.c:1646 Close Channel sofia/internal/1003@x.x.x.x [CS_DESTROY] 2015-09-09 10:05:56.600460 [DEBUG] switch_core_state_machine.c:626 (sofia/internal/1003@x.x.x.x) Running State Change CS_DESTROY 2015-09-09 10:05:56.600460 [DEBUG] switch_core_state_machine.c:636 (sofia/internal/1003@x.x.x.x) State DESTROY 2015-09-09 10:05:56.600460 [DEBUG] mod_sofia.c:323 sofia/internal/1003@x.x.x.x SOFIA DESTROY 2015-09-09 10:05:56.600460 [DEBUG] switch_core_state_machine.c:111 sofia/internal/1003@x.x.x.x Standard DESTROY 2015-09-09 10:05:56.600460 [DEBUG] switch_core_state_machine.c:636 (sofia/internal/1003@x.x.x.x) State DESTROY going to sleep send 569 bytes to tls/[180.151.83.178]:63093 at 10:05:56.617659: ------------------------------------------------------------------------ BYE sip:1003@180.151.83.178:63093;transport=tls SIP/2.0 Via: SIP/2.0/TLS x.x.x.x:5061;rport;branch=z9hG4bKp3ZQgF12K46Sg Max-Forwards: 70 From: ;tag=7j0Bjvte21NFe To: ;tag=hKZC8L27Q Call-ID: BbPYZv5Bca CSeq: 80560514 BYE User-Agent: FreeSWITCH-mod_sofia/1.4.21+git~20150901T202622Z~a223dd0236~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Reason: Q.850;cause=16;text="NORMAL_CLEARING" Content-Length: 0 ------------------------------------------------------------------------ recv 326 bytes from tls/[180.151.83.178]:63093 at 10:05:57.406495: ------------------------------------------------------------------------ SIP/2.0 200 Ok Via: SIP/2.0/TLS x.x.x.x:5061;rport;branch=z9hG4bKp3ZQgF12K46Sg From: ;tag=7j0Bjvte21NFe To: ;tag=hKZC8L27Q Call-ID: BbPYZv5Bca CSeq: 80560514 BYE User-Agent: LinphoneAndroid/2.4.1-28-g98516d9 (belle-sip/1.4.1) Supported: outbound Content-Length: 0 --------------------