1207056 - WebRTC SDP format

Status: RESOLVED WORKSFORME

(Core :: WebRTC: Signaling, defect)

Description

[thibaud.buffet]

User Agent: Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/45.0.2454.93 Safari/537.36

Steps to reproduce:

Hi,
I try to set up a WebRTC app using one/multiple datachannels.

Also, I need to install a "MEDIA Service" between two Firefox clients. So I should be able to negociate two datachannels:
eg : 
[client1 FF] -----datachannel1-----> [MEDIA Service] -----datachannel2-----> [client2 FF].

I'm able to establish my datachannel1 between the client1 FF and my MEDIA Service.
But when I negociate between MEDIA service and client2 FF, the datachannel never opens, and the callback "onopen" is never raised.
Maybe it is coming from the SDP provided by the MEDIA service for client2 FF, here it is :

"v=0
o=ISF 2716565101271028330 2 IN IP4 127.0.0.1
s=-
t=0 0
a=msid-semantic:WMS *
a=group:BUNDLE sdparta_0
a=ice-lite
m=application 40000 DTLS/SCTP 5000
c=IN IP4 16.17.30.130
a=ice-pwd:NsfNF6wtOBv16923iBMiUmml
a=ice-ufrag:9lKU/TaERhihin8g
a=fingerprint:sha-256 4C:68:21:5A:23:D4:E8:10:78:67:DC:EB:D8:49:9A:B3:7F:45:78:F3:04:47:EE:19:C9:B6:81:75:4F:31:CC:ED
a=candidate:4070578974 1 udp 2130706431 16.17.30.130 40000 typ host
a=sendrecv
a=sctpmap:5000 webrtc-datachannel 256
a=mid:sdparta_0
a=ssrc:1620709405 cname:E9HeQBFb+lw/AZbi
a=ssrc:1620709405 msid:uTCAuq0BaS6mL9gUBbpbiO5vbSnLbEYJXaJF 1ae223c8-6d0f-1cd9-241c-18e36c1a4888ca81
a=ssrc:1620709405 mslabel:uTCAuq0BaS6mL9gUBbpbiO5vbSnLbEYJXaJF
a=ssrc:1620709405 label:1ae223c8-6d0f-1cd9-241c-18e36c1a4888ca81
a=setup:actpass"


Also, when I look at the logs on about:webrtc here is what I found :
(ice/ERR) ICE(PC:1442578615506000 (id=54 url=https://ducati27.com:3443/?debug=true)): peer (PC:1442578615506000 (id=54 url=https://ducati27.com:3443/?debug=true):default) pairing local trickle ICE candidate host(IP4:192.168.99.1:61289/UDP)


Do you have any ideas of what could be my issue ?
Do you know any way to validate the SDP offered to firefox (validate the firefox parser )? 

Thanks for your answers.

Comment 1

[Randell Jesup [:jesup] (needinfo me)]

Not sure, but more complete logs from about:webrtc would help (connection log, and the table at the top)

How are you handling ICE trickle, etc?

Comment 2

[Nils Ohlmeier [:drno]]

First of all even though it says (ice/ERR) at the beginning of the log messages this only an informational logging, not really an error: https://dxr.mozilla.org/mozilla-central/source/media/mtransport/third_party/nICEr/src/ice/ice_peer_ctx.c#428

A couple of questions/points here:

1) I'm assuming for datachannel1 'client1 FF' is the offerer and 'MEDIA Service' is answerer. Correct?
2) For datachannel2 is 'MEDIA Service' the offerer?
3) The log message shows a 192.168.x.x IP address for 'client2 FF', but the SDP contains a public IP address. Are both FF behind NATs/firewalls? Is ICE suppose to take of the NAT traversal?
4) I see a=ice-lite in the offer. Does the 'MEDIA Service' really only support ice lite?

I would recommend to focus on the simplified scenario of just 'Media Service' -> FF as that seems to be the problematic scenario. And it would be helpful to compare the 'about:webrtc' ICE connection tables of the working case with the non-working scenario.

Comment 3

[thibaud.buffet]

Attachment: FFclient1offer.html provides log from the FF1 client to media service

Comment 4

[thibaud.buffet]

Attachment: FFclient2receiver.html provides logs for the media service to FF2 client

Comment 5

[thibaud.buffet]

Here are some more logs about 
"FF1 client" ---> "Media Service" (filename : FFclient1offer.html)
"Media Service" ---> "FF1 client" (filename : FFclient2receiver.html) --> this one is the problem in my case.

@Nils answers:
1) Correct, For the first datachannel "FF1 client" is the offerer and "Media Service" the receiver
2) Yes, in the datachannel2 the "Media Service" is the offerer
3) Yes, they are both behind NAT and firewalls. 
4) Yes "Media service" supports the ice-lite.

Comment 6

[Nils Ohlmeier [:drno]]

What I noticed in your logs from scenario two is that your "Media service" offers 1024 streams for the data channel. Firefox answer claims that it will do 256 streams. But from what I saw in the code so far it appears that is not the truth, see bug 1211097, but in fact we initialize our SCTP stack with the 1024 streams the "Media service" requested.
Do you know if your "Media service" is really going to rely on amount of streams in the answer and only opens 256 streams? If that would be the case that could explain why onopen never fires as Firefox might still wait for the remaining 768 channels to open, before fyring the event.

Comment 7

[Nils Ohlmeier [:drno]]

