[Freeswitch-users] Fwd: NOTIFYs not received for conference SUBSCRIBE events

Ram Anji raman.chv at gmail.com
Thu Jan 19 19:21:12 MSK 2017


Hi,

I am testing conference on freeswitch with jitsi. Jitsi sending SUBSCRIBE
event after receiving 200 ok of call with focus parameter along with
contact header.
Server is responding 202 of subscription but no NOTIFY is observed for the
subscription.

I am testing with FreeSWITCH version: 1.6.14~64bit ( 64bit) where it is
installed from freeswitch rpms and os is centos.

Enclosed the console logs for the reference

Regards,
Raman
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20170119/fd8ec2b8/attachment-0001.html 
-------------- next part --------------
freeswitch at localhost.localdomain> 2017-01-19 17:55:08.515299 [WARNING] sofia_presence.c:5077 check_subs: external-ipv6 is passive, skipping

freeswitch at localhost.localdomain> 
freeswitch at localhost.localdomain> sofi

[               sofia]	[       sofia_contact]	[     sofia_count_reg]	[           sofia_dig]	
[  sofia_gateway_data]	[ sofia_presence_data]	[   sofia_username_of]	

freeswitch at localhost.localdomain> sofia glo

[              global]	

freeswitch at 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 at localhost.localdomain> sofia global siptrace o

[                  on]	[                 off]	

freeswitch at localhost.localdomain> sofia global siptrace on

[                  on]	

freeswitch at localhost.localdomain> sofia global siptrace on 

+OK Global siptrace on
freeswitch at localhost.localdomain> console loglev

[            loglevel]	

freeswitch at localhost.localdomain> console loglevel debug

+OK console log level set to DEBUG

freeswitch at 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 at localhost.localdomain> recv 1422 bytes from udp/[10.90.111.21]:5060 at 17:56:35.736340:
   ------------------------------------------------------------------------
   INVITE sip:30000 at 10.90.111.196 SIP/2.0
   Call-ID: 64517400ba1d554c830f45be85e95607 at 0:0:0:0:0:0:0:0
   CSeq: 1 INVITE
   From: "1001" <sip:1001 at 10.90.111.196>;tag=4f65891a
   To: <sip:30000 at 10.90.111.196>
   Via: SIP/2.0/UDP 10.90.111.21:5060;branch=z9hG4bK-313938-33fecedd00708bbca83bad7b51034efa
   Max-Forwards: 70
   Contact: "1001" <sip:1001 at 10.90.111.21:5060;transport=udp;registering_acc=10_90_111_196>
   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" <sip:1001 at 10.90.111.196>;tag=4f65891a
   To: <sip:30000 at 10.90.111.196>
   Call-ID: 64517400ba1d554c830f45be85e95607 at 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 at 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 at 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 at 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" <sip:1001 at 10.90.111.196>;tag=4f65891a
   To: <sip:30000 at 10.90.111.196>;tag=7UF5N931pQypp
   Call-ID: 64517400ba1d554c830f45be85e95607 at 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 at 10.90.111.196) State NEW
recv 340 bytes from udp/[10.90.111.21]:5060 at 17:56:35.750809:
   ------------------------------------------------------------------------
   ACK sip:30000 at 10.90.111.196 SIP/2.0
   Call-ID: 64517400ba1d554c830f45be85e95607 at 0:0:0:0:0:0:0:0
   Max-Forwards: 70
   From: "1001" <sip:1001 at 10.90.111.196>;tag=4f65891a
   To: <sip:30000 at 10.90.111.196>;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 at 10.90.111.196 SIP/2.0
   Call-ID: 64517400ba1d554c830f45be85e95607 at 0:0:0:0:0:0:0:0
   CSeq: 2 INVITE
   From: "1001" <sip:1001 at 10.90.111.196>;tag=4f65891a
   To: <sip:30000 at 10.90.111.196>
   Max-Forwards: 70
   Contact: "1001" <sip:1001 at 10.90.111.21:5060;transport=udp;registering_acc=10_90_111_196>
   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 at 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" <sip:1001 at 10.90.111.196>;tag=4f65891a
   To: <sip:30000 at 10.90.111.196>
   Call-ID: 64517400ba1d554c830f45be85e95607 at 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 at 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 at 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 at 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 at 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 at 10.90.111.196) State INIT
