clarifying how to avoid Trickle ICE

dpocock commented 3 years ago

Prerequisites

These are MANDATORY, otherwise the issue will be automatically closed.

[x] I agree to fill this issue template.
[x] I have read the Troubleshooting Guide and Support Instructions.

Issue description

I followed the instructions here, in particular, I am calling gatherCandidates() before processOffer() https://doc-kurento.readthedocs.io/en/stable/_static/client-javadoc/org/kurento/client/WebRtcEndpoint.html

processOffer() returns an SDP answer without any candidates

Are there any other steps, for example, does it not work properly if the event listeners are not configured? If there are any mandatory steps, can you please add that to the documentation?

Context

Trying to use JsSIP with Kurento.

JsSIP doesn't currently support Trickle ICE https://github.com/versatica/JsSIP/issues/716

How to reproduce?

create pipeline create endpoint add listeners (IceCandidateFound, IceGatheringDone) generateCandidates() processOffer look at the SDP answer, does it only contain 0.0.0.0 or does it contain real candidates?

Expected & current behavior

If I call generateCandidates first then I would expect to see some candidates in the SDP answer

(Optional) Possible solution

Info about your environment

Development environment, adapting another free software product, the reSIProcate C++ SIP stack, to support Kurento

About Kurento Media Server

Kurento version: 6.16.0
Server OS: tried both Ubuntu bionic and the Docker image
Installation method:
- x
- x

About your Application Server

Programming Language: C++
Kurento Client version: custom C++ code

About end-user clients

Device(s):
OS(es):
Browser(s):

Run these commands

cat /etc/lsb-release

kurento-media-server --version

dpkg -l | grep -Pi 'kurento|kms-|gst.*1.5|nice'

github-actions[bot] commented 3 years ago

Hello @dpocock! :wave: we're sorry you found a bug... so first of all, thank you very much for reporting it.

To know about progress, check in Triage. All issues are considered Backlog Candidates until work priorities align and the issue is selected for development. It will then become part of our official Backlog.

j1elo commented 3 years ago

Check if it works if you call processOffer() after receiving the IceGatheringDone event. This event is what tells you that all ICE candidates have been gathered. Otherwise, you might be calling processOffer() when not even a single candidate has been found...

think of it this way: if candidate gathering took 20 seconds... is your code really waiting all those 20 seconds before calling processOffer()?

dpocock commented 3 years ago

reading the API docs, I had the impression that gatherCandidates() would return synchronously, after IceGatheringDone

If that is not the case then I'll modify the code to wait for the event and it would be useful to emphasize this in the docs.

Looking at the Kurento logs I notice that it says the candidates are added but it doesn't show IceGatheringDone in the log.

When I run the hello-world Java demo then I do see the IceGatheringDone message in the server log. It looks like there is some subtle difference in how the demo sets up the pipeline.

j1elo commented 3 years ago

thanks for the suggestions; I've mostly rewritten the docs of the gatherCandidates method, to make it clearer and more useful for users

dpocock commented 3 years ago

@j1elo thanks, the documentation is helpful but the issue still appears to be a bug or maybe a regression.

Can you please reopen the issue until we get to the bottom of this?

Do you have any unit test that validates this behavior? If not, do you remember the last time it was tested?

Here is what I observe, I have GST_DEBUG="7" for full logging.

a) using kurento-tutorial-java/kurento-hello-world: I capture the Kurento logs and everything looks good in there. The tutorial uses trickle ICE, in particular:

processOffer(sdp)
gatherCandidates()

Running the tutorial, when I look at the Kurento log, I can see that it finds the local candidates and sends IceGatheringDone in less than 1 second.

b) then I run my own code. Instead of using the events, I just created a 10 second sleep to test everything and I watch the log.

gatherCandidates()
sleep (10 seconds)
processOffer(sdp)

I grep the log and I can not find any events AddIceCandidate or IceGatheringDone

