search

awslabs / amazon-kinesis-video-streams-webrtc-sdk-android

Android SDK for interfacing with Amazon Kinesis Video Streams Signaling Service.
Apache License 2.0
57 stars 37 forks source link

"Added ice candidate Failed" when Android SDK receives ICE candidate before SDP answer #44

Closed yuma-m closed 3 years ago

yuma-m commented 3 years ago

Environment

When Android SDK receives ICE candidate before receiving SDP answer, it fails to add ICE candidate. (Added ice candidate ... Failed line below)

D/CustomMessageHandler: Received message{"messagePayload":"eyJjYW5kaWRhdGUiOiJjYW5kaWRhdGU6MCAxIHVkcCAyMTMwNzA2NDMxIDE3Mi4zMS4yMi4wIDUyMDMwIHR5cCBob3N0IHJhZGRyIDAuMC4wLjAgcnBvcnQgMCBnZW5lcmF0aW9uIDAgbmV0d29yay1jb3N0IDk5OSIsInNkcE1pZCI6IjAiLCJzZHBNTGluZUluZGV4IjowfQ==","messageType":"ICE_CANDIDATE"}
D/CustomMessageHandler: Ice Candidate received: SenderClientId=null
    {"candidate":"candidate:0 1 udp 2130706431 172.31.22.0 52030 typ host raddr 0.0.0.0 rport 0 generation 0 network-cost 999","sdpMid":"0","sdpMLineIndex":0}
D/KVSWebRtcActivity: Received IceCandidate from remote 
D/KVSWebRtcActivity: Added ice candidate 0:0:candidate:0 1 udp 2130706431 172.31.22.0 52030 typ host raddr 0.0.0.0 rport 0 generation 0 network-cost 999: Failed

...

D/CustomMessageHandler: Received message{"messagePayload":"..."}
D/CustomMessageHandler: Answer received: SenderClientId=null
D/KVSWebRtcActivity: SDP answer received from signaling
D/Event: SDP answer received from master:v=0

After receiving SDP answer, it succeeds to add ICE candidate. (Added ice candidate ... Successfully line below)

D/CustomMessageHandler: Received message{"messagePayload":"eyJjYW5kaWRhdGUiOiJjYW5kaWRhdGU6MSAxIHVkcCAxNjk0NDk4ODE1IDE4LjE3OS41OS4yMTQgNDM3MzMgdHlwIHNyZmx4IHJhZGRyIDAuMC4wLjAgcnBvcnQgMCBnZW5lcmF0aW9uIDAgbmV0d29yay1jb3N0IDk5OSIsInNkcE1pZCI6IjAiLCJzZHBNTGluZUluZGV4IjowfQ==","messageType":"ICE_CANDIDATE"}
    Ice Candidate received: SenderClientId=null
I/org.webrtc.Logging: SurfaceViewRenderer: remote_view: onMeasure(). New size: 1080x1815
D/CustomMessageHandler: {"candidate":"candidate:1 1 udp 1694498815 18.179.59.214 43733 typ srflx raddr 0.0.0.0 rport 0 generation 0 network-cost 999","sdpMid":"0","sdpMLineIndex":0}
D/KVSWebRtcActivity: Received IceCandidate from remote 
D/KVSWebRtcActivity: Added ice candidate 0:0:candidate:1 1 udp 1694498815 18.179.59.214 43733 typ srflx raddr 0.0.0.0 rport 0 generation 0 network-cost 999: Successfully

Does this behavior affect the Android SDK to ignore the ICE candidate which is received before SDP answer (maybe local or srflx candidate) and tend to choose relay candidate?

MushMal commented 3 years ago

I assume you are using Trickle ICE.

Need to check the RFCs and the masters behavior to understand what's right.

MushMal commented 3 years ago

One NOTE: I assume you are using the stock samples without any modifications - please confirm.

yuma-m commented 3 years ago

Hi @MushMal,

Thank you for your support. I didn't modify either C SDK or Android SDK, so I assume Trickle ICE is used.

MushMal commented 3 years ago

Looking at the code I see that in case of Trickle ICE we do properly serialize the messages. First, we send the answer, next we spin up a timerqueue to handle the ice candidates.

However, we have an optimization by which if we have pending ice candidates, we immediately start sending those:

https://github.com/awslabs/amazon-kinesis-video-streams-webrtc-sdk-c/blob/master/samples/Common.c#L1086-L1096