2017-01-19 17:56:35.774369 [DEBUG] mod_sofia.c:90 sofia/internal/1001 at 10.90.111.196 SOFIA INIT
2017-01-19 17:56:35.774369 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1001 at 10.90.111.196 Standard INIT
2017-01-19 17:56:35.774369 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1001 at 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 at 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 at 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 at 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 at 10.90.111.196) State ROUTING
2017-01-19 17:56:35.774369 [DEBUG] mod_sofia.c:143 sofia/internal/1001 at 10.90.111.196 SOFIA ROUTING
2017-01-19 17:56:35.774369 [DEBUG] switch_core_state_machine.c:236 sofia/internal/1001 at 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 at 10.90.111.196 parsing [default->unloop] continue=false
Dialplan: sofia/internal/1001 at 10.90.111.196 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/internal/1001 at 10.90.111.196 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/internal/1001 at 10.90.111.196 parsing [default->tod_example] continue=true
Dialplan: sofia/internal/1001 at 10.90.111.196 Date/Time Match (PASS) [tod_example] break=on-false
Dialplan: sofia/internal/1001 at 10.90.111.196 Action set(open=true) 
Dialplan: sofia/internal/1001 at 10.90.111.196 parsing [default->holiday_example] continue=true
Dialplan: sofia/internal/1001 at 10.90.111.196 Date/TimeMatch (FAIL) [holiday_example] break=on-false
Dialplan: sofia/internal/1001 at 10.90.111.196 parsing [default->global-intercept] continue=false
Dialplan: sofia/internal/1001 at 10.90.111.196 Regex (FAIL) [global-intercept] destination_number(30000) =~ /^886$/ break=on-false
Dialplan: sofia/internal/1001 at 10.90.111.196 parsing [default->group-intercept] continue=false
Dialplan: sofia/internal/1001 at 10.90.111.196 Regex (FAIL) [group-intercept] destination_number(30000) =~ /^\*8$/ break=on-false
Dialplan: sofia/internal/1001 at 10.90.111.196 parsing [default->intercept-ext] continue=false
Dialplan: sofia/internal/1001 at 10.90.111.196 Regex (FAIL) [intercept-ext] destination_number(30000) =~ /^\*\*(\d+)$/ break=on-false
Dialplan: sofia/internal/1001 at 10.90.111.196 parsing [default->redial] continue=false
Dialplan: sofia/internal/1001 at 10.90.111.196 Regex (FAIL) [redial] destination_number(30000) =~ /^(redial|870)$/ break=on-false
Dialplan: sofia/internal/1001 at 10.90.111.196 parsing [default->global] continue=true
Dialplan: sofia/internal/1001 at 10.90.111.196 Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/1001 at 10.90.111.196 Regex (PASS) [global] ${default_password}(1234) =~ /^1234$/ break=never
Dialplan: sofia/internal/1001 at 10.90.111.196 Action log(CRIT WARNING WARNING WARNING WARNING WARNING WARNING WARNING WARNING WARNING ) 
Dialplan: sofia/internal/1001 at 10.90.111.196 Action log(CRIT Open /etc/freeswitch/vars.xml and change the default_password.) 
Dialplan: sofia/internal/1001 at 10.90.111.196 Action log(CRIT Once changed type 'reloadxml' at the console.) 
Dialplan: sofia/internal/1001 at 10.90.111.196 Action log(CRIT WARNING WARNING WARNING WARNING WARNING WARNING WARNING WARNING WARNING ) 
Dialplan: sofia/internal/1001 at 10.90.111.196 Action sleep(10000) 
Dialplan: sofia/internal/1001 at 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 at 10.90.111.196 Regex (PASS) [global] ${endpoint_disposition}(DELAYED NEGOTIATION) =~ /^(DELAYED NEGOTIATION)/ break=on-false
Dialplan: sofia/internal/1001 at 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 at 10.90.111.196 Absolute Condition [global]
Dialplan: sofia/internal/1001 at 10.90.111.196 Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid}) 
Dialplan: sofia/internal/1001 at 10.90.111.196 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number}) 
Dialplan: sofia/internal/1001 at 10.90.111.196 Action hash(insert/${domain_name}-last_dial/global/${uuid}) 
Dialplan: sofia/internal/1001 at 10.90.111.196 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) 
Dialplan: sofia/internal/1001 at 10.90.111.196 parsing [default->snom-demo-2] continue=false
Dialplan: sofia/internal/1001 at 10.90.111.196 Regex (FAIL) [snom-demo-2] destination_number(30000) =~ /^9001$/ break=on-false
Dialplan: sofia/internal/1001 at 10.90.111.196 parsing [default->snom-demo-1] continue=false
Dialplan: sofia/internal/1001 at 10.90.111.196 Regex (FAIL) [snom-demo-1] destination_number(30000) =~ /^9000$/ break=on-false
Dialplan: sofia/internal/1001 at 10.90.111.196 parsing [default->eavesdrop] continue=false
Dialplan: sofia/internal/1001 at 10.90.111.196 Regex (FAIL) [eavesdrop] destination_number(30000) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false
Dialplan: sofia/internal/1001 at 10.90.111.196 parsing [default->eavesdrop] continue=false
Dialplan: sofia/internal/1001 at 10.90.111.196 Regex (FAIL) [eavesdrop] destination_number(30000) =~ /^779$/ break=on-false
Dialplan: sofia/internal/1001 at 10.90.111.196 parsing [default->call_return] continue=false
Dialplan: sofia/internal/1001 at 10.90.111.196 Regex (FAIL) [call_return] destination_number(30000) =~ /^\*69$|^869$|^lcr$/ break=on-false
Dialplan: sofia/internal/1001 at 10.90.111.196 parsing [default->del-group] continue=false
Dialplan: sofia/internal/1001 at 10.90.111.196 Regex (FAIL) [del-group] destination_number(30000) =~ /^80(\d{2})$/ break=on-false
Dialplan: sofia/internal/1001 at 10.90.111.196 parsing [default->add-group] continue=false
Dialplan: sofia/internal/1001 at 10.90.111.196 Regex (FAIL) [add-group] destination_number(30000) =~ /^81(\d{2})$/ break=on-false
Dialplan: sofia/internal/1001 at 10.90.111.196 parsing [default->call-group-simo] continue=false
Dialplan: sofia/internal/1001 at 10.90.111.196 Regex (FAIL) [call-group-simo] destination_number(30000) =~ /^82(\d{2})$/ break=on-false
Dialplan: sofia/internal/1001 at 10.90.111.196 parsing [default->call-group-order] continue=false
Dialplan: sofia/internal/1001 at 10.90.111.196 Regex (FAIL) [call-group-order] destination_number(30000) =~ /^83(\d{2})$/ break=on-false
Dialplan: sofia/internal/1001 at 10.90.111.196 parsing [default->extension-intercom] continue=false
Dialplan: sofia/internal/1001 at 10.90.111.196 Regex (FAIL) [extension-intercom] destination_number(30000) =~ /^8(10[01][0-9])$/ break=on-false
Dialplan: sofia/internal/1001 at 10.90.111.196 parsing [default->Local_Extension] continue=false
Dialplan: sofia/internal/1001 at 10.90.111.196 Regex (FAIL) [Local_Extension] destination_number(30000) =~ /^(10[01][0-9])$/ break=on-false
Dialplan: sofia/internal/1001 at 10.90.111.196 parsing [default->Local_Extension_Skinny] continue=false
Dialplan: sofia/internal/1001 at 10.90.111.196 Regex (FAIL) [Local_Extension_Skinny] destination_number(30000) =~ /^(11[01][0-9])$/ break=on-false
Dialplan: sofia/internal/1001 at 10.90.111.196 parsing [default->group_dial_sales] continue=false
Dialplan: sofia/internal/1001 at 10.90.111.196 Regex (FAIL) [group_dial_sales] destination_number(30000) =~ /^2000$/ break=on-false
Dialplan: sofia/internal/1001 at 10.90.111.196 parsing [default->group_dial_support] continue=false
Dialplan: sofia/internal/1001 at 10.90.111.196 Regex (FAIL) [group_dial_support] destination_number(30000) =~ /^2001$/ break=on-false
Dialplan: sofia/internal/1001 at 10.90.111.196 parsing [default->group_dial_billing] continue=false
Dialplan: sofia/internal/1001 at 10.90.111.196 Regex (FAIL) [group_dial_billing] destination_number(30000) =~ /^2002$/ break=on-false
Dialplan: sofia/internal/1001 at 10.90.111.196 parsing [default->operator] continue=false
Dialplan: sofia/internal/1001 at 10.90.111.196 Regex (FAIL) [operator] destination_number(30000) =~ /^(operator|0)$/ break=on-false
Dialplan: sofia/internal/1001 at 10.90.111.196 parsing [default->vmain] continue=false
Dialplan: sofia/internal/1001 at 10.90.111.196 Regex (FAIL) [vmain] destination_number(30000) =~ /^vmain$|^4000$|^\*98$/ break=on-false
Dialplan: sofia/internal/1001 at 10.90.111.196 parsing [default->sip_uri] continue=false
Dialplan: sofia/internal/1001 at 10.90.111.196 Regex (FAIL) [sip_uri] destination_number(30000) =~ /^sip:(.*)$/ break=on-false
Dialplan: sofia/internal/1001 at 10.90.111.196 parsing [default->my_conferences] continue=false
Dialplan: sofia/internal/1001 at 10.90.111.196 Regex (PASS) [my_conferences] destination_number(30000) =~ /^(300\d{2})$/ break=on-false
Dialplan: sofia/internal/1001 at 10.90.111.196 Action answer(is_conference) 
Dialplan: sofia/internal/1001 at 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 at 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 at 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 at 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 at 10.90.111.196) State EXECUTE
2017-01-19 17:56:35.815142 [DEBUG] mod_sofia.c:198 sofia/internal/1001 at 10.90.111.196 SOFIA EXECUTE
2017-01-19 17:56:35.815142 [DEBUG] switch_core_state_machine.c:328 sofia/internal/1001 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 10.90.111.196 set(open=true)
2017-01-19 17:56:35.875099 [DEBUG] mod_dptools.c:1527 SET sofia/internal/1001 at 10.90.111.196 [open]=[true]
EXECUTE sofia/internal/1001 at 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 at 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 at 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 at 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 at 10.90.111.196 sleep(10000)
2017-01-19 17:56:35.875099 [CRIT] sofia_presence.c:1378 CHECK SQL: 1001 at 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 at 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 at 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 at 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 at 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 at 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 at 10.90.111.196 hash(insert/10.90.111.196-spymap/1001/84ba0012-de42-11e6-bb7c-b9b014fd381e)
EXECUTE sofia/internal/1001 at 10.90.111.196 hash(insert/10.90.111.196-last_dial/1001/30000)
EXECUTE sofia/internal/1001 at 10.90.111.196 hash(insert/10.90.111.196-last_dial/global/84ba0012-de42-11e6-bb7c-b9b014fd381e)
EXECUTE sofia/internal/1001 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 10.90.111.196!
2017-01-19 17:56:46.154382 [DEBUG] switch_channel.c:3473 (sofia/internal/1001 at 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 at 10.90.111.196.
2017-01-19 17:56:46.154382 [DEBUG] mod_sofia.c:849 Local SDP sofia/internal/1001 at 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" <sip:1001 at 10.90.111.196>;tag=4f65891a
   To: <sip:30000 at 10.90.111.196>;tag=848XQ4m5K0m9H
   Call-ID: 64517400ba1d554c830f45be85e95607 at 0:0:0:0:0:0:0:0
   CSeq: 2 INVITE
   Contact: <sip:30000 at 10.90.111.196:5060;transport=udp>;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" <sip:30000 at 10.90.111.196>;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 at 10.90.111.196 entering state [completed][200]
2017-01-19 17:56:46.154382 [NOTICE] mod_dptools.c:1309 Channel [sofia/internal/1001 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 10.90.111.196) Callstate Change EARLY -> ACTIVE
2017-01-19 17:56:46.154382 [CRIT] sofia_presence.c:1378 CHECK SQL: 1001 at 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 at 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 at 10.90.111.196:5060;transport=udp SIP/2.0
   Call-ID: 64517400ba1d554c830f45be85e95607 at 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" <sip:1001 at 10.90.111.196>;tag=4f65891a
   To: <sip:30000 at 10.90.111.196>;tag=848XQ4m5K0m9H
   Max-Forwards: 70
   Contact: "1001" <sip:1001 at 10.90.111.21:5060;transport=udp;registering_acc=10_90_111_196>
   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 at 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 at 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 at 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 at 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 at 10.90.111.196 conference(30000-10.90.111.196 at default)
2017-01-19 17:56:46.154382 [DEBUG] sofia.c:7041 Channel sofia/internal/1001 at 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 at 48000hz 1 channel 20ms
2017-01-19 17:56:46.199781 [DEBUG] conference_member.c:1726 Raw Codec Activation Success L16 at 8000hz 1 channel 20ms
2017-01-19 17:56:46.199781 [DEBUG] switch_core_codec.c:223 sofia/internal/1001 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 10.90.111.196:5060;transport=udp SIP/2.0
   CSeq: 3 SUBSCRIBE
   From: "1001" <sip:1001 at 10.90.111.196>;tag=4f65891a
   To: <sip:30000 at 10.90.111.196>;tag=848XQ4m5K0m9H
   Call-ID: 64517400ba1d554c830f45be85e95607 at 0:0:0:0:0:0:0:0
   Via: SIP/2.0/UDP 10.90.111.21:5060;branch=z9hG4bK-313938-bde2d1b2d9287374c9da0da52a2d9ce9
   Contact: "1001" <sip:1001 at 10.90.111.21:5060;transport=udp;registering_acc=10_90_111_196>
   Proxy-Authorization: Digest username="1001",realm="10.90.111.196",nonce="84ba4cac-de42-11e6-bb7d-b9b014fd381e",uri="sip:30000 at 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 at 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 at 10.90.111.196 30000 at 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" <sip:1001 at 10.90.111.21:5060;transport=udp;registering_acc=10_90_111_196>','64517400ba1d554c830f45be85e95607 at 0:0:0:0:0:0:0:0','"1001" <sip:1001 at 10.90.111.196>;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','<sip:30000 at 10.90.111.196>;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" <sip:1001 at 10.90.111.196>;tag=4f65891a
   To: <sip:30000 at 10.90.111.196>;tag=848XQ4m5K0m9H
   Call-ID: 64517400ba1d554c830f45be85e95607 at 0:0:0:0:0:0:0:0
   CSeq: 3 SUBSCRIBE
   Contact: <sip:30000 at 10.90.111.196:5060>
   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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 48000hz 1 channel 20ms
2017-01-19 17:56:46.395284 [DEBUG] conference_member.c:1726 Raw Codec Activation Success L16 at 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 at 0:0:0:0:0:0:0:0
   CSeq: 39 REGISTER
   From: "1001" <sip:1001 at 10.90.111.196>;tag=bb27c622
   To: "1001" <sip:1001 at 10.90.111.196>
   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" <sip:1001 at 10.90.111.21:5060;transport=udp;registering_acc=10_90_111_196>;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" <sip:1001 at 10.90.111.196>;tag=bb27c622
   To: "1001" <sip:1001 at 10.90.111.196>;tag=9D2pSZ58g9avD
   Call-ID: 0ebcb3a3c821b82ce4ed280dc5fd85db at 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 at 0:0:0:0:0:0:0:0
   CSeq: 40 REGISTER
   From: "1001" <sip:1001 at 10.90.111.196>;tag=bb27c622
   To: "1001" <sip:1001 at 10.90.111.196>
   Max-Forwards: 70
   User-Agent: Jitsi2.8.5426Windows 8
   Expires: 600
   Contact: "1001" <sip:1001 at 10.90.111.21:5060;transport=udp;registering_acc=10_90_111_196>;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" <sip:1001 at 10.90.111.196>;tag=bb27c622
   To: "1001" <sip:1001 at 10.90.111.196>;tag=aQUFUtpcej1eS
   Call-ID: 0ebcb3a3c821b82ce4ed280dc5fd85db at 0:0:0:0:0:0:0:0
   CSeq: 40 REGISTER
   Contact: <sip:1001 at 10.90.111.21:5060;transport=udp;registering_acc=10_90_111_196>;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 at 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: <sip:1001 at 10.90.111.196>;tag=B0m8vN7FBUQ1m
   To: <sip:1001 at 10.90.111.196>
   Call-ID: 8ca26d1b-58e5-1235-14ad-08002772c459
   CSeq: 102078374 NOTIFY
   Contact: <sip:mod_sofia at 10.90.111.196:5060>
   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 at 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: <sip:1001 at 10.90.111.196>;tag=B0m8vN7FBUQ1m
   To: <sip:1001 at 10.90.111.196>;tag=7f9fea93
   Via: SIP/2.0/UDP 10.90.111.196;rport=5060;branch=z9hG4bKm6aFa4663908m;received=10.90.111.196
   Contact: "1001" <sip:1001 at 10.90.111.21:5060;transport=udp;registering_acc=10_90_111_196>
   User-Agent: Jitsi2.8.5426Windows 8
   Content-Length: 0
   
   ------------------------------------------------------------------------



Join us at ClueCon 2016 Aug 8-12, 2016
More information about the FreeSWITCH-users mailing list