COTURN + Kurento MediaServer Trickle IceConnectionState "Connected" on one tab and "Checking" on the other

Viewed 381

I've been working on this project for a while now and have no other solution but to turn to you guys. I setup a STUN/TURN on Azure VM. The setup of the server is as follow:

listening-port=3478
tls-listening-port=5349
fingerprint
user=user:pass
lt-cred-mech
realm=kurento.org
log-file=/var/log/turnserver.log
verbose
external-ip=<Public_IP>

On the VM on which KMS runs, I configured the file :

/etc/kurento/modules/kurento/WebRtcEndpoint.conf.ini

With these modifications :

stunServerAddress=<public_ip>
stunServerPort=3478
turnURL=user:pass@<public_ip>:3478

In the client , I setup the RTCPeerClient with these options before getting the user media and creating the offer.

const configuration:
RTCConfiguration
= {"iceServers": [
        {
            urls:['turn:<public_ip_VM>:3478'],  
            username: "user",
            credential: "pass"
        },
        {urls:['stun:<public_ip_VM>']},
    ],
    iceTransportPolicy: "all"
};

I then join a call in one browser and join on another.

Here are the complete logs for the first browser that joins the communication:

WebSocket is opened
CallScreen.tsx:220 RTCSessionDescription {type: "offer", sdp: "v=0
↵o=- 635656127645712694 2 IN IP4 127.0.0.1
↵s=…
↵a=fmtp:119 apt=124
↵a=rtpmap:123 ulpfec/90000
↵"}
CallScreen.tsx:229 Message Conn: {ConnectionInfo: {…}, Action: "Join", sdpOffer: RTCSessionDescription}
CallScreen.tsx:91 ICE Candidate Found: RTCIceCandidate {candidate: "candidate:2686451073 1 udp 2122262783 2a02:a03f:61…eration 0 ufrag 3hQF network-id 2 network-cost 10", sdpMid: "0", sdpMLineIndex: 0, foundation: "2686451073", component: "rtp", …}
index.js:1 ERROR GATHERING ICE CANDIDATES ==>  RTCPeerConnectionIceErrorEvent {isTrusted: true, address: "[2a02:a03f:61c4:x:x:x:x:x]", port: 35184, hostCandidate: "[2a02:a03f:61c4:x:x:x:x:x]:35184", url: "stun:52.165.30.212:3478", …}
console.<computed> @ index.js:1
CallScreen.webRtcPeer.onicecandidateerror @ CallScreen.tsx:46
index.js:1 [Deprecation] 
console.<computed> @ index.js:1
CallScreen.webRtcPeer.onicecandidateerror @ CallScreen.tsx:46
CallScreen.tsx:91 ICE Candidate Found: RTCIceCandidate {candidate: "candidate:2447636755 1 udp 2122194687 192.168.1.42…eration 0 ufrag 3hQF network-id 1 network-cost 10", sdpMid: "0", sdpMLineIndex: 0, foundation: "2447636755", component: "rtp", …}
CallScreen.tsx:91 ICE Candidate Found: RTCIceCandidate {candidate: "candidate:4003201393 1 tcp 1518283007 2a02:a03f:61…eration 0 ufrag 3hQF network-id 2 network-cost 10", sdpMid: "0", sdpMLineIndex: 0, foundation: "4003201393", component: "rtp", …}
CallScreen.tsx:91 ICE Candidate Found: RTCIceCandidate {candidate: "candidate:3747612131 1 tcp 1518214911 192.168.1.42…eration 0 ufrag 3hQF network-id 1 network-cost 10", sdpMid: "0", sdpMLineIndex: 0, foundation: "3747612131", component: "rtp", …}
CallScreen.tsx:91 ICE Candidate Found: RTCIceCandidate {candidate: "candidate:1744011463 1 udp 1685987071 109.136.191.…eration 0 ufrag 3hQF network-id 1 network-cost 10", sdpMid: "0", sdpMLineIndex: 0, foundation: "1744011463", component: "rtp", …}
CallScreen.tsx:91 ICE Candidate Found: RTCIceCandidate {candidate: "candidate:3687200995 1 udp 41819903 52.165.30.212 …eration 0 ufrag 3hQF network-id 1 network-cost 10", sdpMid: "0", sdpMLineIndex: 0, foundation: "3687200995", component: "rtp", …}
CallScreen.tsx:91 ICE Candidate Found: null
CallScreen.tsx:107 Received all Ice Candidates
CallScreen.tsx:135 Received Message: {"id":"callStatus","response":"accepted","sdpAnswer":"v=0\r\no=- 3820652736 3820652736 IN IP4 0.0.0.0\r\ns=Kurento Media Server\r\nc=IN IP4 0.0.0.0\r\nt=0 0\r\na=msid-semantic: WMS\r\na=group:BUNDLE 0\r\nm=video 1 UDP/TLS/RTP/SAVPF 96 102 127 125 108\r\na=extmap:2 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time\r\na=sendonly\r\na=mid:0\r\na=rtcp:9 IN IP4 0.0.0.0\r\na=rtpmap:96 VP8/90000\r\na=rtpmap:102 H264/90000\r\na=rtpmap:127 H264/90000\r\na=rtpmap:125 H264/90000\r\na=rtpmap:108 H264/90000\r\na=rtcp-fb:96 goog-remb\r\na=rtcp-fb:96 ccm fir\r\na=rtcp-fb:96 nack\r\na=rtcp-fb:96 nack pli\r\na=rtcp-fb:102 goog-remb\r\na=rtcp-fb:102 ccm fir\r\na=rtcp-fb:102 nack\r\na=rtcp-fb:102 nack pli\r\na=rtcp-fb:127 goog-remb\r\na=rtcp-fb:127 ccm fir\r\na=rtcp-fb:127 nack\r\na=rtcp-fb:127 nack pli\r\na=rtcp-fb:125 goog-remb\r\na=rtcp-fb:125 ccm fir\r\na=rtcp-fb:125 nack\r\na=rtcp-fb:125 nack pli\r\na=rtcp-fb:108 goog-remb\r\na=rtcp-fb:108 ccm fir\r\na=rtcp-fb:108 nack\r\na=rtcp-fb:108 nack pli\r\na=setup:active\r\na=rtcp-mux\r\na=fmtp:102 level-asymmetry-allowed=1;packetization-mode=1;profile-level-id=42001f\r\na=fmtp:127 level-asymmetry-allowed=1;packetization-mode=0;profile-level-id=42001f\r\na=fmtp:125 level-asymmetry-allowed=1;packetization-mode=1;profile-level-id=42e01f\r\na=fmtp:108 level-asymmetry-allowed=1;packetization-mode=0;profile-level-id=42e01f\r\na=ssrc:3755615383 cname:user1459207244@host-ffbb510\r\na=ice-ufrag:lapS\r\na=ice-pwd:vEblLRMQWUGRqiExBV9mXm\r\na=fingerprint:sha-256 CC:CF:1F:DB:38:36:4F:7A:F3:71:D9:46:10:43:37:C1:BE:90:FB:D6:C9:45:2D:B0:1B:40:2C:B5:74:00:2A:84\r\n"}
CallScreen.tsx:75 Remote Stream Added: MediaStream {id: "default", active: true, onaddtrack: null, onremovetrack: null, onactive: null, …}
CallScreen.tsx:146 Remote sdp successfully set:  {sdp: "v=0
↵o=- 3820652736 3820652736 IN IP4 0.0.0.0
↵s=K…BE:90:FB:D6:C9:45:2D:B0:1B:40:2C:B5:74:00:2A:84
↵", type: "answer"}
CallScreen.tsx:135 Received Message: {"id":"iceCandidate","candidate":{"candidate":"candidate:3 1 TCP 1010827519 10.0.2.5 45037 typ host tcptype passive","sdpMid":"0","sdpMLineIndex":0}}
CallScreen.tsx:53 ICE Connection State Changed:  checking
CallScreen.tsx:54 Event {isTrusted: true, type: "iceconnectionstatechange", target: RTCPeerConnection, currentTarget: RTCPeerConnection, eventPhase: 2, …}
CallScreen.tsx:135 Received Message: {"id":"iceCandidate","candidate":{"candidate":"candidate:6 2 TCP 1010827774 fe80::20d:3aff:fea6:612b 2023 typ host tcptype passive","sdpMid":"0","sdpMLineIndex":0}}
CallScreen.tsx:135 Received Message: {"id":"iceCandidate","candidate":{"candidate":"candidate:5 2 TCP 1015022078 fe80::20d:3aff:fea6:612b 9 typ host tcptype active","sdpMid":"0","sdpMLineIndex":0}}
CallScreen.tsx:135 Received Message: {"id":"iceCandidate","candidate":{"candidate":"candidate:4 2 UDP 2015363582 fe80::20d:3aff:fea6:612b 51592 typ host","sdpMid":"0","sdpMLineIndex":0}}
CallScreen.tsx:135 Received Message: {"id":"iceCandidate","candidate":{"candidate":"candidate:3 2 TCP 1010827518 10.0.2.5 43244 typ host tcptype passive","sdpMid":"0","sdpMLineIndex":0}}
CallScreen.tsx:135 Received Message: {"id":"iceCandidate","candidate":{"candidate":"candidate:2 2 TCP 1015021822 10.0.2.5 9 typ host tcptype active","sdpMid":"0","sdpMLineIndex":0}}
CallScreen.tsx:135 Received Message: {"id":"iceCandidate","candidate":{"candidate":"candidate:1 2 UDP 2015363326 10.0.2.5 9993 typ host","sdpMid":"0","sdpMLineIndex":0}}
CallScreen.tsx:135 Received Message: {"id":"iceCandidate","candidate":{"candidate":"candidate:6 1 TCP 1010827775 fe80::20d:3aff:fea6:612b 17406 typ host tcptype passive","sdpMid":"0","sdpMLineIndex":0}}
CallScreen.tsx:135 Received Message: {"id":"iceCandidate","candidate":{"candidate":"candidate:5 1 TCP 1015022079 fe80::20d:3aff:fea6:612b 9 typ host tcptype active","sdpMid":"0","sdpMLineIndex":0}}
CallScreen.tsx:135 Received Message: {"id":"iceCandidate","candidate":{"candidate":"candidate:4 1 UDP 2015363583 fe80::20d:3aff:fea6:612b 46945 typ host","sdpMid":"0","sdpMLineIndex":0}}
CallScreen.tsx:135 Received Message: {"id":"iceCandidate","candidate":{"candidate":"candidate:2 1 TCP 1015021823 10.0.2.5 9 typ host tcptype active","sdpMid":"0","sdpMLineIndex":0}}
CallScreen.tsx:135 Received Message: {"id":"iceCandidate","candidate":{"candidate":"candidate:1 1 UDP 2015363327 10.0.2.5 50941 typ host","sdpMid":"0","sdpMLineIndex":0}}
CallScreen.tsx:135 Received Message: {"id":"iceCandidate","candidate":{"candidate":"candidate:9 1 TCP 843055359 52.165.30.212 45037 typ srflx raddr 10.0.2.5 rport 45037 tcptype passive","sdpMid":"0","sdpMLineIndex":0}}
CallScreen.tsx:135 Received Message: {"id":"iceCandidate","candidate":{"candidate":"candidate:8 1 TCP 847249663 52.165.30.212 9 typ srflx raddr 10.0.2.5 rport 9 tcptype active","sdpMid":"0","sdpMLineIndex":0}}
CallScreen.tsx:135 Received Message: {"id":"iceCandidate","candidate":{"candidate":"candidate:7 1 UDP 1679819007 52.165.30.212 50941 typ srflx raddr 10.0.2.5 rport 50941","sdpMid":"0","sdpMLineIndex":0}}
CallScreen.tsx:135 Received Message: {"id":"iceCandidate","candidate":{"candidate":"candidate:10 1 UDP 505413887 52.165.30.212 50898 typ relay raddr 10.0.2.5 rport 50941","sdpMid":"0","sdpMLineIndex":0}}
CallScreen.tsx:53 ICE Connection State Changed:  disconnected
CallScreen.tsx:54 Event {isTrusted: true, type: "iceconnectionstatechange", target: RTCPeerConnection, currentTarget: RTCPeerConnection, eventPhase: 2, …}

You can see that the iceconnectionchanged results in a state of "checking" Whereas in the second tab that I join the call session on :

WebSocket is opened
CallScreen.tsx:220 RTCSessionDescription {type: "offer", sdp: "v=0
↵o=- 4700503829836937653 2 IN IP4 127.0.0.1
↵s…
↵a=fmtp:119 apt=124
↵a=rtpmap:123 ulpfec/90000
↵"}
CallScreen.tsx:229 Message Conn: {ConnectionInfo: {…}, Action: "Join", sdpOffer: RTCSessionDescription}
CallScreen.tsx:91 ICE Candidate Found: RTCIceCandidate {candidate: "candidate:2686451073 1 udp 2122262783 2a02:a03f:61…eration 0 ufrag oexL network-id 2 network-cost 10", sdpMid: "0", sdpMLineIndex: 0, foundation: "2686451073", component: "rtp", …}
index.js:1 ERROR GATHERING ICE CANDIDATES ==>  RTCPeerConnectionIceErrorEvent {isTrusted: true, address: "[2a02:a03f:61c4:x:x:x:x:x]", port: 39827, hostCandidate: "[2a02:a03f:61c4:x:x:x:x:x]:39827", url: "stun:52.165.30.212:3478", …}
console.<computed> @ index.js:1
CallScreen.webRtcPeer.onicecandidateerror @ CallScreen.tsx:46
index.js:1 [Deprecation] 
console.<computed> @ index.js:1
CallScreen.webRtcPeer.onicecandidateerror @ CallScreen.tsx:46
CallScreen.tsx:91 ICE Candidate Found: RTCIceCandidate {candidate: "candidate:2447636755 1 udp 2122194687 192.168.1.42…eration 0 ufrag oexL network-id 1 network-cost 10", sdpMid: "0", sdpMLineIndex: 0, foundation: "2447636755", component: "rtp", …}
CallScreen.tsx:91 ICE Candidate Found: RTCIceCandidate {candidate: "candidate:4003201393 1 tcp 1518283007 2a02:a03f:61…eration 0 ufrag oexL network-id 2 network-cost 10", sdpMid: "0", sdpMLineIndex: 0, foundation: "4003201393", component: "rtp", …}
CallScreen.tsx:91 ICE Candidate Found: RTCIceCandidate {candidate: "candidate:3747612131 1 tcp 1518214911 192.168.1.42…eration 0 ufrag oexL network-id 1 network-cost 10", sdpMid: "0", sdpMLineIndex: 0, foundation: "3747612131", component: "rtp", …}
CallScreen.tsx:91 ICE Candidate Found: RTCIceCandidate {candidate: "candidate:1744011463 1 udp 1685987071 109.136.191.…eration 0 ufrag oexL network-id 1 network-cost 10", sdpMid: "0", sdpMLineIndex: 0, foundation: "1744011463", component: "rtp", …}
CallScreen.tsx:135 Received Message: {"id":"callStatus","response":"accepted","sdpAnswer":"v=0\r\no=- 3820652736 3820652736 IN IP4 0.0.0.0\r\ns=Kurento Media Server\r\nc=IN IP4 0.0.0.0\r\nt=0 0\r\na=msid-semantic: WMS\r\na=group:BUNDLE 0\r\nm=video 1 UDP/TLS/RTP/SAVPF 96 102 127 125 108\r\na=extmap:2 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time\r\na=sendonly\r\na=mid:0\r\na=rtcp:9 IN IP4 0.0.0.0\r\na=rtpmap:96 VP8/90000\r\na=rtpmap:102 H264/90000\r\na=rtpmap:127 H264/90000\r\na=rtpmap:125 H264/90000\r\na=rtpmap:108 H264/90000\r\na=rtcp-fb:96 goog-remb\r\na=rtcp-fb:96 ccm fir\r\na=rtcp-fb:96 nack\r\na=rtcp-fb:96 nack pli\r\na=rtcp-fb:102 goog-remb\r\na=rtcp-fb:102 ccm fir\r\na=rtcp-fb:102 nack\r\na=rtcp-fb:102 nack pli\r\na=rtcp-fb:127 goog-remb\r\na=rtcp-fb:127 ccm fir\r\na=rtcp-fb:127 nack\r\na=rtcp-fb:127 nack pli\r\na=rtcp-fb:125 goog-remb\r\na=rtcp-fb:125 ccm fir\r\na=rtcp-fb:125 nack\r\na=rtcp-fb:125 nack pli\r\na=rtcp-fb:108 goog-remb\r\na=rtcp-fb:108 ccm fir\r\na=rtcp-fb:108 nack\r\na=rtcp-fb:108 nack pli\r\na=setup:active\r\na=rtcp-mux\r\na=fmtp:102 level-asymmetry-allowed=1;packetization-mode=1;profile-level-id=42001f\r\na=fmtp:127 level-asymmetry-allowed=1;packetization-mode=0;profile-level-id=42001f\r\na=fmtp:125 level-asymmetry-allowed=1;packetization-mode=1;profile-level-id=42e01f\r\na=fmtp:108 level-asymmetry-allowed=1;packetization-mode=0;profile-level-id=42e01f\r\na=ssrc:3432352628 cname:user1173761955@host-61d2b2cc\r\na=ice-ufrag:2qt5\r\na=ice-pwd:VVCpYq3BJe70fPIM8mdrPe\r\na=fingerprint:sha-256 CC:CF:1F:DB:38:36:4F:7A:F3:71:D9:46:10:43:37:C1:BE:90:FB:D6:C9:45:2D:B0:1B:40:2C:B5:74:00:2A:84\r\n"}
CallScreen.tsx:75 Remote Stream Added: MediaStream {id: "default", active: true, onaddtrack: null, onremovetrack: null, onactive: null, …}
CallScreen.tsx:146 Remote sdp successfully set:  {sdp: "v=0
↵o=- 3820652736 3820652736 IN IP4 0.0.0.0
↵s=K…BE:90:FB:D6:C9:45:2D:B0:1B:40:2C:B5:74:00:2A:84
↵", type: "answer"}
CallScreen.tsx:91 ICE Candidate Found: RTCIceCandidate {candidate: "candidate:3687200995 1 udp 41819903 52.165.30.212 …eration 0 ufrag oexL network-id 1 network-cost 10", sdpMid: "0", sdpMLineIndex: 0, foundation: "3687200995", component: "rtp", …}
CallScreen.tsx:91 ICE Candidate Found: null
CallScreen.tsx:107 Received all Ice Candidates
CallScreen.tsx:123 Sending Message Ice Candidate:  {ConnectionInfo: {…}, Action: "onIceCandidate", candidate: RTCIceCandidate}
CallScreen.tsx:123 Sending Message Ice Candidate:  {ConnectionInfo: {…}, Action: "onIceCandidate", candidate: RTCIceCandidate}
CallScreen.tsx:123 Sending Message Ice Candidate:  {ConnectionInfo: {…}, Action: "onIceCandidate", candidate: RTCIceCandidate}
CallScreen.tsx:123 Sending Message Ice Candidate:  {ConnectionInfo: {…}, Action: "onIceCandidate", candidate: RTCIceCandidate}
CallScreen.tsx:123 Sending Message Ice Candidate:  {ConnectionInfo: {…}, Action: "onIceCandidate", candidate: RTCIceCandidate}
CallScreen.tsx:123 Sending Message Ice Candidate:  {ConnectionInfo: {…}, Action: "onIceCandidate", candidate: RTCIceCandidate}
CallScreen.tsx:135 Received Message: {"id":"iceCandidate","candidate":{"candidate":"candidate:2 1 TCP 1015021823 10.0.2.5 9 typ host tcptype active","sdpMid":"0","sdpMLineIndex":0}}
CallScreen.tsx:135 Received Message: {"id":"iceCandidate","candidate":{"candidate":"candidate:5 1 TCP 1015022079 fe80::20d:3aff:fea6:612b 9 typ host tcptype active","sdpMid":"0","sdpMLineIndex":0}}
CallScreen.tsx:135 Received Message: {"id":"iceCandidate","candidate":{"candidate":"candidate:3 1 TCP 1010827519 10.0.2.5 35980 typ host tcptype passive","sdpMid":"0","sdpMLineIndex":0}}
CallScreen.tsx:135 Received Message: {"id":"iceCandidate","candidate":{"candidate":"candidate:4 1 UDP 2015363583 fe80::20d:3aff:fea6:612b 24009 typ host","sdpMid":"0","sdpMLineIndex":0}}
CallScreen.tsx:135 Received Message: {"id":"iceCandidate","candidate":{"candidate":"candidate:1 2 UDP 2015363326 10.0.2.5 5018 typ host","sdpMid":"0","sdpMLineIndex":0}}
CallScreen.tsx:135 Received Message: {"id":"iceCandidate","candidate":{"candidate":"candidate:6 1 TCP 1010827775 fe80::20d:3aff:fea6:612b 48841 typ host tcptype passive","sdpMid":"0","sdpMLineIndex":0}}
CallScreen.tsx:135 Received Message: {"id":"iceCandidate","candidate":{"candidate":"candidate:1 1 UDP 2015363327 10.0.2.5 63778 typ host","sdpMid":"0","sdpMLineIndex":0}}
CallScreen.tsx:135 Received Message: {"id":"iceCandidate","candidate":{"candidate":"candidate:2 2 TCP 1015021822 10.0.2.5 9 typ host tcptype active","sdpMid":"0","sdpMLineIndex":0}}
CallScreen.tsx:53 ICE Connection State Changed:  checking
CallScreen.tsx:54 Event {isTrusted: true, type: "iceconnectionstatechange", target: RTCPeerConnection, currentTarget: RTCPeerConnection, eventPhase: 2, …}
CallScreen.tsx:135 Received Message: {"id":"iceCandidate","candidate":{"candidate":"candidate:5 2 TCP 1015022078 fe80::20d:3aff:fea6:612b 9 typ host tcptype active","sdpMid":"0","sdpMLineIndex":0}}
CallScreen.tsx:135 Received Message: {"id":"iceCandidate","candidate":{"candidate":"candidate:3 2 TCP 1010827518 10.0.2.5 2472 typ host tcptype passive","sdpMid":"0","sdpMLineIndex":0}}
CallScreen.tsx:135 Received Message: {"id":"iceCandidate","candidate":{"candidate":"candidate:4 2 UDP 2015363582 fe80::20d:3aff:fea6:612b 46023 typ host","sdpMid":"0","sdpMLineIndex":0}}
CallScreen.tsx:135 Received Message: {"id":"iceCandidate","candidate":{"candidate":"candidate:7 1 UDP 1679819007 52.165.30.212 63778 typ srflx raddr 10.0.2.5 rport 63778","sdpMid":"0","sdpMLineIndex":0}}
CallScreen.tsx:135 Received Message: {"id":"iceCandidate","candidate":{"candidate":"candidate:6 2 TCP 1010827774 fe80::20d:3aff:fea6:612b 21311 typ host tcptype passive","sdpMid":"0","sdpMLineIndex":0}}
CallScreen.tsx:135 Received Message: {"id":"iceCandidate","candidate":{"candidate":"candidate:8 1 TCP 847249663 52.165.30.212 9 typ srflx raddr 10.0.2.5 rport 9 tcptype active","sdpMid":"0","sdpMLineIndex":0}}
CallScreen.tsx:135 Received Message: {"id":"iceCandidate","candidate":{"candidate":"candidate:9 1 TCP 843055359 52.165.30.212 35980 typ srflx raddr 10.0.2.5 rport 35980 tcptype passive","sdpMid":"0","sdpMLineIndex":0}}
CallScreen.tsx:135 Received Message: {"id":"iceCandidate","candidate":{"candidate":"candidate:10 1 UDP 505413887 52.165.30.212 56391 typ relay raddr 10.0.2.5 rport 63778","sdpMid":"0","sdpMLineIndex":0}}
CallScreen.tsx:53 ICE Connection State Changed:  connected
CallScreen.tsx:54 Event {isTrusted: true, type: "iceconnectionstatechange", target: RTCPeerConnection, currentTarget: RTCPeerConnection, eventPhase: 2, …}

You can see that I receive all the candidates. The communication is set up. I even receive the MediaStream from the other browser when the "ontack" triggers. The problem is there is never video being shared on the network and The iceconnectionchanged event on the first browser tab gives me a state of "checking". It ultimately ends up in a state "disconnected" after a while. Whereas the second one gives me a state of "connected".

0 Answers
Related