freeswitchforum.com

Форум поддержки FreeSWITCH

FreeSWITCH is a registered trademark of Anthony Minessale. Official FreeSWITCH site.

Текущее время: 16 май 2024 06:23

Сообщения без ответов | Активные темы


Список форумов » FreeSWITCH Main » Для новичков/FAQ

Часовой пояс: UTC + 4 часа




Начать новую тему Ответить на тему  Страница 1 из 1
  [ Сообщений: 8 ] 
  Версия для печати Пред. тема | След. тема 
Автор Сообщение
astashov
СообщениеДобавлено: 15 апр 2015 13:26 

Зарегистрирован: 24 дек 2014 10:40
Сообщения: 85
Здравствуйте.

Моя проблема чем то схоже с http://freeswitchforum.com/viewtopic.php?f=6&t=417, только у меня нет внешнего провайдера.

FreeSWITCH Version 1.4.18-1~64bit (-1 64bit)
Chrome Версия 41.0.2272.118 m

fs - 192.168.100.25
client - 192.168.100.100

При звонках через ws нет звука. При обычном звонке через любой sip клиент, звук есть. Проверяю на эхо тесте.
[+] Лог звонка в консоле FS
freeswitch@internal> recv 2921 bytes from ws/[192.168.100.100]:56423 at 14:43:42.483039:
------------------------------------------------------------------------
INVITE sip:555@192.168.100.25 SIP/2.0
Via: SIP/2.0/WS df7jal23ls0d.invalid;branch=z9hG4bKWHX2Ud921T1TeiMTIZThe9uPpoddiXWb;rport
From: "2*1010"<sip:2*1010@192.168.100.25:5060>;tag=4fyvoq30Xvq5HQamaPC9
To: <sip:555@192.168.100.25>
Contact: "2*1010"<sip:2*1010@df7jal23ls0d.invalid;rtcweb-breaker=yes;click2call=no;transport=ws>;impi=2*1010;ha1=a030a2f2db4447801a80d549eaba17bb;+g.oma.sip-im;language="en,fr"
Call-ID: c0887f86-6084-e40e-14c2-df3f3272523f
CSeq: 63455 INVITE
Content-Type: application/sdp
Content-Length: 2287
Max-Forwards: 70
User-Agent: IM-client/OMA1.0 sipML5-v1.2014.12.11
Organization: Doubango Telecom

v=0
o=- 3278827385588036600 2 IN IP4 127.0.0.1
s=Doubango Telecom - chrome
t=0 0
a=group:BUNDLE audio
a=msid-semantic: WMS oO45qPjQKtcP9Bc0fl4HMqR6lC9W18wCNDqQ
m=audio 57040 UDP/TLS/RTP/SAVPF 111 103 104 9 0 8 106 105 13 126
c=IN IP4 217.25.223.94
a=rtcp:57040 IN IP4 217.25.223.94
a=candidate:398667111 1 udp 2122255103 2001::5ef5:79fd:280b:3592:3f57:9b9b 57039 typ host generation 0
a=candidate:398667111 2 udp 2122255103 2001::5ef5:79fd:280b:3592:3f57:9b9b 57039 typ host generation 0
a=candidate:2626306135 1 udp 2122194687 192.168.100.100 57040 typ host generation 0
a=candidate:2626306135 2 udp 2122194687 192.168.100.100 57040 typ host generation 0
a=candidate:1497420183 1 tcp 1518275327 2001::5ef5:79fd:280b:3592:3f57:9b9b 0 typ host tcptype active generation 0
a=candidate:1497420183 2 tcp 1518275327 2001::5ef5:79fd:280b:3592:3f57:9b9b 0 typ host tcptype active generation 0
a=candidate:3523853479 1 tcp 1518214911 192.168.100.100 0 typ host tcptype active generation 0
a=candidate:3523853479 2 tcp 1518214911 192.168.100.100 0 typ host tcptype active generation 0
a=candidate:4114616214 1 udp 1685987071 <Внешний IP адрес> 57040 typ srflx raddr 192.168.100.100 rport 57040 generation 0
a=candidate:4114616214 2 udp 1685987071 <Внешний IP адрес> 57040 typ srflx raddr 192.168.100.100 rport 57040 generation 0
a=ice-ufrag:Sr95EOMasRED4QPp
a=ice-pwd:8aktcCIctEIBD3/eJo0HEfp4
a=ice-options:google-ice
a=fingerprint:sha-256 41:B3:08:08:0F:0C:3C:34:E5:95:02:66:FB:6E:10:FA:A6:67:91:10:3F:A2:3F:D6:82:36:0B:E5:A0:09:DF:84
a=setup:actpass
a=mid:audio
a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level
a=extmap:3 http://www.webrtc.org/experiments/rtp-h ... -send-time
a=sendrecv
a=rtcp-mux
a=rtpmap:111 opus/48000/2
a=fmtp:111 minptime=10; useinbandfec=1
a=rtpmap:103 ISAC/16000
a=rtpmap:104 ISAC/32000
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:106 CN/32000
a=rtpmap:105 CN/16000
a=rtpmap:13 CN/8000
a=rtpmap:126 telephone-event/8000
a=maxptime:60
a=ssrc:3925911445 cname:u9kLWVqN2vXCZOnT
a=ssrc:3925911445 msid:oO45qPjQKtcP9Bc0fl4HMqR6lC9W18wCNDqQ 5503b2c2-b676-46b2-9daf-6ccabc4223a7
a=ssrc:3925911445 mslabel:oO45qPjQKtcP9Bc0fl4HMqR6lC9W18wCNDqQ
a=ssrc:3925911445 label:5503b2c2-b676-46b2-9daf-6ccabc4223a7
------------------------------------------------------------------------
send 391 bytes to ws/[192.168.100.100]:56423 at 14:43:42.484508:
------------------------------------------------------------------------
SIP/2.0 100 Trying
Via: SIP/2.0/WS df7jal23ls0d.invalid;branch=z9hG4bKWHX2Ud921T1TeiMTIZThe9uPpoddiXWb;rport=56423;received=192.168.100.100
From: "2*1010"<sip:2*1010@192.168.100.25:5060>;tag=4fyvoq30Xvq5HQamaPC9
To: <sip:555@192.168.100.25>
Call-ID: c0887f86-6084-e40e-14c2-df3f3272523f
CSeq: 63455 INVITE
User-Agent: WS Client(Based on FreeSWITCH PBX)
Content-Length: 0

------------------------------------------------------------------------
2015-04-15 14:43:42.468435 [NOTICE] switch_channel.c:1055 New Channel sofia/internal/2*1010@192.168.100.25:5060 [7cff162e-e524-44bd-9de8-b24d92d3b2cc]
2015-04-15 14:43:42.468435 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/2*1010@192.168.100.25:5060 [BREAK]
2015-04-15 14:43:42.468435 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/2*1010@192.168.100.25:5060 [BREAK]
2015-04-15 14:43:42.468435 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/2*1010@192.168.100.25:5060) Running State Change CS_NEW
2015-04-15 14:43:42.468435 [DEBUG] sofia.c:8844 sofia/internal/2*1010@192.168.100.25:5060 receiving invite from 192.168.100.100:56423 version: 1.4.18 -1 64bit
2015-04-15 14:43:42.468435 [DEBUG] sofia.c:9011 IP 192.168.100.100 Rejected by acl "domains". Falling back to Digest auth.
2015-04-15 14:43:42.468435 [WARNING] sofia_reg.c:1742 SIP auth challenge (INVITE) on sofia profile 'internal' for [555@192.168.100.25] from ip 192.168.100.100
2015-04-15 14:43:42.468435 [DEBUG] switch_core_state_machine.c:491 (sofia/internal/2*1010@192.168.100.25:5060) State NEW
send 896 bytes to ws/[192.168.100.100]:56423 at 14:43:42.487684:
------------------------------------------------------------------------
SIP/2.0 407 Proxy Authentication Required
Via: SIP/2.0/WS df7jal23ls0d.invalid;branch=z9hG4bKWHX2Ud921T1TeiMTIZThe9uPpoddiXWb;rport=56423;received=192.168.100.100
From: "2*1010"<sip:2*1010@192.168.100.25:5060>;tag=4fyvoq30Xvq5HQamaPC9
To: <sip:555@192.168.100.25>;tag=gpNa22QgSKQ3a
Call-ID: c0887f86-6084-e40e-14c2-df3f3272523f
CSeq: 63455 INVITE
User-Agent: WS Client(Based on FreeSWITCH PBX)
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="192.168.100.25", nonce="12cea1ae-1c4e-4523-9644-bd1df7f8e5b5", algorithm=MD5, qop="auth"
Content-Length: 0

------------------------------------------------------------------------
2015-04-15 14:43:42.468435 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/2*1010@192.168.100.25:5060 [BREAK]
2015-04-15 14:43:42.468435 [DEBUG] sofia.c:2065 detaching session 7cff162e-e524-44bd-9de8-b24d92d3b2cc
recv 351 bytes from ws/[192.168.100.100]:56423 at 14:43:42.526416:
------------------------------------------------------------------------
ACK sip:555@192.168.100.25 SIP/2.0
Via: SIP/2.0/WS df7jal23ls0d.invalid;branch=z9hG4bKWHX2Ud921T1TeiMTIZThe9uPpoddiXWb;rport
From: "2*1010"<sip:2*1010@192.168.100.25:5060>;tag=4fyvoq30Xvq5HQamaPC9
To: <sip:555@192.168.100.25>;tag=gpNa22QgSKQ3a
Call-ID: c0887f86-6084-e40e-14c2-df3f3272523f
CSeq: 63455 ACK
Content-Length: 0
Max-Forwards: 70

------------------------------------------------------------------------
recv 3186 bytes from ws/[192.168.100.100]:56423 at 14:43:42.534755:
------------------------------------------------------------------------
INVITE sip:555@192.168.100.25 SIP/2.0
Via: SIP/2.0/WS df7jal23ls0d.invalid;branch=z9hG4bK8Xq2P91cUocdokwWkenO58cRpC4RBlTg;rport
From: "2*1010"<sip:2*1010@192.168.100.25:5060>;tag=4fyvoq30Xvq5HQamaPC9
To: <sip:555@192.168.100.25>
Contact: "2*1010"<sip:2*1010@df7jal23ls0d.invalid;rtcweb-breaker=yes;click2call=no;transport=ws>;impi=2*1010;ha1=a030a2f2db4447801a80d549eaba17bb;+g.oma.sip-im;language="en,fr"
Call-ID: c0887f86-6084-e40e-14c2-df3f3272523f
CSeq: 63456 INVITE
Content-Type: application/sdp
Content-Length: 2287
Max-Forwards: 70
Proxy-Authorization: Digest username="2*1010",realm="192.168.100.25",nonce="12cea1ae-1c4e-4523-9644-bd1df7f8e5b5",uri="sip:555@192.168.100.25",response="baf12dacc582940a2751b87da290a94b",algorithm=MD5,cnonce="67ef04408a5a82e9bcfd336a5d2f58ef",qop=auth,nc=00000001
User-Agent: IM-client/OMA1.0 sipML5-v1.2014.12.11
Organization: Doubango Telecom

