Mixedreality-webrtc: Can't get fired IceCandidateReadytoSend and LocalSdpReadytoSend on PeerConnection

[giansimo]

I'm trying to develop an assistance remote software based on release/1.0 in which a web-client sends an offer by means of a socket communication on a server developed with Node.js.
So far I managed to receive offer and IceCandidates from the web-client but I can't get IceCandidateReadytoSend and LocalSdpReadytoSend events fired in order to create and send back the IceCandidates.
What/where could be the issue?!

[giansimo]

More info: when I get the offer by the socket in the below function, res value is true but no LocalSdpReadytoSend is created.

        Debug.Log("[SocketIO] Offer Received event received: " + e.name + " " + e.data);
        JSONObject json = (JSONObject)e.data;
        var sdp = "" + json.GetField("sdp");

        if (peerConnection.Peer != null) { 
            peerConnection.Peer.SetRemoteDescription("offer", sdp);
            bool res = peerConnection.Peer.CreateAnswer();
            Debug.Log("[SocketIO] " + res.ToString());
        }
        Debug.Log("[SocketIO] OnOfferReceivedEnded");

Moreover, when I correctly receive IceCandidates in the below function and I try to set these candidates to my local peerConnection, I cannot even get printed the last Debug.Log line

        Debug.Log("[SocketIO] Ice event received: " + e.name + " " + e.data);
        string label = "" + json.GetField("label");
        string id = "" + json.GetField("id");
        string candidate = "" + json.GetField("candidate");
        Debug.Log("[SocketIO] \nCandidate: " + candidate + "\nLabel: " + label + "\nID:" + id);
        if (peerConnection.Peer != null)
        {
            peerConnection.Peer.AddIceCandidate(label, int.Parse(id), candidate);
        }
        Debug.Log("[SocketIO] Ice event received ended: ");

[djee-ms]

Hi @giansimo,

When something like CreateOffer() / CreateAnswer() / AddIceCandidate() fails, it generally means the method was called in a state where the peer connection didn't expect it to be.

This is not very intuitive but in your call to CreateAnswer(), the res = true means the internal task which will create the offer has successfully been submitted. After that, the answer creation occurs in the background, and can still fail itself. I admit this is poorly logged, so is difficult to debug.

For the AddIceCandidate(), if the Debug.Log is not reached, it means either an exception was thrown or a Debug.Assert() hit internally. Can you please paste a sample ICE candidate to see if it looks correct?

[HyperLethalVector]

Hi there!

