[QUESTION] WebRTC connections fail after multiple connections/disconnections

[mark-gu-aws]

Hi,

I need help to establish consistent WebRTC connections to multiple cameras simultaneously even after multiple connections and disconnections.

Please see below for log file extracts and design considerations.

** Logging **

One of the successful connections on Camera 2

2022-03-02 09:28:02 DEBUG   dtlsSessionProcessPacket(): Detected DTLS close_notify alert
2022-03-02 09:28:02 INFO    onConnectionStateChange(): New connection state 6
2022-03-02 09:28:02 DEBUG   freeSampleStreamingSession(): Freeing streaming session with peer id: C2 
2022-03-02 09:28:02 DEBUG   socketConnectionClosed(): Close socket 14
2022-03-02 09:28:02 DEBUG   socketConnectionClosed(): Close socket 13
2022-03-02 09:28:37 DEBUG   receiveLwsMessage(): Client received message of type: SDP_OFFER
2022-03-02 09:28:37 DEBUG   lwsWssCallbackRoutine(): Client is writable
2022-03-02 09:28:37 DEBUG   refreshIceConfiguration(): Refreshing the ICE Server Configuration
2022-03-02 09:28:37 DEBUG   refreshIceConfiguration(): Refreshing the ICE Server Configuration
2022-03-02 09:28:37 DEBUG   iceAgentValidateKvsRtcConfig(): 
	iceLocalCandidateGatheringTimeout: 10000 ms
	iceConnectionCheckTimeout: 10000 ms
	iceCandidateNominationTimeout: 10000 ms
	iceConnectionCheckPollingInterval: 50 ms
2022-03-02 09:28:37 DEBUG   initializePeerConnection(): time taken to create peer connection 183 ms
2022-03-02 09:28:37 DEBUG   createSocket(): setsockopt() NO_SIGNAL failed with errno Protocol not available
2022-03-02 09:28:37 DEBUG   createSocket(): setsockopt() NO_SIGNAL failed with errno Protocol not available
2022-03-02 09:28:37 DEBUG   createSocket(): setsockopt() NO_SIGNAL failed with errno Protocol not available
2022-03-02 09:28:37 DEBUG   createSocket(): setsockopt() NO_SIGNAL failed with errno Protocol not available
2022-03-02 09:28:37 DEBUG   sendLwsMessage(): Sending data over web socket: Message type: SDP_ANSWER, RecepientId: C2
2022-03-02 09:28:37 DEBUG   lwsWssCallbackRoutine(): Client is writable
2022-03-02 09:28:37 DEBUG   handleOffer(): time taken to send answer 0 ms
2022-03-02 09:28:37 DEBUG   iceAgentCheckConnectionStateSetup(): ice candidate pair count 0
2022-03-02 09:28:37 DEBUG   stepIceAgentStateMachine(): Ice agent state changed from ICE_AGENT_STATE_NONE to ICE_AGENT_STATE_CHECK_CONNECTION.
2022-03-02 09:28:37 INFO    onConnectionStateChange(): New connection state 2
2022-03-02 09:28:37 DEBUG   turnConnectionStepState(): TurnConnection state changed from TURN_STATE_NEW to TURN_STATE_CHECK_SOCKET_CONNECTION
2022-03-02 09:28:37 DEBUG   turnConnectionStepState(): TurnConnection state changed from TURN_STATE_NEW to TURN_STATE_CHECK_SOCKET_CONNECTION
2022-03-02 09:28:37 DEBUG   iceAgentLogNewCandidate(): New local ice candidate discovered. Id: 15h5DqNz0. Ip: 10.168.12.66:36016. Type: host. Protocol: udp.
2022-03-02 09:28:37 DEBUG   sendLwsMessage(): Sending data over web socket: Message type: ICE_CANDIDATE, RecepientId: C2
2022-03-02 09:28:37 DEBUG   lwsWssCallbackRoutine(): Client is writable
2022-03-02 09:28:37 DEBUG   turnConnectionStepState(): TurnConnection state changed from TURN_STATE_CHECK_SOCKET_CONNECTION to TURN_STATE_GET_CREDENTIALS
2022-03-02 09:28:37 DEBUG   turnConnectionStepState(): TurnConnection state changed from TURN_STATE_CHECK_SOCKET_CONNECTION to TURN_STATE_GET_CREDENTIALS
2022-03-02 09:28:38 DEBUG   iceAgentLogNewCandidate(): New local ice candidate discovered. Id: JaIW1Wnxr. Ip: 203.116.181.205:43558. Type: srflx. Protocol: udp.
2022-03-02 09:28:38 DEBUG   sendLwsMessage(): Sending data over web socket: Message type: ICE_CANDIDATE, RecepientId: C2