v=0
o=- 3278827385588036600 2 IN IP4 127.0.0.1
s=Doubango Telecom - chrome
t=0 0
a=group:BUNDLE audio
a=msid-semantic: WMS oO45qPjQKtcP9Bc0fl4HMqR6lC9W18wCNDqQ
m=audio 57040 UDP/TLS/RTP/SAVPF 111 103 104 9 0 8 106 105 13 126
c=IN IP4 217.25.223.94
a=rtcp:57040 IN IP4 217.25.223.94
a=candidate:398667111 1 udp 2122255103 2001::5ef5:79fd:280b:3592:3f57:9b9b 57039 typ host generation 0
a=candidate:398667111 2 udp 2122255103 2001::5ef5:79fd:280b:3592:3f57:9b9b 57039 typ host generation 0
a=candidate:2626306135 1 udp 2122194687 192.168.100.100 57040 typ host generation 0
a=candidate:2626306135 2 udp 2122194687 192.168.100.100 57040 typ host generation 0
a=candidate:1497420183 1 tcp 1518275327 2001::5ef5:79fd:280b:3592:3f57:9b9b 0 typ host tcptype active generation 0
a=candidate:1497420183 2 tcp 1518275327 2001::5ef5:79fd:280b:3592:3f57:9b9b 0 typ host tcptype active generation 0
a=candidate:3523853479 1 tcp 1518214911 192.168.100.100 0 typ host tcptype active generation 0
a=candidate:3523853479 2 tcp 1518214911 192.168.100.100 0 typ host tcptype active generation 0
a=candidate:4114616214 1 udp 1685987071 <Внешний IP адрес> 57040 typ srflx raddr 192.168.100.100 rport 57040 generation 0
a=candidate:4114616214 2 udp 1685987071 <Внешний IP адрес> 57040 typ srflx raddr 192.168.100.100 rport 57040 generation 0
a=ice-ufrag:Sr95EOMasRED4QPp
a=ice-pwd:8aktcCIctEIBD3/eJo0HEfp4
a=ice-options:google-ice
a=fingerprint:sha-256 41:B3:08:08:0F:0C:3C:34:E5:95:02:66:FB:6E:10:FA:A6:67:91:10:3F:A2:3F:D6:82:36:0B:E5:A0:09:DF:84
a=setup:actpass
a=mid:audio
a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level
a=extmap:3 http://www.webrtc.org/experiments/rtp-h ... -send-time
a=sendrecv
a=rtcp-mux
a=rtpmap:111 opus/48000/2
a=fmtp:111 minptime=10; useinbandfec=1
a=rtpmap:103 ISAC/16000
a=rtpmap:104 ISAC/32000
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:106 CN/32000
a=rtpmap:105 CN/16000
a=rtpmap:13 CN/8000
a=rtpmap:126 telephone-event/8000
a=maxptime:60
a=ssrc:3925911445 cname:u9kLWVqN2vXCZOnT
a=ssrc:3925911445 msid:oO45qPjQKtcP9Bc0fl4HMqR6lC9W18wCNDqQ 5503b2c2-b676-46b2-9daf-6ccabc4223a7
a=ssrc:3925911445 mslabel:oO45qPjQKtcP9Bc0fl4HMqR6lC9W18wCNDqQ
a=ssrc:3925911445 label:5503b2c2-b676-46b2-9daf-6ccabc4223a7
------------------------------------------------------------------------
send 391 bytes to ws/[192.168.100.100]:56423 at 14:43:42.535680:
------------------------------------------------------------------------
SIP/2.0 100 Trying
Via: SIP/2.0/WS df7jal23ls0d.invalid;branch=z9hG4bK8Xq2P91cUocdokwWkenO58cRpC4RBlTg;rport=56423;received=192.168.100.100
From: "2*1010"<sip:2*1010@192.168.100.25:5060>;tag=4fyvoq30Xvq5HQamaPC9
To: <sip:555@192.168.100.25>
Call-ID: c0887f86-6084-e40e-14c2-df3f3272523f
CSeq: 63456 INVITE
User-Agent: WS Client(Based on FreeSWITCH PBX)
Content-Length: 0

------------------------------------------------------------------------
2015-04-15 14:43:42.529503 [DEBUG] sofia.c:2173 Re-attaching to session 7cff162e-e524-44bd-9de8-b24d92d3b2cc
2015-04-15 14:43:42.529503 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/2*1010@192.168.100.25:5060 [BREAK]
2015-04-15 14:43:42.529503 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/2*1010@192.168.100.25:5060 [BREAK]
2015-04-15 14:43:42.529503 [DEBUG] sofia.c:8844 sofia/internal/2*1010@192.168.100.25:5060 receiving invite from 192.168.100.100:56423 version: 1.4.18 -1 64bit
2015-04-15 14:43:42.548414 [DEBUG] sofia.c:9011 IP 192.168.100.100 Rejected by acl "domains". Falling back to Digest auth.
2015-04-15 14:43:42.548414 [DEBUG] sofia.c:10109 Setting NAT mode based on websockets
2015-04-15 14:43:42.548414 [DEBUG] sofia.c:6623 Channel sofia/internal/2*1010@192.168.100.25:5060 entering state [received][100]
2015-04-15 14:43:42.548414 [DEBUG] sofia.c:6633 Remote SDP:
v=0
o=- 3278827385588036600 2 IN IP4 127.0.0.1
s=Doubango Telecom - chrome
t=0 0
a=group:BUNDLE audio
a=msid-semantic: WMS oO45qPjQKtcP9Bc0fl4HMqR6lC9W18wCNDqQ
m=audio 57040 UDP/TLS/RTP/SAVPF 111 103 104 9 0 8 106 105 13 126
c=IN IP4 217.25.223.94
a=rtpmap:111 opus/48000/2
a=fmtp:111 minptime=10; useinbandfec=1
a=rtpmap:103 ISAC/16000
a=rtpmap:104 ISAC/32000
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:106 CN/32000
a=rtpmap:105 CN/16000
a=rtpmap:13 CN/8000
a=rtpmap:126 telephone-event/8000
a=rtcp:57040 IN IP4 217.25.223.94
a=candidate:398667111 1 udp 2122255103 2001::5ef5:79fd:280b:3592:3f57:9b9b 57039 typ host generation 0
a=candidate:398667111 2 udp 2122255103 2001::5ef5:79fd:280b:3592:3f57:9b9b 57039 typ host generation 0
a=candidate:2626306135 1 udp 2122194687 192.168.100.100 57040 typ host generation 0
a=candidate:2626306135 2 udp 2122194687 192.168.100.100 57040 typ host generation 0
a=candidate:1497420183 1 tcp 1518275327 2001::5ef5:79fd:280b:3592:3f57:9b9b 0 typ host tcptype active generation 0
a=candidate:1497420183 2 tcp 1518275327 2001::5ef5:79fd:280b:3592:3f57:9b9b 0 typ host tcptype active generation 0
a=candidate:3523853479 1 tcp 1518214911 192.168.100.100 0 typ host tcptype active generation 0
a=candidate:3523853479 2 tcp 1518214911 192.168.100.100 0 typ host tcptype active generation 0
a=candidate:4114616214 1 udp 1685987071 <Внешний IP адрес> 57040 typ srflx raddr 192.168.100.100 rport 57040 generation 0
a=candidate:4114616214 2 udp 1685987071 <Внешний IP адрес> 57040 typ srflx raddr 192.168.100.100 rport 57040 generation 0
a=ice-ufrag:Sr95EOMasRED4QPp
a=ice-pwd:8aktcCIctEIBD3/eJo0HEfp4
a=ice-options:google-ice
a=fingerprint:sha-256 41:B3:08:08:0F:0C:3C:34:E5:95:02:66:FB:6E:10:FA:A6:67:91:10:3F:A2:3F:D6:82:36:0B:E5:A0:09:DF:84
a=setup:actpass
a=mid:audio
a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level
a=extmap:3 http://www.webrtc.org/experiments/rtp-h ... -send-time
a=rtcp-mux
a=maxptime:60
a=ssrc:3925911445 cname:u9kLWVqN2vXCZOnT
a=ssrc:3925911445 msid:oO45qPjQKtcP9Bc0fl4HMqR6lC9W18wCNDqQ 5503b2c2-b676-46b2-9daf-6ccabc4223a7
a=ssrc:3925911445 mslabel:oO45qPjQKtcP9Bc0fl4HMqR6lC9W18wCNDqQ
a=ssrc:3925911445 label:5503b2c2-b676-46b2-9daf-6ccabc4223a7