Since I pulled this morning I'm encountering the same issues,
Here's the SDP message (which was working before I pulled)
{"sdp":"v=0\r\no=- 7406922622716167042 2 IN IP4 127.0.0.1\r\ns=-\r\nt=0 0\r\na=group:BUNDLE 0 1 2\r\na=msid-semantic: WMS stream_label\r\nm=audio 9 UDP/TLS/RTP/SAVPF 111 103 104 9 102 0 8 106 105 13 110 112 113 126\r\nc=IN IP4 0.0.0.0\r\na=rtcp:9 IN IP4 0.0.0.0\r\na=ice-ufrag:O57r\r\na=ice-pwd:V82DXgyESlE0Ror9WfhIvTV+\r\na=ice-options:trickle\r\na=fingerprint:sha-256 91:94:D6:EB:ED:DC:57:81:96:65:19:23:59:5E:0E:60:20:E0:03:EF:40:90:95:72:1F:1D:F4:B4:F4:A0:B6:75\r\na=setup:actpass\r\na=mid:0\r\na=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level\r\na=extmap:9 urn:ietf:params:rtp-hdrext:sdes:mid\r\na=sendrecv\r\na=msid:stream_label audio_label\r\na=rtcp-mux\r\na=rtpmap:111 opus/48000/2\r\na=rtcp-fb:111 transport-cc\r\na=fmtp:111 minptime=10;useinbandfec=1\r\na=rtpmap:103 ISAC/16000\r\na=rtpmap:104 ISAC/32000\r\na=rtpmap:9 G722/8000\r\na=rtpmap:102 ILBC/8000\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:8 PCMA/8000\r\na=rtpmap:106 CN/32000\r\na=rtpmap:105 CN/16000\r\na=rtpmap:13 CN/8000\r\na=rtpmap:110 telephone-event/48000\r\na=rtpmap:112 telephone-event/32000\r\na=rtpmap:113 telephone-event/16000\r\na=rtpmap:126 telephone-event/8000\r\na=ssrc:2065542750 cname:RyCnkrKJbtTTm9BB\r\na=ssrc:2065542750 msid:stream_label audio_label\r\na=ssrc:2065542750 mslabel:stream_label\r\na=ssrc:2065542750 label:audio_label\r\nm=video 9 UDP/TLS/RTP/SAVPF 96 97 98 99 100 101 127\r\nc=IN IP4 0.0.0.0\r\na=rtcp:9 IN IP4 0.0.0.0\r\na=ice-ufrag:O57r\r\na=ice-pwd:V82DXgyESlE0Ror9WfhIvTV+\r\na=ice-options:trickle\r\na=fingerprint:sha-256 91:94:D6:EB:ED:DC:57:81:96:65:19:23:59:5E:0E:60:20:E0:03:EF:40:90:95:72:1F:1D:F4:B4:F4:A0:B6:75\r\na=setup:actpass\r\na=mid:1\r\na=extmap:2 urn:ietf:params:rtp-hdrext:toffset\r\na=extmap:3 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time\r\na=extmap:4 urn:3gpp:video-orientation\r\na=extmap:5 http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01\r\na=extmap:6 http://www.webrtc.org/experiments/rtp-hdrext/playout-delay\r\na=extmap:7 http://www.webrtc.org/experiments/rtp-hdrext/video-content-type\r\na=extmap:8 http://www.webrtc.org/experiments/rtp-hdrext/video-timing\r\na=extmap:10 http://tools.ietf.org/html/draft-ietf-avtext-framemarking-07\r\na=extmap:9 urn:ietf:params:rtp-hdrext:sdes:mid\r\na=sendrecv\r\na=msid:stream_label video_label\r\na=rtcp-mux\r\na=rtcp-rsize\r\na=rtpmap:96 VP8/90000\r\na=rtcp-fb:96 goog-remb\r\na=rtcp-fb:96 transport-cc\r\na=rtcp-fb:96 ccm fir\r\na=rtcp-fb:96 nack\r\na=rtcp-fb:96 nack pli\r\na=rtpmap:97 rtx/90000\r\na=fmtp:97 apt=96\r\na=rtpmap:98 VP9/90000\r\na=rtcp-fb:98 goog-remb\r\na=rtcp-fb:98 transport-cc\r\na=rtcp-fb:98 ccm fir\r\na=rtcp-fb:98 nack\r\na=rtcp-fb:98 nack pli\r\na=fmtp:98 profile-id=0\r\na=rtpmap:99 rtx/90000\r\na=fmtp:99 apt=98\r\na=rtpmap:100 red/90000\r\na=rtpmap:101 rtx/90000\r\na=fmtp:101 apt=100\r\na=rtpmap:127 ulpfec/90000\r\na=ssrc-group:FID 832253623 3712395075\r\na=ssrc:832253623 cname:RyCnkrKJbtTTm9BB\r\na=ssrc:832253623 msid:stream_label video_label\r\na=ssrc:832253623 mslabel:stream_label\r\na=ssrc:832253623 label:video_label\r\na=ssrc:3712395075 cname:RyCnkrKJbtTTm9BB\r\na=ssrc:3712395075 msid:stream_label video_label\r\na=ssrc:3712395075 mslabel:stream_label\r\na=ssrc:3712395075 label:video_label\r\nm=application 9 DTLS/SCTP 5000\r\nc=IN IP4 0.0.0.0\r\na=ice-ufrag:O57r\r\na=ice-pwd:V82DXgyESlE0Ror9WfhIvTV+\r\na=ice-options:trickle\r\na=fingerprint:sha-256 91:94:D6:EB:ED:DC:57:81:96:65:19:23:59:5E:0E:60:20:E0:03:EF:40:90:95:72:1F:1D:F4:B4:F4:A0:B6:75\r\na=setup:actpass\r\na=mid:2\r\na=sctpmap:5000 webrtc-datachannel 1024\r\n","type":"offer"}
Here's a couple of example ICE candidates
`
candidate:2134042263 1 tcp 1518280447 192.168.1.138 54955 typ host tcptype passive generation 0 ufrag jjwt network-id 1

candidate:2134042263 1 tcp 1518280447 192.168.1.138 54957 typ host tcptype passive generation 0 ufrag jjwt network-id 1
`

