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

Amazon Kinesis Video Streams Webrtc SDK is for developers to install and customize realtime communication between devices and enable secure streaming of video, audio to Kinesis Video Streams.
https://awslabs.github.io/amazon-kinesis-video-streams-webrtc-sdk-c/group__PublicMemberFunctions.html
Apache License 2.0
1.01k stars 304 forks source link

[BUG] Socket being closed due to SSL/TLS issue: (dtlsSessionProcessPacket(): Detected DTLS close_notify alert) #1098

Closed maneeshj closed 3 years ago

maneeshj commented 3 years ago

Logging 2021-03-12T12:58:45.860-08:00 2021-03-12 20:58:45 VERBOSE on_new_sample(): [writeFrame] Number of open streaming sessions: 2 2021-03-12T12:58:45.860-08:00 2021-03-12 20:58:45 VERBOSE on_new_sample(): [writeFrame] Number of open streaming sessions: 2 2021-03-12T12:58:45.860-08:00 2021-03-12 20:58:45 VERBOSE bandwidthEstimationHandler(): received bitrate suggestion: 1019476.000000 2021-03-12T12:58:45.860-08:00 2021-03-12 20:58:45 VERBOSE rtcpReportsCallback(): sender report 611147283 16426409624744452706 77547970840865 : 0 packets 0 bytes 2021-03-12T12:58:45.860-08:00 2021-03-12 20:58:45 VERBOSE resendPacketOnNack(): Resent packet ssrc 1277931242 seq 17335 succeeded 2021-03-12T12:58:45.860-08:00 2021-03-12 20:58:45 VERBOSE bandwidthEstimationHandler(): received bitrate suggestion: 1019476.000000 2021-03-12 20:58:45 DEBUG dtlsSessionProcessPacket(): Detected DTLS close_notify alert 2021-03-12 20:58:45 INFO onConnectionStateChange(): Channel TPA2-GATE1-CHECK_IN-1-REAR-1-LO, New connection state 6 2021-03-12 20:58:45 VERBOSE sessionCleanupWait(): [sessionCleanupWait] TPA2-GATE1-CHECK_IN-1-REAR-1-LO, Number of open streaming sessions: 2 2021-03-12 20:58:45 DEBUG freeStreamingSession(): Freeing streaming session with peer id: aeb3ac52-7983-49f5-b5b0-f595624d1b37 2021-03-12 20:58:45 DEBUG socketConnectionClosed(): Close socket 16 2021-03-12 20:58:45 DEBUG socketConnectionClosed(): Close socket 15 2021-03-12 20:58:45 VERBOSE rtcpReportsCallback(): sender report 1708202500 16426409625037606988 12671735 : 31856 packets 34373826 bytes 2021-03-12 20:58:45 DEBUG on_new_sample(): [GStreamerWrapper] on_new_sample() callback is called 2021-03-12 20:58:45 VERBOSE on_new_sample(): [writeFrame] Number of open streaming sessions: 1 2021-03-12 20:58:45 DEBUG turnConnectionStepState(): TurnConnection state changed from TURN_STATE_READY to TURN_STATE_CLEAN_UP 2021-03-12 20:58:46 WARN iceAgentShutdown(): TurnConnection shutdown did not complete within 1 seconds 2021-03-12 20:58:46 DEBUG socketConnectionClosed(): Close socket 34 2021-03-12T12:58:46.974-08:00 2021-03-12 20:58:46 WARN iceAgentShutdown(): TurnConnection shutdown did not complete within 1 seconds 2021-03-12T12:58:46.974-08:00 2021-03-12 20:58:46 DEBUG socketConnectionClosed(): Close socket 32 2021-03-12 20:58:46 DEBUG socketConnectionSendData(): Warning: Failed to send data. Socket closed already 2021-03-12 20:58:46 ERROR iceUtilsSendData(): operation returned status cod6 DEBUG socketConnectionSendData(): Warning: Failed to send data. Socket closed already 2021-03-12 20:58:46 ERROR iceUtilsSendData(): operation returned status code: 0x58000022 2021-03-12 20:58:46 ERROR iceUtilsSendStunPacket(): operation returned status code: 0x58000022 2021-03-12 20:58:46 ERROR turnConnectionTimerCallback(): TurnConnection socket 34 closed unexpectedly 2021-03-12 20:58:46 WARN turnConnectionStepState(): TurnConnection in TURN_STATE_FAILED due to 0x58000022. Aborting TurnConnection 2021-03-12 20:58:46 DEBUG turnConnectionStepState(): TurnConnection state changed from TURN_STATE_FAILED to TURN_STATE_CLEAN_UP

Describe the bug We have 4 cameras streaming over 4 signaling channels. The streams work fine initially(with bit rate of 1-2mbps), but later just die down with bit rate showing as 0kbps. The streams to be stable for only few seconds. This pattern is specially true when we stream using high resolution 1920*1080px. I looked at the logs and from my understanding, it looks like its failing on SSL_read() because of this error: 2021-03-12 20:58:45 DEBUG dtlsSessionProcessPacket(): Detected DTLS close_notify alert. Then I see a cascade of errors being thrown, since the socket gets closed and eventually the stream dies. I am not sure if my understanding of the issue is correct. I have pasted the logs above. Any help is appreciated.

SDK version number Release 1.4.0

Expected behavior Streams to continue streaming without any issues for long periods.

Screenshots Before in AWS KVS Screen Shot 2021-03-12 at 5 06 17 PM

After: Screen Shot 2021-03-12 at 5 06 50 PM

Desktop (please complete the following information):

Additional context Add any other context about the problem here.

disa6302 commented 3 years ago

@maneeshj ,

DTLS close_notify alert usually indicates that the other peer shutdown and there is no peer to send data to or receive data from. Also, I assume this is a single master-viewer set up right? You have 4 masters and 4 viewers?

maneeshj commented 3 years ago

Hi Divya, Thanks for answering. We have 1 master and multiple viewers. So our streaming works when started and after a while the bitrate drops to 0. Do you think its because of DTLS close_notify alert? Do you think it is networking or SSL related ?

disa6302 commented 3 years ago

@maneeshj ,

It could be network related that causes the viewer to drop out, thereby sending a close_alert.

maneeshj commented 3 years ago

Thanks! So what do you recommend ?

disa6302 commented 3 years ago

I would recommend you to debug your network. Also, try starting with 1 master and 1 viewer and then take it from there.

disa6302 commented 3 years ago

Closing assuming question is answered. Feel free to reach or reopen this issue if you have questions.

maneeshj commented 3 years ago

Hi Divya, These are some of the different errors I get: 2021-03-03 17:24:44 ERROR iceAgentAddRemoteCandidate(): operation returned status code: 0x5a000005 2021-03-04 19:07:18 ERROR iceAgentAddRemoteCandidate(): operation returned status code: 0x00000002 2021-03-04 19:07:19 ERROR turnConnectionSendData(): operation returned status code: 0x5a000027 2021-03-05 02:23:52 ERROR executeFailedIceAgentState(): IceAgent failed with 0x5a00000d 2021-03-05 02:23:52 ERROR executeFailedIceAgentState(): IceAgent failed with 0x5a00000d 2021-03-05 21:28:27 ERROR iceUtilsSendData(): operation returned status code: 0x58000022 2021-03-05 21:28:27 ERROR iceUtilsSendStunPacket(): operation returned status code: 0x58000022

I was able to get their meaning from https://awslabs.github.io/amazon-kinesis-video-streams-webrtc-sdk-c. But I want to understand if these errors being thrown are of a CONCERN or if they are normal while making a peer to peer connection between master and viewer ? Could you please let me know. Thanks!