2015-04-15 14:43:42.548414 [DEBUG] sofia.c:6899 (sofia/internal/2*1010@192.168.100.25:5060) State Change CS_NEW -> CS_INIT
2015-04-15 14:43:42.548414 [DEBUG] switch_core_session.c:1396 Send signal sofia/internal/2*1010@192.168.100.25:5060 [BREAK]
2015-04-15 14:43:42.548414 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/2*1010@192.168.100.25:5060) Running State Change CS_INIT
2015-04-15 14:43:42.548414 [DEBUG] switch_core_state_machine.c:512 (sofia/internal/2*1010@192.168.100.25:5060) State INIT
2015-04-15 14:43:42.548414 [DEBUG] mod_sofia.c:87 sofia/internal/2*1010@192.168.100.25:5060 SOFIA INIT
2015-04-15 14:43:42.548414 [DEBUG] switch_core_state_machine.c:40 sofia/internal/2*1010@192.168.100.25:5060 Standard INIT
2015-04-15 14:43:42.548414 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/2*1010@192.168.100.25:5060) State Change CS_INIT -> CS_ROUTING
2015-04-15 14:43:42.548414 [DEBUG] switch_core_session.c:1396 Send signal sofia/internal/2*1010@192.168.100.25:5060 [BREAK]
2015-04-15 14:43:42.548414 [DEBUG] switch_core_state_machine.c:512 (sofia/internal/2*1010@192.168.100.25:5060) State INIT going to sleep
2015-04-15 14:43:42.548414 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/2*1010@192.168.100.25:5060) Running State Change CS_ROUTING
2015-04-15 14:43:42.548414 [DEBUG] switch_channel.c:2184 (sofia/internal/2*1010@192.168.100.25:5060) Callstate Change DOWN -> RINGING
2015-04-15 14:43:42.548414 [DEBUG] switch_core_state_machine.c:528 (sofia/internal/2*1010@192.168.100.25:5060) State ROUTING
2015-04-15 14:43:42.548414 [DEBUG] mod_sofia.c:123 sofia/internal/2*1010@192.168.100.25:5060 SOFIA ROUTING
2015-04-15 14:43:42.548414 [DEBUG] switch_core_state_machine.c:166 sofia/internal/2*1010@192.168.100.25:5060 Standard ROUTING
2015-04-15 14:43:42.548414 [INFO] mod_dialplan_xml.c:635 Processing 2*1010 <2*1010>->555 in context ws-context
2015-04-15 14:43:42.548414 [DEBUG] mod_dialplan_xml.c:688 Dialplan: sofia/internal/2*1010@192.168.100.25:5060 parsing [ws-context->unloop] continue=false
2015-04-15 14:43:42.548414 [DEBUG] mod_dialplan_xml.c:418 Dialplan: sofia/internal/2*1010@192.168.100.25:5060 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
2015-04-15 14:43:42.548414 [DEBUG] mod_dialplan_xml.c:429 Dialplan: sofia/internal/2*1010@192.168.100.25:5060 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
2015-04-15 14:43:42.548414 [DEBUG] mod_dialplan_xml.c:688 Dialplan: sofia/internal/2*1010@192.168.100.25:5060 parsing [ws-context->redial] continue=false
2015-04-15 14:43:42.548414 [DEBUG] mod_dialplan_xml.c:429 Dialplan: sofia/internal/2*1010@192.168.100.25:5060 Regex (FAIL) [redial] destination_number(555) =~ /^(redial|870)$/ break=on-false
2015-04-15 14:43:42.548414 [DEBUG] mod_dialplan_xml.c:688 Dialplan: sofia/internal/2*1010@192.168.100.25:5060 parsing [ws-context->eavesdrop] continue=false
2015-04-15 14:43:42.548414 [DEBUG] mod_dialplan_xml.c:429 Dialplan: sofia/internal/2*1010@192.168.100.25:5060 Regex (FAIL) [eavesdrop] destination_number(555) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false
2015-04-15 14:43:42.548414 [DEBUG] mod_dialplan_xml.c:688 Dialplan: sofia/internal/2*1010@192.168.100.25:5060 parsing [ws-context->eavesdrop] continue=false
2015-04-15 14:43:42.548414 [DEBUG] mod_dialplan_xml.c:429 Dialplan: sofia/internal/2*1010@192.168.100.25:5060 Regex (FAIL) [eavesdrop] destination_number(555) =~ /^779$/ break=on-false
2015-04-15 14:43:42.548414 [DEBUG] mod_dialplan_xml.c:688 Dialplan: sofia/internal/2*1010@192.168.100.25:5060 parsing [ws-context->call_return] continue=false
2015-04-15 14:43:42.548414 [DEBUG] mod_dialplan_xml.c:429 Dialplan: sofia/internal/2*1010@192.168.100.25:5060 Regex (FAIL) [call_return] destination_number(555) =~ /^\*69$|^869$|^lcr$/ break=on-false
2015-04-15 14:43:42.548414 [DEBUG] mod_dialplan_xml.c:688 Dialplan: sofia/internal/2*1010@192.168.100.25:5060 parsing [ws-context->valet_park] continue=false
2015-04-15 14:43:42.548414 [DEBUG] mod_dialplan_xml.c:429 Dialplan: sofia/internal/2*1010@192.168.100.25:5060 Regex (FAIL) [valet_park] destination_number(555) =~ /^(6000)$/ break=on-false
2015-04-15 14:43:42.548414 [DEBUG] mod_dialplan_xml.c:688 Dialplan: sofia/internal/2*1010@192.168.100.25:5060 parsing [ws-context->valet_park] continue=false
2015-04-15 14:43:42.548414 [DEBUG] mod_dialplan_xml.c:429 Dialplan: sofia/internal/2*1010@192.168.100.25:5060 Regex (FAIL) [valet_park] destination_number(555) =~ /^((?!6000)60\d{2})$/ break=on-false
2015-04-15 14:43:42.548414 [DEBUG] mod_dialplan_xml.c:688 Dialplan: sofia/internal/2*1010@192.168.100.25:5060 parsing [ws-context->delay_echo] continue=false
2015-04-15 14:43:42.548414 [DEBUG] mod_dialplan_xml.c:418 Dialplan: sofia/internal/2*1010@192.168.100.25:5060 Regex (PASS) [delay_echo] destination_number(555) =~ /^555$/ break=on-false
2015-04-15 14:43:42.548414 [DEBUG] mod_dialplan_xml.c:563 Dialplan: sofia/internal/2*1010@192.168.100.25:5060 Action answer()
2015-04-15 14:43:42.548414 [DEBUG] mod_dialplan_xml.c:563 Dialplan: sofia/internal/2*1010@192.168.100.25:5060 Action delay_echo(5000)
2015-04-15 14:43:42.548414 [DEBUG] switch_core_state_machine.c:216 (sofia/internal/2*1010@192.168.100.25:5060) State Change CS_ROUTING -> CS_EXECUTE
2015-04-15 14:43:42.548414 [DEBUG] switch_core_session.c:1396 Send signal sofia/internal/2*1010@192.168.100.25:5060 [BREAK]
2015-04-15 14:43:42.548414 [DEBUG] switch_core_state_machine.c:528 (sofia/internal/2*1010@192.168.100.25:5060) State ROUTING going to sleep
2015-04-15 14:43:42.548414 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/2*1010@192.168.100.25:5060) Running State Change CS_EXECUTE
2015-04-15 14:43:42.548414 [DEBUG] switch_core_state_machine.c:535 (sofia/internal/2*1010@192.168.100.25:5060) State EXECUTE
2015-04-15 14:43:42.548414 [DEBUG] mod_sofia.c:178 sofia/internal/2*1010@192.168.100.25:5060 SOFIA EXECUTE
2015-04-15 14:43:42.548414 [DEBUG] switch_core_state_machine.c:258 sofia/internal/2*1010@192.168.100.25:5060 Standard EXECUTE
2015-04-15 14:43:42.548414 [DEBUG] switch_core_session.c:2823 EXECUTE sofia/internal/2*1010@192.168.100.25:5060 answer()
2015-04-15 14:43:42.548414 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [opus:111:48000:60:0:2]/[PCMU:0:8000:20:64000:1]
2015-04-15 14:43:42.548414 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [opus:111:48000:60:0:2]/[PCMA:8:8000:20:64000:1]
2015-04-15 14:43:42.548414 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [ISAC:103:16000:30:32000:1]/[PCMU:0:8000:20:64000:1]
2015-04-15 14:43:42.548414 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [ISAC:103:16000:30:32000:1]/[PCMA:8:8000:20:64000:1]
2015-04-15 14:43:42.548414 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [ISAC:104:32000:30:32000:1]/[PCMU:0:8000:20:64000:1]
2015-04-15 14:43:42.548414 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [ISAC:104:32000:30:32000:1]/[PCMA:8:8000:20:64000:1]
2015-04-15 14:43:42.548414 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [G722:9:8000:60:64000:1]/[PCMU:0:8000:20:64000:1]
2015-04-15 14:43:42.548414 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [G722:9:8000:60:64000:1]/[PCMA:8:8000:20:64000:1]
2015-04-15 14:43:42.548414 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [PCMU:0:8000:60:64000:1]/[PCMU:0:8000:20:64000:1]
2015-04-15 14:43:42.548414 [DEBUG] switch_core_media.c:3687 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2015-04-15 14:43:42.548414 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [PCMU:0:8000:60:64000:1]/[PCMA:8:8000:20:64000:1]
2015-04-15 14:43:42.548414 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [PCMA:8:8000:60:64000:1]/[PCMU:0:8000:20:64000:1]
2015-04-15 14:43:42.548414 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [PCMA:8:8000:60:64000:1]/[PCMA:8:8000:20:64000:1]
2015-04-15 14:43:42.548414 [DEBUG] switch_core_media.c:3687 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2015-04-15 14:43:42.548414 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [CN:105:16000:60:0:1]/[PCMU:0:8000:20:64000:1]
2015-04-15 14:43:42.548414 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [CN:105:16000:60:0:1]/[PCMA:8:8000:20:64000:1]
2015-04-15 14:43:42.548414 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [CN:13:8000:60:0:1]/[PCMU:0:8000:20:64000:1]
2015-04-15 14:43:42.548414 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [CN:13:8000:60:0:1]/[PCMA:8:8000:20:64000:1]
2015-04-15 14:43:42.548414 [DEBUG] switch_core_media.c:3548 Set telephone-event payload to 126
2015-04-15 14:43:42.548414 [DEBUG] switch_core_media.c:2473 Set Codec sofia/internal/2*1010@192.168.100.25:5060 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2015-04-15 14:43:42.548414 [DEBUG] switch_core_codec.c:111 sofia/internal/2*1010@192.168.100.25:5060 Original read codec set to PCMU:0
2015-04-15 14:43:42.548414 [WARNING] switch_core_media.c:2757 NO candidate ACL defined, Defaulting to wan.auto
2015-04-15 14:43:42.548414 [DEBUG] switch_core_media.c:2781 Checking Candidate cid: 1 proto: udp type: host addr: 2001::5ef5:79fd:280b:3592:3f57:9b9b:57039
2015-04-15 14:43:42.548414 [NOTICE] switch_core_media.c:2790 Choose audio Candidate cid: 1 proto: udp type: host addr: 2001::5ef5:79fd:280b:3592:3f57:9b9b:57039
2015-04-15 14:43:42.548414 [DEBUG] switch_core_media.c:2781 Checking Candidate cid: 2 proto: udp type: host addr: 2001::5ef5:79fd:280b:3592:3f57:9b9b:57039
2015-04-15 14:43:42.548414 [NOTICE] switch_core_media.c:2790 Choose audio Candidate cid: 2 proto: udp type: host addr: 2001::5ef5:79fd:280b:3592:3f57:9b9b:57039
2015-04-15 14:43:42.548414 [DEBUG] switch_core_media.c:2781 Checking Candidate cid: 1 proto: udp type: host addr: 192.168.100.100:57040
2015-04-15 14:43:42.548414 [NOTICE] switch_core_media.c:2795 Save audio Candidate cid: 1 proto: udp type: host addr: 192.168.100.100:57040
2015-04-15 14:43:42.548414 [DEBUG] switch_core_media.c:2781 Checking Candidate cid: 2 proto: udp type: host addr: 192.168.100.100:57040
2015-04-15 14:43:42.548414 [NOTICE] switch_core_media.c:2795 Save audio Candidate cid: 2 proto: udp type: host addr: 192.168.100.100:57040
2015-04-15 14:43:42.548414 [DEBUG] switch_core_media.c:2781 Checking Candidate cid: 1 proto: udp type: srflx addr: <Внешний IP адрес>:57040
2015-04-15 14:43:42.548414 [NOTICE] switch_core_media.c:2795 Save audio Candidate cid: 1 proto: udp type: srflx addr: <Внешний IP адрес>:57040
2015-04-15 14:43:42.548414 [DEBUG] switch_core_media.c:2781 Checking Candidate cid: 2 proto: udp type: srflx addr: <Внешний IP адрес>:57040
2015-04-15 14:43:42.548414 [NOTICE] switch_core_media.c:2795 Save audio Candidate cid: 2 proto: udp type: srflx addr: <Внешний IP адрес>:57040
2015-04-15 14:43:42.548414 [NOTICE] switch_core_media.c:2919 setting remote audio ice addr to 2001::5ef5:79fd:280b:3592:3f57:9b9b:57039 based on candidate
2015-04-15 14:43:42.548414 [NOTICE] switch_core_media.c:2944 setting remote rtcp audio addr to 2001::5ef5:79fd:280b:3592:3f57:9b9b:57039 based on candidate
2015-04-15 14:43:42.548414 [DEBUG] switch_core_media.c:3895 Set 2833 dtmf send/recv payload to 126
2015-04-15 14:43:42.548414 [DEBUG] switch_core_media.c:5147 AUDIO RTP [sofia/internal/2*1010@192.168.100.25:5060] 192.168.100.25 port 22864 -> 2001::5ef5:79fd:280b:3592:3f57:9b9b port 57039 codec: 0 ms: 20
2015-04-15 14:43:42.548414 [DEBUG] switch_rtp.c:3562 Starting timer [soft] 160 bytes per 20ms
2015-04-15 14:43:42.548414 [DEBUG] switch_rtp.c:1370 [ zrtp main]: START SESSION INITIALIZATION. sID=13.
2015-04-15 14:43:42.548414 [DEBUG] switch_rtp.c:1370 [ zrtp main]: ZID=633061383634313464366363.
2015-04-15 14:43:42.548414 [DEBUG] switch_rtp.c:1370 [ zrtp main]: Loading User's profile:
2015-04-15 14:43:42.548414 [DEBUG] switch_rtp.c:1370 [ zrtp main]: allowclear: OFF
2015-04-15 14:43:42.548414 [DEBUG] switch_rtp.c:1370 [ zrtp main]: autosecure: ON
2015-04-15 14:43:42.548414 [DEBUG] switch_rtp.c:1370 [ zrtp main]: disclose_bit: OFF
2015-04-15 14:43:42.548414 [DEBUG] switch_rtp.c:1370 [ zrtp main]: signal. role: Unknown
2015-04-15 14:43:42.548414 [DEBUG] switch_rtp.c:1370 [ zrtp main]: TTL: 4294967295
2015-04-15 14:43:42.548414 [DEBUG] switch_rtp.c:1370 [ zrtp main]: SAS schemes:
2015-04-15 14:43:42.548414 [DEBUG] switch_rtp.c:1370 B256
2015-04-15 14:43:42.548414 [DEBUG] switch_rtp.c:1370 B32
2015-04-15 14:43:42.548414 [DEBUG] switch_rtp.c:1370
2015-04-15 14:43:42.548414 [DEBUG] switch_rtp.c:1370 [ zrtp main]: Ciphers:
2015-04-15 14:43:42.548414 [DEBUG] switch_rtp.c:1370 AES3
2015-04-15 14:43:42.548414 [DEBUG] switch_rtp.c:1370 AES1
2015-04-15 14:43:42.548414 [DEBUG] switch_rtp.c:1370
2015-04-15 14:43:42.548414 [DEBUG] switch_rtp.c:1370 [ zrtp main]: PK schemes:
2015-04-15 14:43:42.548414 [DEBUG] switch_rtp.c:1370 EC25
2015-04-15 14:43:42.548414 [DEBUG] switch_rtp.c:1370 DH3k
2015-04-15 14:43:42.548414 [DEBUG] switch_rtp.c:1370 DH2k
2015-04-15 14:43:42.548414 [DEBUG] switch_rtp.c:1370 Mult
2015-04-15 14:43:42.548414 [DEBUG] switch_rtp.c:1370
2015-04-15 14:43:42.548414 [DEBUG] switch_rtp.c:1370 [ zrtp main]: ATL:
2015-04-15 14:43:42.548414 [DEBUG] switch_rtp.c:1370 HS32
2015-04-15 14:43:42.548414 [DEBUG] switch_rtp.c:1370
2015-04-15 14:43:42.548414 [DEBUG] switch_rtp.c:1370 [ zrtp main]: Hashes:
2015-04-15 14:43:42.548414 [DEBUG] switch_rtp.c:1370 S256
2015-04-15 14:43:42.548414 [DEBUG] switch_rtp.c:1370
2015-04-15 14:43:42.548414 [DEBUG] switch_rtp.c:1370 [ zrtp main]: Session initialization - DONE. sID=13.