[giansimo]

After some test I came up with a solution.
The problem in my case was in the sdp message received by means of the socket (guess it concern with SocketIO Unity package).
SDP has invalid format because it has '"' char at the begin and at the end, and also have "\r\n" not decoded in a proper way.
This problem come out each time I use a SocketIO function/callback (when I receive ICE candidates/SDP message).
So, in order to solve it's enough clean the message.

        public void onOfferReceivedEvent(SocketIOEvent e)
        {
            Debug.Log("[SocketIO] Offer Received event received: " + e.name + " " + e.data);

            JSONObject json = (JSONObject)e.data;
            string sdp = cleanData("" + json.GetField("sdp")).Replace("\\r\\n", "\r\n");


            if (peerConnection.Peer != null) { 
                peerConnection.Peer.SetRemoteDescription("offer", sdp);
                bool res = peerConnection.Peer.CreateAnswer();
                Debug.Log("[SocketIO] " + res.ToString());
            }
            Debug.Log("[SocketIO] OnOfferReceivedEnded");
        }

        private string cleanData(string txt){
            txt = txt.Substring(1);
            txt = txt.Remove(txt.Length - 1);
            return txt;
        }

Hope this can help you and sorry for my english!! :)

[djee-ms]

Glad you fixed it @giansimo! If I understand correctly this is due to your own signaling solution, so there is nothing for us to fix, right? I will close this bug as Invalid then, just for clarity.

[giansimo]

Yes, It occurs when you use SocketIO package in the signaling component.

[HyperLethalVector]

I'm still having issues, and the above fix did not work, I'll post it as a new bug after I've completely reimported a freshly built project

[jonlindeheim]

I have similar problems when connecting to two different peers, one is using the standard WebRTC JS APIs running in Chrome (works) but the other is a gstreamer implementation (does not work). The latter works if I connect to it in Chrome but not with UWP.
The outcome is that LocalSdpReadytoSend and IceCandidateReadytoSend are never triggered. PeerConnection.Connected or IceStateChanged are not triggered either.
From my view the SDP looks correct even though it's different from the one I get from Chrome, and I don't get any exceptions at all.
Ice candidates keeps coming from the gstreamer application but I never send anyone from the UWP app.
Would appreciate some ideas for going forward with troubleshooting this.

I am using the Microsoft.MixedReality.WebRTC.UWP nuget package v 1.0.3.
And same signallingserver for all scenarios.

[djee-ms]

That sounds like failure to apply the SDP message. Unsupported codec maybe? Notable one is that H.264 is supported only on UWP at the moment.

[jonlindeheim]

This is the SDP:

v=0
o=- 1248825917882444672 0 IN IP4 0.0.0.0
s=-
t=0 0
a=ice-options:trickle
a=group:BUNDLE video0
m=video 9 UDP/TLS/RTP/SAVPF 96
c=IN IP4 0.0.0.0
a=setup:actpass
a=ice-ufrag:yG9dQayBLjwbvUyKlSsGTWRj4Pr+xdpZ
a=ice-pwd:cntNu6ZMPh7TerGzZmu3Cg+TrVFBGiDU
a=rtcp-mux
a=rtcp-rsize
a=sendonly
a=rtpmap:96 H264/90000
a=rtcp-fb:96 nack pli
a=framerate:30
a=fmtp:96 packetization-mode=1;profile-level-id=420029;sprop-parameter-sets=Z0IAKeKQFAe03AQEBpB4kRU=,aM48gA==
a=ssrc:2331184021 msid:user2577391394@host-f3808906 webrtctransceiver0
a=ssrc:2331184021 cname:user2577391394@host-f3808906
a=mid:video0
a=fingerprint:sha-256 C8:CA:BD:5B:93:22:09:0A:E5:E6:13:76:CF:99:18:04:5C:52:A9:F5:A1:1E:24:8C:06:96:0D:6C:49:35:81:FF

