freeswitch@localhost.localdomain> 2017-01-19 17:55:08.515299 [WARNING] sofia_presence.c:5077 check_subs: external-ipv6 is passive, skipping freeswitch@localhost.localdomain> freeswitch@localhost.localdomain> sofi [ sofia] [ sofia_contact] [ sofia_count_reg] [ sofia_dig] [ sofia_gateway_data] [ sofia_presence_data] [ sofia_username_of] freeswitch@localhost.localdomain> sofia glo [ global] freeswitch@localhost.localdomain> sofia global 2017-01-19 17:55:38.755302 [WARNING] sofia_presence.c:5077 check_subs: external-ipv6 is passive, skipping siptra [ siptrace] freeswitch@localhost.localdomain> sofia global siptrace o [ on] [ off] freeswitch@localhost.localdomain> sofia global siptrace on [ on] freeswitch@localhost.localdomain> sofia global siptrace on +OK Global siptrace on freeswitch@localhost.localdomain> console loglev [ loglevel] freeswitch@localhost.localdomain> console loglevel debug +OK console log level set to DEBUG freeswitch@localhost.localdomain> 2017-01-19 17:56:09.014392 [WARNING] sofia_presence.c:5077 check_subs: external-ipv6 is passive, skipping sofia tracelevel alert +OK tracelevel is ALERT freeswitch@localhost.localdomain> recv 1422 bytes from udp/[10.90.111.21]:5060 at 17:56:35.736340: ------------------------------------------------------------------------ INVITE sip:30000@10.90.111.196 SIP/2.0 Call-ID: 64517400ba1d554c830f45be85e95607@0:0:0:0:0:0:0:0 CSeq: 1 INVITE From: "1001" ;tag=4f65891a To: Via: SIP/2.0/UDP 10.90.111.21:5060;branch=z9hG4bK-313938-33fecedd00708bbca83bad7b51034efa Max-Forwards: 70 Contact: "1001" User-Agent: Jitsi2.8.5426Windows 8 Content-Type: application/sdp Content-Length: 935 v=0 o=1001-jitsi.org 0 0 IN IP4 10.90.111.21 s=- c=IN IP4 10.90.111.21 t=0 0 m=audio 5008 RTP/AVP 96 97 98 9 100 102 0 8 103 3 104 4 101 a=rtpmap:96 opus/48000/2 a=fmtp:96 usedtx=1 a=rtpmap:97 SILK/24000 a=rtpmap:98 SILK/16000 a=rtpmap:9 G722/8000 a=rtpmap:100 speex/32000 a=rtpmap:102 speex/16000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:103 iLBC/8000 a=rtpmap:3 GSM/8000 a=rtpmap:104 speex/8000 a=rtpmap:4 G723/8000 a=fmtp:4 annexa=no;bitrate=6.3 a=rtpmap:101 telephone-event/8000 a=extmap:1 urn:ietf:params:rtp-hdrext:csrc-audio-level a=extmap:2 urn:ietf:params:rtp-hdrext:ssrc-audio-level a=rtcp-xr:voip-metrics m=video 5010 RTP/AVP 105 99 a=recvonly a=rtpmap:105 H264/90000 a=fmtp:105 profile-level-id=4DE01f;packetization-mode=1 a=imageattr:105 send * recv [x=[0-1366],y=[0-768]] a=rtpmap:99 H264/90000 a=fmtp:99 profile-level-id=4DE01f a=imageattr:99 send * recv [x=[0-1366],y=[0-768]] ------------------------------------------------------------------------ send 337 bytes to udp/[10.90.111.21]:5060 at 17:56:35.736574: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.90.111.21:5060;branch=z9hG4bK-313938-33fecedd00708bbca83bad7b51034efa From: "1001" ;tag=4f65891a To: Call-ID: 64517400ba1d554c830f45be85e95607@0:0:0:0:0:0:0:0 CSeq: 1 INVITE User-Agent: FreeSWITCH-mod_sofia/1.6.14~64bit Content-Length: 0 ------------------------------------------------------------------------ 2017-01-19 17:56:35.736067 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1001@10.90.111.196 [84ba0012-de42-11e6-bb7c-b9b014fd381e] 2017-01-19 17:56:35.736067 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@10.90.111.196) Running State Change CS_NEW (Cur 1 Tot 4) 2017-01-19 17:56:35.736067 [DEBUG] sofia.c:9815 sofia/internal/1001@10.90.111.196 receiving invite from 10.90.111.21:5060 version: 1.6.14 64bit 2017-01-19 17:56:35.736067 [DEBUG] sofia.c:9982 IP 10.90.111.21 Rejected by acl "domains". Falling back to Digest auth. send 841 bytes to udp/[10.90.111.21]:5060 at 17:56:35.748410: ------------------------------------------------------------------------ SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 10.90.111.21:5060;branch=z9hG4bK-313938-33fecedd00708bbca83bad7b51034efa From: "1001" ;tag=4f65891a To: ;tag=7UF5N931pQypp Call-ID: 64517400ba1d554c830f45be85e95607@0:0:0:0:0:0:0:0 CSeq: 1 INVITE User-Agent: FreeSWITCH-mod_sofia/1.6.14~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="10.90.111.196", nonce="84ba4cac-de42-11e6-bb7d-b9b014fd381e", algorithm=MD5, qop="auth" Content-Length: 0 ------------------------------------------------------------------------ 2017-01-19 17:56:35.736067 [DEBUG] sofia.c:2333 detaching session 84ba0012-de42-11e6-bb7c-b9b014fd381e 2017-01-19 17:56:35.736067 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/1001@10.90.111.196) State NEW recv 340 bytes from udp/[10.90.111.21]:5060 at 17:56:35.750809: ------------------------------------------------------------------------ ACK sip:30000@10.90.111.196 SIP/2.0 Call-ID: 64517400ba1d554c830f45be85e95607@0:0:0:0:0:0:0:0 Max-Forwards: 70 From: "1001" ;tag=4f65891a To: ;tag=7UF5N931pQypp Via: SIP/2.0/UDP 10.90.111.21:5060;branch=z9hG4bK-313938-33fecedd00708bbca83bad7b51034efa CSeq: 1 ACK Content-Length: 0 ------------------------------------------------------------------------ recv 1656 bytes from udp/[10.90.111.21]:5060 at 17:56:35.752487: ------------------------------------------------------------------------ INVITE sip:30000@10.90.111.196 SIP/2.0 Call-ID: 64517400ba1d554c830f45be85e95607@0:0:0:0:0:0:0:0 CSeq: 2 INVITE From: "1001" ;tag=4f65891a To: Max-Forwards: 70 Contact: "1001" User-Agent: Jitsi2.8.5426Windows 8 Content-Type: application/sdp Via: SIP/2.0/UDP 10.90.111.21:5060;branch=z9hG4bK-313938-5fc9fe0a66995f7f4289e7fa174576d0 Proxy-Authorization: Digest username="1001",realm="10.90.111.196",nonce="84ba4cac-de42-11e6-bb7d-b9b014fd381e",uri="sip:30000@10.90.111.196",response="7f0ed5ee03b2e50e108ec28320829290",algorithm=MD5,qop=auth,cnonce="xyz",nc=00000001 Content-Length: 935 v=0 o=1001-jitsi.org 0 0 IN IP4 10.90.111.21 s=- c=IN IP4 10.90.111.21 t=0 0 m=audio 5008 RTP/AVP 96 97 98 9 100 102 0 8 103 3 104 4 101 a=rtpmap:96 opus/48000/2 a=fmtp:96 usedtx=1 a=rtpmap:97 SILK/24000 a=rtpmap:98 SILK/16000 a=rtpmap:9 G722/8000 a=rtpmap:100 speex/32000 a=rtpmap:102 speex/16000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:103 iLBC/8000 a=rtpmap:3 GSM/8000 a=rtpmap:104 speex/8000 a=rtpmap:4 G723/8000 a=fmtp:4 annexa=no;bitrate=6.3 a=rtpmap:101 telephone-event/8000 a=extmap:1 urn:ietf:params:rtp-hdrext:csrc-audio-level a=extmap:2 urn:ietf:params:rtp-hdrext:ssrc-audio-level a=rtcp-xr:voip-metrics m=video 5010 RTP/AVP 105 99 a=recvonly a=rtpmap:105 H264/90000 a=fmtp:105 profile-level-id=4DE01f;packetization-mode=1 a=imageattr:105 send * recv [x=[0-1366],y=[0-768]] a=rtpmap:99 H264/90000 a=fmtp:99 profile-level-id=4DE01f a=imageattr:99 send * recv [x=[0-1366],y=[0-768]] ------------------------------------------------------------------------ send 337 bytes to udp/[10.90.111.21]:5060 at 17:56:35.752865: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.90.111.21:5060;branch=z9hG4bK-313938-5fc9fe0a66995f7f4289e7fa174576d0 From: "1001" ;tag=4f65891a To: Call-ID: 64517400ba1d554c830f45be85e95607@0:0:0:0:0:0:0:0 CSeq: 2 INVITE User-Agent: FreeSWITCH-mod_sofia/1.6.14~64bit Content-Length: 0 ------------------------------------------------------------------------ 2017-01-19 17:56:35.736067 [DEBUG] sofia.c:2441 Re-attaching to session 84ba0012-de42-11e6-bb7c-b9b014fd381e 2017-01-19 17:56:35.736067 [DEBUG] sofia.c:9815 sofia/internal/1001@10.90.111.196 receiving invite from 10.90.111.21:5060 version: 1.6.14 64bit 2017-01-19 17:56:35.736067 [DEBUG] sofia.c:9982 IP 10.90.111.21 Rejected by acl "domains". Falling back to Digest auth. 2017-01-19 17:56:35.774369 [DEBUG] sofia.c:7041 Channel sofia/internal/1001@10.90.111.196 entering state [received][100] 2017-01-19 17:56:35.774369 [DEBUG] sofia.c:7051 Remote SDP: v=0 o=1001-jitsi.org 0 0 IN IP4 10.90.111.21 s=- c=IN IP4 10.90.111.21 t=0 0 m=audio 5008 RTP/AVP 96 97 98 9 100 102 0 8 103 3 104 4 101 a=rtpmap:96 opus/48000/2 a=fmtp:96 usedtx=1 a=rtpmap:97 SILK/24000 a=rtpmap:98 SILK/16000 a=rtpmap:9 G722/8000 a=rtpmap:100 speex/32000 a=rtpmap:102 speex/16000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:103 iLBC/8000 a=rtpmap:3 GSM/8000 a=rtpmap:104 speex/8000 a=rtpmap:4 G723/8000 a=fmtp:4 annexa=no;bitrate=6.3 a=rtpmap:101 telephone-event/8000 a=extmap:1 urn:ietf:params:rtp-hdrext:csrc-audio-level a=extmap:2 urn:ietf:params:rtp-hdrext:ssrc-audio-level a=rtcp-xr:voip-metrics m=video 5010 RTP/AVP 105 99 a=rtpmap:105 H264/90000 a=fmtp:105 profile-level-id=4DE01f;packetization-mode=1 a=rtpmap:99 H264/90000 a=fmtp:99 profile-level-id=4DE01f a=recvonly a=imageattr:105 send * recv [x=[0-1366],y=[0-768]] a=imageattr:99 send * recv [x=[0-1366],y=[0-768]] 2017-01-19 17:56:35.774369 [DEBUG] sofia.c:7443 (sofia/internal/1001@10.90.111.196) State Change CS_NEW -> CS_INIT 2017-01-19 17:56:35.774369 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@10.90.111.196) Running State Change CS_INIT (Cur 1 Tot 4) 2017-01-19 17:56:35.774369 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1001@10.90.111.196) State INIT 2017-01-19 17:56:35.774369 [DEBUG] mod_sofia.c:90 sofia/internal/1001@10.90.111.196 SOFIA INIT 2017-01-19 17:56:35.774369 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1001@10.90.111.196 Standard INIT 2017-01-19 17:56:35.774369 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1001@10.90.111.196) State Change CS_INIT -> CS_ROUTING 2017-01-19 17:56:35.774369 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1001@10.90.111.196) State INIT going to sleep 2017-01-19 17:56:35.774369 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@10.90.111.196) Running State Change CS_ROUTING (Cur 1 Tot 4) 2017-01-19 17:56:35.774369 [DEBUG] switch_channel.c:2249 (sofia/internal/1001@10.90.111.196) Callstate Change DOWN -> RINGING 2017-01-19 17:56:35.774369 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1001@10.90.111.196) State ROUTING 2017-01-19 17:56:35.774369 [DEBUG] mod_sofia.c:143 sofia/internal/1001@10.90.111.196 SOFIA ROUTING 2017-01-19 17:56:35.774369 [DEBUG] switch_core_state_machine.c:236 sofia/internal/1001@10.90.111.196 Standard ROUTING 2017-01-19 17:56:35.815142 [INFO] mod_dialplan_xml.c:637 Processing 1001 <1001>->30000 in context default Dialplan: sofia/internal/1001@10.90.111.196 parsing [default->unloop] continue=false Dialplan: sofia/internal/1001@10.90.111.196 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/internal/1001@10.90.111.196 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: sofia/internal/1001@10.90.111.196 parsing [default->tod_example] continue=true Dialplan: sofia/internal/1001@10.90.111.196 Date/Time Match (PASS) [tod_example] break=on-false Dialplan: sofia/internal/1001@10.90.111.196 Action set(open=true) Dialplan: sofia/internal/1001@10.90.111.196 parsing [default->holiday_example] continue=true Dialplan: sofia/internal/1001@10.90.111.196 Date/TimeMatch (FAIL) [holiday_example] break=on-false Dialplan: sofia/internal/1001@10.90.111.196 parsing [default->global-intercept] continue=false Dialplan: sofia/internal/1001@10.90.111.196 Regex (FAIL) [global-intercept] destination_number(30000) =~ /^886$/ break=on-false Dialplan: sofia/internal/1001@10.90.111.196 parsing [default->group-intercept] continue=false Dialplan: sofia/internal/1001@10.90.111.196 Regex (FAIL) [group-intercept] destination_number(30000) =~ /^\*8$/ break=on-false Dialplan: sofia/internal/1001@10.90.111.196 parsing [default->intercept-ext] continue=false Dialplan: sofia/internal/1001@10.90.111.196 Regex (FAIL) [intercept-ext] destination_number(30000) =~ /^\*\*(\d+)$/ break=on-false Dialplan: sofia/internal/1001@10.90.111.196 parsing [default->redial] continue=false Dialplan: sofia/internal/1001@10.90.111.196 Regex (FAIL) [redial] destination_number(30000) =~ /^(redial|870)$/ break=on-false Dialplan: sofia/internal/1001@10.90.111.196 parsing [default->global] continue=true Dialplan: sofia/internal/1001@10.90.111.196 Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never Dialplan: sofia/internal/1001@10.90.111.196 Regex (PASS) [global] ${default_password}(1234) =~ /^1234$/ break=never Dialplan: sofia/internal/1001@10.90.111.196 Action log(CRIT WARNING WARNING WARNING WARNING WARNING WARNING WARNING WARNING WARNING ) Dialplan: sofia/internal/1001@10.90.111.196 Action log(CRIT Open /etc/freeswitch/vars.xml and change the default_password.) Dialplan: sofia/internal/1001@10.90.111.196 Action log(CRIT Once changed type 'reloadxml' at the console.) Dialplan: sofia/internal/1001@10.90.111.196 Action log(CRIT WARNING WARNING WARNING WARNING WARNING WARNING WARNING WARNING WARNING ) Dialplan: sofia/internal/1001@10.90.111.196 Action sleep(10000) Dialplan: sofia/internal/1001@10.90.111.196 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/1001@10.90.111.196 Regex (PASS) [global] ${endpoint_disposition}(DELAYED NEGOTIATION) =~ /^(DELAYED NEGOTIATION)/ break=on-false Dialplan: sofia/internal/1001@10.90.111.196 Regex (FAIL) [global] ${switch_r_sdp}(v=0 o=1001-jitsi.org 0 0 IN IP4 10.90.111.21 s=- c=IN IP4 10.90.111.21 t=0 0 m=audio 5008 RTP/AVP 96 97 98 9 100 102 0 8 103 3 104 4 101 a=rtpmap:96 opus/48000/2 a=fmtp:96 usedtx=1 a=rtpmap:97 SILK/24000 a=rtpmap:98 SILK/16000 a=rtpmap:9 G722/8000 a=rtpmap:100 speex/32000 a=rtpmap:102 speex/16000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:103 iLBC/8000 a=rtpmap:3 GSM/8000 a=rtpmap:104 speex/8000 a=rtpmap:4 G723/8000 a=fmtp:4 annexa=no;bitrate=6.3 a=rtpmap:101 telephone-event/8000 a=extmap:1 urn:ietf:params:rtp-hdrext:csrc-audio-level a=extmap:2 urn:ietf:params:rtp-hdrext:ssrc-audio-level a=rtcp-xr:voip-metrics m=video 5010 RTP/AVP 105 99 a=rtpmap:105 H264/90000 a=fmtp:105 profile-level-id=4DE01f;packetization-mode=1 a=rtpmap:99 H264/90000 a=fmtp:99 profile-level-id=4DE01f a=recvonly a=imageattr:105 send * recv [x=[0-1366],y=[0-768]] a=imageattr:99 send * recv [x=[0-1366],y=[0-768]] ) =~ /(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)/ break=never Dialplan: sofia/internal/1001@10.90.111.196 Absolute Condition [global] Dialplan: sofia/internal/1001@10.90.111.196 Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid}) Dialplan: sofia/internal/1001@10.90.111.196 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number}) Dialplan: sofia/internal/1001@10.90.111.196 Action hash(insert/${domain_name}-last_dial/global/${uuid}) Dialplan: sofia/internal/1001@10.90.111.196 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) Dialplan: sofia/internal/1001@10.90.111.196 parsing [default->snom-demo-2] continue=false Dialplan: sofia/internal/1001@10.90.111.196 Regex (FAIL) [snom-demo-2] destination_number(30000) =~ /^9001$/ break=on-false Dialplan: sofia/internal/1001@10.90.111.196 parsing [default->snom-demo-1] continue=false Dialplan: sofia/internal/1001@10.90.111.196 Regex (FAIL) [snom-demo-1] destination_number(30000) =~ /^9000$/ break=on-false Dialplan: sofia/internal/1001@10.90.111.196 parsing [default->eavesdrop] continue=false Dialplan: sofia/internal/1001@10.90.111.196 Regex (FAIL) [eavesdrop] destination_number(30000) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false Dialplan: sofia/internal/1001@10.90.111.196 parsing [default->eavesdrop] continue=false Dialplan: sofia/internal/1001@10.90.111.196 Regex (FAIL) [eavesdrop] destination_number(30000) =~ /^779$/ break=on-false Dialplan: sofia/internal/1001@10.90.111.196 parsing [default->call_return] continue=false Dialplan: sofia/internal/1001@10.90.111.196 Regex (FAIL) [call_return] destination_number(30000) =~ /^\*69$|^869$|^lcr$/ break=on-false Dialplan: sofia/internal/1001@10.90.111.196 parsing [default->del-group] continue=false Dialplan: sofia/internal/1001@10.90.111.196 Regex (FAIL) [del-group] destination_number(30000) =~ /^80(\d{2})$/ break=on-false Dialplan: sofia/internal/1001@10.90.111.196 parsing [default->add-group] continue=false Dialplan: sofia/internal/1001@10.90.111.196 Regex (FAIL) [add-group] destination_number(30000) =~ /^81(\d{2})$/ break=on-false Dialplan: sofia/internal/1001@10.90.111.196 parsing [default->call-group-simo] continue=false Dialplan: sofia/internal/1001@10.90.111.196 Regex (FAIL) [call-group-simo] destination_number(30000) =~ /^82(\d{2})$/ break=on-false Dialplan: sofia/internal/1001@10.90.111.196 parsing [default->call-group-order] continue=false Dialplan: sofia/internal/1001@10.90.111.196 Regex (FAIL) [call-group-order] destination_number(30000) =~ /^83(\d{2})$/ break=on-false Dialplan: sofia/internal/1001@10.90.111.196 parsing [default->extension-intercom] continue=false Dialplan: sofia/internal/1001@10.90.111.196 Regex (FAIL) [extension-intercom] destination_number(30000) =~ /^8(10[01][0-9])$/ break=on-false Dialplan: sofia/internal/1001@10.90.111.196 parsing [default->Local_Extension] continue=false Dialplan: sofia/internal/1001@10.90.111.196 Regex (FAIL) [Local_Extension] destination_number(30000) =~ /^(10[01][0-9])$/ break=on-false Dialplan: sofia/internal/1001@10.90.111.196 parsing [default->Local_Extension_Skinny] continue=false Dialplan: sofia/internal/1001@10.90.111.196 Regex (FAIL) [Local_Extension_Skinny] destination_number(30000) =~ /^(11[01][0-9])$/ break=on-false Dialplan: sofia/internal/1001@10.90.111.196 parsing [default->group_dial_sales] continue=false Dialplan: sofia/internal/1001@10.90.111.196 Regex (FAIL) [group_dial_sales] destination_number(30000) =~ /^2000$/ break=on-false Dialplan: sofia/internal/1001@10.90.111.196 parsing [default->group_dial_support] continue=false Dialplan: sofia/internal/1001@10.90.111.196 Regex (FAIL) [group_dial_support] destination_number(30000) =~ /^2001$/ break=on-false Dialplan: sofia/internal/1001@10.90.111.196 parsing [default->group_dial_billing] continue=false Dialplan: sofia/internal/1001@10.90.111.196 Regex (FAIL) [group_dial_billing] destination_number(30000) =~ /^2002$/ break=on-false Dialplan: sofia/internal/1001@10.90.111.196 parsing [default->operator] continue=false Dialplan: sofia/internal/1001@10.90.111.196 Regex (FAIL) [operator] destination_number(30000) =~ /^(operator|0)$/ break=on-false Dialplan: sofia/internal/1001@10.90.111.196 parsing [default->vmain] continue=false Dialplan: sofia/internal/1001@10.90.111.196 Regex (FAIL) [vmain] destination_number(30000) =~ /^vmain$|^4000$|^\*98$/ break=on-false Dialplan: sofia/internal/1001@10.90.111.196 parsing [default->sip_uri] continue=false Dialplan: sofia/internal/1001@10.90.111.196 Regex (FAIL) [sip_uri] destination_number(30000) =~ /^sip:(.*)$/ break=on-false Dialplan: sofia/internal/1001@10.90.111.196 parsing [default->my_conferences] continue=false Dialplan: sofia/internal/1001@10.90.111.196 Regex (PASS) [my_conferences] destination_number(30000) =~ /^(300\d{2})$/ break=on-false Dialplan: sofia/internal/1001@10.90.111.196 Action answer(is_conference) Dialplan: sofia/internal/1001@10.90.111.196 Action conference(30000-${domain_name}@default) 2017-01-19 17:56:35.815142 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/1001@10.90.111.196) State Change CS_ROUTING -> CS_EXECUTE 2017-01-19 17:56:35.815142 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1001@10.90.111.196) State ROUTING going to sleep 2017-01-19 17:56:35.815142 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@10.90.111.196) Running State Change CS_EXECUTE (Cur 1 Tot 4) 2017-01-19 17:56:35.815142 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/1001@10.90.111.196) State EXECUTE 2017-01-19 17:56:35.815142 [DEBUG] mod_sofia.c:198 sofia/internal/1001@10.90.111.196 SOFIA EXECUTE 2017-01-19 17:56:35.815142 [DEBUG] switch_core_state_machine.c:328 sofia/internal/1001@10.90.111.196 Standard EXECUTE 2017-01-19 17:56:35.875099 [WARNING] sofia_presence.c:1312 external-ipv6 is passive, skipping 2017-01-19 17:56:35.875099 [CRIT] sofia_presence.c:1378 CHECK SQL: 1001@10.90.111.196 [select state,status,rpid,presence_id,uuid from sip_dialogs where uuid != '84ba0012-de42-11e6-bb7c-b9b014fd381e' and call_info_state != 'seized' and hostname='localhost.localdomain' and profile_name='external' and ((sip_from_user='1001' and sip_from_host='10.90.111.196') or presence_id='1001@10.90.111.196') order by rcd desc] hits: 0 2017-01-19 17:56:35.875099 [ERR] sofia_presence.c:1435 PRES SQL update sip_subscriptions set version=version+1 where hostname='localhost.localdomain' and profile_name='external' and sip_subscriptions.event != 'line-seize' and sip_subscriptions.proto='sip' and (event='presence' or event='dialog') and sub_to_user='1001' and (sub_to_host='10.90.111.196' or sub_to_host='10.90.111.196' or sub_to_host='N/A' or presence_hosts like '%10.90.111.196%') and (sip_subscriptions.profile_name = 'external' or presence_hosts like '%10.90.111.196%') 2017-01-19 17:56:35.875099 [INFO] sofia_presence.c:1510 IN START_PRESENCE_SQL (external) 2017-01-19 17:56:35.875099 [ERR] sofia_presence.c:1519 DUMP PRESENCE SQL: select distinct sip_subscriptions.proto,sip_subscriptions.sip_user,sip_subscriptions.sip_host,sip_subscriptions.sub_to_user,sip_subscriptions.sub_to_host,sip_subscriptions.event,sip_subscriptions.contact,sip_subscriptions.call_id,sip_subscriptions.full_from,sip_subscriptions.full_via,sip_subscriptions.expires,sip_subscriptions.user_agent,sip_subscriptions.accept,sip_subscriptions.profile_name,'CS_ROUTING','unknown','10.90.111.196',sip_presence.status,sip_presence.rpid,sip_presence.open_closed,'','',sip_subscriptions.version, '',sip_subscriptions.orig_proto,sip_subscriptions.full_to,sip_subscriptions.network_ip, sip_subscriptions.network_port from sip_subscriptions left join sip_presence on (sip_subscriptions.sub_to_user=sip_presence.sip_user and sip_subscriptions.sub_to_host=sip_presence.sip_host and sip_subscriptions.profile_name=sip_presence.profile_name and sip_subscriptions.hostname=sip_presence.hostname) where sip_subscriptions.hostname='localhost.localdomain' and sip_subscriptions.profile_name='external' and sip_subscriptions.event != 'line-seize' and sip_subscriptions.proto='sip' and (event='presence' or event='dialog') and sub_to_user='1001' and (sub_to_host='10.90.111.196' or sub_to_host='10.90.111.196' or sub_to_host='N/A' or presence_hosts like '%10.90.111.196%') EVENT DUMP: Event-Name: [PRESENCE_IN] Core-UUID: [a161672c-de2a-11e6-bb22-b9b014fd381e] FreeSWITCH-Hostname: [localhost.localdomain] FreeSWITCH-Switchname: [localhost.localdomain] FreeSWITCH-IPv4: [10.90.111.196] FreeSWITCH-IPv6: [::1] Event-Date-Local: [2017-01-19 17:56:35] Event-Date-GMT: [Thu, 19 Jan 2017 12:26:35 GMT] Event-Date-Timestamp: [1484828795815142] Event-Calling-File: [switch_channel.c] Event-Calling-Function: [switch_channel_perform_presence] Event-Calling-Line-Number: [785] Event-Sequence: [2452] Channel-State: [CS_ROUTING] Channel-Call-State: [RINGING] Channel-State-Number: [4] Channel-Name: [sofia/internal/1001@10.90.111.196] Unique-ID: [84ba0012-de42-11e6-bb7c-b9b014fd381e] Call-Direction: [inbound] Presence-Call-Direction: [inbound] Channel-HIT-Dialplan: [true] Channel-Presence-ID: [1001@10.90.111.196] Channel-Call-UUID: [84ba0012-de42-11e6-bb7c-b9b014fd381e] Answer-State: [ringing] Caller-Direction: [inbound] Caller-Logical-Direction: [inbound] Caller-Username: [1001] Caller-Dialplan: [XML] Caller-Caller-ID-Name: [1001] Caller-Caller-ID-Number: [1001] Caller-Orig-Caller-ID-Name: [1001] Caller-Orig-Caller-ID-Number: [1001] Caller-Network-Addr: [10.90.111.21] Caller-ANI: [1001] Caller-Destination-Number: [30000] Caller-Unique-ID: [84ba0012-de42-11e6-bb7c-b9b014fd381e] Caller-Source: [mod_sofia] Caller-Context: [default] Caller-Channel-Name: [sofia/internal/1001@10.90.111.196] Caller-Profile-Index: [1] Caller-Profile-Created-Time: [1484828795774369] Caller-Channel-Created-Time: [1484828795774369] Caller-Channel-Answered-Time: [0] Caller-Channel-Progress-Time: [0] Caller-Channel-Progress-Media-Time: [0] Caller-Channel-Hangup-Time: [0] Caller-Channel-Transfer-Time: [0] Caller-Channel-Resurrect-Time: [0] Caller-Channel-Bridged-Time: [0] Caller-Channel-Last-Hold: [0] Caller-Channel-Hold-Accum: [0] Caller-Screen-Bit: [true] Caller-Privacy-Hide-Name: [false] Caller-Privacy-Hide-Number: [false] proto: [any] login: [src/switch_channel.c] from: [1001@10.90.111.196] rpid: [unknown] status: [CS_ROUTING] event_type: [presence] alt_event_type: [dialog] presence-call-info-state: [alerting] presence-call-direction: [inbound] event_count: [0] Presence-Calling-File: [src/switch_core_state_machine.c] Presence-Calling-Function: [check_presence] Presence-Calling-Line: [524] 2017-01-19 17:56:35.875099 [INFO] sofia_presence.c:1530 IN END_PRESENCE_SQL (external) 2017-01-19 17:56:35.875099 [CRIT] sofia_presence.c:1378 CHECK SQL: 1001@10.90.111.196 [select state,status,rpid,presence_id,uuid from sip_dialogs where uuid != '84ba0012-de42-11e6-bb7c-b9b014fd381e' and call_info_state != 'seized' and hostname='localhost.localdomain' and profile_name='internal-ipv6' and ((sip_from_user='1001' and sip_from_host='10.90.111.196') or presence_id='1001@10.90.111.196') order by rcd desc] hits: 0 2017-01-19 17:56:35.875099 [ERR] sofia_presence.c:1435 PRES SQL update sip_subscriptions set version=version+1 where hostname='localhost.localdomain' and profile_name='internal-ipv6' and sip_subscriptions.event != 'line-seize' and sip_subscriptions.proto='sip' and (event='presence' or event='dialog') and sub_to_user='1001' and (sub_to_host='10.90.111.196' or sub_to_host='::1' or sub_to_host='N/A' or presence_hosts like '%10.90.111.196%') and (sip_subscriptions.profile_name = 'internal-ipv6' or presence_hosts like '%10.90.111.196%') 2017-01-19 17:56:35.875099 [INFO] sofia_presence.c:1510 IN START_PRESENCE_SQL (internal-ipv6) 2017-01-19 17:56:35.875099 [ERR] sofia_presence.c:1519 DUMP PRESENCE SQL: select distinct sip_subscriptions.proto,sip_subscriptions.sip_user,sip_subscriptions.sip_host,sip_subscriptions.sub_to_user,sip_subscriptions.sub_to_host,sip_subscriptions.event,sip_subscriptions.contact,sip_subscriptions.call_id,sip_subscriptions.full_from,sip_subscriptions.full_via,sip_subscriptions.expires,sip_subscriptions.user_agent,sip_subscriptions.accept,sip_subscriptions.profile_name,'CS_ROUTING','unknown','10.90.111.196',sip_presence.status,sip_presence.rpid,sip_presence.open_closed,'','',sip_subscriptions.version, '',sip_subscriptions.orig_proto,sip_subscriptions.full_to,sip_subscriptions.network_ip, sip_subscriptions.network_port from sip_subscriptions left join sip_presence on (sip_subscriptions.sub_to_user=sip_presence.sip_user and sip_subscriptions.sub_to_host=sip_presence.sip_host and sip_subscriptions.profile_name=sip_presence.profile_name and sip_subscriptions.hostname=sip_presence.hostname) where sip_subscriptions.hostname='localhost.localdomain' and sip_subscriptions.profile_name='internal-ipv6' and sip_subscriptions.event != 'line-seize' and sip_subscriptions.proto='sip' and (event='presence' or event='dialog') and sub_to_user='1001' and (sub_to_host='10.90.111.196' or sub_to_host='::1' or sub_to_host='N/A' or presence_hosts like '%10.90.111.196%') EVENT DUMP: Event-Name: [PRESENCE_IN] Core-UUID: [a161672c-de2a-11e6-bb22-b9b014fd381e] FreeSWITCH-Hostname: [localhost.localdomain] FreeSWITCH-Switchname: [localhost.localdomain] FreeSWITCH-IPv4: [10.90.111.196] FreeSWITCH-IPv6: [::1] Event-Date-Local: [2017-01-19 17:56:35] Event-Date-GMT: [Thu, 19 Jan 2017 12:26:35 GMT] Event-Date-Timestamp: [1484828795815142] Event-Calling-File: [switch_channel.c] Event-Calling-Function: [switch_channel_perform_presence] Event-Calling-Line-Number: [785] Event-Sequence: [2452] Channel-State: [CS_ROUTING] Channel-Call-State: [RINGING] Channel-State-Number: [4] Channel-Name: [sofia/internal/1001@10.90.111.196] Unique-ID: [84ba0012-de42-11e6-bb7c-b9b014fd381e] Call-Direction: [inbound] Presence-Call-Direction: [inbound] Channel-HIT-Dialplan: [true] Channel-Presence-ID: [1001@10.90.111.196] Channel-Call-UUID: [84ba0012-de42-11e6-bb7c-b9b014fd381e] Answer-State: [ringing] Caller-Direction: [inbound] Caller-Logical-Direction: [inbound] Caller-Username: [1001] Caller-Dialplan: [XML] Caller-Caller-ID-Name: [1001] Caller-Caller-ID-Number: [1001] Caller-Orig-Caller-ID-Name: [1001] Caller-Orig-Caller-ID-Number: [1001] Caller-Network-Addr: [10.90.111.21] Caller-ANI: [1001] Caller-Destination-Number: [30000] Caller-Unique-ID: [84ba0012-de42-11e6-bb7c-b9b014fd381e] Caller-Source: [mod_sofia] Caller-Context: [default] Caller-Channel-Name: [sofia/internal/1001@10.90.111.196] Caller-Profile-Index: [1] Caller-Profile-Created-Time: [1484828795774369] Caller-Channel-Created-Time: [1484828795774369] Caller-Channel-Answered-Time: [0] Caller-Channel-Progress-Time: [0] Caller-Channel-Progress-Media-Time: [0] Caller-Channel-Hangup-Time: [0] Caller-Channel-Transfer-Time: [0] Caller-Channel-Resurrect-Time: [0] Caller-Channel-Bridged-Time: [0] Caller-Channel-Last-Hold: [0] Caller-Channel-Hold-Accum: [0] Caller-Screen-Bit: [true] Caller-Privacy-Hide-Name: [false] Caller-Privacy-Hide-Number: [false] proto: [any] login: [src/switch_channel.c] from: [1001@10.90.111.196] rpid: [unknown] status: [CS_ROUTING] event_type: [presence] alt_event_type: [dialog] presence-call-info-state: [alerting] presence-call-direction: [inbound] event_count: [0] Presence-Calling-File: [src/switch_core_state_machine.c] Presence-Calling-Function: [check_presence] Presence-Calling-Line: [524] 2017-01-19 17:56:35.875099 [INFO] sofia_presence.c:1530 IN END_PRESENCE_SQL (internal-ipv6) EXECUTE sofia/internal/1001@10.90.111.196 set(open=true) 2017-01-19 17:56:35.875099 [DEBUG] mod_dptools.c:1527 SET sofia/internal/1001@10.90.111.196 [open]=[true] EXECUTE sofia/internal/1001@10.90.111.196 log(CRIT WARNING WARNING WARNING WARNING WARNING WARNING WARNING WARNING WARNING ) 2017-01-19 17:56:35.875099 [CRIT] mod_dptools.c:1721 WARNING WARNING WARNING WARNING WARNING WARNING WARNING WARNING WARNING EXECUTE sofia/internal/1001@10.90.111.196 log(CRIT Open /etc/freeswitch/vars.xml and change the default_password.) 2017-01-19 17:56:35.875099 [CRIT] mod_dptools.c:1721 Open /etc/freeswitch/vars.xml and change the default_password. EXECUTE sofia/internal/1001@10.90.111.196 log(CRIT Once changed type 'reloadxml' at the console.) 2017-01-19 17:56:35.875099 [CRIT] mod_dptools.c:1721 Once changed type 'reloadxml' at the console. EXECUTE sofia/internal/1001@10.90.111.196 log(CRIT WARNING WARNING WARNING WARNING WARNING WARNING WARNING WARNING WARNING ) 2017-01-19 17:56:35.875099 [CRIT] mod_dptools.c:1721 WARNING WARNING WARNING WARNING WARNING WARNING WARNING WARNING WARNING EXECUTE sofia/internal/1001@10.90.111.196 sleep(10000) 2017-01-19 17:56:35.875099 [CRIT] sofia_presence.c:1378 CHECK SQL: 1001@10.90.111.196 [select state,status,rpid,presence_id,uuid from sip_dialogs where uuid != '84ba0012-de42-11e6-bb7c-b9b014fd381e' and call_info_state != 'seized' and hostname='localhost.localdomain' and profile_name='internal' and ((sip_from_user='1001' and sip_from_host='10.90.111.196') or presence_id='1001@10.90.111.196') order by rcd desc] hits: 0 2017-01-19 17:56:35.875099 [ERR] sofia_presence.c:1435 PRES SQL update sip_subscriptions set version=version+1 where hostname='localhost.localdomain' and profile_name='internal' and sip_subscriptions.event != 'line-seize' and sip_subscriptions.proto='sip' and (event='presence' or event='dialog') and sub_to_user='1001' and (sub_to_host='10.90.111.196' or sub_to_host='10.90.111.196' or sub_to_host='N/A' or presence_hosts like '%10.90.111.196%') and (sip_subscriptions.profile_name = 'internal' or presence_hosts like '%10.90.111.196%') 2017-01-19 17:56:35.875099 [INFO] sofia_presence.c:1510 IN START_PRESENCE_SQL (internal) 2017-01-19 17:56:35.875099 [ERR] sofia_presence.c:1519 DUMP PRESENCE SQL: select distinct sip_subscriptions.proto,sip_subscriptions.sip_user,sip_subscriptions.sip_host,sip_subscriptions.sub_to_user,sip_subscriptions.sub_to_host,sip_subscriptions.event,sip_subscriptions.contact,sip_subscriptions.call_id,sip_subscriptions.full_from,sip_subscriptions.full_via,sip_subscriptions.expires,sip_subscriptions.user_agent,sip_subscriptions.accept,sip_subscriptions.profile_name,'CS_ROUTING','unknown','10.90.111.196',sip_presence.status,sip_presence.rpid,sip_presence.open_closed,'','',sip_subscriptions.version, '',sip_subscriptions.orig_proto,sip_subscriptions.full_to,sip_subscriptions.network_ip, sip_subscriptions.network_port from sip_subscriptions left join sip_presence on (sip_subscriptions.sub_to_user=sip_presence.sip_user and sip_subscriptions.sub_to_host=sip_presence.sip_host and sip_subscriptions.profile_name=sip_presence.profile_name and sip_subscriptions.hostname=sip_presence.hostname) where sip_subscriptions.hostname='localhost.localdomain' and sip_subscriptions.profile_name='internal' and sip_subscriptions.event != 'line-seize' and sip_subscriptions.proto='sip' and (event='presence' or event='dialog') and sub_to_user='1001' and (sub_to_host='10.90.111.196' or sub_to_host='10.90.111.196' or sub_to_host='N/A' or presence_hosts like '%10.90.111.196%') EVENT DUMP: Event-Name: [PRESENCE_IN] Core-UUID: [a161672c-de2a-11e6-bb22-b9b014fd381e] FreeSWITCH-Hostname: [localhost.localdomain] FreeSWITCH-Switchname: [localhost.localdomain] FreeSWITCH-IPv4: [10.90.111.196] FreeSWITCH-IPv6: [::1] Event-Date-Local: [2017-01-19 17:56:35] Event-Date-GMT: [Thu, 19 Jan 2017 12:26:35 GMT] Event-Date-Timestamp: [1484828795815142] Event-Calling-File: [switch_channel.c] Event-Calling-Function: [switch_channel_perform_presence] Event-Calling-Line-Number: [785] Event-Sequence: [2452] Channel-State: [CS_ROUTING] Channel-Call-State: [RINGING] Channel-State-Number: [4] Channel-Name: [sofia/internal/1001@10.90.111.196] Unique-ID: [84ba0012-de42-11e6-bb7c-b9b014fd381e] Call-Direction: [inbound] Presence-Call-Direction: [inbound] Channel-HIT-Dialplan: [true] Channel-Presence-ID: [1001@10.90.111.196] Channel-Call-UUID: [84ba0012-de42-11e6-bb7c-b9b014fd381e] Answer-State: [ringing] Caller-Direction: [inbound] Caller-Logical-Direction: [inbound] Caller-Username: [1001] Caller-Dialplan: [XML] Caller-Caller-ID-Name: [1001] Caller-Caller-ID-Number: [1001] Caller-Orig-Caller-ID-Name: [1001] Caller-Orig-Caller-ID-Number: [1001] Caller-Network-Addr: [10.90.111.21] Caller-ANI: [1001] Caller-Destination-Number: [30000] Caller-Unique-ID: [84ba0012-de42-11e6-bb7c-b9b014fd381e] Caller-Source: [mod_sofia] Caller-Context: [default] Caller-Channel-Name: [sofia/internal/1001@10.90.111.196] Caller-Profile-Index: [1] Caller-Profile-Created-Time: [1484828795774369] Caller-Channel-Created-Time: [1484828795774369] Caller-Channel-Answered-Time: [0] Caller-Channel-Progress-Time: [0] Caller-Channel-Progress-Media-Time: [0] Caller-Channel-Hangup-Time: [0] Caller-Channel-Transfer-Time: [0] Caller-Channel-Resurrect-Time: [0] Caller-Channel-Bridged-Time: [0] Caller-Channel-Last-Hold: [0] Caller-Channel-Hold-Accum: [0] Caller-Screen-Bit: [true] Caller-Privacy-Hide-Name: [false] Caller-Privacy-Hide-Number: [false] proto: [any] login: [src/switch_channel.c] from: [1001@10.90.111.196] rpid: [unknown] status: [CS_ROUTING] event_type: [presence] alt_event_type: [dialog] presence-call-info-state: [alerting] presence-call-direction: [inbound] event_count: [0] Presence-Calling-File: [src/switch_core_state_machine.c] Presence-Calling-Function: [check_presence] Presence-Calling-Line: [524] 2017-01-19 17:56:35.875099 [INFO] sofia_presence.c:1530 IN END_PRESENCE_SQL (internal) 2017-01-19 17:56:39.134390 [WARNING] sofia_presence.c:5077 check_subs: external-ipv6 is passive, skipping EXECUTE sofia/internal/1001@10.90.111.196 hash(insert/10.90.111.196-spymap/1001/84ba0012-de42-11e6-bb7c-b9b014fd381e) EXECUTE sofia/internal/1001@10.90.111.196 hash(insert/10.90.111.196-last_dial/1001/30000) EXECUTE sofia/internal/1001@10.90.111.196 hash(insert/10.90.111.196-last_dial/global/84ba0012-de42-11e6-bb7c-b9b014fd381e) EXECUTE sofia/internal/1001@10.90.111.196 export(RFC2822_DATE=Thu, 19 Jan 2017 17:56:46 +0530) 2017-01-19 17:56:46.114792 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Thu, 19 Jan 2017 17:56:46 +0530] EXECUTE sofia/internal/1001@10.90.111.196 answer(is_conference) 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [opus:96:48000:20:0:1]/[opus:116:48000:20:0:1] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4433 Audio Codec Compare [opus:116:48000:20:0:1] ++++ is saved as a match 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [opus:96:48000:20:0:1]/[G722:9:8000:20:64000:1] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [opus:96:48000:20:0:1]/[PCMU:0:8000:20:64000:1] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [opus:96:48000:20:0:1]/[PCMA:8:8000:20:64000:1] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [SILK:97:24000:20:0:1]/[opus:116:48000:20:0:1] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [SILK:97:24000:20:0:1]/[G722:9:8000:20:64000:1] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [SILK:97:24000:20:0:1]/[PCMU:0:8000:20:64000:1] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [SILK:97:24000:20:0:1]/[PCMA:8:8000:20:64000:1] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [SILK:98:16000:20:0:1]/[opus:116:48000:20:0:1] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [SILK:98:16000:20:0:1]/[G722:9:8000:20:64000:1] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [SILK:98:16000:20:0:1]/[PCMU:0:8000:20:64000:1] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [SILK:98:16000:20:0:1]/[PCMA:8:8000:20:64000:1] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [G722:9:8000:20:64000:1]/[opus:116:48000:20:0:1] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4433 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [speex:100:32000:20:0:1]/[opus:116:48000:20:0:1] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [speex:100:32000:20:0:1]/[G722:9:8000:20:64000:1] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [speex:100:32000:20:0:1]/[PCMU:0:8000:20:64000:1] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [speex:100:32000:20:0:1]/[PCMA:8:8000:20:64000:1] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [speex:102:16000:20:0:1]/[opus:116:48000:20:0:1] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [speex:102:16000:20:0:1]/[G722:9:8000:20:64000:1] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [speex:102:16000:20:0:1]/[PCMU:0:8000:20:64000:1] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [speex:102:16000:20:0:1]/[PCMA:8:8000:20:64000:1] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4433 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4433 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [iLBC:103:8000:30:13330:1]/[opus:116:48000:20:0:1] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [iLBC:103:8000:30:13330:1]/[G722:9:8000:20:64000:1] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [iLBC:103:8000:30:13330:1]/[PCMU:0:8000:20:64000:1] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [iLBC:103:8000:30:13330:1]/[PCMA:8:8000:20:64000:1] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [GSM:3:8000:20:13200:1]/[opus:116:48000:20:0:1] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [GSM:3:8000:20:13200:1]/[G722:9:8000:20:64000:1] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMU:0:8000:20:64000:1] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMA:8:8000:20:64000:1] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [speex:104:8000:20:0:1]/[opus:116:48000:20:0:1] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [speex:104:8000:20:0:1]/[G722:9:8000:20:64000:1] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [speex:104:8000:20:0:1]/[PCMU:0:8000:20:64000:1] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [speex:104:8000:20:0:1]/[PCMA:8:8000:20:64000:1] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [G723:4:8000:30:6300:1]/[opus:116:48000:20:0:1] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [G723:4:8000:30:6300:1]/[G722:9:8000:20:64000:1] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [G723:4:8000:30:6300:1]/[PCMU:0:8000:20:64000:1] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4378 Audio Codec Compare [G723:4:8000:30:6300:1]/[PCMA:8:8000:20:64000:1] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4294 Set telephone-event payload to 101@8000 2017-01-19 17:56:46.134405 [DEBUG] mod_opus.c:586 Opus encoder: set bitrate to local settings [72000bps] 2017-01-19 17:56:46.134405 [DEBUG] mod_opus.c:586 Opus encoder: set bitrate to local settings [72000bps] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:3043 Set Codec sofia/internal/1001@10.90.111.196 opus/48000 20 ms 960 samples 0 bits 1 channels 2017-01-19 17:56:46.134405 [DEBUG] switch_core_codec.c:111 sofia/internal/1001@10.90.111.196 Original read codec set to opus:116 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4696 sofia/internal/1001@10.90.111.196 Set 2833 dtmf send payload to 101 recv payload to 101 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4877 Video Codec Compare [H264:105]/[VP8:99] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:4877 Video Codec Compare [H264:99]/[VP8:99] 2017-01-19 17:56:46.134405 [DEBUG] switch_core_media.c:6703 AUDIO RTP [sofia/internal/1001@10.90.111.196] 10.90.111.196 port 24596 -> 10.90.111.21 port 5008 codec: 96 ms: 20 2017-01-19 17:56:46.134405 [DEBUG] switch_rtp.c:3878 Starting timer [soft] 960 bytes per 20ms 2017-01-19 17:56:46.154382 [DEBUG] switch_core_media.c:7009 sofia/internal/1001@10.90.111.196 Set 2833 dtmf send payload to 101 2017-01-19 17:56:46.154382 [DEBUG] switch_core_media.c:7016 sofia/internal/1001@10.90.111.196 Set 2833 dtmf receive payload to 101 2017-01-19 17:56:46.154382 [DEBUG] switch_core_media.c:7039 sofia/internal/1001@10.90.111.196 Set rtp dtmf delay to 40 2017-01-19 17:56:46.154382 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/1001@10.90.111.196! 2017-01-19 17:56:46.154382 [DEBUG] switch_channel.c:3473 (sofia/internal/1001@10.90.111.196) Callstate Change RINGING -> EARLY 2017-01-19 17:56:46.154382 [DEBUG] switch_core_media.c:6686 Audio params are unchanged for sofia/internal/1001@10.90.111.196. 2017-01-19 17:56:46.154382 [DEBUG] mod_sofia.c:849 Local SDP sofia/internal/1001@10.90.111.196: v=0 o=FreeSWITCH 1484804210 1484804211 IN IP4 10.90.111.196 s=FreeSWITCH c=IN IP4 10.90.111.196 t=0 0 m=audio 24596 RTP/AVP 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 m=video 0 RTP/AVP 19 send 1180 bytes to udp/[10.90.111.21]:5060 at 17:56:46.156308: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 10.90.111.21:5060;branch=z9hG4bK-313938-5fc9fe0a66995f7f4289e7fa174576d0 From: "1001" ;tag=4f65891a To: ;tag=848XQ4m5K0m9H Call-ID: 64517400ba1d554c830f45be85e95607@0:0:0:0:0:0:0:0 CSeq: 2 INVITE Contact: ;isfocus User-Agent: FreeSWITCH-mod_sofia/1.6.14~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: 275 Remote-Party-ID: "30000" ;party=calling;privacy=off;screen=no v=0 o=FreeSWITCH 1484804210 1484804211 IN IP4 10.90.111.196 s=FreeSWITCH c=IN IP4 10.90.111.196 t=0 0 m=audio 24596 RTP/AVP 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 m=video 0 RTP/AVP 19 ------------------------------------------------------------------------ 2017-01-19 17:56:46.154382 [DEBUG] sofia.c:7041 Channel sofia/internal/1001@10.90.111.196 entering state [completed][200] 2017-01-19 17:56:46.154382 [NOTICE] mod_dptools.c:1309 Channel [sofia/internal/1001@10.90.111.196] has been answered 2017-01-19 17:56:46.154382 [WARNING] sofia_presence.c:1312 external-ipv6 is passive, skipping 2017-01-19 17:56:46.154382 [CRIT] sofia_presence.c:1378 CHECK SQL: 1001@10.90.111.196 [select state,status,rpid,presence_id,uuid from sip_dialogs where uuid != '84ba0012-de42-11e6-bb7c-b9b014fd381e' and call_info_state != 'seized' and hostname='localhost.localdomain' and profile_name='external' and ((sip_from_user='1001' and sip_from_host='10.90.111.196') or presence_id='1001@10.90.111.196') order by rcd desc] hits: 0 2017-01-19 17:56:46.154382 [ERR] sofia_presence.c:1435 PRES SQL update sip_subscriptions set version=version+1 where hostname='localhost.localdomain' and profile_name='external' and sip_subscriptions.event != 'line-seize' and sip_subscriptions.proto='sip' and (event='presence' or event='dialog') and sub_to_user='1001' and (sub_to_host='10.90.111.196' or sub_to_host='10.90.111.196' or sub_to_host='N/A' or presence_hosts like '%10.90.111.196%') and (sip_subscriptions.profile_name = 'external' or presence_hosts like '%10.90.111.196%') 2017-01-19 17:56:46.154382 [INFO] sofia_presence.c:1510 IN START_PRESENCE_SQL (external) 2017-01-19 17:56:46.154382 [ERR] sofia_presence.c:1519 DUMP PRESENCE SQL: select distinct sip_subscriptions.proto,sip_subscriptions.sip_user,sip_subscriptions.sip_host,sip_subscriptions.sub_to_user,sip_subscriptions.sub_to_host,sip_subscriptions.event,sip_subscriptions.contact,sip_subscriptions.call_id,sip_subscriptions.full_from,sip_subscriptions.full_via,sip_subscriptions.expires,sip_subscriptions.user_agent,sip_subscriptions.accept,sip_subscriptions.profile_name,'answered','unknown','10.90.111.196',sip_presence.status,sip_presence.rpid,sip_presence.open_closed,'','',sip_subscriptions.version, '',sip_subscriptions.orig_proto,sip_subscriptions.full_to,sip_subscriptions.network_ip, sip_subscriptions.network_port from sip_subscriptions left join sip_presence on (sip_subscriptions.sub_to_user=sip_presence.sip_user and sip_subscriptions.sub_to_host=sip_presence.sip_host and sip_subscriptions.profile_name=sip_presence.profile_name and sip_subscriptions.hostname=sip_presence.hostname) where sip_subscriptions.hostname='localhost.localdomain' and sip_subscriptions.profile_name='external' and sip_subscriptions.event != 'line-seize' and sip_subscriptions.proto='sip' and (event='presence' or event='dialog') and sub_to_user='1001' and (sub_to_host='10.90.111.196' or sub_to_host='10.90.111.196' or sub_to_host='N/A' or presence_hosts like '%10.90.111.196%') EVENT DUMP: Event-Name: [PRESENCE_IN] Core-UUID: [a161672c-de2a-11e6-bb22-b9b014fd381e] FreeSWITCH-Hostname: [localhost.localdomain] FreeSWITCH-Switchname: [localhost.localdomain] FreeSWITCH-IPv4: [10.90.111.196] FreeSWITCH-IPv6: [::1] Event-Date-Local: [2017-01-19 17:56:46] Event-Date-GMT: [Thu, 19 Jan 2017 12:26:46 GMT] Event-Date-Timestamp: [1484828806154382] Event-Calling-File: [switch_channel.c] Event-Calling-Function: [switch_channel_perform_presence] Event-Calling-Line-Number: [785] Event-Sequence: [2481] Channel-State: [CS_EXECUTE] Channel-Call-State: [EARLY] Channel-State-Number: [4] Channel-Name: [sofia/internal/1001@10.90.111.196] Unique-ID: [84ba0012-de42-11e6-bb7c-b9b014fd381e] Call-Direction: [inbound] Presence-Call-Direction: [inbound] Channel-HIT-Dialplan: [true] Channel-Presence-ID: [1001@10.90.111.196] Channel-Call-UUID: [84ba0012-de42-11e6-bb7c-b9b014fd381e] Answer-State: [answered] Channel-Read-Codec-Name: [opus] Channel-Read-Codec-Rate: [48000] Channel-Read-Codec-Bit-Rate: [0] Channel-Write-Codec-Name: [opus] Channel-Write-Codec-Rate: [48000] Channel-Write-Codec-Bit-Rate: [0] Caller-Direction: [inbound] Caller-Logical-Direction: [inbound] Caller-Username: [1001] Caller-Dialplan: [XML] Caller-Caller-ID-Name: [1001] Caller-Caller-ID-Number: [1001] Caller-Orig-Caller-ID-Name: [1001] Caller-Orig-Caller-ID-Number: [1001] Caller-Network-Addr: [10.90.111.21] Caller-ANI: [1001] Caller-Destination-Number: [30000] Caller-Unique-ID: [84ba0012-de42-11e6-bb7c-b9b014fd381e] Caller-Source: [mod_sofia] Caller-Context: [default] Caller-Channel-Name: [sofia/internal/1001@10.90.111.196] Caller-Profile-Index: [1] Caller-Profile-Created-Time: [1484828795774369] Caller-Channel-Created-Time: [1484828795774369] Caller-Channel-Answered-Time: [1484828806154382] Caller-Channel-Progress-Time: [0] Caller-Channel-Progress-Media-Time: [1484828806154382] Caller-Channel-Hangup-Time: [0] Caller-Channel-Transfer-Time: [0] Caller-Channel-Resurrect-Time: [0] Caller-Channel-Bridged-Time: [0] Caller-Channel-Last-Hold: [0] Caller-Channel-Hold-Accum: [0] Caller-Screen-Bit: [true] Caller-Privacy-Hide-Name: [false] Caller-Privacy-Hide-Number: [false] proto: [any] login: [src/switch_channel.c] from: [1001@10.90.111.196] rpid: [unknown] status: [answered] event_type: [presence] alt_event_type: [dialog] presence-call-info-state: [active] presence-call-direction: [inbound] event_count: [1] Presence-Calling-File: [src/switch_channel.c] Presence-Calling-Function: [switch_channel_perform_mark_answered] Presence-Calling-Line: [3766] 2017-01-19 17:56:46.154382 [INFO] sofia_presence.c:1530 IN END_PRESENCE_SQL (external) 2017-01-19 17:56:46.154382 [CRIT] sofia_presence.c:1378 CHECK SQL: 1001@10.90.111.196 [select state,status,rpid,presence_id,uuid from sip_dialogs where uuid != '84ba0012-de42-11e6-bb7c-b9b014fd381e' and call_info_state != 'seized' and hostname='localhost.localdomain' and profile_name='internal-ipv6' and ((sip_from_user='1001' and sip_from_host='10.90.111.196') or presence_id='1001@10.90.111.196') order by rcd desc] hits: 0 2017-01-19 17:56:46.154382 [ERR] sofia_presence.c:1435 PRES SQL update sip_subscriptions set version=version+1 where hostname='localhost.localdomain' and profile_name='internal-ipv6' and sip_subscriptions.event != 'line-seize' and sip_subscriptions.proto='sip' and (event='presence' or event='dialog') and sub_to_user='1001' and (sub_to_host='10.90.111.196' or sub_to_host='::1' or sub_to_host='N/A' or presence_hosts like '%10.90.111.196%') and (sip_subscriptions.profile_name = 'internal-ipv6' or presence_hosts like '%10.90.111.196%') 2017-01-19 17:56:46.154382 [INFO] sofia_presence.c:1510 IN START_PRESENCE_SQL (internal-ipv6) 2017-01-19 17:56:46.154382 [ERR] sofia_presence.c:1519 DUMP PRESENCE SQL: select distinct sip_subscriptions.proto,sip_subscriptions.sip_user,sip_subscriptions.sip_host,sip_subscriptions.sub_to_user,sip_subscriptions.sub_to_host,sip_subscriptions.event,sip_subscriptions.contact,sip_subscriptions.call_id,sip_subscriptions.full_from,sip_subscriptions.full_via,sip_subscriptions.expires,sip_subscriptions.user_agent,sip_subscriptions.accept,sip_subscriptions.profile_name,'answered','unknown','10.90.111.196',sip_presence.status,sip_presence.rpid,sip_presence.open_closed,'','',sip_subscriptions.version, '',sip_subscriptions.orig_proto,sip_subscriptions.full_to,sip_subscriptions.network_ip, sip_subscriptions.network_port from sip_subscriptions left join sip_presence on (sip_subscriptions.sub_to_user=sip_presence.sip_user and sip_subscriptions.sub_to_host=sip_presence.sip_host and sip_subscriptions.profile_name=sip_presence.profile_name and sip_subscriptions.hostname=sip_presence.hostname) where sip_subscriptions.hostname='localhost.localdomain' and sip_subscriptions.profile_name='internal-ipv6' and sip_subscriptions.event != 'line-seize' and sip_subscriptions.proto='sip' and (event='presence' or event='dialog') and sub_to_user='1001' and (sub_to_host='10.90.111.196' or sub_to_host='::1' or sub_to_host='N/A' or presence_hosts like '%10.90.111.196%') EVENT DUMP: Event-Name: [PRESENCE_IN] Core-UUID: [a161672c-de2a-11e6-bb22-b9b014fd381e] FreeSWITCH-Hostname: [localhost.localdomain] FreeSWITCH-Switchname: [localhost.localdomain] FreeSWITCH-IPv4: [10.90.111.196] FreeSWITCH-IPv6: [::1] Event-Date-Local: [2017-01-19 17:56:46] Event-Date-GMT: [Thu, 19 Jan 2017 12:26:46 GMT] Event-Date-Timestamp: [1484828806154382] Event-Calling-File: [switch_channel.c] Event-Calling-Function: [switch_channel_perform_presence] Event-Calling-Line-Number: [785] Event-Sequence: [2481] Channel-State: [CS_EXECUTE] Channel-Call-State: [EARLY] Channel-State-Number: [4] Channel-Name: [sofia/internal/1001@10.90.111.196] Unique-ID: [84ba0012-de42-11e6-bb7c-b9b014fd381e] Call-Direction: [inbound] Presence-Call-Direction: [inbound] Channel-HIT-Dialplan: [true] Channel-Presence-ID: [1001@10.90.111.196] Channel-Call-UUID: [84ba0012-de42-11e6-bb7c-b9b014fd381e] Answer-State: [answered] Channel-Read-Codec-Name: [opus] Channel-Read-Codec-Rate: [48000] Channel-Read-Codec-Bit-Rate: [0] Channel-Write-Codec-Name: [opus] Channel-Write-Codec-Rate: [48000] Channel-Write-Codec-Bit-Rate: [0] Caller-Direction: [inbound] Caller-Logical-Direction: [inbound] Caller-Username: [1001] Caller-Dialplan: [XML] Caller-Caller-ID-Name: [1001] Caller-Caller-ID-Number: [1001] Caller-Orig-Caller-ID-Name: [1001] Caller-Orig-Caller-ID-Number: [1001] Caller-Network-Addr: [10.90.111.21] Caller-ANI: [1001] Caller-Destination-Number: [30000] Caller-Unique-ID: [84ba0012-de42-11e6-bb7c-b9b014fd381e] Caller-Source: [mod_sofia] Caller-Context: [default] Caller-Channel-Name: [sofia/internal/1001@10.90.111.196] Caller-Profile-Index: [1] Caller-Profile-Created-Time: [1484828795774369] Caller-Channel-Created-Time: [1484828795774369] Caller-Channel-Answered-Time: [1484828806154382] Caller-Channel-Progress-Time: [0] Caller-Channel-Progress-Media-Time: [1484828806154382] Caller-Channel-Hangup-Time: [0] Caller-Channel-Transfer-Time: [0] Caller-Channel-Resurrect-Time: [0] Caller-Channel-Bridged-Time: [0] Caller-Channel-Last-Hold: [0] Caller-Channel-Hold-Accum: [0] Caller-Screen-Bit: [true] Caller-Privacy-Hide-Name: [false] Caller-Privacy-Hide-Number: [false] proto: [any] login: [src/switch_channel.c] from: [1001@10.90.111.196] rpid: [unknown] status: [answered] event_type: [presence] alt_event_type: [dialog] presence-call-info-state: [active] presence-call-direction: [inbound] event_count: [1] Presence-Calling-File: [src/switch_channel.c] Presence-Calling-Function: [switch_channel_perform_mark_answered] Presence-Calling-Line: [3766] 2017-01-19 17:56:46.154382 [INFO] sofia_presence.c:1530 IN END_PRESENCE_SQL (internal-ipv6) 2017-01-19 17:56:46.154382 [DEBUG] switch_channel.c:3772 (sofia/internal/1001@10.90.111.196) Callstate Change EARLY -> ACTIVE 2017-01-19 17:56:46.154382 [CRIT] sofia_presence.c:1378 CHECK SQL: 1001@10.90.111.196 [select state,status,rpid,presence_id,uuid from sip_dialogs where uuid != '84ba0012-de42-11e6-bb7c-b9b014fd381e' and call_info_state != 'seized' and hostname='localhost.localdomain' and profile_name='internal' and ((sip_from_user='1001' and sip_from_host='10.90.111.196') or presence_id='1001@10.90.111.196') order by rcd desc] hits: 0 2017-01-19 17:56:46.154382 [ERR] sofia_presence.c:1435 PRES SQL update sip_subscriptions set version=version+1 where hostname='localhost.localdomain' and profile_name='internal' and sip_subscriptions.event != 'line-seize' and sip_subscriptions.proto='sip' and (event='presence' or event='dialog') and sub_to_user='1001' and (sub_to_host='10.90.111.196' or sub_to_host='10.90.111.196' or sub_to_host='N/A' or presence_hosts like '%10.90.111.196%') and (sip_subscriptions.profile_name = 'internal' or presence_hosts like '%10.90.111.196%') recv 485 bytes from udp/[10.90.111.21]:5060 at 17:56:46.162672: ------------------------------------------------------------------------ ACK sip:30000@10.90.111.196:5060;transport=udp SIP/2.0 Call-ID: 64517400ba1d554c830f45be85e95607@0:0:0:0:0:0:0:0 CSeq: 2 ACK Via: SIP/2.0/UDP 10.90.111.21:5060;branch=z9hG4bK-313938-da3b30bd24bc02315db96108b7b13aa5 From: "1001" ;tag=4f65891a To: ;tag=848XQ4m5K0m9H Max-Forwards: 70 Contact: "1001" User-Agent: Jitsi2.8.5426Windows 8 Content-Length: 0 ------------------------------------------------------------------------ 2017-01-19 17:56:46.154382 [INFO] sofia_presence.c:1510 IN START_PRESENCE_SQL (internal) 2017-01-19 17:56:46.154382 [ERR] sofia_presence.c:1519 DUMP PRESENCE SQL: select distinct sip_subscriptions.proto,sip_subscriptions.sip_user,sip_subscriptions.sip_host,sip_subscriptions.sub_to_user,sip_subscriptions.sub_to_host,sip_subscriptions.event,sip_subscriptions.contact,sip_subscriptions.call_id,sip_subscriptions.full_from,sip_subscriptions.full_via,sip_subscriptions.expires,sip_subscriptions.user_agent,sip_subscriptions.accept,sip_subscriptions.profile_name,'answered','unknown','10.90.111.196',sip_presence.status,sip_presence.rpid,sip_presence.open_closed,'','',sip_subscriptions.version, '',sip_subscriptions.orig_proto,sip_subscriptions.full_to,sip_subscriptions.network_ip, sip_subscriptions.network_port from sip_subscriptions left join sip_presence on (sip_subscriptions.sub_to_user=sip_presence.sip_user and sip_subscriptions.sub_to_host=sip_presence.sip_host and sip_subscriptions.profile_name=sip_presence.profile_name and sip_subscriptions.hostname=sip_presence.hostname) where sip_subscriptions.hostname='localhost.localdomain' and sip_subscriptions.profile_name='internal' and sip_subscriptions.event != 'line-seize' and sip_subscriptions.proto='sip' and (event='presence' or event='dialog') and sub_to_user='1001' and (sub_to_host='10.90.111.196' or sub_to_host='10.90.111.196' or sub_to_host='N/A' or presence_hosts like '%10.90.111.196%') EVENT DUMP: Event-Name: [PRESENCE_IN] Core-UUID: [a161672c-de2a-11e6-bb22-b9b014fd381e] FreeSWITCH-Hostname: [localhost.localdomain] FreeSWITCH-Switchname: [localhost.localdomain] FreeSWITCH-IPv4: [10.90.111.196] FreeSWITCH-IPv6: [::1] Event-Date-Local: [2017-01-19 17:56:46] Event-Date-GMT: [Thu, 19 Jan 2017 12:26:46 GMT] Event-Date-Timestamp: [1484828806154382] Event-Calling-File: [switch_channel.c] Event-Calling-Function: [switch_channel_perform_presence] Event-Calling-Line-Number: [785] Event-Sequence: [2481] Channel-State: [CS_EXECUTE] Channel-Call-State: [EARLY] Channel-State-Number: [4] Channel-Name: [sofia/internal/1001@10.90.111.196] Unique-ID: [84ba0012-de42-11e6-bb7c-b9b014fd381e] Call-Direction: [inbound] Presence-Call-Direction: [inbound] Channel-HIT-Dialplan: [true] Channel-Presence-ID: [1001@10.90.111.196] Channel-Call-UUID: [84ba0012-de42-11e6-bb7c-b9b014fd381e] Answer-State: [answered] Channel-Read-Codec-Name: [opus] Channel-Read-Codec-Rate: [48000] Channel-Read-Codec-Bit-Rate: [0] Channel-Write-Codec-Name: [opus] Channel-Write-Codec-Rate: [48000] Channel-Write-Codec-Bit-Rate: [0] Caller-Direction: [inbound] Caller-Logical-Direction: [inbound] Caller-Username: [1001] Caller-Dialplan: [XML] Caller-Caller-ID-Name: [1001] Caller-Caller-ID-Number: [1001] Caller-Orig-Caller-ID-Name: [1001] Caller-Orig-Caller-ID-Number: [1001] Caller-Network-Addr: [10.90.111.21] Caller-ANI: [1001] Caller-Destination-Number: [30000] Caller-Unique-ID: [84ba0012-de42-11e6-bb7c-b9b014fd381e] Caller-Source: [mod_sofia] Caller-Context: [default] Caller-Channel-Name: [sofia/internal/1001@10.90.111.196] Caller-Profile-Index: [1] Caller-Profile-Created-Time: [1484828795774369] Caller-Channel-Created-Time: [1484828795774369] Caller-Channel-Answered-Time: [1484828806154382] Caller-Channel-Progress-Time: [0] Caller-Channel-Progress-Media-Time: [1484828806154382] Caller-Channel-Hangup-Time: [0] Caller-Channel-Transfer-Time: [0] Caller-Channel-Resurrect-Time: [0] Caller-Channel-Bridged-Time: [0] Caller-Channel-Last-Hold: [0] Caller-Channel-Hold-Accum: [0] Caller-Screen-Bit: [true] Caller-Privacy-Hide-Name: [false] Caller-Privacy-Hide-Number: [false] proto: [any] login: [src/switch_channel.c] from: [1001@10.90.111.196] rpid: [unknown] status: [answered] event_type: [presence] alt_event_type: [dialog] presence-call-info-state: [active] presence-call-direction: [inbound] event_count: [1] Presence-Calling-File: [src/switch_channel.c] Presence-Calling-Function: [switch_channel_perform_mark_answered] Presence-Calling-Line: [3766] 2017-01-19 17:56:46.154382 [INFO] sofia_presence.c:1530 IN END_PRESENCE_SQL (internal) EXECUTE sofia/internal/1001@10.90.111.196 conference(30000-10.90.111.196@default) 2017-01-19 17:56:46.154382 [DEBUG] sofia.c:7041 Channel sofia/internal/1001@10.90.111.196 entering state [ready][200] 2017-01-19 17:56:46.154382 [DEBUG] sofia.c:7089 QUERY SQL update sip_dialogs set sip_to_tag='848XQ4m5K0m9H' where uuid='84ba0012-de42-11e6-bb7c-b9b014fd381e' and sip_to_tag = '' 2017-01-19 17:56:46.199781 [DEBUG] mod_conference.c:3077 using channel sound prefix: /usr/share/freeswitch/sounds/en/us/callie 2017-01-19 17:56:46.199781 [DEBUG] conference_member.c:1679 Raw Codec Activation Success L16@48000hz 1 channel 20ms 2017-01-19 17:56:46.199781 [DEBUG] conference_member.c:1726 Raw Codec Activation Success L16@8000hz 1 channel 20ms 2017-01-19 17:56:46.199781 [DEBUG] switch_core_codec.c:223 sofia/internal/1001@10.90.111.196 Push codec L16:100 2017-01-19 17:56:46.199781 [WARNING] sofia_presence.c:1312 external-ipv6 is passive, skipping 2017-01-19 17:56:46.199781 [CRIT] sofia_presence.c:1378 CHECK SQL: 30000-10.90.111.196@10.90.111.196 [select state,status,rpid,presence_id,uuid from sip_dialogs where uuid != '30000-10.90.111.196' and call_info_state != 'seized' and hostname='localhost.localdomain' and profile_name='external' and ((sip_from_user='30000-10.90.111.196' and sip_from_host='10.90.111.196') or presence_id='30000-10.90.111.196@10.90.111.196') order by rcd desc] hits: 0 2017-01-19 17:56:46.199781 [ERR] sofia_presence.c:1435 PRES SQL update sip_subscriptions set version=version+1 where hostname='localhost.localdomain' and profile_name='external' and sip_subscriptions.event != 'line-seize' and sip_subscriptions.proto='conf' and (event='presence' or event='dialog') and sub_to_user='30000-10.90.111.196' and (sub_to_host='10.90.111.196' or sub_to_host='10.90.111.196' or sub_to_host='N/A' or presence_hosts like '%10.90.111.196%') and (sip_subscriptions.profile_name = 'external' or presence_hosts like '%10.90.111.196%') 2017-01-19 17:56:46.199781 [INFO] sofia_presence.c:1510 IN START_PRESENCE_SQL (external) 2017-01-19 17:56:46.199781 [ERR] sofia_presence.c:1519 DUMP PRESENCE SQL: select distinct sip_subscriptions.proto,sip_subscriptions.sip_user,sip_subscriptions.sip_host,sip_subscriptions.sub_to_user,sip_subscriptions.sub_to_host,sip_subscriptions.event,sip_subscriptions.contact,sip_subscriptions.call_id,sip_subscriptions.full_from,sip_subscriptions.full_via,sip_subscriptions.expires,sip_subscriptions.user_agent,sip_subscriptions.accept,sip_subscriptions.profile_name,'Available','','10.90.111.196',sip_presence.status,sip_presence.rpid,sip_presence.open_closed,'','',sip_subscriptions.version, '',sip_subscriptions.orig_proto,sip_subscriptions.full_to,sip_subscriptions.network_ip, sip_subscriptions.network_port from sip_subscriptions left join sip_presence on (sip_subscriptions.sub_to_user=sip_presence.sip_user and sip_subscriptions.sub_to_host=sip_presence.sip_host and sip_subscriptions.profile_name=sip_presence.profile_name and sip_subscriptions.hostname=sip_presence.hostname) where sip_subscriptions.hostname='localhost.localdomain' and sip_subscriptions.profile_name='external' and sip_subscriptions.event != 'line-seize' and sip_subscriptions.proto='conf' and (event='presence' or event='dialog') and sub_to_user='30000-10.90.111.196' and (sub_to_host='10.90.111.196' or sub_to_host='10.90.111.196' or sub_to_host='N/A' or presence_hosts like '%10.90.111.196%') EVENT DUMP: Event-Name: [PRESENCE_IN] Core-UUID: [a161672c-de2a-11e6-bb22-b9b014fd381e] FreeSWITCH-Hostname: [localhost.localdomain] FreeSWITCH-Switchname: [localhost.localdomain] FreeSWITCH-IPv4: [10.90.111.196] FreeSWITCH-IPv6: [::1] Event-Date-Local: [2017-01-19 17:56:46] Event-Date-GMT: [Thu, 19 Jan 2017 12:26:46 GMT] Event-Date-Timestamp: [1484828806199781] Event-Calling-File: [mod_conference.c] Event-Calling-Function: [conference_send_presence] Event-Calling-Line-Number: [3349] Event-Sequence: [2488] proto: [conf] login: [30000-10.90.111.196] from: [30000-10.90.111.196@10.90.111.196] event_type: [presence] alt_event_type: [dialog] event_count: [12] unique-id: [30000-10.90.111.196] force-status: [Active (1 caller)] channel-state: [CS_ROUTING] answer-state: [early] presence-call-direction: [outbound] 2017-01-19 17:56:46.199781 [INFO] sofia_presence.c:1530 IN END_PRESENCE_SQL (external) 2017-01-19 17:56:46.199781 [CRIT] sofia_presence.c:1378 CHECK SQL: 30000-10.90.111.196@10.90.111.196 [select state,status,rpid,presence_id,uuid from sip_dialogs where uuid != '30000-10.90.111.196' and call_info_state != 'seized' and hostname='localhost.localdomain' and profile_name='internal-ipv6' and ((sip_from_user='30000-10.90.111.196' and sip_from_host='10.90.111.196') or presence_id='30000-10.90.111.196@10.90.111.196') order by rcd desc] hits: 0 2017-01-19 17:56:46.199781 [ERR] sofia_presence.c:1435 PRES SQL update sip_subscriptions set version=version+1 where hostname='localhost.localdomain' and profile_name='internal-ipv6' and sip_subscriptions.event != 'line-seize' and sip_subscriptions.proto='conf' and (event='presence' or event='dialog') and sub_to_user='30000-10.90.111.196' and (sub_to_host='10.90.111.196' or sub_to_host='::1' or sub_to_host='N/A' or presence_hosts like '%10.90.111.196%') and (sip_subscriptions.profile_name = 'internal-ipv6' or presence_hosts like '%10.90.111.196%') 2017-01-19 17:56:46.199781 [INFO] sofia_presence.c:1510 IN START_PRESENCE_SQL (internal-ipv6) 2017-01-19 17:56:46.199781 [ERR] sofia_presence.c:1519 DUMP PRESENCE SQL: select distinct sip_subscriptions.proto,sip_subscriptions.sip_user,sip_subscriptions.sip_host,sip_subscriptions.sub_to_user,sip_subscriptions.sub_to_host,sip_subscriptions.event,sip_subscriptions.contact,sip_subscriptions.call_id,sip_subscriptions.full_from,sip_subscriptions.full_via,sip_subscriptions.expires,sip_subscriptions.user_agent,sip_subscriptions.accept,sip_subscriptions.profile_name,'Available','','10.90.111.196',sip_presence.status,sip_presence.rpid,sip_presence.open_closed,'','',sip_subscriptions.version, '',sip_subscriptions.orig_proto,sip_subscriptions.full_to,sip_subscriptions.network_ip, sip_subscriptions.network_port from sip_subscriptions left join sip_presence on (sip_subscriptions.sub_to_user=sip_presence.sip_user and sip_subscriptions.sub_to_host=sip_presence.sip_host and sip_subscriptions.profile_name=sip_presence.profile_name and sip_subscriptions.hostname=sip_presence.hostname) where sip_subscriptions.hostname='localhost.localdomain' and sip_subscriptions.profile_name='internal-ipv6' and sip_subscriptions.event != 'line-seize' and sip_subscriptions.proto='conf' and (event='presence' or event='dialog') and sub_to_user='30000-10.90.111.196' and (sub_to_host='10.90.111.196' or sub_to_host='::1' or sub_to_host='N/A' or presence_hosts like '%10.90.111.196%') EVENT DUMP: Event-Name: [PRESENCE_IN] Core-UUID: [a161672c-de2a-11e6-bb22-b9b014fd381e] FreeSWITCH-Hostname: [localhost.localdomain] FreeSWITCH-Switchname: [localhost.localdomain] FreeSWITCH-IPv4: [10.90.111.196] FreeSWITCH-IPv6: [::1] Event-Date-Local: [2017-01-19 17:56:46] Event-Date-GMT: [Thu, 19 Jan 2017 12:26:46 GMT] Event-Date-Timestamp: [1484828806199781] Event-Calling-File: [mod_conference.c] Event-Calling-Function: [conference_send_presence] Event-Calling-Line-Number: [3349] Event-Sequence: [2488] proto: [conf] login: [30000-10.90.111.196] from: [30000-10.90.111.196@10.90.111.196] event_type: [presence] alt_event_type: [dialog] event_count: [12] unique-id: [30000-10.90.111.196] force-status: [Active (1 caller)] channel-state: [CS_ROUTING] answer-state: [early] presence-call-direction: [outbound] 2017-01-19 17:56:46.199781 [INFO] sofia_presence.c:1530 IN END_PRESENCE_SQL (internal-ipv6) 2017-01-19 17:56:46.199781 [ERR] switch_core_video.c:1870 This function is not available, libpng not installed 2017-01-19 17:56:46.199781 [DEBUG] mod_conference.c:220 Setup timer success interval: 20 samples: 160 2017-01-19 17:56:46.199781 [CRIT] sofia_presence.c:1378 CHECK SQL: 30000-10.90.111.196@10.90.111.196 [select state,status,rpid,presence_id,uuid from sip_dialogs where uuid != '30000-10.90.111.196' and call_info_state != 'seized' and hostname='localhost.localdomain' and profile_name='internal' and ((sip_from_user='30000-10.90.111.196' and sip_from_host='10.90.111.196') or presence_id='30000-10.90.111.196@10.90.111.196') order by rcd desc] hits: 0 2017-01-19 17:56:46.199781 [ERR] sofia_presence.c:1435 PRES SQL update sip_subscriptions set version=version+1 where hostname='localhost.localdomain' and profile_name='internal' and sip_subscriptions.event != 'line-seize' and sip_subscriptions.proto='conf' and (event='presence' or event='dialog') and sub_to_user='30000-10.90.111.196' and (sub_to_host='10.90.111.196' or sub_to_host='10.90.111.196' or sub_to_host='N/A' or presence_hosts like '%10.90.111.196%') and (sip_subscriptions.profile_name = 'internal' or presence_hosts like '%10.90.111.196%') 2017-01-19 17:56:46.199781 [INFO] sofia_presence.c:1510 IN START_PRESENCE_SQL (internal) 2017-01-19 17:56:46.199781 [ERR] sofia_presence.c:1519 DUMP PRESENCE SQL: select distinct sip_subscriptions.proto,sip_subscriptions.sip_user,sip_subscriptions.sip_host,sip_subscriptions.sub_to_user,sip_subscriptions.sub_to_host,sip_subscriptions.event,sip_subscriptions.contact,sip_subscriptions.call_id,sip_subscriptions.full_from,sip_subscriptions.full_via,sip_subscriptions.expires,sip_subscriptions.user_agent,sip_subscriptions.accept,sip_subscriptions.profile_name,'Available','','10.90.111.196',sip_presence.status,sip_presence.rpid,sip_presence.open_closed,'','',sip_subscriptions.version, '',sip_subscriptions.orig_proto,sip_subscriptions.full_to,sip_subscriptions.network_ip, sip_subscriptions.network_port from sip_subscriptions left join sip_presence on (sip_subscriptions.sub_to_user=sip_presence.sip_user and sip_subscriptions.sub_to_host=sip_presence.sip_host and sip_subscriptions.profile_name=sip_presence.profile_name and sip_subscriptions.hostname=sip_presence.hostname) where sip_subscriptions.hostname='localhost.localdomain' and sip_subscriptions.profile_name='internal' and sip_subscriptions.event != 'line-seize' and sip_subscriptions.proto='conf' and (event='presence' or event='dialog') and sub_to_user='30000-10.90.111.196' and (sub_to_host='10.90.111.196' or sub_to_host='10.90.111.196' or sub_to_host='N/A' or presence_hosts like '%10.90.111.196%') EVENT DUMP: Event-Name: [PRESENCE_IN] Core-UUID: [a161672c-de2a-11e6-bb22-b9b014fd381e] FreeSWITCH-Hostname: [localhost.localdomain] FreeSWITCH-Switchname: [localhost.localdomain] FreeSWITCH-IPv4: [10.90.111.196] FreeSWITCH-IPv6: [::1] Event-Date-Local: [2017-01-19 17:56:46] Event-Date-GMT: [Thu, 19 Jan 2017 12:26:46 GMT] Event-Date-Timestamp: [1484828806199781] Event-Calling-File: [mod_conference.c] Event-Calling-Function: [conference_send_presence] Event-Calling-Line-Number: [3349] Event-Sequence: [2488] proto: [conf] login: [30000-10.90.111.196] from: [30000-10.90.111.196@10.90.111.196] event_type: [presence] alt_event_type: [dialog] event_count: [12] unique-id: [30000-10.90.111.196] force-status: [Active (1 caller)] channel-state: [CS_ROUTING] answer-state: [early] presence-call-direction: [outbound] 2017-01-19 17:56:46.199781 [INFO] sofia_presence.c:1530 IN END_PRESENCE_SQL (internal) 2017-01-19 17:56:46.234609 [DEBUG] conference_member.c:128 sofia/internal/1001@10.90.111.196 binding '0' to 'mute' 2017-01-19 17:56:46.234609 [INFO] switch_ivr_async.c:214 Digit parser mod_conference: Setting realm to 'conf' 2017-01-19 17:56:46.234609 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 0/conf/0 callback: 0x7fccf3451770 data: 0x7fccf4071898 2017-01-19 17:56:46.234609 [DEBUG] conference_member.c:128 sofia/internal/1001@10.90.111.196 binding '*' to 'deaf mute' 2017-01-19 17:56:46.234609 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding */conf/0 callback: 0x7fccf3451770 data: 0x7fccf40718c8 2017-01-19 17:56:46.234609 [DEBUG] conference_member.c:128 sofia/internal/1001@10.90.111.196 binding '9' to 'energy up' 2017-01-19 17:56:46.234609 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 9/conf/0 callback: 0x7fccf3451770 data: 0x7fccf40718f8 2017-01-19 17:56:46.234609 [DEBUG] conference_member.c:128 sofia/internal/1001@10.90.111.196 binding '8' to 'energy equ' 2017-01-19 17:56:46.234609 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 8/conf/0 callback: 0x7fccf3451770 data: 0x7fccf4071928 2017-01-19 17:56:46.234609 [DEBUG] conference_member.c:128 sofia/internal/1001@10.90.111.196 binding '7' to 'energy dn' 2017-01-19 17:56:46.234609 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 7/conf/0 callback: 0x7fccf3451770 data: 0x7fccf4071958 2017-01-19 17:56:46.234609 [DEBUG] conference_member.c:128 sofia/internal/1001@10.90.111.196 binding '3' to 'vol talk up' 2017-01-19 17:56:46.234609 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 3/conf/0 callback: 0x7fccf3451770 data: 0x7fccf4071988 2017-01-19 17:56:46.234609 [DEBUG] conference_member.c:128 sofia/internal/1001@10.90.111.196 binding '2' to 'vol talk zero' 2017-01-19 17:56:46.234609 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 2/conf/0 callback: 0x7fccf3451770 data: 0x7fccf40719b8 2017-01-19 17:56:46.234609 [DEBUG] conference_member.c:128 sofia/internal/1001@10.90.111.196 binding '1' to 'vol talk dn' 2017-01-19 17:56:46.234609 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 1/conf/0 callback: 0x7fccf3451770 data: 0x7fccf40719e8 2017-01-19 17:56:46.234609 [DEBUG] conference_member.c:128 sofia/internal/1001@10.90.111.196 binding '6' to 'vol listen up' 2017-01-19 17:56:46.234609 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 6/conf/0 callback: 0x7fccf3451770 data: 0x7fccf4071a18 2017-01-19 17:56:46.234609 [DEBUG] conference_member.c:128 sofia/internal/1001@10.90.111.196 binding '5' to 'vol listen zero' 2017-01-19 17:56:46.234609 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 5/conf/0 callback: 0x7fccf3451770 data: 0x7fccf4071a48 2017-01-19 17:56:46.234609 [DEBUG] conference_member.c:128 sofia/internal/1001@10.90.111.196 binding '4' to 'vol listen dn' 2017-01-19 17:56:46.234609 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 4/conf/0 callback: 0x7fccf3451770 data: 0x7fccf4071a78 2017-01-19 17:56:46.234609 [DEBUG] conference_member.c:128 sofia/internal/1001@10.90.111.196 binding '#' to 'hangup' 2017-01-19 17:56:46.234609 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding #/conf/0 callback: 0x7fccf3451770 data: 0x7fccf4071aa8 2017-01-19 17:56:46.234609 [DEBUG] conference_loop.c:1140 Setup timer soft success interval: 20 samples: 960 from codec opus 2017-01-19 17:56:46.234609 [NOTICE] switch_core_io.c:1202 Activating write resampler recv 806 bytes from udp/[10.90.111.21]:5060 at 17:56:46.257889: ------------------------------------------------------------------------ SUBSCRIBE sip:30000@10.90.111.196:5060;transport=udp SIP/2.0 CSeq: 3 SUBSCRIBE From: "1001" ;tag=4f65891a To: ;tag=848XQ4m5K0m9H Call-ID: 64517400ba1d554c830f45be85e95607@0:0:0:0:0:0:0:0 Via: SIP/2.0/UDP 10.90.111.21:5060;branch=z9hG4bK-313938-bde2d1b2d9287374c9da0da52a2d9ce9 Contact: "1001" Proxy-Authorization: Digest username="1001",realm="10.90.111.196",nonce="84ba4cac-de42-11e6-bb7d-b9b014fd381e",uri="sip:30000@10.90.111.196",response="7f0ed5ee03b2e50e108ec28320829290",algorithm=MD5,qop=auth,cnonce="xyz",nc=00000001 User-Agent: Jitsi2.8.5426Windows 8 Max-Forwards: 70 Event: conference Accept: application/conference-info+xml Expires: 3600 Content-Length: 0 ------------------------------------------------------------------------ 2017-01-19 17:56:46.254727 [ERR] sofia_presence.c:3774 DELTA 3600 2017-01-19 17:56:46.254727 [ERR] sofia_presence.c:3896 check subs sql: select contact from sip_subscriptions where call_id='64517400ba1d554c830f45be85e95607@0:0:0:0:0:0:0:0' and profile_name='internal' and hostname='localhost.localdomain' [] 2017-01-19 17:56:46.254727 [NOTICE] sofia_presence.c:3976 internal SUBSCRIBE 1001@10.90.111.196 30000@10.90.111.196 insert into sip_subscriptions (proto,sip_user,sip_host,sub_to_user,sub_to_host,presence_hosts,event,contact,call_id,full_from,full_via,expires,user_agent,accept,profile_name,hostname,network_port,network_ip,version,orig_proto, full_to) values ('conf','1001','10.90.111.196','30000','10.90.111.196','10.90.111.196,10.90.111.196','conference','"user" ','64517400ba1d554c830f45be85e95607@0:0:0:0:0:0:0:0','"1001" ;tag=4f65891a','SIP/2.0/UDP 10.90.111.21:5060;branch=z9hG4bK-313938-bde2d1b2d9287374c9da0da52a2d9ce9',1484832406,'Jitsi2.8.5426Windows 8','application/conference-info+xml ','internal','localhost.localdomain','5060','10.90.111.21',-1,'sip',';tag=848XQ4m5K0m9H;tag=848XQ4m5K0m9H') 2017-01-19 17:56:46.254727 [DEBUG] sofia_presence.c:4089 Responding to SUBSCRIBE with 202 Accepted send 772 bytes to udp/[10.90.111.21]:5060 at 17:56:46.271684: ------------------------------------------------------------------------ SIP/2.0 202 Accepted Via: SIP/2.0/UDP 10.90.111.21:5060;branch=z9hG4bK-313938-bde2d1b2d9287374c9da0da52a2d9ce9 From: "1001" ;tag=4f65891a To: ;tag=848XQ4m5K0m9H Call-ID: 64517400ba1d554c830f45be85e95607@0:0:0:0:0:0:0:0 CSeq: 3 SUBSCRIBE Contact: Expires: 3600 User-Agent: FreeSWITCH-mod_sofia/1.6.14~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 Subscription-State: active;expires=3600 Content-Length: 0 ------------------------------------------------------------------------ 2017-01-19 17:56:46.274433 [WARNING] sofia_presence.c:1312 external-ipv6 is passive, skipping 2017-01-19 17:56:46.274433 [CRIT] sofia_presence.c:1378 CHECK SQL: 30000@10.90.111.196 [select state,status,rpid,presence_id,uuid from sip_dialogs where uuid != '30000' and call_info_state != 'seized' and hostname='localhost.localdomain' and profile_name='external' and ((sip_from_user='30000' and sip_from_host='10.90.111.196') or presence_id='30000@10.90.111.196') order by rcd desc] hits: 0 2017-01-19 17:56:46.274433 [ERR] sofia_presence.c:1435 PRES SQL update sip_subscriptions set version=version+1 where hostname='localhost.localdomain' and profile_name='external' and sip_subscriptions.event != 'line-seize' and sip_subscriptions.proto='conf' and (event='presence' or event='dialog') and sub_to_user='30000' and (sub_to_host='10.90.111.196' or sub_to_host='10.90.111.196' or sub_to_host='N/A' or presence_hosts like '%10.90.111.196%') and (sip_subscriptions.profile_name = 'external' or presence_hosts like '%10.90.111.196%') 2017-01-19 17:56:46.274433 [INFO] sofia_presence.c:1510 IN START_PRESENCE_SQL (external) 2017-01-19 17:56:46.274433 [ERR] sofia_presence.c:1519 DUMP PRESENCE SQL: select distinct sip_subscriptions.proto,sip_subscriptions.sip_user,sip_subscriptions.sip_host,sip_subscriptions.sub_to_user,sip_subscriptions.sub_to_host,sip_subscriptions.event,sip_subscriptions.contact,sip_subscriptions.call_id,sip_subscriptions.full_from,sip_subscriptions.full_via,sip_subscriptions.expires,sip_subscriptions.user_agent,sip_subscriptions.accept,sip_subscriptions.profile_name,'Available','unknown','10.90.111.196',sip_presence.status,sip_presence.rpid,sip_presence.open_closed,'','',sip_subscriptions.version, '',sip_subscriptions.orig_proto,sip_subscriptions.full_to,sip_subscriptions.network_ip, sip_subscriptions.network_port from sip_subscriptions left join sip_presence on (sip_subscriptions.sub_to_user=sip_presence.sip_user and sip_subscriptions.sub_to_host=sip_presence.sip_host and sip_subscriptions.profile_name=sip_presence.profile_name and sip_subscriptions.hostname=sip_presence.hostname) where sip_subscriptions.hostname='localhost.localdomain' and sip_subscriptions.profile_name='external' and sip_subscriptions.event != 'line-seize' and sip_subscriptions.proto='conf' and (event='presence' or event='dialog') and sub_to_user='30000' and (sub_to_host='10.90.111.196' or sub_to_host='10.90.111.196' or sub_to_host='N/A' or presence_hosts like '%10.90.111.196%') EVENT DUMP: Event-Name: [PRESENCE_IN] Core-UUID: [a161672c-de2a-11e6-bb22-b9b014fd381e] FreeSWITCH-Hostname: [localhost.localdomain] FreeSWITCH-Switchname: [localhost.localdomain] FreeSWITCH-IPv4: [10.90.111.196] FreeSWITCH-IPv6: [::1] Event-Date-Local: [2017-01-19 17:56:46] Event-Date-GMT: [Thu, 19 Jan 2017 12:26:46 GMT] Event-Date-Timestamp: [1484828806274433] Event-Calling-File: [conference_event.c] Event-Calling-Function: [conference_event_pres_handler] Event-Calling-Line-Number: [808] Event-Sequence: [2496] proto: [conf] login: [30000] from: [conf+30000@10.90.111.196] force-status: [Idle] rpid: [unknown] event_type: [presence] alt_event_type: [dialog] event_count: [13] unique-id: [30000] channel-state: [CS_HANGUP] answer-state: [terminated] call-direction: [inbound] 2017-01-19 17:56:46.274433 [INFO] sofia_presence.c:1530 IN END_PRESENCE_SQL (external) 2017-01-19 17:56:46.274433 [CRIT] sofia_presence.c:1378 CHECK SQL: 30000@10.90.111.196 [select state,status,rpid,presence_id,uuid from sip_dialogs where uuid != '30000' and call_info_state != 'seized' and hostname='localhost.localdomain' and profile_name='internal-ipv6' and ((sip_from_user='30000' and sip_from_host='10.90.111.196') or presence_id='30000@10.90.111.196') order by rcd desc] hits: 0 2017-01-19 17:56:46.274433 [ERR] sofia_presence.c:1435 PRES SQL update sip_subscriptions set version=version+1 where hostname='localhost.localdomain' and profile_name='internal-ipv6' and sip_subscriptions.event != 'line-seize' and sip_subscriptions.proto='conf' and (event='presence' or event='dialog') and sub_to_user='30000' and (sub_to_host='10.90.111.196' or sub_to_host='::1' or sub_to_host='N/A' or presence_hosts like '%10.90.111.196%') and (sip_subscriptions.profile_name = 'internal-ipv6' or presence_hosts like '%10.90.111.196%') 2017-01-19 17:56:46.274433 [INFO] sofia_presence.c:1510 IN START_PRESENCE_SQL (internal-ipv6) 2017-01-19 17:56:46.274433 [ERR] sofia_presence.c:1519 DUMP PRESENCE SQL: select distinct sip_subscriptions.proto,sip_subscriptions.sip_user,sip_subscriptions.sip_host,sip_subscriptions.sub_to_user,sip_subscriptions.sub_to_host,sip_subscriptions.event,sip_subscriptions.contact,sip_subscriptions.call_id,sip_subscriptions.full_from,sip_subscriptions.full_via,sip_subscriptions.expires,sip_subscriptions.user_agent,sip_subscriptions.accept,sip_subscriptions.profile_name,'Available','unknown','10.90.111.196',sip_presence.status,sip_presence.rpid,sip_presence.open_closed,'','',sip_subscriptions.version, '',sip_subscriptions.orig_proto,sip_subscriptions.full_to,sip_subscriptions.network_ip, sip_subscriptions.network_port from sip_subscriptions left join sip_presence on (sip_subscriptions.sub_to_user=sip_presence.sip_user and sip_subscriptions.sub_to_host=sip_presence.sip_host and sip_subscriptions.profile_name=sip_presence.profile_name and sip_subscriptions.hostname=sip_presence.hostname) where sip_subscriptions.hostname='localhost.localdomain' and sip_subscriptions.profile_name='internal-ipv6' and sip_subscriptions.event != 'line-seize' and sip_subscriptions.proto='conf' and (event='presence' or event='dialog') and sub_to_user='30000' and (sub_to_host='10.90.111.196' or sub_to_host='::1' or sub_to_host='N/A' or presence_hosts like '%10.90.111.196%') EVENT DUMP: Event-Name: [PRESENCE_IN] Core-UUID: [a161672c-de2a-11e6-bb22-b9b014fd381e] FreeSWITCH-Hostname: [localhost.localdomain] FreeSWITCH-Switchname: [localhost.localdomain] FreeSWITCH-IPv4: [10.90.111.196] FreeSWITCH-IPv6: [::1] Event-Date-Local: [2017-01-19 17:56:46] Event-Date-GMT: [Thu, 19 Jan 2017 12:26:46 GMT] Event-Date-Timestamp: [1484828806274433] Event-Calling-File: [conference_event.c] Event-Calling-Function: [conference_event_pres_handler] Event-Calling-Line-Number: [808] Event-Sequence: [2496] proto: [conf] login: [30000] from: [conf+30000@10.90.111.196] force-status: [Idle] rpid: [unknown] event_type: [presence] alt_event_type: [dialog] event_count: [13] unique-id: [30000] channel-state: [CS_HANGUP] answer-state: [terminated] call-direction: [inbound] 2017-01-19 17:56:46.274433 [INFO] sofia_presence.c:1530 IN END_PRESENCE_SQL (internal-ipv6) 2017-01-19 17:56:46.274433 [CRIT] sofia_presence.c:1378 CHECK SQL: 30000@10.90.111.196 [select state,status,rpid,presence_id,uuid from sip_dialogs where uuid != '30000' and call_info_state != 'seized' and hostname='localhost.localdomain' and profile_name='internal' and ((sip_from_user='30000' and sip_from_host='10.90.111.196') or presence_id='30000@10.90.111.196') order by rcd desc] hits: 0 2017-01-19 17:56:46.274433 [ERR] sofia_presence.c:1435 PRES SQL update sip_subscriptions set version=version+1 where hostname='localhost.localdomain' and profile_name='internal' and sip_subscriptions.event != 'line-seize' and sip_subscriptions.proto='conf' and (event='presence' or event='dialog') and sub_to_user='30000' and (sub_to_host='10.90.111.196' or sub_to_host='10.90.111.196' or sub_to_host='N/A' or presence_hosts like '%10.90.111.196%') and (sip_subscriptions.profile_name = 'internal' or presence_hosts like '%10.90.111.196%') 2017-01-19 17:56:46.274433 [INFO] sofia_presence.c:1510 IN START_PRESENCE_SQL (internal) 2017-01-19 17:56:46.274433 [ERR] sofia_presence.c:1519 DUMP PRESENCE SQL: select distinct sip_subscriptions.proto,sip_subscriptions.sip_user,sip_subscriptions.sip_host,sip_subscriptions.sub_to_user,sip_subscriptions.sub_to_host,sip_subscriptions.event,sip_subscriptions.contact,sip_subscriptions.call_id,sip_subscriptions.full_from,sip_subscriptions.full_via,sip_subscriptions.expires,sip_subscriptions.user_agent,sip_subscriptions.accept,sip_subscriptions.profile_name,'Available','unknown','10.90.111.196',sip_presence.status,sip_presence.rpid,sip_presence.open_closed,'','',sip_subscriptions.version, '',sip_subscriptions.orig_proto,sip_subscriptions.full_to,sip_subscriptions.network_ip, sip_subscriptions.network_port from sip_subscriptions left join sip_presence on (sip_subscriptions.sub_to_user=sip_presence.sip_user and sip_subscriptions.sub_to_host=sip_presence.sip_host and sip_subscriptions.profile_name=sip_presence.profile_name and sip_subscriptions.hostname=sip_presence.hostname) where sip_subscriptions.hostname='localhost.localdomain' and sip_subscriptions.profile_name='internal' and sip_subscriptions.event != 'line-seize' and sip_subscriptions.proto='conf' and (event='presence' or event='dialog') and sub_to_user='30000' and (sub_to_host='10.90.111.196' or sub_to_host='10.90.111.196' or sub_to_host='N/A' or presence_hosts like '%10.90.111.196%') EVENT DUMP: Event-Name: [PRESENCE_IN] Core-UUID: [a161672c-de2a-11e6-bb22-b9b014fd381e] FreeSWITCH-Hostname: [localhost.localdomain] FreeSWITCH-Switchname: [localhost.localdomain] FreeSWITCH-IPv4: [10.90.111.196] FreeSWITCH-IPv6: [::1] Event-Date-Local: [2017-01-19 17:56:46] Event-Date-GMT: [Thu, 19 Jan 2017 12:26:46 GMT] Event-Date-Timestamp: [1484828806274433] Event-Calling-File: [conference_event.c] Event-Calling-Function: [conference_event_pres_handler] Event-Calling-Line-Number: [808] Event-Sequence: [2496] proto: [conf] login: [30000] from: [conf+30000@10.90.111.196] force-status: [Idle] rpid: [unknown] event_type: [presence] alt_event_type: [dialog] event_count: [13] unique-id: [30000] channel-state: [CS_HANGUP] answer-state: [terminated] call-direction: [inbound] 2017-01-19 17:56:46.294419 [INFO] sofia_presence.c:1530 IN END_PRESENCE_SQL (internal) 2017-01-19 17:56:46.316874 [DEBUG] switch_rtp.c:6994 Correct audio ip/port confirmed. 2017-01-19 17:56:46.395284 [DEBUG] conference_member.c:1679 Raw Codec Activation Success L16@48000hz 1 channel 20ms 2017-01-19 17:56:46.395284 [DEBUG] conference_member.c:1726 Raw Codec Activation Success L16@8000hz 1 channel 20ms 2017-01-19 17:56:46.395284 [DEBUG] conference_loop.c:1140 Setup timer soft success interval: 20 samples: 960 from codec opus 2017-01-19 17:56:49.014470 [DEBUG] mod_local_stream.c:866 Opening Stream [moh/8000] 8000hz 2017-01-19 17:57:09.234360 [WARNING] sofia_presence.c:5077 check_subs: external-ipv6 is passive, skipping 2017-01-19 17:57:39.474664 [WARNING] sofia_presence.c:5077 check_subs: external-ipv6 is passive, skipping recv 707 bytes from udp/[10.90.111.21]:5060 at 17:57:57.095739: ------------------------------------------------------------------------ REGISTER sip:10.90.111.196 SIP/2.0 Call-ID: 0ebcb3a3c821b82ce4ed280dc5fd85db@0:0:0:0:0:0:0:0 CSeq: 39 REGISTER From: "1001" ;tag=bb27c622 To: "1001" Via: SIP/2.0/UDP 10.90.111.21:5060;branch=z9hG4bK-313938-acfa729113d6cfd3a6d9c2141d86f299 Max-Forwards: 70 Authorization: Digest username="1001",realm="10.90.111.196",nonce="73541386-de41-11e6-bb7a-b9b014fd381e",uri="sip:10.90.111.196",response="3ba4f3489b81392712e88f1241ea6ff0",algorithm=MD5,qop=auth,cnonce="xyz",nc=00000001 User-Agent: Jitsi2.8.5426Windows 8 Expires: 600 Contact: "1001" ;expires=600 Content-Length: 0 ------------------------------------------------------------------------ send 647 bytes to udp/[10.90.111.21]:5060 at 17:57:57.102238: ------------------------------------------------------------------------ SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 10.90.111.21:5060;branch=z9hG4bK-313938-acfa729113d6cfd3a6d9c2141d86f299 From: "1001" ;tag=bb27c622 To: "1001" ;tag=9D2pSZ58g9avD Call-ID: 0ebcb3a3c821b82ce4ed280dc5fd85db@0:0:0:0:0:0:0:0 CSeq: 39 REGISTER User-Agent: FreeSWITCH-mod_sofia/1.6.14~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces WWW-Authenticate: Digest realm="10.90.111.196", nonce="b538df24-de42-11e6-bb8d-b9b014fd381e", stale=true, algorithm=MD5, qop="auth" Content-Length: 0 ------------------------------------------------------------------------ recv 707 bytes from udp/[10.90.111.21]:5060 at 17:57:57.106665: ------------------------------------------------------------------------ REGISTER sip:10.90.111.196 SIP/2.0 Call-ID: 0ebcb3a3c821b82ce4ed280dc5fd85db@0:0:0:0:0:0:0:0 CSeq: 40 REGISTER From: "1001" ;tag=bb27c622 To: "1001" Max-Forwards: 70 User-Agent: Jitsi2.8.5426Windows 8 Expires: 600 Contact: "1001" ;expires=600 Via: SIP/2.0/UDP 10.90.111.21:5060;branch=z9hG4bK-313938-a2b494f58e33dbfa497a4637f8ca0f41 Authorization: Digest username="1001",realm="10.90.111.196",nonce="b538df24-de42-11e6-bb8d-b9b014fd381e",uri="sip:10.90.111.196",response="d2402414eb8f01f120508b6d37f175c7",algorithm=MD5,qop=auth,cnonce="xyz",nc=00000001 Content-Length: 0 ------------------------------------------------------------------------ 2017-01-19 17:57:57.114497 [ERR] sofia_reg.c:1988 DELETE PRESENCE SQL: delete from sip_presence where sip_user='1001' and sip_host='10.90.111.196' and profile_name='internal' and open_closed='closed' send 636 bytes to udp/[10.90.111.21]:5060 at 17:57:57.117936: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 10.90.111.21:5060;branch=z9hG4bK-313938-a2b494f58e33dbfa497a4637f8ca0f41 From: "1001" ;tag=bb27c622 To: "1001" ;tag=aQUFUtpcej1eS Call-ID: 0ebcb3a3c821b82ce4ed280dc5fd85db@0:0:0:0:0:0:0:0 CSeq: 40 REGISTER Contact: ;expires=600 Date: Thu, 19 Jan 2017 12:27:57 GMT User-Agent: FreeSWITCH-mod_sofia/1.6.14~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Content-Length: 0 ------------------------------------------------------------------------ send 940 bytes to udp/[10.90.111.21]:5060 at 17:57:57.173115: ------------------------------------------------------------------------ NOTIFY sip:1001@10.90.111.21:5060;transport=udp;registering_acc=10_90_111_196 SIP/2.0 Via: SIP/2.0/UDP 10.90.111.196;rport;branch=z9hG4bKm6aFa4663908m Max-Forwards: 70 From: ;tag=B0m8vN7FBUQ1m To: Call-ID: 8ca26d1b-58e5-1235-14ad-08002772c459 CSeq: 102078374 NOTIFY Contact: User-Agent: FreeSWITCH-mod_sofia/1.6.14~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE Supported: timer, path, replaces Event: message-summary Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer Subscription-State: terminated;reason=noresource Content-Type: application/simple-message-summary Content-Length: 65 Messages-Waiting: no Message-Account: sip:1001@10.90.111.196 ------------------------------------------------------------------------ recv 421 bytes from udp/[10.90.111.21]:5060 at 17:57:57.181076: ------------------------------------------------------------------------ SIP/2.0 200 OK CSeq: 102078374 NOTIFY Call-ID: 8ca26d1b-58e5-1235-14ad-08002772c459 From: ;tag=B0m8vN7FBUQ1m To: ;tag=7f9fea93 Via: SIP/2.0/UDP 10.90.111.196;rport=5060;branch=z9hG4bKm6aFa4663908m;received=10.90.111.196 Contact: "1001" User-Agent: Jitsi2.8.5426Windows 8 Content-Length: 0 ------------------------------------------------------------------------