2015-04-15 14:43:42.548414 [DEBUG] switch_rtp.c:1370 [ zrtp main]: ATTACH NEW STREAM to sID=13:
2015-04-15 14:43:42.548414 [DEBUG] switch_rtp.c:1370 [ zrtp]: Stream ID=0 UNKNOWN switching <NONE> ---> <ACTIVE>.
2015-04-15 14:43:42.548414 [DEBUG] switch_rtp.c:1370 [ zrtp main]: Empty slot was found - initializing new stream with ID=13.
2015-04-15 14:43:42.548414 [DEBUG] switch_rtp.c:1370 [ zrtp main]: Preparing ZRTP Hello according to the Session profile.
2015-04-15 14:43:42.548414 [DEBUG] switch_rtp.c:1370 [ zrtp main]: ATTACH NEW STREAM - DONE.
2015-04-15 14:43:42.548414 [DEBUG] switch_rtp.c:1370 [ zrtp engine]: START STREAM ID=13 mode=CLEAR state=ACTIVE.
2015-04-15 14:43:42.548414 [DEBUG] switch_rtp.c:1370 [ zrtp]: Stream ID=13 CLEAR switching <ACTIVE> ---> <START>.
2015-04-15 14:43:42.548414 [DEBUG] switch_rtp.c:1370 [ zrtp utils]: Send <HELLO> ssrc=1899339974 seq=34771 size=144. Stream 13:CLEAR:START
2015-04-15 14:43:42.548414 [INFO] switch_core_media.c:5321 Activating Audio ICE
2015-04-15 14:43:42.548414 [NOTICE] switch_rtp.c:4012 Activating RTP audio ICE: Sr95EOMasRED4QPp:Ebys8jRjnvUJta0U 2001::5ef5:79fd:280b:3592:3f57:9b9b:57039
2015-04-15 14:43:42.548414 [INFO] switch_core_media.c:5364 Activating RTCP PORT 57039
2015-04-15 14:43:42.548414 [DEBUG] switch_rtp.c:3912 RTCP send rate is: 10000 and packet rate is: 20000 Remote Port: 57039
2015-04-15 14:43:42.548414 [DEBUG] switch_rtp.c:2367 Setting RTCP remote addr to :57039
2015-04-15 14:43:42.548414 [INFO] switch_core_media.c:5372 Skipping RTCP ICE (Same as RTP)
2015-04-15 14:43:42.548414 [INFO] switch_rtp.c:3104 Activate RTP/RTCP audio DTLS client
2015-04-15 14:43:42.548414 [DEBUG] switch_core_media.c:5445 Set 2833 dtmf send payload to 126
2015-04-15 14:43:42.548414 [DEBUG] switch_core_media.c:5451 Set 2833 dtmf receive payload to 126
2015-04-15 14:43:42.548414 [DEBUG] switch_core_media.c:5479 Set comfort noise payload to 106
2015-04-15 14:43:42.548414 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/2*1010@192.168.100.25:5060!
2015-04-15 14:43:42.548414 [DEBUG] switch_channel.c:3399 (sofia/internal/2*1010@192.168.100.25:5060) Callstate Change RINGING -> EARLY
2015-04-15 14:43:42.548414 [DEBUG] mod_sofia.c:780 Local SDP sofia/internal/2*1010@192.168.100.25:5060:
v=0
o=FreeSWITCH 1429064558 1429064559 IN IP4 192.168.100.25
s=FreeSWITCH
c=IN IP4 192.168.100.25
t=0 0
a=msid-semantic: WMS 6CaVFRUPB7UF7JI8VatPX7UzleNKv8qr
m=audio 22864 UDP/TLS/RTP/SAVPF 0 126 106
a=rtpmap:0 PCMU/8000
a=rtpmap:126 telephone-event/8000
a=rtpmap:106 CN/8000
a=ptime:20
a=sendrecv
a=fingerprint:sha-256 DA:BD:5D:C8:CC:7A:1B:19:92:8A:90:58:8B:CD:C9:CF:EF:0A:EB:7A:2F:9C:E7:6C:9D:E2:70:BE:07:B4:C2:AF
a=rtcp-mux
a=rtcp:22864 IN IP4 192.168.100.25
a=ssrc:1899222590 cname:Arc69XLAVw6T6ERS
a=ssrc:1899222590 msid:6CaVFRUPB7UF7JI8VatPX7UzleNKv8qr a0
a=ssrc:1899222590 mslabel:6CaVFRUPB7UF7JI8VatPX7UzleNKv8qr
a=ssrc:1899222590 label:6CaVFRUPB7UF7JI8VatPX7UzleNKv8qra0
a=ice-ufrag:Ebys8jRjnvUJta0U
a=ice-pwd:s3QrRsSDPOmMi4uN5T632Ndf
a=candidate:3101577738 1 udp 659136 192.168.100.25 22864 typ host generation 0

2015-04-15 14:43:42.548414 [DEBUG] switch_core_session.c:912 Send signal sofia/internal/2*1010@192.168.100.25:5060 [BREAK]
send 1816 bytes to ws/[192.168.100.100]:56423 at 14:43:42.565359:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/WS df7jal23ls0d.invalid;branch=z9hG4bK8Xq2P91cUocdokwWkenO58cRpC4RBlTg;rport=56423;received=192.168.100.100
From: "2*1010"<sip:2*1010@192.168.100.25:5060>;tag=4fyvoq30Xvq5HQamaPC9
To: <sip:555@192.168.100.25>;tag=HZe33X8KpvDpp
Call-ID: c0887f86-6084-e40e-14c2-df3f3272523f
CSeq: 63456 INVITE
Contact: <sip:555@192.168.100.25:5060;transport=udp>
User-Agent: WS Client(Based on FreeSWITCH PBX)
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
Session-Expires: 120;refresher=uas
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 833
Remote-Party-ID: "555" <sip:555@192.168.100.25>;party=calling;privacy=off;screen=no

v=0
o=FreeSWITCH 1429064558 1429064559 IN IP4 192.168.100.25
s=FreeSWITCH
c=IN IP4 192.168.100.25
t=0 0
a=msid-semantic: WMS 6CaVFRUPB7UF7JI8VatPX7UzleNKv8qr
m=audio 22864 UDP/TLS/RTP/SAVPF 0 126 106
a=rtpmap:0 PCMU/8000
a=rtpmap:126 telephone-event/8000
a=rtpmap:106 CN/8000
a=ptime:20
a=fingerprint:sha-256 DA:BD:5D:C8:CC:7A:1B:19:92:8A:90:58:8B:CD:C9:CF:EF:0A:EB:7A:2F:9C:E7:6C:9D:E2:70:BE:07:B4:C2:AF
a=rtcp-mux
a=rtcp:22864 IN IP4 192.168.100.25
a=ssrc:1899222590 cname:Arc69XLAVw6T6ERS
a=ssrc:1899222590 msid:6CaVFRUPB7UF7JI8VatPX7UzleNKv8qr a0
a=ssrc:1899222590 mslabel:6CaVFRUPB7UF7JI8VatPX7UzleNKv8qr
a=ssrc:1899222590 label:6CaVFRUPB7UF7JI8VatPX7UzleNKv8qra0
a=ice-ufrag:Ebys8jRjnvUJta0U
a=ice-pwd:s3QrRsSDPOmMi4uN5T632Ndf
a=candidate:3101577738 1 udp 659136 192.168.100.25 22864 typ host generation 0
------------------------------------------------------------------------
2015-04-15 14:43:42.548414 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/2*1010@192.168.100.25:5060 [BREAK]
2015-04-15 14:43:42.548414 [NOTICE] mod_dptools.c:1268 Channel [sofia/internal/2*1010@192.168.100.25:5060] has been answered
2015-04-15 14:43:42.548414 [DEBUG] switch_channel.c:3689 (sofia/internal/2*1010@192.168.100.25:5060) Callstate Change EARLY -> ACTIVE
2015-04-15 14:43:42.548414 [DEBUG] sofia.c:6623 Channel sofia/internal/2*1010@192.168.100.25:5060 entering state [completed][200]
2015-04-15 14:43:42.548414 [DEBUG] switch_core_session.c:2823 EXECUTE sofia/internal/2*1010@192.168.100.25:5060 delay_echo(5000)
2015-04-15 14:43:42.548414 [DEBUG] switch_ivr.c:2957 Setting delay to 5000ms (250 frames)
recv 854 bytes from ws/[192.168.100.100]:56423 at 14:43:42.575513:
------------------------------------------------------------------------
ACK sip:555@192.168.100.25:5060;transport=udp SIP/2.0
Via: SIP/2.0/WS df7jal23ls0d.invalid;branch=z9hG4bKMFIUZqzni9fpml1p1Ttw;rport
From: "2*1010"<sip:2*1010@192.168.100.25:5060>;tag=4fyvoq30Xvq5HQamaPC9
To: <sip:555@192.168.100.25>;tag=HZe33X8KpvDpp
Contact: "2*1010"<sip:2*1010@df7jal23ls0d.invalid;rtcweb-breaker=yes;click2call=no;transport=ws>;+g.oma.sip-im;language="en,fr"
Call-ID: c0887f86-6084-e40e-14c2-df3f3272523f
CSeq: 63456 ACK
Content-Length: 0
Max-Forwards: 70
Proxy-Authorization: Digest username="2*1010",realm="192.168.100.25",nonce="12cea1ae-1c4e-4523-9644-bd1df7f8e5b5",uri="sip:555@192.168.100.25:5060;transport=udp",response="36de4fbbf90fcd885dff2801200c34db",algorithm=MD5,cnonce="67ef04408a5a82e9bcfd336a5d2f58ef",qop=auth,nc=00000002
User-Agent: IM-client/OMA1.0 sipML5-v1.2014.12.11
Organization: Doubango Telecom

------------------------------------------------------------------------
2015-04-15 14:43:42.568268 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/2*1010@192.168.100.25:5060 [BREAK]
2015-04-15 14:43:42.568268 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/2*1010@192.168.100.25:5060 [BREAK]
2015-04-15 14:43:42.568268 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/2*1010@192.168.100.25:5060 [BREAK]
2015-04-15 14:43:42.568268 [DEBUG] sofia.c:6623 Channel sofia/internal/2*1010@192.168.100.25:5060 entering state [ready][200]
2015-04-15 14:43:42.588282 [NOTICE] switch_rtp.c:1151 Auto Changing stun/rtp/dtls port from 2001:0:5ef5:79fd:280b:3592:3f57:9b9b:57039 to 192.168.100.100:57040
2015-04-15 14:43:42.588282 [ERR] switch_rtp.c:2976 audio DTLS packet not written
2015-04-15 14:43:42.608344 [DEBUG] switch_rtp.c:1370 [ zrtp utils]: Send <HELLO> ssrc=1899339974 seq=34772 size=144. Stream 13:CLEAR:START
2015-04-15 14:43:42.708519 [DEBUG] switch_rtp.c:1370 [ zrtp utils]: Send <HELLO> ssrc=1899339974 seq=34773 size=144. Stream 13:CLEAR:START
2015-04-15 14:43:42.928433 [DEBUG] switch_rtp.c:1370 [ zrtp utils]: Send <HELLO> ssrc=1899339974 seq=34774 size=144. Stream 13:CLEAR:START
2015-04-15 14:43:43.129343 [DEBUG] switch_rtp.c:1370 [ zrtp utils]: Send <HELLO> ssrc=1899339974 seq=34775 size=144. Stream 13:CLEAR:START
2015-04-15 14:43:43.330069 [DEBUG] switch_rtp.c:1370 [ zrtp engine]: WARNING! HELLO have been resent 5 times without a response. Raising ZRTP_EVENT_NO_ZRTP_QUICK event. ID=13
2015-04-15 14:43:43.330069 [DEBUG] switch_rtp.c:1370 [ zrtp utils]: Send <HELLO> ssrc=1899339974 seq=34776 size=144. Stream 13:CLEAR:START
2015-04-15 14:43:43.529637 [DEBUG] switch_rtp.c:1370 [ zrtp utils]: Send <HELLO> ssrc=1899339974 seq=34777 size=144. Stream 13:CLEAR:START
2015-04-15 14:43:43.589579 [ERR] switch_rtp.c:2976 audio DTLS packet not written
2015-04-15 14:43:43.728425 [DEBUG] switch_rtp.c:1370 [ zrtp utils]: Send <HELLO> ssrc=1899339974 seq=34778 size=144. Stream 13:CLEAR:START
2015-04-15 14:43:43.948461 [DEBUG] switch_rtp.c:1370 [ zrtp utils]: Send <HELLO> ssrc=1899339974 seq=34779 size=144. Stream 13:CLEAR:START
2015-04-15 14:43:44.148490 [DEBUG] switch_rtp.c:1370 [ zrtp utils]: Send <HELLO> ssrc=1899339974 seq=34780 size=144. Stream 13:CLEAR:START
2015-04-15 14:43:44.348480 [DEBUG] switch_rtp.c:1370 [ zrtp utils]: Send <HELLO> ssrc=1899339974 seq=34781 size=144. Stream 13:CLEAR:START
2015-04-15 14:43:44.548385 [DEBUG] switch_rtp.c:1370 [ zrtp utils]: Send <HELLO> ssrc=1899339974 seq=34782 size=144. Stream 13:CLEAR:START
2015-04-15 14:43:44.734610 [DEBUG] switch_rtp.c:1370 [ zrtp utils]: Send <HELLO> ssrc=1899339974 seq=34783 size=144. Stream 13:CLEAR:START
2015-04-15 14:43:44.968455 [DEBUG] switch_rtp.c:1370 [ zrtp utils]: Send <HELLO> ssrc=1899339974 seq=34784 size=144. Stream 13:CLEAR:START
2015-04-15 14:43:45.168588 [DEBUG] switch_rtp.c:1370 [ zrtp utils]: Send <HELLO> ssrc=1899339974 seq=34785 size=144. Stream 13:CLEAR:START
2015-04-15 14:43:45.370353 [DEBUG] switch_rtp.c:1370 [ zrtp utils]: Send <HELLO> ssrc=1899339974 seq=34786 size=144. Stream 13:CLEAR:START
2015-04-15 14:43:45.568317 [DEBUG] switch_rtp.c:1370 [ zrtp utils]: Send <HELLO> ssrc=1899339974 seq=34787 size=144. Stream 13:CLEAR:START
2015-04-15 14:43:45.588474 [ERR] switch_rtp.c:2976 audio DTLS packet not written
2015-04-15 14:43:45.770149 [DEBUG] switch_rtp.c:1370 [ zrtp utils]: Send <HELLO> ssrc=1899339974 seq=34788 size=144. Stream 13:CLEAR:START
2015-04-15 14:43:45.988487 [DEBUG] switch_rtp.c:1370 [ zrtp utils]: Send <HELLO> ssrc=1899339974 seq=34789 size=144. Stream 13:CLEAR:START
2015-04-15 14:43:46.191132 [DEBUG] switch_rtp.c:1370 [ zrtp utils]: Send <HELLO> ssrc=1899339974 seq=34790 size=144. Stream 13:CLEAR:START
2015-04-15 14:43:46.388491 [DEBUG] switch_rtp.c:1370 [ zrtp engine]: WARNING! HELLO Max retransmissions count reached (20 retries). ID=13
2015-04-15 14:43:46.388491 [DEBUG] switch_rtp.c:1370 [ zrtp]: Stream ID=13 CLEAR switching <START> ---> <NOZRTP>.

