<div dir="ltr">Hi guys,<div><br></div><div>I am using Freeswitch from master (month old). I tried several WebRTC clients (my own test app on Android and sipml5) and on certain WiFi&#39;s I am getting connection time up to 35 seconds when using STUN and TURN servers. Also, when I am using TURN and STUN, Freeswitch chooses the TURN candidate although as far as connectivity, when I am not using STUN and TURN I am connecting successfully after ~2 seconds (so no real need for TURN). Attaching the SIP trace from Freeswitch:</div><div><br></div><div><div>nua.c:575 nua_set_params() nua: nua_set_params: entering</div><div>nua_stack.c:529 nua_signal() nua((nil)): sent signal r_set_params</div><div>nua.c:575 nua_set_params() nua: nua_set_params: entering</div><div>nua_stack.c:529 nua_signal() nua((nil)): sent signal r_set_params</div><div>nua.c:575 nua_set_params() nua: nua_set_params: entering</div><div>nua_stack.c:529 nua_signal() nua((nil)): sent signal r_set_params</div><div>nua.c:575 nua_set_params() nua: nua_set_params: entering</div><div>nua_stack.c:569 nua_stack_signal() nua((nil)): recv signal r_set_params</div><div>nua_stack.c:529 nua_signal() nua((nil)): sent signal r_set_params</div><div>nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering</div><div>nua.c:575 nua_set_params() nua: nua_set_params: entering</div><div>nua_stack.c:529 nua_signal() nua((nil)): sent signal r_set_params</div><div>soa.c:403 soa_set_params() soa_set_params(static::0x7fe17c001930, ...) called</div><div>nua_stack.c:271 nua_stack_event() nua((nil)): event r_set_params 200 OK</div><div>nua_stack.c:359 nua_application_event() nua: nua_application_event: entering</div><div>nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering</div><div>nua_stack.c:569 nua_stack_signal() nua((nil)): recv signal r_set_params</div><div>nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering</div><div>soa.c:403 soa_set_params() soa_set_params(static::0x7fe18c001930, ...) called</div><div>nua_stack.c:569 nua_stack_signal() nua((nil)): recv signal r_set_params</div><div>nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering</div><div>nua_stack.c:271 nua_stack_event() nua((nil)): event r_set_params 200 OK</div><div>soa.c:403 soa_set_params() soa_set_params(static::0x7fe17c001930, ...) called</div><div>nua_stack.c:271 nua_stack_event() nua((nil)): event r_set_params 200 OK</div><div>nua_stack.c:569 nua_stack_signal() nua((nil)): recv signal r_set_params</div><div>nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering</div><div>soa.c:403 soa_set_params() soa_set_params(static::0x7fe184001930, ...) called</div><div>nua_stack.c:359 nua_application_event() nua: nua_application_event: entering</div><div>nua_stack.c:271 nua_stack_event() nua((nil)): event r_set_params 200 OK</div><div>nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering</div><div>nua_stack.c:359 nua_application_event() nua: nua_application_event: entering</div><div>nua_stack.c:569 nua_stack_signal() nua((nil)): recv signal r_set_params</div><div>nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering</div><div>nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering</div><div>soa.c:403 soa_set_params() soa_set_params(static::0x7fe188001930, ...) called</div><div>nua_stack.c:271 nua_stack_event() nua((nil)): event r_set_params 200 OK</div><div>nua_stack.c:359 nua_application_event() nua: nua_application_event: entering</div><div>nua_stack.c:359 nua_application_event() nua: nua_application_event: entering</div><div>nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering</div><div>nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering</div><div>tport.c:2773 tport_wakeup() tport_wakeup(0x7fe17c0d4ba0): events IN</div><div>tport.c:2864 tport_recv_event() tport_recv_event(0x7fe17c0d4ba0)</div><div>tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7fe17c0d4ba0) msg 0x7fe17c089c50 from (ws/<a href="http://82.166.84.247:53645">82.166.84.247:53645</a>) has 2598 bytes, veclen = 1</div><div>recv 2598 bytes from ws/[82.166.84.247]:53645 at 08:21:30.468866:</div><div>   ------------------------------------------------------------------------</div><div>   INVITE sip:991234@aaaa SIP/2.0</div><div>   Via: SIP/2.0/WS df7jal23ls0d.invalid;branch=z9hG4bKml28I3BsDokxOyXDaHfSBPW94I6MO4HK;rport</div><div>   From: &quot;asdasda&quot;&lt;sip:1000@xxx.xxx.xxx.xxx&gt;;tag=THvNqRR9fmMzKb6JP9hp</div><div>   To: &lt;sip:991234@aaaa&gt;</div><div>   Contact: &quot;asdasda&quot;&lt;sip:1000@df7jal23ls0d.invalid;rtcweb-breaker=no;click2call=no;transport=ws&gt;;+g.oma.sip-im;language=&quot;en,fr&quot;</div><div>   Call-ID: fa0bf4d8-2037-a467-61fd-4f78e9746fbe</div><div>   CSeq: 28092 INVITE</div><div>   Content-Type: application/sdp</div><div>   Content-Length: 2039</div><div>   Max-Forwards: 70</div><div>   User-Agent: IM-client/OMA1.0 sipML5-v1.2015.03.18</div><div>   Organization: Doubango Telecom</div><div><br></div><div>   v=0</div><div>   o=- 3843427479443760600 2 IN IP4 127.0.0.1</div><div>   s=Doubango Telecom - chrome</div><div>   t=0 0</div><div>   a=group:BUNDLE audio</div><div>   a=msid-semantic: WMS QqT0ePCaEFzZ3vHeaMToEsTZan1K2F3O3czm</div><div>   m=audio 58209 UDP/TLS/RTP/SAVPF 111 103 104 9 0 8 106 105 13 126</div><div>   c=IN IP4 130.211.78.35</div><div>   a=rtcp:58209 IN IP4 130.211.78.35</div><div>   a=candidate:2162125114 1 udp 2122260223 10.0.0.10 63888 typ host generation 0</div><div>   a=candidate:2162125114 2 udp 2122260223 10.0.0.10 63888 typ host generation 0</div><div>   a=candidate:3260192690 1 udp 1686052607 82.166.84.247 63888 typ srflx raddr 10.0.0.10 rport 63888 generation 0</div><div>   a=candidate:3260192690 2 udp 1686052607 82.166.84.247 63888 typ srflx raddr 10.0.0.10 rport 63888 generation 0</div><div>   a=candidate:3462174154 1 tcp 1518280447 10.0.0.10 0 typ host tcptype active generation 0</div><div>   a=candidate:3462174154 2 tcp 1518280447 10.0.0.10 0 typ host tcptype active generation 0</div><div>   a=candidate:3098925784 1 udp 25108223 130.211.78.35 58209 typ relay raddr 82.166.84.247 rport 53792 generation 0</div><div>   a=candidate:3098925784 2 udp 25108223 130.211.78.35 58209 typ relay raddr 82.166.84.247 rport 53792 generation 0</div><div>   a=ice-ufrag:EDo5kr308/TXhitG</div><div>   a=ice-pwd:3HWj7s5L/1g2BwIrjJNPnubB</div><div>   a=ice-options:google-ice</div><div>   a=fingerprint:sha-256 2D:92:8B:F0:BD:9C:C3:85:9F:B6:32:4C:B9:73:38:AD:82:1A:D3:02:F5:D8:7B:9E:0E:D4:86:FB:A7:DF:E1:C6</div><div>   a=setup:actpass</div><div>   a=mid:audio</div><div>   a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level</div><div>   a=extmap:3 <a href="http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time">http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time</a></div><div>   a=sendrecv</div><div>   a=rtcp-mux</div><div>   a=rtpmap:111 opus/48000/2</div><div>   a=fmtp:111 minptime=10; useinbandfec=1</div><div>   a=rtpmap:103 ISAC/16000</div><div>   a=rtpmap:104 ISAC/32000</div><div>   a=rtpmap:9 G722/8000</div><div>   a=rtpmap:0 PCMU/8000</div><div>   a=rtpmap:8 PCMA/8000</div><div>   a=rtpmap:106 CN/32000</div><div>   a=rtpmap:105 CN/16000</div><div>   a=rtpmap:13 CN/8000</div><div>   a=rtpmap:126 telephone-event/8000</div><div>   a=maxptime:60</div><div>   a=ssrc:4099543579 cname:X6JZwCe/LeIJBOws</div><div>   a=ssrc:4099543579 msid:QqT0ePCaEFzZ3vHeaMToEsTZan1K2F3O3czm b8082781-4098-4ac5-8c96-2848d2e9e7e4</div><div>   a=ssrc:4099543579 mslabel:QqT0ePCaEFzZ3vHeaMToEsTZan1K2F3O3czm</div><div>   a=ssrc:4099543579 label:b8082781-4098-4ac5-8c96-2848d2e9e7e4</div><div>   ------------------------------------------------------------------------</div><div>tport.c:3023 tport_deliver() tport_deliver(0x7fe17c0d4ba0): msg 0x7fe17c089c50 (2598 bytes) from ws/<a href="http://82.166.84.247:53645/sip">82.166.84.247:53645/sip</a> next=(nil)</div><div>nta.c:2880 agent_recv_request() nta: received INVITE sip:991234@aaaa SIP/2.0 (CSeq 28092)</div><div>nta.c:3174 agent_check_request_via() nta: Via check: received=82.166.84.247</div><div>nta.c:3085 agent_recv_request() nta: INVITE (28092) going to a default leg</div><div>nta.c:1350 set_timeout() nta: timer set to 2000 ms</div><div>nua_server.c:102 nua_stack_process_request() nua: nua_stack_process_request: entering</div><div>nua_stack.c:899 nh_create() nua: nh_create: entering</div><div>nua_common.c:108 nh_create_handle() nua: nh_create_handle: entering</div><div>nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering</div><div>soa.c:280 soa_clone() soa_clone(static::0x7fe17c001930, 0x7fe17c001130, 0x7fe17c0cf210) called</div><div>soa.c:403 soa_set_params() soa_set_params(static::0x7fe17c0bf4d0, ...) called</div><div>nta.c:4417 nta_leg_tcreate() nta_leg_tcreate(0x7fe17c04a2e0)</div><div>soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7fe17c0bf4d0) called</div><div>soa.c:1171 soa_set_remote_sdp() soa_set_remote_sdp(static::0x7fe17c0bf4d0, (nil), 0x7fe17c0be55f, 2039) called</div><div>nua_dialog.c:338 nua_dialog_usage_add() nua(0x7fe17c0cf210): adding session usage</div><div>tport.c:3257 tport_tsend() tport_tsend(0x7fe17c0d4ba0) tpn = WS/<a href="http://82.166.84.247:53645">82.166.84.247:53645</a></div><div>tport_type_ws.c:311 tport_send_stream_ws() tport_ws_writevec: vec 0x7fe17c0d4d90 0x7fe17c0190a0 140 (140)</div><div>tport_type_ws.c:311 tport_send_stream_ws() tport_ws_writevec: vec 0x7fe17c0d4d90 0x7fe17c0be3ab 86 (86)</div><div>tport_type_ws.c:311 tport_send_stream_ws() tport_ws_writevec: vec 0x7fe17c0d4d90 0x7fe17c0be480 67 (67)</div><div>tport_type_ws.c:311 tport_send_stream_ws() tport_ws_writevec: vec 0x7fe17c0d4d90 0x7fe17c01912c 101 (101)</div><div>tport.c:3594 tport_vsend() tport_vsend(0x7fe17c0d4ba0): 394 bytes of 394 to ws/<a href="http://82.166.84.247:53645">82.166.84.247:53645</a></div><div>tport.c:3492 tport_send_msg() tport_vsend returned 394</div><div>send 394 bytes to ws/[82.166.84.247]:53645 at 08:21:30.469343:</div><div>   ------------------------------------------------------------------------</div><div>   SIP/2.0 100 Trying</div><div>   Via: SIP/2.0/WS df7jal23ls0d.invalid;branch=z9hG4bKml28I3BsDokxOyXDaHfSBPW94I6MO4HK;rport=53645;received=82.166.84.247</div><div>   From: &quot;asdasda&quot;&lt;sip:1000@xxx.xxx.xxx.xxx&gt;;tag=THvNqRR9fmMzKb6JP9hp</div><div>   To: &lt;sip:991234@aaaa&gt;</div><div>   Call-ID: fa0bf4d8-2037-a467-61fd-4f78e9746fbe</div><div>   CSeq: 28092 INVITE</div><div>   User-Agent: FreeSWITCH-mod_sofia/1.5.15b+git~20150423T043308Z~b01352c133~64bit</div><div>   Content-Length: 0</div><div><br></div><div>   ------------------------------------------------------------------------</div><div>tport.c:2296 tport_set_secondary_timer() tport(0x7fe17c0d4ba0): reset timer</div><div>nta.c:6791 incoming_reply() nta: sent 100 Trying for INVITE (28092)</div><div>nua_stack.c:271 nua_stack_event() nua(0x7fe17c0cf210): event i_invite 100 Trying</div><div>nua_session.c:4139 signal_call_state_change() nua(0x7fe17c0cf210): call state changed: init -&gt; received, received offer</div><div>soa.c:1098 soa_get_remote_sdp() soa_get_remote_sdp(static::0x7fe17c0bf4d0, [0x7fe1aa7b35d8], [0x7fe1aa7b35e0], [(nil)]) called</div><div>nua_stack.c:271 nua_stack_event() nua(0x7fe17c0cf210): event i_state 100 Trying</div><div>nua_stack.c:359 nua_application_event() nua: nua_application_event: entering</div><div>tport.c:2296 tport_set_secondary_timer() tport(0x7fe17c0d4ba0): reset timer</div><div>nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering</div><div>2015-05-08 08:21:30.467711 [NOTICE] switch_channel.c:1075 New Channel sofia/internal/1000@xxx.xxx.xxx.xxx [3ac3c622-f55b-11e4-a447-7d37723461ed]</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/1000@xxx.xxx.xxx.xxx [BREAK]</div><div>nua_stack.c:359 nua_application_event() nua: nua_application_event: entering</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/1000@xxx.xxx.xxx.xxx [BREAK]</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/1000@xxx.xxx.xxx.xxx) Running State Change CS_NEW</div><div>nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering</div><div>2015-05-08 08:21:30.467711 [DEBUG] sofia.c:8848 sofia/internal/1000@xxx.xxx.xxx.xxx receiving invite from <a href="http://82.166.84.247:53645">82.166.84.247:53645</a> version: 1.5.15b git b01352c 2015-04-23 04:33:08Z 64bit</div><div>2015-05-08 08:21:30.467711 [DEBUG] sofia.c:8960 IP 82.166.84.247 Approved by acl &quot;domains[]&quot;. Access Granted.</div><div>nua.c:610 nua_set_hparams() nua: nua_set_hparams: entering</div><div>nua.c:610 nua_set_hparams() nua: nua_r_set_params with invalid handle (nil)</div><div>2015-05-08 08:21:30.467711 [DEBUG] sofia.c:10113 Setting NAT mode based on via received</div><div>nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering</div><div>nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering</div><div>2015-05-08 08:21:30.467711 [DEBUG] sofia.c:6627 Channel sofia/internal/1000@xxx.xxx.xxx.xxx entering state [received][100]</div><div>2015-05-08 08:21:30.467711 [DEBUG] sofia.c:6637 Remote SDP:</div><div>v=0</div><div>o=- 3843427479443760600 2 IN IP4 127.0.0.1</div><div>s=Doubango Telecom - chrome</div><div>t=0 0</div><div>a=group:BUNDLE audio</div><div>a=msid-semantic: WMS QqT0ePCaEFzZ3vHeaMToEsTZan1K2F3O3czm</div><div>m=audio 58209 UDP/TLS/RTP/SAVPF 111 103 104 9 0 8 106 105 13 126</div><div>c=IN IP4 130.211.78.35</div><div>a=rtpmap:111 opus/48000/2</div><div>a=fmtp:111 minptime=10; useinbandfec=1</div><div>a=rtpmap:103 ISAC/16000</div><div>a=rtpmap:104 ISAC/32000</div><div>a=rtpmap:9 G722/8000</div><div>a=rtpmap:0 PCMU/8000</div><div>a=rtpmap:8 PCMA/8000</div><div>a=rtpmap:106 CN/32000</div><div>a=rtpmap:105 CN/16000</div><div>a=rtpmap:13 CN/8000</div><div>a=rtpmap:126 telephone-event/8000</div><div>a=rtcp:58209 IN IP4 130.211.78.35</div><div>a=candidate:2162125114 1 udp 2122260223 10.0.0.10 63888 typ host generation 0</div><div>a=candidate:2162125114 2 udp 2122260223 10.0.0.10 63888 typ host generation 0</div><div>a=candidate:3260192690 1 udp 1686052607 82.166.84.247 63888 typ srflx raddr 10.0.0.10 rport 63888 generation 0</div><div>a=candidate:3260192690 2 udp 1686052607 82.166.84.247 63888 typ srflx raddr 10.0.0.10 rport 63888 generation 0</div><div>a=candidate:3462174154 1 tcp 1518280447 10.0.0.10 0 typ host tcptype active generation 0</div><div>a=candidate:3462174154 2 tcp 1518280447 10.0.0.10 0 typ host tcptype active generation 0</div><div>a=candidate:3098925784 1 udp 25108223 130.211.78.35 58209 typ relay raddr 82.166.84.247 rport 53792 generation 0</div><div>a=candidate:3098925784 2 udp 25108223 130.211.78.35 58209 typ relay raddr 82.166.84.247 rport 53792 generation 0</div><div>a=ice-ufrag:EDo5kr308/TXhitG</div><div>a=ice-pwd:3HWj7s5L/1g2BwIrjJNPnubB</div><div>a=ice-options:google-ice</div><div>a=fingerprint:sha-256 2D:92:8B:F0:BD:9C:C3:85:9F:B6:32:4C:B9:73:38:AD:82:1A:D3:02:F5:D8:7B:9E:0E:D4:86:FB:A7:DF:E1:C6</div><div>a=setup:actpass</div><div>a=mid:audio</div><div>a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level</div><div>a=extmap:3 <a href="http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time">http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time</a></div><div>a=rtcp-mux</div><div>a=maxptime:60</div><div>a=ssrc:4099543579 cname:X6JZwCe/LeIJBOws</div><div>a=ssrc:4099543579 msid:QqT0ePCaEFzZ3vHeaMToEsTZan1K2F3O3czm b8082781-4098-4ac5-8c96-2848d2e9e7e4</div><div>a=ssrc:4099543579 mslabel:QqT0ePCaEFzZ3vHeaMToEsTZan1K2F3O3czm</div><div>a=ssrc:4099543579 label:b8082781-4098-4ac5-8c96-2848d2e9e7e4</div><div><br></div><div>2015-05-08 08:21:30.467711 [DEBUG] sofia.c:6903 (sofia/internal/1000@xxx.xxx.xxx.xxx) State Change CS_NEW -&gt; CS_INIT</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_session.c:1396 Send signal sofia/internal/1000@xxx.xxx.xxx.xxx [BREAK]</div><div>nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_state_machine.c:491 (sofia/internal/1000@xxx.xxx.xxx.xxx) State NEW</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/1000@xxx.xxx.xxx.xxx) Running State Change CS_INIT</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_state_machine.c:512 (sofia/internal/1000@xxx.xxx.xxx.xxx) State INIT</div><div>2015-05-08 08:21:30.467711 [DEBUG] mod_sofia.c:87 sofia/internal/1000@xxx.xxx.xxx.xxx SOFIA INIT</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1000@xxx.xxx.xxx.xxx Standard INIT</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1000@xxx.xxx.xxx.xxx) State Change CS_INIT -&gt; CS_ROUTING</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_session.c:1396 Send signal sofia/internal/1000@xxx.xxx.xxx.xxx [BREAK]</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_state_machine.c:512 (sofia/internal/1000@xxx.xxx.xxx.xxx) State INIT going to sleep</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/1000@xxx.xxx.xxx.xxx) Running State Change CS_ROUTING</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_channel.c:2204 (sofia/internal/1000@xxx.xxx.xxx.xxx) Callstate Change DOWN -&gt; RINGING</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_state_machine.c:528 (sofia/internal/1000@xxx.xxx.xxx.xxx) State ROUTING</div><div>2015-05-08 08:21:30.467711 [DEBUG] mod_sofia.c:123 sofia/internal/1000@xxx.xxx.xxx.xxx SOFIA ROUTING</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_state_machine.c:166 sofia/internal/1000@xxx.xxx.xxx.xxx Standard ROUTING</div><div>2015-05-08 08:21:30.467711 [INFO] mod_dialplan_xml.c:635 Processing asdasda &lt;1000&gt;-&gt;991234 in context public</div><div>Dialplan: sofia/internal/1000@xxx.xxx.xxx.xxx parsing [public-&gt;cdquality_conferences_with_api] continue=false</div><div>Dialplan: sofia/internal/1000@xxx.xxx.xxx.xxx Regex (FAIL) [cdquality_conferences_with_api] destination_number(991234) =~ /^(75\d{4,36})$/ break=on-false</div><div>Dialplan: sofia/internal/1000@xxx.xxx.xxx.xxx parsing [public-&gt;test_conferences] continue=false</div><div>Dialplan: sofia/internal/1000@xxx.xxx.xxx.xxx Regex (PASS) [test_conferences] destination_number(991234) =~ /^(99\d{4,36})$/ break=on-false</div><div>Dialplan: sofia/internal/1000@xxx.xxx.xxx.xxx Action answer()</div><div>Dialplan: sofia/internal/1000@xxx.xxx.xxx.xxx Action conference(991234-${domain_name}@test)</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_state_machine.c:216 (sofia/internal/1000@xxx.xxx.xxx.xxx) State Change CS_ROUTING -&gt; CS_EXECUTE</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_session.c:1396 Send signal sofia/internal/1000@xxx.xxx.xxx.xxx [BREAK]</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_state_machine.c:528 (sofia/internal/1000@xxx.xxx.xxx.xxx) State ROUTING going to sleep</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_state_machine.c:472 (sofia/internal/1000@xxx.xxx.xxx.xxx) Running State Change CS_EXECUTE</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_state_machine.c:535 (sofia/internal/1000@xxx.xxx.xxx.xxx) State EXECUTE</div><div>2015-05-08 08:21:30.467711 [DEBUG] mod_sofia.c:178 sofia/internal/1000@xxx.xxx.xxx.xxx SOFIA EXECUTE</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_state_machine.c:258 sofia/internal/1000@xxx.xxx.xxx.xxx Standard EXECUTE</div><div>EXECUTE sofia/internal/1000@xxx.xxx.xxx.xxx answer()</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_media.c:3672 Audio Codec Compare [opus:111:48000:60:0:1]/[opus:116:48000:20:0:1]</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_media.c:3701 Bah HUMBUG! Sticking with opus@48000h@20i</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_media.c:3727 Audio Codec Compare [opus:116:48000:20:0:1] ++++ is saved as a match</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_media.c:3672 Audio Codec Compare [opus:111:48000:60:0:1]/[PCMU:0:8000:20:64000:1]</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_media.c:3672 Audio Codec Compare [opus:111:48000:60:0:1]/[PCMA:8:8000:20:64000:1]</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_media.c:3672 Audio Codec Compare [ISAC:103:16000:30:32000:1]/[opus:116:48000:20:0:1]</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_media.c:3672 Audio Codec Compare [ISAC:103:16000:30:32000:1]/[PCMU:0:8000:20:64000:1]</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_media.c:3672 Audio Codec Compare [ISAC:103:16000:30:32000:1]/[PCMA:8:8000:20:64000:1]</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_media.c:3672 Audio Codec Compare [ISAC:104:32000:30:32000:1]/[opus:116:48000:20:0:1]</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_media.c:3672 Audio Codec Compare [ISAC:104:32000:30:32000:1]/[PCMU:0:8000:20:64000:1]</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_media.c:3672 Audio Codec Compare [ISAC:104:32000:30:32000:1]/[PCMA:8:8000:20:64000:1]</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_media.c:3672 Audio Codec Compare [G722:9:8000:60:64000:1]/[opus:116:48000:20:0:1]</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_media.c:3672 Audio Codec Compare [G722:9:8000:60:64000:1]/[PCMU:0:8000:20:64000:1]</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_media.c:3672 Audio Codec Compare [G722:9:8000:60:64000:1]/[PCMA:8:8000:20:64000:1]</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_media.c:3672 Audio Codec Compare [PCMU:0:8000:60:64000:1]/[opus:116:48000:20:0:1]</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_media.c:3672 Audio Codec Compare [PCMU:0:8000:60:64000:1]/[PCMU:0:8000:20:64000:1]</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_media.c:3701 Bah HUMBUG! Sticking with PCMU@8000h@20i</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_media.c:3727 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_media.c:3672 Audio Codec Compare [PCMU:0:8000:60:64000:1]/[PCMA:8:8000:20:64000:1]</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_media.c:3672 Audio Codec Compare [PCMA:8:8000:60:64000:1]/[opus:116:48000:20:0:1]</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_media.c:3672 Audio Codec Compare [PCMA:8:8000:60:64000:1]/[PCMU:0:8000:20:64000:1]</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_media.c:3672 Audio Codec Compare [PCMA:8:8000:60:64000:1]/[PCMA:8:8000:20:64000:1]</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_media.c:3701 Bah HUMBUG! Sticking with PCMA@8000h@20i</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_media.c:3727 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_media.c:3672 Audio Codec Compare [CN:105:16000:60:0:1]/[opus:116:48000:20:0:1]</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_media.c:3672 Audio Codec Compare [CN:105:16000:60:0:1]/[PCMU:0:8000:20:64000:1]</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_media.c:3672 Audio Codec Compare [CN:105:16000:60:0:1]/[PCMA:8:8000:20:64000:1]</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_media.c:3672 Audio Codec Compare [CN:13:8000:60:0:1]/[opus:116:48000:20:0:1]</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_media.c:3672 Audio Codec Compare [CN:13:8000:60:0:1]/[PCMU:0:8000:20:64000:1]</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_media.c:3672 Audio Codec Compare [CN:13:8000:60:0:1]/[PCMA:8:8000:20:64000:1]</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_media.c:3588 Set telephone-event payload to 126</div><div>2015-05-08 08:21:30.467711 [DEBUG] mod_opus.c:289 Opus encoder set bitrate to local settings [-1000bps]</div><div>2015-05-08 08:21:30.467711 [DEBUG] mod_opus.c:289 Opus encoder set bitrate to local settings [-1000bps]</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_media.c:2507 Set Codec sofia/internal/1000@xxx.xxx.xxx.xxx opus/48000 20 ms 960 samples 0 bits 1 channels</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_codec.c:111 sofia/internal/1000@xxx.xxx.xxx.xxx Original read codec set to opus:116</div><div>2015-05-08 08:21:30.467711 [WARNING] switch_core_media.c:2791 NO candidate ACL defined, Defaulting to wan.auto</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_media.c:2815 Checking Candidate cid: 1 proto: udp type: host addr: <a href="http://10.0.0.10:63888">10.0.0.10:63888</a></div><div>2015-05-08 08:21:30.467711 [NOTICE] switch_core_media.c:2829 Save audio Candidate cid: 1 proto: udp type: host addr: <a href="http://10.0.0.10:63888">10.0.0.10:63888</a></div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_media.c:2815 Checking Candidate cid: 2 proto: udp type: host addr: <a href="http://10.0.0.10:63888">10.0.0.10:63888</a></div><div>2015-05-08 08:21:30.467711 [NOTICE] switch_core_media.c:2829 Save audio Candidate cid: 2 proto: udp type: host addr: <a href="http://10.0.0.10:63888">10.0.0.10:63888</a></div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_media.c:2815 Checking Candidate cid: 1 proto: udp type: srflx addr: <a href="http://82.166.84.247:63888">82.166.84.247:63888</a></div><div>2015-05-08 08:21:30.467711 [NOTICE] switch_core_media.c:2824 Choose audio Candidate cid: 1 proto: udp type: srflx addr: <a href="http://82.166.84.247:63888">82.166.84.247:63888</a></div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_media.c:2815 Checking Candidate cid: 2 proto: udp type: srflx addr: <a href="http://82.166.84.247:63888">82.166.84.247:63888</a></div><div>2015-05-08 08:21:30.467711 [NOTICE] switch_core_media.c:2824 Choose audio Candidate cid: 2 proto: udp type: srflx addr: <a href="http://82.166.84.247:63888">82.166.84.247:63888</a></div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_media.c:2815 Checking Candidate cid: 1 proto: udp type: relay addr: <a href="http://130.211.78.35:58209">130.211.78.35:58209</a></div><div>2015-05-08 08:21:30.467711 [NOTICE] switch_core_media.c:2829 Save audio Candidate cid: 1 proto: udp type: relay addr: <a href="http://130.211.78.35:58209">130.211.78.35:58209</a></div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_media.c:2815 Checking Candidate cid: 2 proto: udp type: relay addr: <a href="http://130.211.78.35:58209">130.211.78.35:58209</a></div><div>2015-05-08 08:21:30.467711 [NOTICE] switch_core_media.c:2829 Save audio Candidate cid: 2 proto: udp type: relay addr: <a href="http://130.211.78.35:58209">130.211.78.35:58209</a></div><div>2015-05-08 08:21:30.467711 [NOTICE] switch_core_media.c:2953 setting remote audio ice addr to <a href="http://82.166.84.247:63888">82.166.84.247:63888</a> based on candidate</div><div>2015-05-08 08:21:30.467711 [NOTICE] switch_core_media.c:2978 setting remote rtcp audio addr to <a href="http://82.166.84.247:63888">82.166.84.247:63888</a> based on candidate</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_media.c:3935 Set 2833 dtmf send/recv payload to 126</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_media.c:5171 AUDIO RTP [sofia/internal/1000@xxx.xxx.xxx.xxx] 172.30.0.219 port 19864 -&gt; 82.166.84.247 port 63888 codec: 111 ms: 20</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_rtp.c:3559 Starting timer [soft] 960 bytes per 20ms</div><div>2015-05-08 08:21:30.467711 [INFO] switch_core_media.c:5345 Activating Audio ICE</div><div>2015-05-08 08:21:30.467711 [NOTICE] switch_rtp.c:4009 Activating RTP audio ICE: EDo5kr308/TXhitG:v9QogVGvZ8jGwYIi <a href="http://82.166.84.247:63888">82.166.84.247:63888</a></div><div>2015-05-08 08:21:30.467711 [INFO] switch_core_media.c:5388 Activating RTCP PORT 63888</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_rtp.c:3909 RTCP send rate is: 10000 and packet rate is: 20000 Remote Port: 63888</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_rtp.c:2349 Setting RTCP remote addr to <a href="http://82.166.84.247:63888">82.166.84.247:63888</a></div><div>2015-05-08 08:21:30.467711 [INFO] switch_core_media.c:5396 Skipping RTCP ICE (Same as RTP)</div><div>2015-05-08 08:21:30.467711 [INFO] switch_rtp.c:3101 Activate RTP/RTCP audio DTLS client</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_media.c:5469 Set 2833 dtmf send payload to 126</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_media.c:5475 Set 2833 dtmf receive payload to 126</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_media.c:5503 Set comfort noise payload to 106</div><div>2015-05-08 08:21:30.467711 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/1000@xxx.xxx.xxx.xxx!</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_channel.c:3419 (sofia/internal/1000@xxx.xxx.xxx.xxx) Callstate Change RINGING -&gt; EARLY</div><div>2015-05-08 08:21:30.467711 [DEBUG] mod_sofia.c:780 Local SDP sofia/internal/1000@xxx.xxx.xxx.xxx:</div><div>v=0</div><div>o=FreeSWITCH 1431053426 1431053427 IN IP4 xxx.xxx.xxx.xxx</div><div>s=FreeSWITCH</div><div>c=IN IP4 xxx.xxx.xxx.xxx</div><div>t=0 0</div><div>a=msid-semantic: WMS tycfgLW7xb89okfsdKHP3gespdCXRxPb</div><div>m=audio 19864 UDP/TLS/RTP/SAVPF 111 126 106</div><div>a=rtpmap:111 opus/48000/2</div><div>a=fmtp:111 useinbandfec=1; minptime=10</div><div>a=rtpmap:126 telephone-event/8000</div><div>a=rtpmap:106 CN/8000</div><div>a=ptime:20</div><div>a=sendrecv</div><div>a=fingerprint:sha-256 83:F4:57:6D:F9:40:C7:E8:28:6D:59:AE:5F:08:23:3E:9E:17:1E:2F:D8:A9:D5:E7:DB:13:92:B5:DE:4A:66:CA</div><div>a=rtcp-mux</div><div>a=rtcp:19864 IN IP4 xxx.xxx.xxx.xxx</div><div>a=ssrc:3914469578 cname:VRh1s3ZQ5XPj8UCb</div><div>a=ssrc:3914469578 msid:tycfgLW7xb89okfsdKHP3gespdCXRxPb a0</div><div>a=ssrc:3914469578 mslabel:tycfgLW7xb89okfsdKHP3gespdCXRxPb</div><div>a=ssrc:3914469578 label:tycfgLW7xb89okfsdKHP3gespdCXRxPba0</div><div>a=ice-ufrag:v9QogVGvZ8jGwYIi</div><div>a=ice-pwd:FP9YIYEDMjNL4fNpftDlfaH5</div><div>a=candidate:8233794353 1 udp 659136 xxx.xxx.xxx.xxx 19864 typ host generation 0</div><div><br></div><div>nua.c:879 nua_respond() nua: nua_respond: entering</div><div>nua_stack.c:529 nua_signal() nua(0x7fe17c0cf210): sent signal r_respond</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_session.c:912 Send signal sofia/internal/1000@xxx.xxx.xxx.xxx [BREAK]</div><div>nua_stack.c:573 nua_stack_signal() nua(0x7fe17c0cf210): recv signal r_respond 200 OK</div><div>nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering</div><div>soa.c:403 soa_set_params() soa_set_params(static::0x7fe17c0bf4d0, ...) called</div><div>soa.c:1052 soa_set_user_sdp() soa_set_user_sdp(static::0x7fe17c0bf4d0, (nil), 0x7fe190041d31, -1) called</div><div>soa.c:890 soa_set_capability_sdp() soa_set_capability_sdp(static::0x7fe17c0bf4d0, (nil), 0x7fe190041d31, -1) called</div><div>2015-05-08 08:21:30.467711 [NOTICE] mod_dptools.c:1292 Channel [sofia/internal/1000@xxx.xxx.xxx.xxx] has been answered</div><div>nua_session.c:2320 nua_invite_server_respond() nua: nua_invite_server_respond: entering</div><div>soa.c:1515 soa_generate_answer() soa_generate_answer(static::0x7fe17c0bf4d0) called</div><div>soa_static.c:1146 offer_answer_step() soa_static_offer_answer_action(0x7fe17c0bf4d0, soa_generate_answer): called</div><div>soa_static.c:1187 offer_answer_step() soa_static(0x7fe17c0bf4d0, soa_generate_answer): generating local description</div><div>soa_static.c:1228 offer_answer_step() soa_static(0x7fe17c0bf4d0, soa_generate_answer): upgrade with remote description</div><div>soa_static.c:1029 soa_sdp_mode_set() soa_sdp_mode_set(0x7fe1aa7b1a30, 0x7fe17c026ac0, &quot;&quot;): called</div><div>soa_static.c:1444 offer_answer_step() soa_static(0x7fe17c0bf4d0, soa_generate_answer): storing local description</div><div>soa.c:1730 soa_activate() soa_activate(static::0x7fe17c0bf4d0, (nil)) called</div><div>soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7fe17c0bf4d0, [(nil)], [0x7fe1aa7b3b58], [0x7fe1aa7b3b54]) called</div><div>tport.c:3257 tport_tsend() tport_tsend(0x7fe17c0d4ba0) tpn = WS/<a href="http://82.166.84.247:53645">82.166.84.247:53645</a></div><div>tport_type_ws.c:311 tport_send_stream_ws() tport_ws_writevec: vec 0x7fe17c0d4d90 0x7fe17c0c5560 136 (136)</div><div>tport_type_ws.c:311 tport_send_stream_ws() tport_ws_writevec: vec 0x7fe17c0d4d90 0x7fe17c0be3ab 63 (63)</div><div>tport_type_ws.c:311 tport_send_stream_ws() tport_ws_writevec: vec 0x7fe17c0d4d90 0x7fe17c0c55e8 41 (41)</div><div>tport_type_ws.c:311 tport_send_stream_ws() tport_ws_writevec: vec 0x7fe17c0d4d90 0x7fe17c0be480 67 (67)</div><div>tport_type_ws.c:311 tport_send_stream_ws() tport_ws_writevec: vec 0x7fe17c0d4d90 0x7fe17c0c5611 631 (631)</div><div>tport_type_ws.c:311 tport_send_stream_ws() tport_ws_writevec: vec 0x7fe17c0d4d90 0x7fe17c0d3020 864 (864)</div><div>tport.c:3594 tport_vsend() tport_vsend(0x7fe17c0d4ba0): 1802 bytes of 1802 to ws/<a href="http://82.166.84.247:53645">82.166.84.247:53645</a></div><div>tport.c:3492 tport_send_msg() tport_vsend returned 1802</div><div>send 1802 bytes to ws/[82.166.84.247]:53645 at 08:21:30.479618:</div><div>   ------------------------------------------------------------------------</div><div>   SIP/2.0 200 OK</div><div>   Via: SIP/2.0/WS df7jal23ls0d.invalid;branch=z9hG4bKml28I3BsDokxOyXDaHfSBPW94I6MO4HK;rport=53645;received=82.166.84.247</div><div>   From: &quot;asdasda&quot;&lt;sip:1000@xxx.xxx.xxx.xxx&gt;;tag=THvNqRR9fmMzKb6JP9hp</div><div>   To: &lt;sip:991234@aaaa&gt;;tag=73aKc8ZegaUHr</div><div>   Call-ID: fa0bf4d8-2037-a467-61fd-4f78e9746fbe</div><div>   CSeq: 28092 INVITE</div><div>   Contact: &lt;sip:991234@xxx.xxx.xxx.xxx:5060;transport=udp&gt;</div><div>   User-Agent: FreeSWITCH-mod_sofia/1.5.15b+git~20150423T043308Z~b01352c133~64bit</div><div>   Accept: application/sdp</div><div>   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE</div><div>   Supported: path, replaces</div><div>   Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer</div><div>   Content-Type: application/sdp</div><div>   Content-Disposition: session</div><div>   Content-Length: 864</div><div>   Remote-Party-ID: &quot;991234&quot; &lt;sip:991234@aaaa&gt;;party=calling;privacy=off;screen=no</div><div><br></div><div>   v=0</div><div>   o=FreeSWITCH 1431053426 1431053427 IN IP4 xxx.xxx.xxx.xxx</div><div>   s=FreeSWITCH</div><div>   c=IN IP4 xxx.xxx.xxx.xxx</div><div>   t=0 0</div><div>   a=msid-semantic: WMS tycfgLW7xb89okfsdKHP3gespdCXRxPb</div><div>   m=audio 19864 UDP/TLS/RTP/SAVPF 111 126 106</div><div>   a=rtpmap:111 opus/48000/2</div><div>   a=fmtp:111 useinbandfec=1; minptime=10</div><div>   a=rtpmap:126 telephone-event/8000</div><div>   a=rtpmap:106 CN/8000</div><div>   a=ptime:20</div><div>   a=fingerprint:sha-256 83:F4:57:6D:F9:40:C7:E8:28:6D:59:AE:5F:08:23:3E:9E:17:1E:2F:D8:A9:D5:E7:DB:13:92:B5:DE:4A:66:CA</div><div>   a=rtcp-mux</div><div>   a=rtcp:19864 IN IP4 xxx.xxx.xxx.xxx</div><div>   a=ssrc:3914469578 cname:VRh1s3ZQ5XPj8UCb</div><div>   a=ssrc:3914469578 msid:tycfgLW7xb89okfsdKHP3gespdCXRxPb a0</div><div>   a=ssrc:3914469578 mslabel:tycfgLW7xb89okfsdKHP3gespdCXRxPb</div><div>   a=ssrc:3914469578 label:tycfgLW7xb89okfsdKHP3gespdCXRxPba0</div><div>   a=ice-ufrag:v9QogVGvZ8jGwYIi</div><div>   a=ice-pwd:FP9YIYEDMjNL4fNpftDlfaH5</div><div>   a=candidate:8233794353 1 udp 659136 xxx.xxx.xxx.xxx 19864 typ host generation 0</div><div>   ------------------------------------------------------------------------</div><div>tport.c:2296 tport_set_secondary_timer() tport(0x7fe17c0d4ba0): reset timer</div><div>nta.c:6791 incoming_reply() nta: sent 200 OK for INVITE (28092)</div><div>nta.c:1348 set_timeout() nta: timer shortened to 500 ms</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_channel.c:3711 (sofia/internal/1000@xxx.xxx.xxx.xxx) Callstate Change EARLY -&gt; ACTIVE</div><div>nua_session.c:4139 signal_call_state_change() nua(0x7fe17c0cf210): call state changed: received -&gt; completed, sent answer</div><div>soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7fe17c0bf4d0, [0x7fe1aa7b3c48], [0x7fe1aa7b3c50], [(nil)]) called</div><div>soa.c:616 soa_get_params() soa_get_params(static::0x7fe17c0bf4d0, ...) called</div><div>nua_stack.c:271 nua_stack_event() nua(0x7fe17c0cf210): event i_state 200 OK</div><div>nua_stack.c:359 nua_application_event() nua: nua_application_event: entering</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/1000@xxx.xxx.xxx.xxx [BREAK]</div><div>nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering</div><div>2015-05-08 08:21:30.467711 [DEBUG] sofia.c:6627 Channel sofia/internal/1000@xxx.xxx.xxx.xxx entering state [completed][200]</div><div>nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering</div><div>EXECUTE sofia/internal/1000@xxx.xxx.xxx.xxx conference(991234-172.30.0.219@test)</div><div>2015-05-08 08:21:30.467711 [INFO] mod_conference.c:10364 using channel sound prefix: /usr/local/freeswitch/sounds/en/us/callie</div><div>2015-05-08 08:21:30.467711 [DEBUG] mod_conference.c:8991 Raw Codec Activation Success L16@48000hz 1 channel 20ms</div><div>2015-05-08 08:21:30.467711 [DEBUG] mod_conference.c:9037 Raw Codec Activation Success L16@16000hz 1 channel 20ms</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_codec.c:221 sofia/internal/1000@xxx.xxx.xxx.xxx Push codec L16:100</div><div>2015-05-08 08:21:30.467711 [INFO] mod_conference.c:10967 sofia/internal/1000@xxx.xxx.xxx.xxx binding &#39;0&#39; to &#39;mute&#39;</div><div>2015-05-08 08:21:30.467711 [INFO] switch_ivr_async.c:212 Digit parser mod_conference: Setting realm to &#39;conf&#39;</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_ivr_async.c:321 Digit parser mod_conference: binding 0/conf/0 callback: 0x7fe1a92764e0 data: 0x7fe19010b8e0</div><div>2015-05-08 08:21:30.467711 [INFO] mod_conference.c:10967 sofia/internal/1000@xxx.xxx.xxx.xxx binding &#39;*&#39; to &#39;deaf mute&#39;</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_ivr_async.c:321 Digit parser mod_conference: binding */conf/0 callback: 0x7fe1a92764e0 data: 0x7fe19010b910</div><div>2015-05-08 08:21:30.467711 [INFO] mod_conference.c:10967 sofia/internal/1000@xxx.xxx.xxx.xxx binding &#39;9&#39; to &#39;energy up&#39;</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_ivr_async.c:321 Digit parser mod_conference: binding 9/conf/0 callback: 0x7fe1a92764e0 data: 0x7fe19010b940</div><div>2015-05-08 08:21:30.467711 [INFO] mod_conference.c:10967 sofia/internal/1000@xxx.xxx.xxx.xxx binding &#39;8&#39; to &#39;energy equ&#39;</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_ivr_async.c:321 Digit parser mod_conference: binding 8/conf/0 callback: 0x7fe1a92764e0 data: 0x7fe19010b970</div><div>2015-05-08 08:21:30.467711 [INFO] mod_conference.c:10967 sofia/internal/1000@xxx.xxx.xxx.xxx binding &#39;7&#39; to &#39;energy dn&#39;</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_ivr_async.c:321 Digit parser mod_conference: binding 7/conf/0 callback: 0x7fe1a92764e0 data: 0x7fe19010b9a0</div><div>2015-05-08 08:21:30.467711 [INFO] mod_conference.c:10967 sofia/internal/1000@xxx.xxx.xxx.xxx binding &#39;3&#39; to &#39;vol talk up&#39;</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_ivr_async.c:321 Digit parser mod_conference: binding 3/conf/0 callback: 0x7fe1a92764e0 data: 0x7fe19010b9d0</div><div>2015-05-08 08:21:30.467711 [INFO] mod_conference.c:10967 sofia/internal/1000@xxx.xxx.xxx.xxx binding &#39;2&#39; to &#39;vol talk zero&#39;</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_ivr_async.c:321 Digit parser mod_conference: binding 2/conf/0 callback: 0x7fe1a92764e0 data: 0x7fe19010ba00</div><div>2015-05-08 08:21:30.467711 [INFO] mod_conference.c:10967 sofia/internal/1000@xxx.xxx.xxx.xxx binding &#39;1&#39; to &#39;vol talk dn&#39;</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_ivr_async.c:321 Digit parser mod_conference: binding 1/conf/0 callback: 0x7fe1a92764e0 data: 0x7fe19010ba30</div><div>2015-05-08 08:21:30.467711 [INFO] mod_conference.c:10967 sofia/internal/1000@xxx.xxx.xxx.xxx binding &#39;6&#39; to &#39;vol listen up&#39;</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_ivr_async.c:321 Digit parser mod_conference: binding 6/conf/0 callback: 0x7fe1a92764e0 data: 0x7fe19010ba60</div><div>2015-05-08 08:21:30.467711 [INFO] mod_conference.c:10967 sofia/internal/1000@xxx.xxx.xxx.xxx binding &#39;5&#39; to &#39;vol listen zero&#39;</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_ivr_async.c:321 Digit parser mod_conference: binding 5/conf/0 callback: 0x7fe1a92764e0 data: 0x7fe19010ba90</div><div>2015-05-08 08:21:30.467711 [INFO] mod_conference.c:10967 sofia/internal/1000@xxx.xxx.xxx.xxx binding &#39;4&#39; to &#39;vol listen dn&#39;</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_ivr_async.c:321 Digit parser mod_conference: binding 4/conf/0 callback: 0x7fe1a92764e0 data: 0x7fe19010bac0</div><div>2015-05-08 08:21:30.467711 [INFO] mod_conference.c:10967 sofia/internal/1000@xxx.xxx.xxx.xxx binding &#39;#&#39; to &#39;hangup&#39;</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_ivr_async.c:321 Digit parser mod_conference: binding #/conf/0 callback: 0x7fe1a92764e0 data: 0x7fe19010baf0</div><div>2015-05-08 08:21:30.467711 [DEBUG] switch_core_session.c:912 Send signal sofia/internal/1000@xxx.xxx.xxx.xxx [BREAK]</div><div>2015-05-08 08:21:30.467711 [DEBUG] mod_conference.c:4765 Setup timer soft success interval: 20  samples: 960</div><div>2015-05-08 08:21:30.467711 [DEBUG] mod_conference.c:3043 Setup timer success interval: 30  samples: 480</div><div>2015-05-08 08:21:30.507713 [DEBUG] mod_local_stream.c:498 Opening Stream [moh/16000] 16000hz</div><div>2015-05-08 08:21:30.507713 [NOTICE] switch_core_io.c:1261 Activating write resampler</div><div>tport.c:2773 tport_wakeup() tport_wakeup(0x7fe17c0d4ba0): events IN</div><div>tport.c:2864 tport_recv_event() tport_recv_event(0x7fe17c0d4ba0)</div><div>tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7fe17c0d4ba0) msg 0x7fe17c0c6ab0 from (ws/<a href="http://82.166.84.247:53645">82.166.84.247:53645</a>) has 550 bytes, veclen = 1</div><div>recv 550 bytes from ws/[82.166.84.247]:53645 at 08:21:30.662998:</div><div>   ------------------------------------------------------------------------</div><div>   ACK sip:991234@xxx.xxx.xxx.xxx:5060;transport=udp SIP/2.0</div><div>   Via: SIP/2.0/WS df7jal23ls0d.invalid;branch=z9hG4bK30nT8FwJ3EqSVIbdgFvT;rport</div><div>   From: &quot;asdasda&quot;&lt;sip:1000@xxx.xxx.xxx.xxx&gt;;tag=THvNqRR9fmMzKb6JP9hp</div><div>   To: &lt;sip:991234@aaaa&gt;;tag=73aKc8ZegaUHr</div><div>   Contact: &quot;asdasda&quot;&lt;sip:1000@df7jal23ls0d.invalid;rtcweb-breaker=no;click2call=no;transport=ws&gt;;+g.oma.sip-im;language=&quot;en,fr&quot;</div><div>   Call-ID: fa0bf4d8-2037-a467-61fd-4f78e9746fbe</div><div>   CSeq: 28092 ACK</div><div>   Content-Length: 0</div><div>   Max-Forwards: 70</div><div>   User-Agent: IM-client/OMA1.0 sipML5-v1.2015.03.18</div><div>   Organization: Doubango Telecom</div><div><br></div><div>   ------------------------------------------------------------------------</div><div>tport.c:3023 tport_deliver() tport_deliver(0x7fe17c0d4ba0): msg 0x7fe17c0c6ab0 (550 bytes) from ws/<a href="http://82.166.84.247:53645/sip">82.166.84.247:53645/sip</a> next=(nil)</div><div>nta.c:2880 agent_recv_request() nta: received ACK sip:991234@xxx.xxx.xxx.xxx:5060;transport=udp SIP/2.0 (CSeq 28092)</div><div>nta.c:3174 agent_check_request_via() nta: Via check: received=82.166.84.247</div><div>nta.c:3019 agent_recv_request() nta: ACK (28092) is going to INVITE (28092)</div><div>nua_session.c:2569 process_ack_or_cancel() nua: process_ack_or_cancel: entering</div><div>soa.c:1214 soa_clear_remote_sdp() soa_clear_remote_sdp(static::0x7fe17c0bf4d0) called</div><div>nua_stack.c:271 nua_stack_event() nua(0x7fe17c0cf210): event i_ack 200 OK</div><div>nua_session.c:4139 signal_call_state_change() nua(0x7fe17c0cf210): call state changed: completed -&gt; ready</div><div>nua_stack.c:271 nua_stack_event() nua(0x7fe17c0cf210): event i_state 200 OK</div><div>nua_stack.c:271 nua_stack_event() nua(0x7fe17c0cf210): event i_active 200 Call active</div><div>nta.c:5744 incoming_free() nta: incoming_free(0x7fe17c024090)</div><div>tport.c:2296 tport_set_secondary_timer() tport(0x7fe17c0d4ba0): reset timer</div><div>nua_stack.c:359 nua_application_event() nua: nua_application_event: entering</div><div>2015-05-08 08:21:30.647708 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/1000@xxx.xxx.xxx.xxx [BREAK]</div><div>nua_stack.c:359 nua_application_event() nua: nua_application_event: entering</div><div>2015-05-08 08:21:30.647708 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/1000@xxx.xxx.xxx.xxx [BREAK]</div><div>nua_stack.c:359 nua_application_event() nua: nua_application_event: entering</div><div>2015-05-08 08:21:30.647708 [DEBUG] switch_core_session.c:1061 Send signal sofia/internal/1000@xxx.xxx.xxx.xxx [BREAK]</div><div>nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering</div><div>nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering</div><div>nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering</div><div>2015-05-08 08:21:30.667707 [DEBUG] sofia.c:6627 Channel sofia/internal/1000@xxx.xxx.xxx.xxx entering state [ready][200]</div><div>nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering</div><div>nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering</div><div>nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering</div><div>nta.c:1289 agent_timer() nta: timer not set</div><div>2015-05-08 08:21:48.307689 [NOTICE] switch_rtp.c:1133 Auto Changing stun/rtp/dtls port from <a href="http://82.166.84.247:63888">82.166.84.247:63888</a> to <a href="http://130.211.78.35:58209">130.211.78.35:58209</a></div><div>2015-05-08 08:22:02.047711 [INFO] switch_rtp.c:2924 Changing audio DTLS state from HANDSHAKE to SETUP</div><div>2015-05-08 08:22:02.047711 [INFO] switch_rtp.c:2832 audio Fingerprint Verified.</div><div>2015-05-08 08:22:02.047711 [INFO] switch_rtp.c:3374 Activating Audio Secure RTP SEND</div><div>2015-05-08 08:22:02.047711 [INFO] switch_rtp.c:3352 Activating Audio Secure RTP RECV</div><div>2015-05-08 08:22:02.047711 [INFO] switch_rtp.c:2872 Changing audio DTLS state from SETUP to READY</div><div>2015-05-08 08:22:02.047711 [DEBUG] switch_core_sqldb.c:2599 Secure Type: srtp:dtls:AES_CM_128_HMAC_SHA1_80</div><div>2015-05-08 08:22:02.047711 [DEBUG] switch_core_sqldb.c:2599 Secure Type: srtp:dtls:AES_CM_128_HMAC_SHA1_80</div><div>2015-05-08 08:22:02.087708 [DEBUG] switch_rtp.c:1937 rtcp_stats_init: ssrc[-195423717] base_seq[29507]</div></div><div><br></div><div>Notice that the INVITE was received at 08:21:30 while DTLS was READY at 2015-05-08 08:22:02 which means that it took 32 seconds to voice. Again, if I am not using TURN/STUN, the whole process is pretty quick (2 seconds).</div><div><br></div><div>Also, notice:</div><div>2015-05-08 08:21:48.307689 [NOTICE] switch_rtp.c:1133 Auto Changing stun/rtp/dtls port from <a href="http://82.166.84.247:63888">82.166.84.247:63888</a> to <a href="http://130.211.78.35:58209">130.211.78.35:58209</a><br></div><div><br></div><div>Which means that the media is relayed via the TURN server (TURN server IP is 130.211.78.35)...</div><div><br></div><div>Any idea?</div><div><br></div><div>Thanks,</div><div>Adam</div></div>