Failed connection on Camera sometime after multiple connect/disconnect from 4 or 5 viewers.

2022-03-02 09:47:15 DEBUG   rtcPeerConnectionGetMetrics(): ICE local candidate Stats requested at 16462144353158152
2022-03-02 09:47:15 DEBUG   logSelectedIceCandidatesInformation(): Local Candidate IP Address: 203.1**.***.***
2022-03-02 09:47:15 DEBUG   logSelectedIceCandidatesInformation(): Local Candidate type: srflx
2022-03-02 09:47:15 DEBUG   logSelectedIceCandidatesInformation(): Local Candidate port: 42671
2022-03-02 09:47:15 DEBUG   logSelectedIceCandidatesInformation(): Local Candidate priority: 1694498815
2022-03-02 09:47:15 DEBUG   logSelectedIceCandidatesInformation(): Local Candidate transport protocol: udp
2022-03-02 09:47:15 DEBUG   logSelectedIceCandidatesInformation(): Local Candidate relay protocol: N/A
2022-03-02 09:47:15 DEBUG   logSelectedIceCandidatesInformation(): Local Candidate Ice server source: stun.kinesisvideo.ap-southeast-1.amazonaws.com
2022-03-02 09:47:15 DEBUG   rtcPeerConnectionGetMetrics(): ICE remote candidate Stats requested at 16462144353158225
2022-03-02 09:47:15 DEBUG   logSelectedIceCandidatesInformation(): Remote Candidate IP Address: 18.1**.***.***
2022-03-02 09:47:15 DEBUG   logSelectedIceCandidatesInformation(): Remote Candidate type: relay
2022-03-02 09:47:15 DEBUG   logSelectedIceCandidatesInformation(): Remote Candidate port: 58641
2022-03-02 09:47:15 DEBUG   logSelectedIceCandidatesInformation(): Remote Candidate priority: 33563647
2022-03-02 09:47:15 DEBUG   logSelectedIceCandidatesInformation(): Remote Candidate transport protocol: 
2022-03-02 09:47:15 DEBUG   dtlsSessionChangeState(): DTLS init completed. Time taken 500 ms
2022-03-02 09:47:46 DEBUG   receiveLwsMessage(): Client received message of type: SDP_OFFER
2022-03-02 09:47:46 DEBUG   lwsWssCallbackRoutine(): Client is writable
2022-03-02 09:47:46 WARN    signalingMessageReceived(): Max simultaneous streaming session count reached.
2022-03-02 09:47:47 DEBUG   receiveLwsMessage(): Client received message of type: ICE_CANDIDATE
2022-03-02 09:47:47 DEBUG   lwsWssCallbackRoutine(): Client is writable
2022-03-02 09:47:47 DEBUG   receiveLwsMessage(): Client received message of type: ICE_CANDIDATE
2022-03-02 09:47:47 DEBUG   lwsWssCallbackRoutine(): Client is writable
2022-03-02 09:47:47 DEBUG   receiveLwsMessage(): Client received message of type: ICE_CANDIDATE
2022-03-02 09:47:47 DEBUG   lwsWssCallbackRoutine(): Client is writable
2022-03-02 09:47:47 DEBUG   receiveLwsMessage(): Client received message of type: ICE_CANDIDATE

In the entire log file for Camera 2, I extracted the following log messages that contain a Client ID, which might be useful to work out the connection/disconnection timeline.

