[Freeswitch-users] WebRTC connection delay (Auto Changing stun/rtp/dtls port from)

[Adam Ben-Ayoun]

Hi guys,

We are using Freeswitch as an MCU for WebRTC (only for audio conferences),
most of the times connecting from our WebRTC client is pretty quick,
however, on some WiFi's (probably with a certain NAT/topology), the audio
connection can take up to 10sec to initialize when using STUN and TURN, we
also see there are differences on the Freeswitch logs when it happens:

2015-02-22 21:06:25.920612 [NOTICE] switch_rtp.c:1151 Auto Changing
stun/rtp/dtls port from 67.180.21.132:59854 to 166.170.42.141:40334
2015-02-22 21:06:25.960618 [NOTICE] switch_rtp.c:1151 Auto Changing
stun/rtp/dtls port from 166.170.42.141:40334 to 67.180.21.132:59854
2015-02-22 21:06:26.080616 [NOTICE] switch_rtp.c:1151 Auto Changing
stun/rtp/dtls port from 67.180.21.132:59854 to 54.187.44.182:53379
2015-02-22 21:06:26.680617 [NOTICE] switch_rtp.c:1151 Auto Changing
stun/rtp/dtls port from 54.187.44.182:53379 to 166.170.42.141:40334
2015-02-22 21:06:27.040614 [NOTICE] switch_rtp.c:1151 Auto Changing
stun/rtp/dtls port from 166.170.42.141:40334 to 67.180.21.132:59854
2015-02-22 21:06:27.880612 [NOTICE] switch_rtp.c:1151 Auto Changing
stun/rtp/dtls port from 67.180.21.132:59854 to 166.170.42.141:40334
2015-02-22 21:06:28.020610 [NOTICE] switch_rtp.c:1151 Auto Changing
stun/rtp/dtls port from 166.170.42.141:40334 to 67.180.21.132:59854
2015-02-22 21:06:28.600614 [NOTICE] switch_rtp.c:1151 Auto Changing
stun/rtp/dtls port from 67.180.21.132:59854 to 166.170.42.141:40334
2015-02-22 21:06:28.980603 [NOTICE] switch_rtp.c:1151 Auto Changing
stun/rtp/dtls port from 166.170.42.141:40334 to 67.180.21.132:59854
2015-02-22 21:06:29.560612 [NOTICE] switch_rtp.c:1151 Auto Changing
stun/rtp/dtls port from 67.180.21.132:59854 to 166.170.42.141:40334
2015-02-22 21:06:29.940602 [NOTICE] switch_rtp.c:1151 Auto Changing
stun/rtp/dtls port from 166.170.42.141:40334 to 67.180.21.132:59854
2015-02-22 21:06:30.540561 [NOTICE] switch_rtp.c:1151 Auto Changing
stun/rtp/dtls port from 67.180.21.132:59854 to 166.170.42.141:40334
2015-02-22 21:06:30.940606 [NOTICE] switch_rtp.c:1151 Auto Changing
stun/rtp/dtls port from 166.170.42.141:40334 to 67.180.21.132:59854
2015-02-22 21:06:31.500595 [NOTICE] switch_rtp.c:1151 Auto Changing
stun/rtp/dtls port from 67.180.21.132:59854 to 166.170.42.141:40334
2015-02-22 21:06:31.900613 [NOTICE] switch_rtp.c:1151 Auto Changing
stun/rtp/dtls port from 166.170.42.141:40334 to 67.180.21.132:59854
2015-02-22 21:06:32.460602 [NOTICE] switch_rtp.c:1151 Auto Changing
stun/rtp/dtls port from 67.180.21.132:59854 to 166.170.42.141:40334
2015-02-22 21:06:32.860614 [NOTICE] switch_rtp.c:1151 Auto Changing
stun/rtp/dtls port from 166.170.42.141:40334 to 67.180.21.132:59854
2015-02-22 21:06:33.040612 [INFO] switch_rtp.c:2926 Changing audio DTLS
state from HANDSHAKE to SETUP
2015-02-22 21:06:33.040612 [INFO] switch_rtp.c:2834 audio Fingerprint
Verified.
2015-02-22 21:06:33.040612 [INFO] switch_rtp.c:3376 Activating Audio Secure
RTP SEND
2015-02-22 21:06:33.040612 [INFO] switch_rtp.c:3354 Activating Audio Secure
RTP RECV
2015-02-22 21:06:33.040612 [DEBUG] switch_core_sqldb.c:2599 Secure Type:
srtp:dtls:AES_CM_128_HMAC_SHA1_80
2015-02-22 21:06:33.040612 [INFO] switch_rtp.c:2874 Changing audio DTLS
state from SETUP to READY
2015-02-22 21:06:33.040612 [DEBUG] switch_core_sqldb.c:2599 Secure Type:
srtp:dtls:AES_CM_128_HMAC_SHA1_80
2015-02-22 21:06:33.100606 [DEBUG] switch_rtp.c:1954 rtcp_stats_init:
ssrc[-1706748029] base_seq[28893]


X.X.X.X is the IP of our TURN server, now, it seems like although we have a
good reflexive candidate, it takes some time for Freeswitch to pick it up
and it actually tries to use the relay (TURN)... Any idea what is happening
and what we can do to solve that?

Here are the ICE candidates from the client SDP:
a=candidate:1780409101 1 udp 2122063615 192.168.15.3 56494 typ host
generation 0
a=candidate:1780409101 2 udp 2122063615 192.168.15.3 56494 typ host
generation 0
a=candidate:4043381328 1 udp 2122129151 10.159.103.156 51485 typ host
generation 0
a=candidate:4043381328 2 udp 2122129151 10.159.103.156 51485 typ host
generation 0
a=candidate:2618202841 1 udp 1685855999 67.180.21.132 56494 typ srflx raddr
192.168.15.3 rport 56494 generation 0
a=candidate:2618202841 2 udp 1685855999 67.180.21.132 56494 typ srflx raddr
192.168.15.3 rport 56494 generation 0
a=candidate:614277117 1 tcp 1518083839 192.168.15.3 54312 typ host tcptype
passive generation 0
a=candidate:614277117 2 tcp 1518083839 192.168.15.3 54312 typ host tcptype
passive generation 0
a=candidate:3213026976 1 tcp 1518149375 10.159.103.156 54313 typ host
tcptype passive generation 0
a=candidate:3213026976 2 tcp 1518149375 10.159.103.156 54313 typ host
tcptype passive generation 0
a=candidate:3054806047 1 udp 24911615 X.X.X.X 65452 typ relay raddr
67.180.21.132 rport 54310 generation 0
a=candidate:3054806047 2 udp 24911615 X.X.X.X 65452 typ relay raddr
67.180.21.132 rport 54310 generation 0
a=candidate:1032594883 1 udp 1685921535 166.170.42.141 64296 typ srflx
raddr 10.159.103.156 rport 51485 generation 0
a=candidate:1032594883 2 udp 1685921535 166.170.42.141 64296 typ srflx
raddr 10.159.103.156 rport 51485 generation 0
a=candidate:3054806047 1 udp 24977151 X.X.X.X 49737 typ relay raddr
166.170.42.141 rport 56009 generation 0
a=candidate:3054806047 2 udp 24977151 X.X.X.X 49737 typ relay raddr
166.170.42.141 rport 56009 generation 0

Thanks,
Adam
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20150222/d6468e1a/attachment-0001.html