2015-04-15 14:43:49.574626 [ERR] switch_rtp.c:2976 audio DTLS packet not written
recv 806 bytes from ws/[192.168.100.100]:56423 at 14:43:49.759266:
------------------------------------------------------------------------
BYE sip:555@192.168.100.25:5060;transport=udp SIP/2.0
Via: SIP/2.0/WS df7jal23ls0d.invalid;branch=z9hG4bKBzEb4wC4Rpb5QPS9POBiCQHDeoeazdfw;rport
From: "2*1010"<sip:2*1010@192.168.100.25:5060>;tag=4fyvoq30Xvq5HQamaPC9
To: <sip:555@192.168.100.25>;tag=HZe33X8KpvDpp
Call-ID: c0887f86-6084-e40e-14c2-df3f3272523f
CSeq: 63457 BYE
Content-Length: 0
Max-Forwards: 70
Accept-Contact: *;+g.oma.sip-im
Accept-Contact: *;language="en,fr"
Proxy-Authorization: Digest username="2*1010",realm="192.168.100.25",nonce="12cea1ae-1c4e-4523-9644-bd1df7f8e5b5",uri="sip:555@192.168.100.25:5060;transport=udp",response="9aa907f7b44f682d20f98668a5aabbca",algorithm=MD5,cnonce="67ef04408a5a82e9bcfd336a5d2f58ef",qop=auth,nc=00000003
User-Agent: IM-client/OMA1.0 sipML5-v1.2014.12.11
Organization: Doubango Telecom

------------------------------------------------------------------------
2015-04-15 14:43:49.748429 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/2*1010@192.168.100.25:5060 [BREAK]
2015-04-15 14:43:49.748429 [NOTICE] sofia.c:952 Hangup sofia/internal/2*1010@192.168.100.25:5060 [CS_EXECUTE] [NORMAL_CLEARING]
2015-04-15 14:43:49.748429 [DEBUG] switch_channel.c:3222 Send signal sofia/internal/2*1010@192.168.100.25:5060 [KILL]
2015-04-15 14:43:49.748429 [DEBUG] switch_core_session.c:1396 Send signal sofia/internal/2*1010@192.168.100.25:5060 [BREAK]
send 546 bytes to ws/[192.168.100.100]:56423 at 14:43:49.766339:
------------------------------------------------------------------------
SIP/2.0 200 OK
Via: SIP/2.0/WS df7jal23ls0d.invalid;branch=z9hG4bKBzEb4wC4Rpb5QPS9POBiCQHDeoeazdfw;rport=56423;received=192.168.100.100
From: "2*1010"<sip:2*1010@192.168.100.25:5060>;tag=4fyvoq30Xvq5HQamaPC9
To: <sip:555@192.168.100.25>;tag=HZe33X8KpvDpp
Call-ID: c0887f86-6084-e40e-14c2-df3f3272523f
CSeq: 63457 BYE
User-Agent: WS Client(Based on FreeSWITCH PBX)
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
Supported: timer, path, replaces
Content-Length: 0

------------------------------------------------------------------------
2015-04-15 14:43:49.771985 [DEBUG] switch_core_session.c:2901 sofia/internal/2*1010@192.168.100.25:5060 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2015-04-15 14:43:49.771985 [DEBUG] switch_core_state_machine.c:535 (sofia/internal/2*1010@192.168.100.25:5060) State EXECUTE going to sleep
2015-04-15 14:43:49.771985 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/2*1010@192.168.100.25:5060) Running State Change CS_HANGUP
2015-04-15 14:43:49.771985 [DEBUG] switch_core_state_machine.c:735 (sofia/internal/2*1010@192.168.100.25:5060) Callstate Change ACTIVE -> HANGUP
2015-04-15 14:43:49.771985 [DEBUG] switch_core_state_machine.c:737 (sofia/internal/2*1010@192.168.100.25:5060) State HANGUP
2015-04-15 14:43:49.771985 [DEBUG] mod_sofia.c:413 Channel sofia/internal/2*1010@192.168.100.25:5060 hanging up, cause: NORMAL_CLEARING
2015-04-15 14:43:49.771985 [DEBUG] switch_core_state_machine.c:60 sofia/internal/2*1010@192.168.100.25:5060 Standard HANGUP, cause: NORMAL_CLEARING
2015-04-15 14:43:49.771985 [DEBUG] switch_core_state_machine.c:737 (sofia/internal/2*1010@192.168.100.25:5060) State HANGUP going to sleep
2015-04-15 14:43:49.771985 [DEBUG] switch_core_state_machine.c:504 (sofia/internal/2*1010@192.168.100.25:5060) State Change CS_HANGUP -> CS_REPORTING
2015-04-15 14:43:49.771985 [DEBUG] switch_core_session.c:1396 Send signal sofia/internal/2*1010@192.168.100.25:5060 [BREAK]
2015-04-15 14:43:49.771985 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/2*1010@192.168.100.25:5060) Running State Change CS_REPORTING
2015-04-15 14:43:49.771985 [DEBUG] switch_core_state_machine.c:823 (sofia/internal/2*1010@192.168.100.25:5060) State REPORTING
2015-04-15 14:43:49.771985 [DEBUG] switch_core_state_machine.c:104 sofia/internal/2*1010@192.168.100.25:5060 Standard REPORTING, cause: NORMAL_CLEARING
2015-04-15 14:43:49.771985 [DEBUG] switch_core_state_machine.c:823 (sofia/internal/2*1010@192.168.100.25:5060) State REPORTING going to sleep
2015-04-15 14:43:49.771985 [DEBUG] switch_core_state_machine.c:498 (sofia/internal/2*1010@192.168.100.25:5060) State Change CS_REPORTING -> CS_DESTROY
2015-04-15 14:43:49.771985 [DEBUG] switch_core_session.c:1396 Send signal sofia/internal/2*1010@192.168.100.25:5060 [BREAK]
2015-04-15 14:43:49.771985 [DEBUG] switch_core_session.c:1623 Session 14 (sofia/internal/2*1010@192.168.100.25:5060) Locked, Waiting on external entities
2015-04-15 14:43:49.771985 [NOTICE] switch_core_session.c:1641 Session 14 (sofia/internal/2*1010@192.168.100.25:5060) Ended
2015-04-15 14:43:49.771985 [NOTICE] switch_core_session.c:1645 Close Channel sofia/internal/2*1010@192.168.100.25:5060 [CS_DESTROY]
2015-04-15 14:43:49.771985 [DEBUG] switch_core_state_machine.c:626 (sofia/internal/2*1010@192.168.100.25:5060) Running State Change CS_DESTROY
2015-04-15 14:43:49.771985 [DEBUG] switch_core_state_machine.c:636 (sofia/internal/2*1010@192.168.100.25:5060) State DESTROY
2015-04-15 14:43:49.771985 [DEBUG] mod_sofia.c:323 sofia/internal/2*1010@192.168.100.25:5060 SOFIA DESTROY
2015-04-15 14:43:49.771985 [DEBUG] switch_rtp.c:1370 [ zrtp engine]: STOP STREAM ID=13 mode=CLEAR state=NOZRTP.
2015-04-15 14:43:49.771985 [DEBUG] switch_rtp.c:1370 [ zrtp]: Stream ID=0 UNKNOWN switching <NONE> ---> <NONE>.
2015-04-15 14:43:49.771985 [DEBUG] switch_rtp.c:1370 [ zrtp engine]: STOP STREAM ID=0 mode=UNKNOWN state=NONE.
2015-04-15 14:43:49.771985 [DEBUG] switch_rtp.c:1370 [ zrtp engine]: STOP STREAM ID=0 mode=UNKNOWN state=NONE.
2015-04-15 14:43:49.771985 [DEBUG] switch_core_state_machine.c:111 sofia/internal/2*1010@192.168.100.25:5060 Standard DESTROY
2015-04-15 14:43:49.771985 [DEBUG] switch_core_state_machine.c:636 (sofia/internal/2*1010@192.168.100.25:5060) State DESTROY going to sleep


Пробовал:
1) менять кодеки(по дефолту у меня на ws стоит opus)
2) смотреть tcpdump-ом что и куда уходит с FS. По факту, все тоже самое что и в консоли.
3) Смотрел консоль хрома и chrome://webrtc-internals/