2022-03-02 09:21:01 DEBUG   sendLwsMessage(): Sending data over web socket: Message type: ICE_CANDIDATE, RecepientId: 7hbl9vs203j96fwj27il7c
2022-03-02 09:21:01 DEBUG   sendLwsMessage(): Sending data over web socket: Message type: ICE_CANDIDATE, RecepientId: 7hbl9vs203j96fwj27il7c
2022-03-02 09:21:01 DEBUG   sendLwsMessage(): Sending data over web socket: Message type: ICE_CANDIDATE, RecepientId: 7hbl9vs203j96fwj27il7c
2022-03-02 09:21:01 DEBUG   sendLwsMessage(): Sending data over web socket: Message type: ICE_CANDIDATE, RecepientId: 7hbl9vs203j96fwj27il7c
2022-03-02 09:21:01 DEBUG   sendLwsMessage(): Sending data over web socket: Message type: SDP_ANSWER, RecepientId: 7hbl9vs203j96fwj27il7c
2022-03-02 09:21:07 DEBUG   freeSampleStreamingSession(): Freeing streaming session with peer id: 7hbl9vs203j96fwj27il7c 
2022-03-02 09:24:24 DEBUG   sendLwsMessage(): Sending data over web socket: Message type: ICE_CANDIDATE, RecepientId: 5ycdafsvhdr0uxnt5tx1w1q
2022-03-02 09:24:24 DEBUG   sendLwsMessage(): Sending data over web socket: Message type: ICE_CANDIDATE, RecepientId: 5ycdafsvhdr0uxnt5tx1w1q
2022-03-02 09:24:24 DEBUG   sendLwsMessage(): Sending data over web socket: Message type: SDP_ANSWER, RecepientId: 5ycdafsvhdr0uxnt5tx1w1q
2022-03-02 09:24:25 DEBUG   sendLwsMessage(): Sending data over web socket: Message type: ICE_CANDIDATE, RecepientId: 5ycdafsvhdr0uxnt5tx1w1q
2022-03-02 09:24:25 DEBUG   sendLwsMessage(): Sending data over web socket: Message type: ICE_CANDIDATE, RecepientId: 5ycdafsvhdr0uxnt5tx1w1q
2022-03-02 09:25:07 DEBUG   sendLwsMessage(): Sending data over web socket: Message type: ICE_CANDIDATE, RecepientId: C2
2022-03-02 09:25:07 DEBUG   sendLwsMessage(): Sending data over web socket: Message type: ICE_CANDIDATE, RecepientId: C2
2022-03-02 09:25:07 DEBUG   sendLwsMessage(): Sending data over web socket: Message type: ICE_CANDIDATE, RecepientId: C2
2022-03-02 09:25:07 DEBUG   sendLwsMessage(): Sending data over web socket: Message type: SDP_ANSWER, RecepientId: C2
2022-03-02 09:27:48 DEBUG   freeSampleStreamingSession(): Freeing streaming session with peer id: 5ycdafsvhdr0uxnt5tx1w1q 
2022-03-02 09:27:52 DEBUG   sendLwsMessage(): Sending data over web socket: Message type: ICE_CANDIDATE, RecepientId: dcps5coycpfbuj4a6wn5df
2022-03-02 09:27:52 DEBUG   sendLwsMessage(): Sending data over web socket: Message type: SDP_ANSWER, RecepientId: dcps5coycpfbuj4a6wn5df
2022-03-02 09:27:53 DEBUG   sendLwsMessage(): Sending data over web socket: Message type: ICE_CANDIDATE, RecepientId: dcps5coycpfbuj4a6wn5df
2022-03-02 09:27:53 DEBUG   sendLwsMessage(): Sending data over web socket: Message type: ICE_CANDIDATE, RecepientId: dcps5coycpfbuj4a6wn5df
2022-03-02 09:28:02 DEBUG   freeSampleStreamingSession(): Freeing streaming session with peer id: C2 
2022-03-02 09:28:37 DEBUG   sendLwsMessage(): Sending data over web socket: Message type: ICE_CANDIDATE, RecepientId: C2
2022-03-02 09:28:37 DEBUG   sendLwsMessage(): Sending data over web socket: Message type: SDP_ANSWER, RecepientId: C2
2022-03-02 09:28:38 DEBUG   sendLwsMessage(): Sending data over web socket: Message type: ICE_CANDIDATE, RecepientId: C2
2022-03-02 09:28:38 DEBUG   sendLwsMessage(): Sending data over web socket: Message type: ICE_CANDIDATE, RecepientId: C2
2022-03-02 09:29:20 DEBUG   freeSampleStreamingSession(): Freeing streaming session with peer id: C2 
2022-03-02 09:29:29 DEBUG   sendLwsMessage(): Sending data over web socket: Message type: ICE_CANDIDATE, RecepientId: C2
2022-03-02 09:29:29 DEBUG   sendLwsMessage(): Sending data over web socket: Message type: ICE_CANDIDATE, RecepientId: C2
2022-03-02 09:29:29 DEBUG   sendLwsMessage(): Sending data over web socket: Message type: ICE_CANDIDATE, RecepientId: C2
2022-03-02 09:29:29 DEBUG   sendLwsMessage(): Sending data over web socket: Message type: SDP_ANSWER, RecepientId: C2
2022-03-02 09:29:35 DEBUG   freeSampleStreamingSession(): Freeing streaming session with peer id: C2 
2022-03-02 09:46:38 DEBUG   freeSampleStreamingSession(): Freeing streaming session with peer id: dcps5coycpfbuj4a6wn5df 
2022-03-02 09:47:14 DEBUG   sendLwsMessage(): Sending data over web socket: Message type: ICE_CANDIDATE, RecepientId: 3wk6vxxwmp3ptk4v5z15fe
2022-03-02 09:47:14 DEBUG   sendLwsMessage(): Sending data over web socket: Message type: ICE_CANDIDATE, RecepientId: 3wk6vxxwmp3ptk4v5z15fe
2022-03-02 09:47:14 DEBUG   sendLwsMessage(): Sending data over web socket: Message type: ICE_CANDIDATE, RecepientId: 3wk6vxxwmp3ptk4v5z15fe
2022-03-02 09:47:14 DEBUG   sendLwsMessage(): Sending data over web socket: Message type: ICE_CANDIDATE, RecepientId: 3wk6vxxwmp3ptk4v5z15fe
2022-03-02 09:47:14 DEBUG   sendLwsMessage(): Sending data over web socket: Message type: SDP_ANSWER, RecepientId: 3wk6vxxwmp3ptk4v5z15fe
2022-03-02 09:48:36 DEBUG   freeSampleStreamingSession(): Freeing streaming session with peer id: 3wk6vxxwmp3ptk4v5z15fe 
2022-03-02 09:48:46 DEBUG   sendLwsMessage(): Sending data over web socket: Message type: ICE_CANDIDATE, RecepientId: w4gkwjoupork5v6la72
2022-03-02 09:48:46 DEBUG   sendLwsMessage(): Sending data over web socket: Message type: SDP_ANSWER, RecepientId: w4gkwjoupork5v6la72
2022-03-02 09:48:47 DEBUG   sendLwsMessage(): Sending data over web socket: Message type: ICE_CANDIDATE, RecepientId: w4gkwjoupork5v6la72
2022-03-02 09:48:47 DEBUG   sendLwsMessage(): Sending data over web socket: Message type: ICE_CANDIDATE, RecepientId: w4gkwjoupork5v6la72
2022-03-02 09:51:45 DEBUG   freeSampleStreamingSession(): Freeing streaming session with peer id: w4gkwjoupork5v6la72 