grep KmsIceNice 2021-06-15T090636.00000.pid13043.log
2021-06-15T09:07:54,883123 13043 0x00007fb2d372d700   debug kmsiceniceagent           kmsiceniceagent.c:249 kms_ice_nice_agent_new() <KmsIceNiceAgent@0x7fb2c8040d60>  Create new instance, compatibility level: RFC5245
2021-06-15T09:07:54,883513 13043 0x00007fb2d372d700   debug kmsiceniceagent           kmsiceniceagent.c:253 kms_ice_nice_agent_new() <KmsIceNiceAgent@0x7fb2c8040d60>  Disable UPNP support
2021-06-15T09:07:54,883585 13043 0x00007fb2d372d700   trace kmsiceniceagent           kmsiceniceagent.c:630 kms_ice_nice_agent_run_agent() <KmsIceNiceAgent@0x7fb2c8040d60>  Nothing to do in run_agent
2021-06-15T09:08:04,983820 13043 0x00007fb2d1729700     log kmsiceniceagent           kmsiceniceagent.c:322 kms_ice_nice_agent_add_stream() <KmsIceNiceAgent@0x7fb2c8040d60>  Added data stream, ID: 1, stream_id: bundle0
2021-06-15T09:08:04,983876 13043 0x00007fb2d1729700     log kmsiceniceagent           kmsiceniceagent.c:324 kms_ice_nice_agent_add_stream() <KmsIceNiceAgent@0x7fb2c8040d60>  Set port range: [1024, 65535]
2021-06-15T09:08:05,670679 13043 0x00007fb2d1729700     log kmsiceniceagent           kmsiceniceagent.c:371 kms_ice_nice_agent_get_local_credentials() <KmsIceNiceAgent@0x7fb2c8040d60>  Get local credentials, stream_id: 1
2021-06-15T09:08:05,764427 13043 0x00007fb2d1729700     log kmsiceniceagent           kmsiceniceagent.c:371 kms_ice_nice_agent_get_local_credentials() <KmsIceNiceAgent@0x7fb2c8040d60>  Get local credentials, stream_id: 1
2021-06-15T09:08:06,169564 13043 0x00007fb2d1729700     log kmsiceniceagent           kmsiceniceagent.c:358 kms_ice_nice_agent_set_remote_credentials() <KmsIceNiceAgent@0x7fb2c8040d60>  Set remote credentials, stream_id: 1
2021-06-15T09:08:06,170134 13043 0x00007fb2d1729700     log kmsiceniceagent           kmsiceniceagent.c:502 kms_ice_nice_agent_add_ice_candidate() <KmsIceNiceAgent@0x7fb2c8040d60>  [AddIceCandidate] remote: 'candidate:0 1 UDP 2121269503 ...

Notice that I see lots of lines for [AddIceCandidate] remote. I don't see the local candidates in that log.

When I did the test with hello-world, the [AddIceCandidate] local entries appear in the log file.

c) I came up with a workaround, I do the following:

sdpAnswer = processOffer(sdp)
gatherCandidates()
sleep (2 seconds)
sdpAnswer2 = getLocalSessionDescriptor()

With this solution, I see the IceGatheringDone event in the Kurento log and the sdpAnswer2 includes all the local candidates. I send the sdpAnswer2 to the caller and the session is established.

Can you please reopen the issue until we get to the bottom of this?

j1elo commented 3 years ago

You're right, I got confused because of the old comment in the documentation. Turns out that comment is wrong: it's not possible to call gatherCandidates before having processed an initial SDP. This is because all the internal structures, to handle connections and sessions, are created upon the first appearance of an SDP in the Endpoints.

Web browsers have decoupled the act of setting an SDP Offer from the phase of explicitly setting a local or remote description. In Kurento, these two are merged into a single operation, which serves better the needs for 99% cases, but makes it more weird for the 1%.

I believe the correct way to do it would be as you propose, with a slight change. Here's a more complete pseudocode, being more explicit about the signaling component, so it is clearer when each part would run:

webrtc.onIceGatheringDone({
    fullSdpAnswer = webrtc.getLocalSessionDescriptor()
    signaling.sendSdpAnswer(fullSdpAnswer)
})

signaling.onSdpoffer({
    dummySdpAnswer = webrtc.processOffer(sdpOffer)
    webrtc.gatherCandidates()
})

Kurento / bugtracker