Причем по графикам видно что хром микрофон видит и реагирует на него.
По дампу видно только один повторяющийся udp пакет в сторону FS, и FS видимо на него отвечает.
[+] Кусочек tcpdump
15:03:19.268865 IP 192.168.100.100.63041 > 192.168.100.25.27398: UDP, length 116
E...&.........dd..d..Ak..|.6...`!..B1Y8ECN/1uTGr...!5nXKEuKNqNv6euH0:UD+3r25SkBOdWtOz....*...V..&a...%...$..n~............}3.5[.......^..(...q..
15:03:19.284830 IP 192.168.100.25.27398 > 192.168.100.100.63041: UDP, length 64
E..\,[@.@..g..d...ddk..A.HJ(...,!..B1Y8ECN/1uTGr. .....S...&....$..#...h..........s .(..{=.7

Трафик по графику полученных пакетов имеет периодический вид, явно указывающий на повторение переданной-принятой информации. googRTT периодический и без всплесков.
А вот packetsSentPerSecond наоборот пустой.


Так же пробовал звонок из Firefox, но на нем я не знаю диагностического функционала, да это уже и не важно. Там ведь тоже голоса не было.

Самое досадное, что оно работало. Но вот после какого момента перестало работать - не пойму. Не вспомню. Все больше тестировал диалплан из обычного клиента.
Накатил ванильные конфиги - и вот оно чудо. Тоже не работает.
Вот сейчас и не пойму, то ли лыжи не едут, то ли я ....

В общем у меня уже мыслей нет, поэтому обращаюсь к вам за помощью.

_________________
Если бы я был админом одной организации, я бы сделал все по другому.....
Вернуться к началу
 Профиль  
 
Vlad1983
СообщениеДобавлено: 15 апр 2015 13:37 
FreeSWITCH_GuRu

Зарегистрирован: 22 авг 2012 09:52
Сообщения: 1710
Код:
c=IN IP4 217.25.223.94
a=rtcp:57040 IN IP4 217.25.223.94

_________________
ЛС: @rostel
Сообщество: @ru_freeswitch
Вернуться к началу
 Профиль  
 
astashov
СообщениеДобавлено: 15 апр 2015 14:00 

Зарегистрирован: 24 дек 2014 10:40
Сообщения: 85
Прошу прощения. Виноват. :oops:
В пылу эксперементов отключал опцию "не использовать stun", вот и вылез.
Но картину это не меняет:
[+] Консоль FS с отключенным ice/stun на клиенте
2015-04-15 05:49:37.685124 [NOTICE] switch_channel.c:1055 New Channel sofia/internal/1000@192.168.100.20:5060 [b9555f22-07d2-4fe2-9cb9-2ba2377f61e0]
2015-04-15 05:49:37.685124 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/1000@192.168.100.20:5060 [BREAK]
2015-04-15 05:49:37.685124 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/1000@192.168.100.20:5060 [BREAK]
2015-04-15 05:49:37.685124 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/1000@192.168.100.20:5060) Running State Change CS_NEW
2015-04-15 05:49:37.685124 [DEBUG] sofia.c:8844 sofia/internal/1000@192.168.100.20:5060 receiving invite from 192.168.100.100:52485 version: 1.4.18 -1 64bit
2015-04-15 05:49:37.685124 [DEBUG] sofia.c:9011 IP 192.168.100.100 Rejected by acl "domains". Falling back to Digest auth.
2015-04-15 05:49:37.685124 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/1000@192.168.100.20:5060 [BREAK]
2015-04-15 05:49:37.685124 [DEBUG] sofia.c:2065 detaching session b9555f22-07d2-4fe2-9cb9-2ba2377f61e0
2015-04-15 05:49:37.685124 [DEBUG] switch_core_state_machine.c:491 (sofia/internal/1000@192.168.100.20:5060) State NEW
2015-04-15 05:49:37.705587 [DEBUG] sofia.c:2173 Re-attaching to session b9555f22-07d2-4fe2-9cb9-2ba2377f61e0
2015-04-15 05:49:37.705587 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/1000@192.168.100.20:5060 [BREAK]
2015-04-15 05:49:37.705587 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/1000@192.168.100.20:5060 [BREAK]
2015-04-15 05:49:37.705587 [DEBUG] sofia.c:8844 sofia/internal/1000@192.168.100.20:5060 receiving invite from 192.168.100.100:52485 version: 1.4.18 -1 64bit
2015-04-15 05:49:37.705587 [DEBUG] sofia.c:9011 IP 192.168.100.100 Rejected by acl "domains". Falling back to Digest auth.
2015-04-15 05:49:37.705587 [DEBUG] sofia.c:10109 Setting NAT mode based on websockets
2015-04-15 05:49:37.705587 [DEBUG] sofia.c:6623 Channel sofia/internal/1000@192.168.100.20:5060 entering state [received][100]
2015-04-15 05:49:37.705587 [DEBUG] sofia.c:6633 Remote SDP:
v=0
o=- 8708667471225166000 2 IN IP4 127.0.0.1
s=Doubango Telecom - chrome
t=0 0
a=group:BUNDLE audio
a=msid-semantic: WMS 5hk8dRj4ArLC1YaxmcdBRlBNrG8O2VLB8GiM
m=audio 58102 UDP/TLS/RTP/SAVPF 111 103 104 9 0 8 106 105 13 126
c=IN IP6 2001::5ef5:79fd:280b:3592:3f57:9b9b
a=rtpmap:111 opus/48000/2
a=fmtp:111 minptime=10; useinbandfec=1
a=rtpmap:103 ISAC/16000
a=rtpmap:104 ISAC/32000
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:106 CN/32000
a=rtpmap:105 CN/16000
a=rtpmap:13 CN/8000
a=rtpmap:126 telephone-event/8000
a=rtcp:58102 IN IP6 2001::5ef5:79fd:280b:3592:3f57:9b9b
a=candidate:398667111 1 udp 2122255103 2001::5ef5:79fd:280b:3592:3f57:9b9b 58102 typ host generation 0
a=candidate:398667111 2 udp 2122255103 2001::5ef5:79fd:280b:3592:3f57:9b9b 58102 typ host generation 0
a=candidate:2626306135 1 udp 2122194687 192.168.100.100 58103 typ host generation 0
a=candidate:2626306135 2 udp 2122194687 192.168.100.100 58103 typ host generation 0
a=candidate:1497420183 1 tcp 1518275327 2001::5ef5:79fd:280b:3592:3f57:9b9b 0 typ host tcptype active generation 0
a=candidate:1497420183 2 tcp 1518275327 2001::5ef5:79fd:280b:3592:3f57:9b9b 0 typ host tcptype active generation 0
a=candidate:3523853479 1 tcp 1518214911 192.168.100.100 0 typ host tcptype active generation 0
a=candidate:3523853479 2 tcp 1518214911 192.168.100.100 0 typ host tcptype active generation 0
a=ice-ufrag:DvJULAPDjlBcqnO2
a=ice-pwd:nP9AwpkSWMx1COqltC3XSeuU
a=ice-options:google-ice
a=fingerprint:sha-256 41:B3:08:08:0F:0C:3C:34:E5:95:02:66:FB:6E:10:FA:A6:67:91:10:3F:A2:3F:D6:82:36:0B:E5:A0:09:DF:84
a=setup:actpass
a=mid:audio
a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level
a=extmap:3 http://www.webrtc.org/experiments/rtp-h ... -send-time
a=rtcp-mux
a=maxptime:60
a=ssrc:1524954340 cname:3jN3+t7MQ6jQOapi
a=ssrc:1524954340 msid:5hk8dRj4ArLC1YaxmcdBRlBNrG8O2VLB8GiM 5ef8fe3c-41f9-4993-9dd1-8c3f9b603e05
a=ssrc:1524954340 mslabel:5hk8dRj4ArLC1YaxmcdBRlBNrG8O2VLB8GiM
a=ssrc:1524954340 label:5ef8fe3c-41f9-4993-9dd1-8c3f9b603e05

2015-04-15 05:49:37.705587 [DEBUG] sofia.c:6899 (sofia/internal/1000@192.168.100.20:5060) State Change CS_NEW -> CS_INIT
2015-04-15 05:49:37.705587 [DEBUG] switch_core_session.c:1396 Send signal sofia/internal/1000@192.168.100.20:5060 [BREAK]
2015-04-15 05:49:37.705587 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/1000@192.168.100.20:5060) Running State Change CS_INIT
2015-04-15 05:49:37.705587 [DEBUG] switch_core_state_machine.c:512 (sofia/internal/1000@192.168.100.20:5060) State INIT
2015-04-15 05:49:37.705587 [DEBUG] mod_sofia.c:87 sofia/internal/1000@192.168.100.20:5060 SOFIA INIT
2015-04-15 05:49:37.705587 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1000@192.168.100.20:5060 Standard INIT
2015-04-15 05:49:37.705587 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1000@192.168.100.20:5060) State Change CS_INIT -> CS_ROUTING
2015-04-15 05:49:37.705587 [DEBUG] switch_core_session.c:1396 Send signal sofia/internal/1000@192.168.100.20:5060 [BREAK]
2015-04-15 05:49:37.705587 [DEBUG] switch_core_state_machine.c:512 (sofia/internal/1000@192.168.100.20:5060) State INIT going to sleep
2015-04-15 05:49:37.705587 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/1000@192.168.100.20:5060) Running State Change CS_ROUTING
2015-04-15 05:49:37.705587 [DEBUG] switch_channel.c:2184 (sofia/internal/1000@192.168.100.20:5060) Callstate Change DOWN -> RINGING
2015-04-15 05:49:37.705587 [DEBUG] switch_core_state_machine.c:528 (sofia/internal/1000@192.168.100.20:5060) State ROUTING
2015-04-15 05:49:37.705587 [DEBUG] mod_sofia.c:123 sofia/internal/1000@192.168.100.20:5060 SOFIA ROUTING
2015-04-15 05:49:37.705587 [DEBUG] switch_core_state_machine.c:166 sofia/internal/1000@192.168.100.20:5060 Standard ROUTING
2015-04-15 05:49:37.705587 [INFO] mod_dialplan_xml.c:635 Processing 1000 <1000>->555 in context default
Dialplan: sofia/internal/1000@192.168.100.20:5060 parsing [default->unloop] continue=false
Dialplan: sofia/internal/1000@192.168.100.20:5060 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/internal/1000@192.168.100.20:5060 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/internal/1000@192.168.100.20:5060 parsing [default->delay_echo] continue=false
Dialplan: sofia/internal/1000@192.168.100.20:5060 Regex (PASS) [delay_echo] destination_number(555) =~ /^555$/ break=on-false
Dialplan: sofia/internal/1000@192.168.100.20:5060 Action answer()
Dialplan: sofia/internal/1000@192.168.100.20:5060 Action delay_echo(5000)
2015-04-15 05:49:37.725806 [DEBUG] switch_core_state_machine.c:216 (sofia/internal/1000@192.168.100.20:5060) State Change CS_ROUTING -> CS_EXECUTE
2015-04-15 05:49:37.725806 [DEBUG] switch_core_session.c:1396 Send signal sofia/internal/1000@192.168.100.20:5060 [BREAK]
2015-04-15 05:49:37.725806 [DEBUG] switch_core_state_machine.c:528 (sofia/internal/1000@192.168.100.20:5060) State ROUTING going to sleep
2015-04-15 05:49:37.725806 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/1000@192.168.100.20:5060) Running State Change CS_EXECUTE
2015-04-15 05:49:37.725806 [DEBUG] switch_core_state_machine.c:535 (sofia/internal/1000@192.168.100.20:5060) State EXECUTE
2015-04-15 05:49:37.725806 [DEBUG] mod_sofia.c:178 sofia/internal/1000@192.168.100.20:5060 SOFIA EXECUTE
2015-04-15 05:49:37.725806 [DEBUG] switch_core_state_machine.c:258 sofia/internal/1000@192.168.100.20:5060 Standard EXECUTE
EXECUTE sofia/internal/1000@192.168.100.20:5060 answer()
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [opus:111:48000:60:0:1]/[opus:116:48000:20:0:1]
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:3687 Audio Codec Compare [opus:116:48000:20:0:1] ++++ is saved as a match
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [opus:111:48000:60:0:1]/[G722:9:8000:20:64000:1]
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [opus:111:48000:60:0:1]/[PCMU:0:8000:20:64000:1]
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [opus:111:48000:60:0:1]/[PCMA:8:8000:20:64000:1]
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [opus:111:48000:60:0:1]/[GSM:3:8000:20:13200:1]
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [ISAC:103:16000:30:32000:1]/[opus:116:48000:20:0:1]
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [ISAC:103:16000:30:32000:1]/[G722:9:8000:20:64000:1]
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [ISAC:103:16000:30:32000:1]/[PCMU:0:8000:20:64000:1]
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [ISAC:103:16000:30:32000:1]/[PCMA:8:8000:20:64000:1]
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [ISAC:103:16000:30:32000:1]/[GSM:3:8000:20:13200:1]
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [ISAC:104:32000:30:32000:1]/[opus:116:48000:20:0:1]
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [ISAC:104:32000:30:32000:1]/[G722:9:8000:20:64000:1]
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [ISAC:104:32000:30:32000:1]/[PCMU:0:8000:20:64000:1]
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [ISAC:104:32000:30:32000:1]/[PCMA:8:8000:20:64000:1]
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [ISAC:104:32000:30:32000:1]/[GSM:3:8000:20:13200:1]
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [G722:9:8000:60:64000:1]/[opus:116:48000:20:0:1]
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [G722:9:8000:60:64000:1]/[G722:9:8000:20:64000:1]
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:3687 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [G722:9:8000:60:64000:1]/[PCMU:0:8000:20:64000:1]
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [G722:9:8000:60:64000:1]/[PCMA:8:8000:20:64000:1]
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [G722:9:8000:60:64000:1]/[GSM:3:8000:20:13200:1]
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [PCMU:0:8000:60:64000:1]/[opus:116:48000:20:0:1]
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [PCMU:0:8000:60:64000:1]/[G722:9:8000:20:64000:1]
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [PCMU:0:8000:60:64000:1]/[PCMU:0:8000:20:64000:1]
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:3687 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [PCMU:0:8000:60:64000:1]/[PCMA:8:8000:20:64000:1]
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [PCMU:0:8000:60:64000:1]/[GSM:3:8000:20:13200:1]
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [PCMA:8:8000:60:64000:1]/[opus:116:48000:20:0:1]
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [PCMA:8:8000:60:64000:1]/[G722:9:8000:20:64000:1]
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [PCMA:8:8000:60:64000:1]/[PCMU:0:8000:20:64000:1]
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [PCMA:8:8000:60:64000:1]/[PCMA:8:8000:20:64000:1]
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:3687 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [PCMA:8:8000:60:64000:1]/[GSM:3:8000:20:13200:1]
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [CN:105:16000:60:0:1]/[opus:116:48000:20:0:1]
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [CN:105:16000:60:0:1]/[G722:9:8000:20:64000:1]
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [CN:105:16000:60:0:1]/[PCMU:0:8000:20:64000:1]
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [CN:105:16000:60:0:1]/[PCMA:8:8000:20:64000:1]
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [CN:105:16000:60:0:1]/[GSM:3:8000:20:13200:1]
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [CN:13:8000:60:0:1]/[opus:116:48000:20:0:1]
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [CN:13:8000:60:0:1]/[G722:9:8000:20:64000:1]
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [CN:13:8000:60:0:1]/[PCMU:0:8000:20:64000:1]
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [CN:13:8000:60:0:1]/[PCMA:8:8000:20:64000:1]
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:3632 Audio Codec Compare [CN:13:8000:60:0:1]/[GSM:3:8000:20:13200:1]
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:3548 Set telephone-event payload to 126
2015-04-15 05:49:37.725806 [DEBUG] mod_opus.c:287 Opus encoder set bitrate to local settings [-1000bps]
2015-04-15 05:49:37.725806 [DEBUG] mod_opus.c:287 Opus encoder set bitrate to local settings [-1000bps]
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:2473 Set Codec sofia/internal/1000@192.168.100.20:5060 opus/48000 20 ms 960 samples 0 bits 1 channels
2015-04-15 05:49:37.725806 [DEBUG] switch_core_codec.c:111 sofia/internal/1000@192.168.100.20:5060 Original read codec set to opus:116
2015-04-15 05:49:37.725806 [WARNING] switch_core_media.c:2757 NO candidate ACL defined, Defaulting to wan.auto
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:2781 Checking Candidate cid: 1 proto: udp type: host addr: 2001::5ef5:79fd:280b:3592:3f57:9b9b:58102
2015-04-15 05:49:37.725806 [NOTICE] switch_core_media.c:2790 Choose audio Candidate cid: 1 proto: udp type: host addr: 2001::5ef5:79fd:280b:3592:3f57:9b9b:58102
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:2781 Checking Candidate cid: 2 proto: udp type: host addr: 2001::5ef5:79fd:280b:3592:3f57:9b9b:58102
2015-04-15 05:49:37.725806 [NOTICE] switch_core_media.c:2790 Choose audio Candidate cid: 2 proto: udp type: host addr: 2001::5ef5:79fd:280b:3592:3f57:9b9b:58102
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:2781 Checking Candidate cid: 1 proto: udp type: host addr: 192.168.100.100:58103
2015-04-15 05:49:37.725806 [NOTICE] switch_core_media.c:2795 Save audio Candidate cid: 1 proto: udp type: host addr: 192.168.100.100:58103
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:2781 Checking Candidate cid: 2 proto: udp type: host addr: 192.168.100.100:58103
2015-04-15 05:49:37.725806 [NOTICE] switch_core_media.c:2795 Save audio Candidate cid: 2 proto: udp type: host addr: 192.168.100.100:58103
2015-04-15 05:49:37.725806 [ERR] switch_core_cert.c:210 FP FILE ERR!
2015-04-15 05:49:37.725806 [NOTICE] switch_core_media.c:2919 setting remote audio ice addr to 2001::5ef5:79fd:280b:3592:3f57:9b9b:58102 based on candidate
2015-04-15 05:49:37.725806 [NOTICE] switch_core_media.c:2944 setting remote rtcp audio addr to 2001::5ef5:79fd:280b:3592:3f57:9b9b:58102 based on candidate
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:3895 Set 2833 dtmf send/recv payload to 126
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:5147 AUDIO RTP [sofia/internal/1000@192.168.100.20:5060] 192.168.100.20 port 24944 -> 2001::5ef5:79fd:280b:3592:3f57:9b9b port 58102 codec: 111 ms: 20
2015-04-15 05:49:37.725806 [DEBUG] switch_rtp.c:3562 Starting timer [soft] 960 bytes per 20ms
2015-04-15 05:49:37.725806 [DEBUG] switch_rtp.c:1370 [ zrtp main]: START SESSION INITIALIZATION. sID=15.
2015-04-15 05:49:37.725806 [DEBUG] switch_rtp.c:1370 [ zrtp main]: ZID=633061383634313464366363.
2015-04-15 05:49:37.725806 [DEBUG] switch_rtp.c:1370 [ zrtp main]: Loading User's profile:
2015-04-15 05:49:37.725806 [DEBUG] switch_rtp.c:1370 [ zrtp main]: allowclear: OFF
2015-04-15 05:49:37.725806 [DEBUG] switch_rtp.c:1370 [ zrtp main]: autosecure: ON
2015-04-15 05:49:37.725806 [DEBUG] switch_rtp.c:1370 [ zrtp main]: disclose_bit: OFF
2015-04-15 05:49:37.725806 [DEBUG] switch_rtp.c:1370 [ zrtp main]: signal. role: Unknown
2015-04-15 05:49:37.725806 [DEBUG] switch_rtp.c:1370 [ zrtp main]: TTL: 4294967295
2015-04-15 05:49:37.725806 [DEBUG] switch_rtp.c:1370 [ zrtp main]: SAS schemes:
2015-04-15 05:49:37.725806 [DEBUG] switch_rtp.c:1370 B256
2015-04-15 05:49:37.725806 [DEBUG] switch_rtp.c:1370 B32
2015-04-15 05:49:37.725806 [DEBUG] switch_rtp.c:1370
2015-04-15 05:49:37.725806 [DEBUG] switch_rtp.c:1370 [ zrtp main]: Ciphers:
2015-04-15 05:49:37.725806 [DEBUG] switch_rtp.c:1370 AES3
2015-04-15 05:49:37.725806 [DEBUG] switch_rtp.c:1370 AES1
2015-04-15 05:49:37.725806 [DEBUG] switch_rtp.c:1370
2015-04-15 05:49:37.725806 [DEBUG] switch_rtp.c:1370 [ zrtp main]: PK schemes:
2015-04-15 05:49:37.725806 [DEBUG] switch_rtp.c:1370 EC25
2015-04-15 05:49:37.725806 [DEBUG] switch_rtp.c:1370 DH3k
2015-04-15 05:49:37.725806 [DEBUG] switch_rtp.c:1370 DH2k
2015-04-15 05:49:37.725806 [DEBUG] switch_rtp.c:1370 Mult
2015-04-15 05:49:37.725806 [DEBUG] switch_rtp.c:1370
2015-04-15 05:49:37.725806 [DEBUG] switch_rtp.c:1370 [ zrtp main]: ATL:
2015-04-15 05:49:37.725806 [DEBUG] switch_rtp.c:1370 HS32
2015-04-15 05:49:37.725806 [DEBUG] switch_rtp.c:1370
2015-04-15 05:49:37.725806 [DEBUG] switch_rtp.c:1370 [ zrtp main]: Hashes:
2015-04-15 05:49:37.725806 [DEBUG] switch_rtp.c:1370 S256
2015-04-15 05:49:37.725806 [DEBUG] switch_rtp.c:1370
2015-04-15 05:49:37.725806 [DEBUG] switch_rtp.c:1370 [ zrtp main]: Session initialization - DONE. sID=15.

2015-04-15 05:49:37.725806 [DEBUG] switch_rtp.c:1370 [ zrtp main]: ATTACH NEW STREAM to sID=15:
2015-04-15 05:49:37.725806 [DEBUG] switch_rtp.c:1370 [ zrtp]: Stream ID=0 UNKNOWN switching <NONE> ---> <ACTIVE>.
2015-04-15 05:49:37.725806 [DEBUG] switch_rtp.c:1370 [ zrtp main]: Empty slot was found - initializing new stream with ID=15.
2015-04-15 05:49:37.725806 [DEBUG] switch_rtp.c:1370 [ zrtp main]: Preparing ZRTP Hello according to the Session profile.
2015-04-15 05:49:37.725806 [DEBUG] switch_rtp.c:1370 [ zrtp main]: ATTACH NEW STREAM - DONE.
2015-04-15 05:49:37.725806 [DEBUG] switch_rtp.c:1370 [ zrtp engine]: START STREAM ID=15 mode=CLEAR state=ACTIVE.
2015-04-15 05:49:37.725806 [DEBUG] switch_rtp.c:1370 [ zrtp]: Stream ID=15 CLEAR switching <ACTIVE> ---> <START>.
2015-04-15 05:49:37.725806 [DEBUG] switch_rtp.c:1370 [ zrtp utils]: Send <HELLO> ssrc=2439287545 seq=19682 size=144. Stream 15:CLEAR:START
2015-04-15 05:49:37.725806 [INFO] switch_core_media.c:5321 Activating Audio ICE
2015-04-15 05:49:37.725806 [NOTICE] switch_rtp.c:4012 Activating RTP audio ICE: DvJULAPDjlBcqnO2:9E50AUyDvF3LFQSp 2001::5ef5:79fd:280b:3592:3f57:9b9b:58102
2015-04-15 05:49:37.725806 [INFO] switch_core_media.c:5364 Activating RTCP PORT 58102
2015-04-15 05:49:37.725806 [DEBUG] switch_rtp.c:3912 RTCP send rate is: 10000 and packet rate is: 20000 Remote Port: 58102
2015-04-15 05:49:37.725806 [DEBUG] switch_rtp.c:2367 Setting RTCP remote addr to :58102
2015-04-15 05:49:37.725806 [INFO] switch_core_media.c:5372 Skipping RTCP ICE (Same as RTP)
2015-04-15 05:49:37.725806 [INFO] switch_rtp.c:3104 Activate RTP/RTCP audio DTLS client
2015-04-15 05:49:37.725806 [ERR] switch_rtp.c:3151 audio DTLS cert err [5]
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:5445 Set 2833 dtmf send payload to 126
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:5451 Set 2833 dtmf receive payload to 126
2015-04-15 05:49:37.725806 [DEBUG] switch_core_media.c:5479 Set comfort noise payload to 106
2015-04-15 05:49:37.725806 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/1000@192.168.100.20:5060!
2015-04-15 05:49:37.725806 [DEBUG] switch_channel.c:3399 (sofia/internal/1000@192.168.100.20:5060) Callstate Change RINGING -> EARLY
2015-04-15 05:49:37.725806 [DEBUG] mod_sofia.c:780 Local SDP sofia/internal/1000@192.168.100.20:5060:
v=0
o=FreeSWITCH 1429066433 1429066434 IN IP4 192.168.100.20
s=FreeSWITCH
c=IN IP4 192.168.100.20
t=0 0
a=msid-semantic: WMS 1UIwwFFGIIVqEL48ezD016ZHdKhzp9Wh
m=audio 24944 UDP/TLS/RTP/SAVPF 111 126 106
a=rtpmap:111 opus/48000/2
a=fmtp:111 useinbandfec=1; minptime=10
a=rtpmap:126 telephone-event/8000
a=rtpmap:106 CN/8000
a=ptime:20
a=sendrecv
a=fingerprint:sha-256 41:B3:08:08:0F:0C:3C:34:E5:95:02:66:FB:6E:10:FA:A6:67:91:10:3F:A2:3F:D6:82:36:0B:E5:A0:09:DF:84
a=rtcp-mux
a=rtcp:24944 IN IP4 192.168.100.20
a=ssrc:2436173905 cname:UvDg09NzHzPcaKae
a=ssrc:2436173905 msid:1UIwwFFGIIVqEL48ezD016ZHdKhzp9Wh a0
a=ssrc:2436173905 mslabel:1UIwwFFGIIVqEL48ezD016ZHdKhzp9Wh
a=ssrc:2436173905 label:1UIwwFFGIIVqEL48ezD016ZHdKhzp9Wha0
a=ice-ufrag:9E50AUyDvF3LFQSp
a=ice-pwd:bmw1l9qTy6VyGWCGqxxRiVlD
a=candidate:6139978614 1 udp 659136 192.168.100.20 24944 typ host generation 0

2015-04-15 05:49:37.725806 [DEBUG] switch_core_session.c:912 Send signal sofia/internal/1000@192.168.100.20:5060 [BREAK]
2015-04-15 05:49:37.725806 [NOTICE] mod_dptools.c:1268 Channel [sofia/internal/1000@192.168.100.20:5060] has been answered
2015-04-15 05:49:37.725806 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/1000@192.168.100.20:5060 [BREAK]
2015-04-15 05:49:37.725806 [DEBUG] switch_channel.c:3689 (sofia/internal/1000@192.168.100.20:5060) Callstate Change EARLY -> ACTIVE
2015-04-15 05:49:37.725806 [DEBUG] sofia.c:6623 Channel sofia/internal/1000@192.168.100.20:5060 entering state [completed][200]
EXECUTE sofia/internal/1000@192.168.100.20:5060 delay_echo(5000)
2015-04-15 05:49:37.725806 [DEBUG] switch_ivr.c:2957 Setting delay to 5000ms (250 frames)
2015-04-15 05:49:37.725806 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/1000@192.168.100.20:5060 [BREAK]
2015-04-15 05:49:37.725806 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/1000@192.168.100.20:5060 [BREAK]
2015-04-15 05:49:37.725806 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/1000@192.168.100.20:5060 [BREAK]
2015-04-15 05:49:37.725806 [DEBUG] sofia.c:6623 Channel sofia/internal/1000@192.168.100.20:5060 entering state [ready][200]
2015-04-15 05:49:37.784744 [NOTICE] switch_rtp.c:1151 Auto Changing stun/rtp/dtls port from 2001:0:5ef5:79fd:280b:3592:3f57:9b9b:58102 to 192.168.100.100:58103
2015-04-15 05:49:37.784744 [DEBUG] switch_rtp.c:1370 [ zrtp utils]: Send <HELLO> ssrc=2439287545 seq=19683 size=144. Stream 15:CLEAR:START
2015-04-15 05:49:37.884926 [DEBUG] switch_rtp.c:1370 [ zrtp utils]: Send <HELLO> ssrc=2439287545 seq=19684 size=144. Stream 15:CLEAR:START
2015-04-15 05:49:38.070697 [DEBUG] switch_rtp.c:1370 [ zrtp utils]: Send <HELLO> ssrc=2439287545 seq=19685 size=144. Stream 15:CLEAR:START
2015-04-15 05:49:38.268069 [DEBUG] switch_rtp.c:1370 [ zrtp utils]: Send <HELLO> ssrc=2439287545 seq=19686 size=144. Stream 15:CLEAR:START
2015-04-15 05:49:38.484925 [DEBUG] switch_rtp.c:1370 [ zrtp engine]: WARNING! HELLO have been resent 5 times without a response. Raising ZRTP_EVENT_NO_ZRTP_QUICK event. ID=15
2015-04-15 05:49:38.484925 [DEBUG] switch_rtp.c:1370 [ zrtp utils]: Send <HELLO> ssrc=2439287545 seq=19687 size=144. Stream 15:CLEAR:START
2015-04-15 05:49:38.686878 [DEBUG] switch_rtp.c:1370 [ zrtp utils]: Send <HELLO> ssrc=2439287545 seq=19688 size=144. Stream 15:CLEAR:START
2015-04-15 05:49:38.904898 [DEBUG] switch_rtp.c:1370 [ zrtp utils]: Send <HELLO> ssrc=2439287545 seq=19689 size=144. Stream 15:CLEAR:START
2015-04-15 05:49:39.104876 [DEBUG] switch_rtp.c:1370 [ zrtp utils]: Send <HELLO> ssrc=2439287545 seq=19690 size=144. Stream 15:CLEAR:START
2015-04-15 05:49:39.305559 [DEBUG] switch_rtp.c:1370 [ zrtp utils]: Send <HELLO> ssrc=2439287545 seq=19691 size=144. Stream 15:CLEAR:START
2015-04-15 05:49:39.507537 [DEBUG] switch_rtp.c:1370 [ zrtp utils]: Send <HELLO> ssrc=2439287545 seq=19692 size=144. Stream 15:CLEAR:START
2015-04-15 05:49:39.725911 [DEBUG] switch_rtp.c:1370 [ zrtp utils]: Send <HELLO> ssrc=2439287545 seq=19693 size=144. Stream 15:CLEAR:START
2015-04-15 05:49:39.909441 [DEBUG] switch_rtp.c:1370 [ zrtp utils]: Send <HELLO> ssrc=2439287545 seq=19694 size=144. Stream 15:CLEAR:START
2015-04-15 05:49:40.125226 [DEBUG] switch_rtp.c:1370 [ zrtp utils]: Send <HELLO> ssrc=2439287545 seq=19695 size=144. Stream 15:CLEAR:START
2015-04-15 05:49:40.324960 [DEBUG] switch_rtp.c:1370 [ zrtp utils]: Send <HELLO> ssrc=2439287545 seq=19696 size=144. Stream 15:CLEAR:START
2015-04-15 05:49:40.506554 [DEBUG] switch_rtp.c:1370 [ zrtp utils]: Send <HELLO> ssrc=2439287545 seq=19697 size=144. Stream 15:CLEAR:START
2015-04-15 05:49:40.744940 [DEBUG] switch_rtp.c:1370 [ zrtp utils]: Send <HELLO> ssrc=2439287545 seq=19698 size=144. Stream 15:CLEAR:START
2015-04-15 05:49:40.948121 [DEBUG] switch_rtp.c:1370 [ zrtp utils]: Send <HELLO> ssrc=2439287545 seq=19699 size=144. Stream 15:CLEAR:START
2015-04-15 05:49:41.125256 [DEBUG] switch_rtp.c:1370 [ zrtp utils]: Send <HELLO> ssrc=2439287545 seq=19700 size=144. Stream 15:CLEAR:START
2015-04-15 05:49:41.344897 [DEBUG] switch_rtp.c:1370 [ zrtp utils]: Send <HELLO> ssrc=2439287545 seq=19701 size=144. Stream 15:CLEAR:START
2015-04-15 05:49:41.544890 [DEBUG] switch_rtp.c:1370 [ zrtp engine]: WARNING! HELLO Max retransmissions count reached (20 retries). ID=15
2015-04-15 05:49:41.544890 [DEBUG] switch_rtp.c:1370 [ zrtp]: Stream ID=15 CLEAR switching <START> ---> <NOZRTP>.


2015-04-15 05:49:44.945653 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/1000@192.168.100.20:5060 [BREAK]
2015-04-15 05:49:44.984893 [NOTICE] sofia.c:952 Hangup sofia/internal/1000@192.168.100.20:5060 [CS_EXECUTE] [NORMAL_CLEARING]
2015-04-15 05:49:44.984893 [DEBUG] switch_channel.c:3222 Send signal sofia/internal/1000@192.168.100.20:5060 [KILL]
2015-04-15 05:49:44.984893 [DEBUG] switch_core_session.c:1396 Send signal sofia/internal/1000@192.168.100.20:5060 [BREAK]
2015-04-15 05:49:44.984893 [DEBUG] switch_core_session.c:2901 sofia/internal/1000@192.168.100.20:5060 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2015-04-15 05:49:44.984893 [DEBUG] switch_core_state_machine.c:535 (sofia/internal/1000@192.168.100.20:5060) State EXECUTE going to sleep
2015-04-15 05:49:44.984893 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/1000@192.168.100.20:5060) Running State Change CS_HANGUP
2015-04-15 05:49:44.984893 [DEBUG] switch_core_state_machine.c:735 (sofia/internal/1000@192.168.100.20:5060) Callstate Change ACTIVE -> HANGUP
2015-04-15 05:49:44.984893 [DEBUG] switch_core_state_machine.c:737 (sofia/internal/1000@192.168.100.20:5060) State HANGUP
2015-04-15 05:49:44.984893 [DEBUG] mod_sofia.c:413 Channel sofia/internal/1000@192.168.100.20:5060 hanging up, cause: NORMAL_CLEARING
2015-04-15 05:49:44.984893 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1000@192.168.100.20:5060 Standard HANGUP, cause: NORMAL_CLEARING
2015-04-15 05:49:44.984893 [DEBUG] switch_core_state_machine.c:737 (sofia/internal/1000@192.168.100.20:5060) State HANGUP going to sleep
2015-04-15 05:49:44.984893 [DEBUG] switch_core_state_machine.c:504 (sofia/internal/1000@192.168.100.20:5060) State Change CS_HANGUP -> CS_REPORTING
2015-04-15 05:49:44.984893 [DEBUG] switch_core_session.c:1396 Send signal sofia/internal/1000@192.168.100.20:5060 [BREAK]
2015-04-15 05:49:44.984893 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/1000@192.168.100.20:5060) Running State Change CS_REPORTING
2015-04-15 05:49:44.984893 [DEBUG] switch_core_state_machine.c:823 (sofia/internal/1000@192.168.100.20:5060) State REPORTING
2015-04-15 05:49:44.984893 [DEBUG] switch_core_state_machine.c:104 sofia/internal/1000@192.168.100.20:5060 Standard REPORTING, cause: NORMAL_CLEARING
2015-04-15 05:49:44.984893 [DEBUG] switch_core_state_machine.c:823 (sofia/internal/1000@192.168.100.20:5060) State REPORTING going to sleep
2015-04-15 05:49:45.005140 [DEBUG] switch_core_state_machine.c:498 (sofia/internal/1000@192.168.100.20:5060) State Change CS_REPORTING -> CS_DESTROY
2015-04-15 05:49:45.005140 [DEBUG] switch_core_session.c:1396 Send signal sofia/internal/1000@192.168.100.20:5060 [BREAK]
2015-04-15 05:49:45.005140 [DEBUG] switch_core_session.c:1623 Session 17 (sofia/internal/1000@192.168.100.20:5060) Locked, Waiting on external entities
2015-04-15 05:49:45.005140 [NOTICE] switch_core_session.c:1641 Session 17 (sofia/internal/1000@192.168.100.20:5060) Ended
2015-04-15 05:49:45.005140 [NOTICE] switch_core_session.c:1645 Close Channel sofia/internal/1000@192.168.100.20:5060 [CS_DESTROY]
2015-04-15 05:49:45.005140 [DEBUG] switch_core_state_machine.c:626 (sofia/internal/1000@192.168.100.20:5060) Running State Change CS_DESTROY
2015-04-15 05:49:45.005140 [DEBUG] switch_core_state_machine.c:636 (sofia/internal/1000@192.168.100.20:5060) State DESTROY
2015-04-15 05:49:45.005140 [DEBUG] mod_sofia.c:323 sofia/internal/1000@192.168.100.20:5060 SOFIA DESTROY
2015-04-15 05:49:45.005140 [DEBUG] switch_rtp.c:1370 [ zrtp engine]: STOP STREAM ID=15 mode=CLEAR state=NOZRTP.
2015-04-15 05:49:45.005140 [DEBUG] switch_rtp.c:1370 [ zrtp]: Stream ID=0 UNKNOWN switching <NONE> ---> <NONE>.
2015-04-15 05:49:45.005140 [DEBUG] switch_rtp.c:1370 [ zrtp engine]: STOP STREAM ID=0 mode=UNKNOWN state=NONE.
2015-04-15 05:49:45.005140 [DEBUG] switch_rtp.c:1370 [ zrtp engine]: STOP STREAM ID=0 mode=UNKNOWN state=NONE.
2015-04-15 05:49:45.005140 [DEBUG] switch_core_state_machine.c:111 sofia/internal/1000@192.168.100.20:5060 Standard DESTROY
2015-04-15 05:49:45.005140 [DEBUG] switch_core_state_machine.c:636 (sofia/internal/1000@192.168.100.20:5060) State DESTROY going to sleep


Этот дам собран на ванильном конфиге.

_________________
Если бы я был админом одной организации, я бы сделал все по другому.....
Вернуться к началу
 Профиль  
 
Vlad1983
СообщениеДобавлено: 15 апр 2015 14:02 
FreeSWITCH_GuRu

Зарегистрирован: 22 авг 2012 09:52
Сообщения: 1710
Код:
c=IN IP6 2001::5ef5:79fd:280b:3592:3f57:9b9b

_________________
ЛС: @rostel
Сообщество: @ru_freeswitch
Вернуться к началу
 Профиль  
 
astashov
СообщениеДобавлено: 15 апр 2015 14:07 

Зарегистрирован: 24 дек 2014 10:40
Сообщения: 85
а то что он дальше меняет на
Цитата:
switch_rtp.c:1151 Auto Changing stun/rtp/dtls port from 2001:0:5ef5:79fd:280b:3592:3f57:9b9b:58102 to 192.168.100.100:58103

уже получается никакой роли не играет? Или я не верно интерпретирую то, что мне говорит FS?

И сразу второй вопрос: а почему он тогда подставляет мой локальный v6 адрес, и как можно запретить использовать v6 в стоковых клиентах sipml? Случаем не в курсе? Или это только в "кишки" к нему лезть надо?

_________________
Если бы я был админом одной организации, я бы сделал все по другому.....
Вернуться к началу
 Профиль  
 
Vlad1983
СообщениеДобавлено: 15 апр 2015 14:21 
FreeSWITCH_GuRu

Зарегистрирован: 22 авг 2012 09:52
Сообщения: 1710
попробуете развернуть STUN в локалке
может быть что-то из этого выйдет

_________________
ЛС: @rostel
Сообщество: @ru_freeswitch
Вернуться к началу
 Профиль  
 
astashov
СообщениеДобавлено: 16 апр 2015 16:04 

Зарегистрирован: 24 дек 2014 10:40
Сообщения: 85
Ребята - это пипец. Как оказалось, во всем виноват Chrome версии 42. Что на линуксе, что на винде. Звука нет. Только версия для мака успешно отработала на 42-ой версии. После отката на версию 41 голос пошел и пропали
Цитата:
audio DTLS packet not written

Видимо перемудрили гуглы чего то.
На дев версии 43, голос прошел только в первом звонке, в последующих голоса так же не было. Но на то она и дев версия, что бы иметь косяки.
Будем разбираться и оформлять баг по хрому.

_________________
Если бы я был админом одной организации, я бы сделал все по другому.....
Вернуться к началу
 Профиль  
 
astashov
СообщениеДобавлено: 20 апр 2015 10:13 

Зарегистрирован: 24 дек 2014 10:40
Сообщения: 85
Нашел ответ. Гугл начиная с версии 42 начал отдавать sdp с ipv6. А для FS это оказалось внезапной траблой.
https://freeswitch.org/jira/browse/FS-7396
Если у кого такая же история, то обещают что в 1.4.19 все будет хорошо. Ну или отключаем в хроме ipv6(хотя я вроде отключил, как написано в доке, и на вкладке DNS у меня все выключено, а в ICE все равно адрес ipv6 )

_________________
Если бы я был админом одной организации, я бы сделал все по другому.....
Вернуться к началу
 Профиль  
 
Показать сообщения за:  Поле сортировки  
Начать новую тему Ответить на тему  Страница 1 из 1
  [ Сообщений: 8 ] 

Список форумов » FreeSWITCH Main » Для новичков/FAQ

Часовой пояс: UTC + 4 часа


Кто сейчас на конференции

Сейчас этот форум просматривают: Bing [Bot] и гости: 22

Вы не можете начинать темы
Вы не можете отвечать на сообщения
Вы не можете редактировать свои сообщения
Вы не можете удалять свои сообщения
Вы не можете добавлять вложения

Найти:
Перейти:  
Powered by phpBB® Forum Software © phpBB Group
Русская поддержка phpBB