After the last freeSampleStreamingSession(): Freeing streaming session with peer id: w4gkwjoupork5v6la72, I can see multiple receiveLwsMessage(): Client received message of type: SDP_OFFER, but no message containing SDP_ANSWER any more.

** Any design considerations/constraints ** I have an edge device with 8 security cameras on it. I want to be able to WebRTC to all 8 cameras simultaneously to create a 360 degree view. I now have a Greengrass Component that deploys a Docker container onto the robot to run the aforementioned WebRTC programs (/samples/kvsWebRTCClientMasterGstreamerSample.c) -- one instance for each camera, and connecting to one KVS Signaling Channel (i.e. total of 8 instances of kvsWebRTCClientMasterGstreamerSample running on the robot, and 8 signaling channels in AWS).

This setup worked initially, but stopped working shortly after one or two rounds of connection/disconnection. The symptom is that the browser viewers could no longer receive SDP answers, and as a result, failed to play videos. I had to kill and restart the Docker container for this to work again, but only for a short while.

I noticed Max simultaneous streaming session count reached. were mentioned in the log file, but we had less than 10 viewers connected to a SINGLE camera/signaling channel at any point in time, so I am suspecting if sessions were left orphaned and not cleaned up properly (though I did see freeSampleStreamingSession() invoked as well).

Any help on this would be highly appreciated!

Mark

[niyatim23]

Hi @mark-gu-aws, can you please share the version of the SDK that you're using?

[mark-gu-aws]

Hi @mark-gu-aws, can you please share the version of the SDK that you're using?

Hi @niyatim23, we are building it from source directly in Docker, with minor changes to Common.c and kvsWebRTCClientMasterGstreamerSample.c mostly to do with loading keys and thing name from environment variables. Please see below:

RUN git clone --recursive https://github.com/awslabs/amazon-kinesis-video-streams-webrtc-sdk-c.git /root/amazon-kinesis-video-streams-webrtc-sdk-c
ARG component_folder
COPY $component_folder/webrtc-streamer /root/amazon-kinesis-video-streams-webrtc-sdk-c/samples
RUN mkdir -p /root/amazon-kinesis-video-streams-webrtc-sdk-c/build; cd /root/amazon-kinesis-video-streams-webrtc-sdk-c/build; cmake ..; make

I believe it's using the version (cached in Docker layer) from 5 days ago .

[mark-gu-aws]

Any update? Thanks @niyatim23

[niyatim23]

Hi @mark-gu-aws, we are looking into it. We'll add an update here once we have something

[github-actions[bot]]

This is a very old issue. We encourage you to check if this is still an issue in the latest release and if you find that this is still a problem, please feel free to open a new one.

[niyatim23]

Hi @mark-gu-aws, are we still seeing this issue with the latest release?

[niyatim23]

Closing since this issue is stale. Feel free to reopen / open a new issue if the same problem persists with the latest release