This can only happen if the viewer is using the same peerID in a multiple offers. If the peer (viewer) can not handle the ice candidates which we already have gathered in the previous session then it's OK, those candidates should be generated again in the new sessions ICE gathering.

This should affect latency only.

The other question is why in your experiments you are sending multiple offers? What scenario are you trying?

MushMal commented 3 years ago

@yuma-m I am still not sure whether this will end up dropping the local/rflx candidates and why. Can you do a simple experiment by commenting these lines: https://github.com/awslabs/amazon-kinesis-video-streams-webrtc-sdk-c/blob/master/samples/Common.c#L1086-L1096

yuma-m commented 3 years ago

@MushMal I just tried connection between a C SDK peer and an Android SDK peer a few times and happened to reproduce this issue.

Is the order of messages kept? I confirmed C SDK sent SDP answer before sending any ICE candidate, but Android SDK received ICE candidate before SDP answer. I have the logs of both SDK and can share it if you need.

C SDK logs

2020-12-14 11:29:37 DEBUG   writeLwsData(): Sending data over web socket: {
    "action": "SDP_ANSWER",
    "RecipientClientId": "f8ecae19-ce16-4b54-a6d0-4a870ea5e9da",
    "MessagePayload": "eyJ0eXBlIjogIm..."
}

...

2020-12-14 11:29:37 DEBUG   iceAgentLogNewCandidate(): New local ice candidate discovered. Id: a05KL2bPM. Ip: 172.31.22.0:52030. Type: host. Protocol: UDP.
2020-12-14 11:29:37 INFO    signalingClientSendMessageSync(): Signaling Client Sending Message Sync
2020-12-14 11:29:37 DEBUG   writeLwsData(): Sending data over web socket: {
    "action": "ICE_CANDIDATE",
    "RecipientClientId": "f8ecae19-ce16-4b54-a6d0-4a870ea5e9da",
    "MessagePayload": "eyJjYW5kaWRhdGUiOiJjYW5kaWRhdGU6MCAxIHVkcCAyMTMwNzA2NDMxIDE3Mi4zMS4yMi4wIDUyMDMwIHR5cCBob3N0IHJhZGRyIDAuMC4wLjAgcnBvcnQgMCBnZW5lcmF0aW9uIDAgbmV0d29yay1jb3N0IDk5OSIsInNkcE1pZCI6IjAiLCJzZHBNTGluZUluZGV4IjowfQ=="
}

...

2020-12-14 11:29:37 DEBUG   iceAgentLogNewCandidate(): New local ice candidate discovered. Id: 3/Vneri9L. Ip: 18.179.59.214:43733. Type: srflx. Protocol: UDP.
2020-12-14 11:29:37 INFO    signalingClientSendMessageSync(): Signaling Client Sending Message Sync
2020-12-14 11:29:37 DEBUG   writeLwsData(): Sending data over web socket: {
    "action": "ICE_CANDIDATE",
    "RecipientClientId": "f8ecae19-ce16-4b54-a6d0-4a870ea5e9da",
    "MessagePayload": "eyJjYW5kaWRhdGUiOiJjYW5kaWRhdGU6MSAxIHVkcCAxNjk0NDk4ODE1IDE4LjE3OS41OS4yMTQgNDM3MzMgdHlwIHNyZmx4IHJhZGRyIDAuMC4wLjAgcnBvcnQgMCBnZW5lcmF0aW9uIDAgbmV0d29yay1jb3N0IDk5OSIsInNkcE1pZCI6IjAiLCJzZHBNTGluZUluZGV4IjowfQ=="
}

Android SDK Logs

D/CustomMessageHandler: Received message{"messagePayload":"eyJjYW5kaWRhdGUiOiJjYW5kaWRhdGU6MCAxIHVkcCAyMTMwNzA2NDMxIDE3Mi4zMS4yMi4wIDUyMDMwIHR5cCBob3N0IHJhZGRyIDAuMC4wLjAgcnBvcnQgMCBnZW5lcmF0aW9uIDAgbmV0d29yay1jb3N0IDk5OSIsInNkcE1pZCI6IjAiLCJzZHBNTGluZUluZGV4IjowfQ==","messageType":"ICE_CANDIDATE"}
D/CustomMessageHandler: Ice Candidate received: SenderClientId=null
    {"candidate":"candidate:0 1 udp 2130706431 172.31.22.0 52030 typ host raddr 0.0.0.0 rport 0 generation 0 network-cost 999","sdpMid":"0","sdpMLineIndex":0}