But I am using UWP so h.264 should work? Or am I missing something?
(Target: Universal Windows, Windows 10 1903)

[djee-ms]

m=video 9 UDP/TLS/RTP/SAVPF 96
a=rtpmap:96 H264/90000

Yes that's H.264 being used here.

a=mid:video0

I wonder if this is the same bug as #295, where we (incorrectly) assume a numerical mid value and fail to parse it into an integer. Are the SDP messages for the working scenario also using alphanumerical mid values or only numerical ones?

[jonlindeheim]

The working SDP are using numerical. I tried to change video0 -> 0 but same result. But maybe it does not work to change the SDP on the receiving side like that... I will try and change so that gstreamer also sends numerical values for mid.

[djee-ms]

Yes just changing the SDP won't work because the SDP is sent after it has been applied locally. If you can change gstreamer then that would be the best test. Unfortunately Google doesn't expose the media line index in its API, that's why we used the mid trick, but it's incompatible with other implementations so we have to find another way now.

[jonlindeheim]

Sadly I get the same behavior after changing the gstreamer application. This is the new SDP:

v=0
o=- 3043621224926643957 0 IN IP4 0.0.0.0
s=-
t=0 0
a=ice-options:trickle
a=group:BUNDLE 0
m=video 9 UDP/TLS/RTP/SAVPF 96
c=IN IP4 0.0.0.0
a=setup:actpass
a=ice-ufrag:Y6XI9KeS6dlLUMQq93JkAAQH9tRwPUH7
a=ice-pwd:Trl5uljFJ1ljvCC3NGwfNGIzOJ/UF2Ul
a=rtcp-mux
a=rtcp-rsize
a=sendonly
a=rtpmap:96 H264/90000
a=rtcp-fb:96 nack pli
a=framerate:30
a=fmtp:96 packetization-mode=1;profile-level-id=64001e;sprop-parameter-sets=Z2QAHqw0yAoD3/AW4CAgKAAAH0AABhqHQgAEw4AACYb5d5caEAAmHAAATDfLvLhvqA==,aO48MA==
a=ssrc:3459312128 msid:user3263464531@host-4ae75b06 webrtctransceiver0
a=ssrc:3459312128 cname:user3263464531@host-4ae75b06
a=mid:0
a=fingerprint:sha-256 85:E6:7A:98:D3:C1:45:62:A1:C4:30:9A:AE:94:49:18:54:13:C9:3C:2F:BE:EC:9B:CB:CD:0A:59:49:C1:9F:44

[djee-ms]

Can you see some debug logs in the Visual Studio Output window? Is there anything about some offer/answer failing to be applied? I am running out of ideas on things to test.

[jonlindeheim]

Is there a way to get debug-logs from the underlying libs? Right now I only get from my UWP app.

[djee-ms]

If you're using a Unity build on UWP then I believe you should have them already in the Output window of Visual Studio (with IL2CPP backend), no? Can you try a Debug build otherwise (both of mrwebrtc.dll and of your app)?

[jonlindeheim]

I have been following this tutorial so I guess UWP... Tried to use the dll:s directly when building from source but got into the vs 2017 build tools v141 problems.. So I simply went for the nuget package to keep it simple.

[Avidon0]

@jonlindeheim and I worked on this together and found the problem. We managed to get the build tools needed and built a debug version of the dlls, with which we found this extra output:

(webrtcvideoengine.cc:686): SetSendParameters: {codecs: [VideoCodec[96:H264]], conference_mode: no, extensions: [], max_bandwidth_bps: -1, mid: video0}
(webrtcvideoengine.cc:626): No video codecs supported.

We did some investigation and found that the camera is sending an unsupported h264 profile 'level' in the SDP and when we changed that to one that is supported, everything started working.

Thanks for all your help, @djee-ms

[djee-ms]

@Avidon0, @jonlindeheim > Logged as #403 to add better error reporting in this case.