Another idea: as a workaround you could try to offer only 256 streams in the offer from your "Media service" and see if that fixes the problem until bug 1211097 is fixed on our end.

Comment 8

[thibaud.buffet]

Thanks Nils for those answers.

However I have the same issue/behaviour when I try to offer only 256 from my "Media service".

I updated the Attachements related to the scenario 2 which is the only one concerned.

I still don't understand this behaviour, if you have any idea I would appreciate.

Comment 9

[thibaud.buffet]

Attachment: aboutWebrtc-receiver2.html [In the case of 256 streams only]

Scenario 2
Reduce from 1024 streams to 256 !

Comment 10

[Nils Ohlmeier [:drno]]

Yeah the number of streams was just the only suspicious thing I could see in the SDP exchange. Thanks for trying out so quickly.

To me it looks like the ICE connections gets established, but the DTLS or SCTP stack fails for some reason. I think at this point we need NSPR log files to get a clue what is going on. If you could please follow the instructions here: https://wiki.mozilla.org/Media/WebRTC/Logging#Signaling_.28SDP_offer.2Fanswer_handling.29
to get us some log files and upload them here (or email them if you don't want to share them publicly). I would recommend 
 NSPR_LOG_MODULES=datachannel:9,sctp:9,signaling:9,mtransport:9,jsep:9,timestamp
to be sure we get everything we need in this case.

Comment 11

[thibaud.buffet]

Ok thanks, I wasn't aware of the NSPR log files. 
I set up the environment variables as described in the mozilla wiki.
I attached the log provided by the scenario2 (WEBRTC-NSRP-receiver).

I noticed in the file some lines :
2015-10-06 12:34:52.839000 UTC - 0[711140]: [main|SDP Parse] sdp_main.c:1323: SDP Parse Error  End of line beyond end of buffer., line 21.

This could be related to my issue, right ?

Comment 12

[thibaud.buffet]

Attachment: NSRP log level 9

Comment 13

[Randell Jesup [:jesup] (needinfo me)]

So it looks like DTLS is having problems (nils?) pretty much immediately on connection (ice_completed).  Can you redo the trace and add DataChannel:4,SCTP:4 to the logging?

Comment 14

[Nils Ohlmeier [:drno]]

(In reply to thibaud.buffet from comment #11)
> I noticed in the file some lines :
> 2015-10-06 12:34:52.839000 UTC - 0[711140]: [main|SDP Parse]
> sdp_main.c:1323: SDP Parse Error  End of line beyond end of buffer., line 21.
> 
> This could be related to my issue, right ?

According to our source code: https://dxr.mozilla.org/mozilla-central/source/media/webrtc/signaling/src/sdp/sipcc/sdp_main.c#1017
This is not treated as a parsing error as long as the SDP so far was oaky.

From looking at the log file it appears that the "Media service" has an extra line at the end:
  a=setup:actpass
which is not properly terminated with "\r\n". So this line does not show up in about:webrtc because Firefox failed to parse it.

Yes, it looks like "Media service" is not answering Firefox DTLS packets at all. Randel I assume thibaud did the trace already with datachannel and sctp set to 9 like I asked in comment #10, but because DTLS never succeeds we don't see much logging from these layers.
I think at this point you should check the logs on the "Media service" side and check if you see anything related to DTLS. Or you can make PCAP traces and attach them here, but I fear they will only show us that Firefox sends DTLS client hello packets to "Media service" without ever getting an answer.

Comment 15

[thibaud.buffet]

Hello,

Ok I checked my "Media Service" and it provides DTLSv1.0 over openSSL. 
And, as I checked, Firefox send a DTLS hello/handshake with DTLSv1.2.

It seems the issue is related to the conflict of those versions, right ?
I'm going to upgrade my DTLS to v1.2 and see if it can fix the issue.

I'm wondering why in firefox there is not a second handshake made with a DTLSv1.0 if the v1.2 fails ?

Thanks for your help.

Comment 16

[Eric Rescorla (:ekr)]

(In reply to thibaud.buffet from comment #15)
> Hello,
> 
> Ok I checked my "Media Service" and it provides DTLSv1.0 over openSSL. 
> And, as I checked, Firefox send a DTLS hello/handshake with DTLSv1.2.
> 
> It seems the issue is related to the conflict of those versions, right ?
> I'm going to upgrade my DTLS to v1.2 and see if it can fix the issue.
> 
> I'm wondering why in firefox there is not a second handshake made with a
> DTLSv1.0 if the v1.2 fails ?

Thats not how things work. Your side is supposed to just accept 1.0 when
we offer 1.2. Anyway, I suspect the problem is PFS, as described here:

https://hacks.mozilla.org/2015/02/webrtc-requires-perfect-forward-secrecy-pfs-starting-in-firefox-38/

Comment 17

[thibaud.buffet]

Ok thank you all for your answer. 

@Eric Rescorla : Yes it was related to the PFS! I missed this one.

On my side I solve the issue : 
Though, the proposed solution (using SSL_CTX_set_ecdh_auto) is available only since OpenSSL 1.0.2.
Since I am currently stuck with OpenSSL 1.0.1, I used the solution from https://bugzilla.mozilla.org/show_bug.cgi?id=1153702’s discussion, i.e. basically:
 
  EC_KEY *eckey = EC_KEY_new_by_curve_name(NID_X9_62_prime256v1);
  SSL_CTX_set_tmp_ecdh(sslCtx, eckey);