D/KVSWebRtcActivity: Received IceCandidate from remote 
D/KVSWebRtcActivity: Added ice candidate 0:0:candidate:0 1 udp 2130706431 172.31.22.0 52030 typ host raddr 0.0.0.0 rport 0 generation 0 network-cost 999: Failed

...

D/CustomMessageHandler: Received message{"messagePayload":"eyJ0eXBlIjogIm...
D/CustomMessageHandler: Answer received: SenderClientId=null
D/KVSWebRtcActivity: SDP answer received from signaling
D/Event: SDP answer received from master:v=0

...

D/CustomMessageHandler: Received message{"messagePayload":"eyJjYW5kaWRhdGUiOiJjYW5kaWRhdGU6MSAxIHVkcCAxNjk0NDk4ODE1IDE4LjE3OS41OS4yMTQgNDM3MzMgdHlwIHNyZmx4IHJhZGRyIDAuMC4wLjAgcnBvcnQgMCBnZW5lcmF0aW9uIDAgbmV0d29yay1jb3N0IDk5OSIsInNkcE1pZCI6IjAiLCJzZHBNTGluZUluZGV4IjowfQ==","messageType":"ICE_CANDIDATE"}
    Ice Candidate received: SenderClientId=null
D/CustomMessageHandler: {"candidate":"candidate:1 1 udp 1694498815 18.179.59.214 43733 typ srflx raddr 0.0.0.0 rport 0 generation 0 network-cost 999","sdpMid":"0","sdpMLineIndex":0}
D/KVSWebRtcActivity: Received IceCandidate from remote 
D/KVSWebRtcActivity: Added ice candidate 0:0:candidate:1 1 udp 1694498815 18.179.59.214 43733 typ srflx raddr 0.0.0.0 rport 0 generation 0 network-cost 999: Successfully
MushMal commented 3 years ago

Messages should be delivered in order. Need to understand what's going on. Adding the logs might be useful (with log level = VERBOSE).

yuma-m commented 3 years ago

If this behavior actually happens, it will violate the following section.

https://datatracker.ietf.org/doc/html/draft-ietf-mmusic-trickle-ice-02#section-9.2

Obviously, agents MUST NOT send individual candidates prior to generating the corresponding SDP session description.

hatimkha commented 3 years ago

KVS does not guarantee in-order delivery of signaling messages. Due to processing time, dependencies, and network it is a best effort delivery.

Obviously, agents MUST NOT send individual candidates prior to generating the corresponding SDP session description.

The line linked from the RFC has specifications regarding the sending with the context of encoding the SDP, but not the delivery of those messages.

Were you able to confirm that the candidates that arrived before the SDP answer were dropped? You could run an experiment where you could disable relay candidates and see if there is connectivity from the candidate that arrived before the SDP answer.

A fix for this could be to "hold" that ICE candidate on the client side and wait to process it until the SDP answer is received.

MushMal commented 3 years ago

@hatimkha aside from the network packet level issue, does the backend guarantee the ordering?

In the C webrtc SDK samples we do hold the ICE candidates but none of this happens in any other SDKs/samples.

hatimkha commented 3 years ago

@MushMal No, because message processing can be affected by our dependencies such as by cold start time or DDB latency. In general they should be in order but we do not provide strict guarantees.

yuma-m commented 3 years ago

Were you able to confirm that the candidates that arrived before the SDP answer were dropped?

@hatimkha I could only confirm the logs from Android SDK: Added ice candidate ... Failed and Added ice candidate ... Successfully. Are there any way to confirm whether it is actually dropped or not?

A fix for this could be to "hold" that ICE candidate on the client side and wait to process it until the SDP answer is received.

@MushMal Do you know why it is implemented in C SDK? Should it be implemented in other SDKs?

MushMal commented 3 years ago

@yuma-m this must be implemented in the other SDK samples too. This is a sample-level handling of the discrepancy as we are not in the control of the actual WebRTC implementation on these platforms.

We will resolve this issue once we cut Enhancement issues in each of these repositories. The work will be properly scheduled and prioritized

disa6302 commented 3 years ago

Closing since an enhancement ticket is created.

https://github.com/awslabs/amazon-kinesis-video-streams-webrtc-sdk-android/issues/47