Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

[Bug]: Sample session is closed on master side once viewer disconnection, but it will take time and some time not closed also. #2064

Open
3 tasks done
vasoyanikhil opened this issue Oct 22, 2024 · 1 comment
Open
3 tasks done

[Bug]: Sample session is closed on master side once viewer disconnection, but it will take time and some time not closed also. #2064

vasoyanikhil opened this issue Oct 22, 2024 · 1 comment
Labels
bug Something isn't working needs-triage v1.10.2

Comments

@vasoyanikhil
Copy link

Please confirm you have already done the following

  • I have searched the repository for related/existing bug reports
  • I have all the details the issue requires

Please answer the following prompt

  • This issue is replicable using the unmodified sample application

Describe the bug

frequently connecting and disconnecting the client to master then connection not closing and some time take time to close the issue.

Logs:
[20241022 09:16:26.905] [590] [I] [lc] [startWebrtc, 213]: [KVS Master] Signaling client connection to socket established[m]
2024-10-22 01:16:27.278 PROFILE createRtcCertificate(): [Certificate creation time] Time taken: 21 ms
2024-10-22 01:16:28.280 PROFILE createRtcCertificate(): [Certificate creation time] Time taken: 24 ms
[20241022 09:16:28.305] [590] [D] [lc] [masterSessionWait, 328]: count = 0, kvs total_size = 92387[m]
[20241022 09:16:30.306] [590] [D] [lc] [masterSessionWait, 328]: count = 0, kvs total_size = 92387[m]
[20241022 09:16:32.308] [590] [D] [lc] [masterSessionWait, 328]: count = 0, kvs total_size = 92387[m]
[20241022 09:16:34.309] [590] [D] [lc] [masterSessionWait, 328]: count = 0, kvs total_size = 92387[m]
2024-10-22 01:16:35.629 DEBUG receiveLwsMessage(): Client received message of type: ICE_CANDIDATE
2024-10-22 01:16:35.629 DEBUG lwsWssCallbackRoutine(): Client is writable
2024-10-22 01:16:35.693 DEBUG receiveLwsMessage(): Client received message of type: ICE_CANDIDATE
2024-10-22 01:16:35.693 DEBUG lwsWssCallbackRoutine(): Client is writable
[20241022 09:16:36.310] [590] [D] [lc] [masterSessionWait, 328]: count = 0, kvs total_size = 116591[m]
2024-10-22 01:16:36.905 DEBUG lwsWssCallbackRoutine(): Client is writable
2024-10-22 01:16:36.936 INFO lwsWssCallbackRoutine(): WSS callback with reason 9
[20241022 09:16:38.311] [590] [D] [lc] [masterSessionWait, 328]: count = 0, kvs total_size = 116591[m]
2024-10-22 01:16:38.513 DEBUG receiveLwsMessage(): Client received message of type: SDP_OFFER
2024-10-22 01:16:38.514 DEBUG refreshIceConfiguration(): Refreshing the ICE Server Configuration
2024-10-22 01:16:38.514 INFO refreshIceConfiguration(): Retrieving ICE config through getIceServerConfig call again
2024-10-22 01:16:38.515 DEBUG defaultSignalingStateTransitionHook(): Retry count: 3576767159730176
2024-10-22 01:16:38.516 DEBUG lwsWssCallbackRoutine(): Client is writable
2024-10-22 01:16:38.516 DEBUG receiveLwsMessage(): Client received message of type: ICE_CANDIDATE
2024-10-22 01:16:38.517 DEBUG lwsWssCallbackRoutine(): Client is writable
2024-10-22 01:16:38.537 DEBUG receiveLwsMessage(): Client received message of type: ICE_CANDIDATE
2024-10-22 01:16:38.538 DEBUG lwsWssCallbackRoutine(): Client is writable
2024-10-22 01:16:38.617 DEBUG receiveLwsMessage(): Client received message of type: ICE_CANDIDATE
2024-10-22 01:16:38.617 DEBUG lwsWssCallbackRoutine(): Client is writable
2024-10-22 01:16:38.623 DEBUG receiveLwsMessage(): Client received message of type: ICE_CANDIDATE
2024-10-22 01:16:38.624 DEBUG lwsWssCallbackRoutine(): Client is writable
2024-10-22 01:16:38.680 INFO lwsWssCallbackRoutine(): WSS callback with reason 71
[2024/10/22 09:16:38:6812] N: __lws_lc_tag: ++ [wsicli|3|POST/h1/default/r-2168f5b4.kinesisvideo.ap-south-1.a] (2)
2024-10-22 01:16:38.695 DEBUG lwsWssCallbackRoutine(): Client is writable
2024-10-22 01:16:38.781 DEBUG lwsHttpCallbackRoutine(): Client append handshake header

2024-10-22 01:16:38.783 DEBUG lwsHttpCallbackRoutine(): Sending the body {
"ChannelARN": "arn:aws:kinesisvideo:ap-south-1:210690619675:channel/11E456B78E/1725860492537",
"ClientId": "ProducerMaster",
"Service": "TURN"
}, size 149
2024-10-22 01:16:38.888 DEBUG lwsHttpCallbackRoutine(): Connected with server response: 200
2024-10-22 01:16:38.889 DEBUG lwsHttpCallbackRoutine(): Received client http
2024-10-22 01:16:38.889 DEBUG lwsHttpCallbackRoutine(): Received client http read: 975 bytes
2024-10-22 01:16:38.889 DEBUG lwsHttpCallbackRoutine(): Http client completed
2024-10-22 01:16:38.889 DEBUG lwsHttpCallbackRoutine(): Client http closed
[2024/10/22 09:16:38:8937] N: __lws_lc_untag: -- [wsicli|3|POST/h1/default/r-2168f5b4.kinesisvideo.ap-south-1.a] (1) 212.505ms
2024-10-22 01:16:38.894 PROFILE executeGetIceConfigSignalingState(): [Get ICE config signaling call] Time taken: 379 ms
2024-10-22 01:16:38.894 PROFILE executeConnectSignalingState(): [Connect signaling call] Time taken: 0 ms
2024-10-22 01:16:38.894 DEBUG refreshIceConfiguration(): Refreshing the ICE Server Configuration
2024-10-22 01:16:38.945 PROFILE createDtlsSession(): [Create SSL Context] Time taken: 49 ms
2024-10-22 01:16:38.945 PROFILE createDtlsSession(): [Create SSL session] Time taken: 0 ms
2024-10-22 01:16:38.946 PROFILE createPeerConnection(): [Create DTLS Session object] Time taken: 50 ms
2024-10-22 01:16:38.946 PROFILE createPeerConnection(): [Create connection listener] Time taken: 0 ms
2024-10-22 01:16:38.947 INFO iceAgentValidateKvsRtcConfig():
iceLocalCandidateGatheringTimeout: 10000 ms
iceConnectionCheckTimeout: 0 ms
iceCandidateNominationTimeout: 12000 ms
iceConnectionCheckPollingInterval: 0 ms
2024-10-22 01:16:38.948 DEBUG onSetStunServerIp(): Exiting from stun server IP callback
2024-10-22 01:16:38.948 INFO getIpWithHostName(): ICE SERVER Hostname received: stun.kinesisvideo.ap-south-1.(null)
2024-10-22 01:16:38.949 WARN getIpAddrFromDnsHostname(): Received unexpected hostname format: stun.kinesisvideo.ap-south-1.(null)
2024-10-22 01:16:38.949 WARN getIpWithHostName(): Parsing for address failed for stun.kinesisvideo.ap-south-1.(null), fallback to getaddrinfo
2024-10-22 01:16:38.962 ERROR getIpWithHostName(): getaddrinfo() with errno Name or service not known
2024-10-22 01:16:38.964 ERROR getIpWithHostName(): operation returned status code: 0x5800001b
2024-10-22 01:16:38.965 PROFILE createIceAgent(): [ICE server parsing] Time taken: 16 ms
2024-10-22 01:16:38.965 ERROR createIceAgent(): Failed to parse ICE servers
2024-10-22 01:16:38.965 INFO getIpWithHostName(): ICE SERVER Hostname received: 65-2-186-155.t-7bac9ed8.kinesisvideo.ap-south-1.amazonaws.com
2024-10-22 01:16:38.966 PROFILE parseIceServer(): ICE Server address for 65-2-186-155.t-7bac9ed8.kinesisvideo.ap-south-1.amazonaws.com: 65.2.186.155
2024-10-22 01:16:38.967 PROFILE createIceAgent(): [ICE server parsing] Time taken: 1 ms
2024-10-22 01:16:38.967 INFO getIpWithHostName(): ICE SERVER Hostname received: 65-2-186-155.t-7bac9ed8.kinesisvideo.ap-south-1.amazonaws.com
2024-10-22 01:16:38.967 PROFILE parseIceServer(): ICE Server address for 65-2-186-155.t-7bac9ed8.kinesisvideo.ap-south-1.amazonaws.com: 65.2.186.155
2024-10-22 01:16:38.967 PROFILE createIceAgent(): [ICE server parsing] Time taken: 0 ms
2024-10-22 01:16:38.968 INFO getIpWithHostName(): ICE SERVER Hostname received: 65-2-186-155.t-7bac9ed8.kinesisvideo.ap-south-1.amazonaws.com
2024-10-22 01:16:38.968 PROFILE parseIceServer(): ICE Server address for 65-2-186-155.t-7bac9ed8.kinesisvideo.ap-south-1.amazonaws.com: 65.2.186.155
2024-10-22 01:16:38.968 PROFILE createIceAgent(): [ICE server parsing] Time taken: 0 ms
2024-10-22 01:16:38.969 PROFILE createPeerConnection(): [Create ICE agent object] Time taken: 22 ms
2024-10-22 01:16:38.969 PROFILE createPeerConnection(): [Peer connection object creation time] Time taken: 74 ms
2024-10-22 01:16:38.977 DEBUG initializePeerConnection(): time taken to create peer connection 81 ms
2024-10-22 01:16:38.985 PROFILE iceAgentStartGathering(): [Host candidate gathering from local interfaces] Time taken: 0 ms
2024-10-22 01:16:38.985 DEBUG iceAgentCheckConnectionStateSetup(): ice candidate pair count 0
2024-10-22 01:16:38.986 INFO stepIceAgentStateMachine(): Ice agent state changed from ICE_AGENT_STATE_NEW to ICE_AGENT_STATE_CHECK_CONNECTION.
2024-10-22 01:16:38.986 INFO onConnectionStateChange(): New connection state 2
2024-10-22 01:16:38.986 DEBUG createSocketConnection(): create socket with ip: 192.168.1.117:54655. family:1
2024-10-22 01:16:38.987 PROFILE iceAgentStartGathering(): [Host candidates setup time] Time taken: 1 ms
2024-10-22 01:16:38.987 PROFILE iceAgentStartGathering(): [Srflx candidates setup time] Time taken: 0 ms
2024-10-22 01:16:38.996 DEBUG iceAgentLogNewCandidate(): New local ice candidate discovered. Id: gDX8wt7/q. Ip: 192.168.1.117:54655. Type: host. Protocol: udp.
2024-10-22 01:16:38.997 DEBUG sendLwsMessage(): ICE_CANDIDATE
2024-10-22 01:16:38.997 DEBUG sendLwsMessage(): {"candidate":"candidate:0 1 udp 2130706431 192.168.1.117 54655 typ host raddr 0.0.0.0 rport 0 generation 0 network-cost 999","sdpMid":"0","}
2024-10-22 01:16:38.997 DEBUG sendLwsMessage(): Sending data over web socket: Message type: ICE_CANDIDATE, RecepientId: 0c2ea6fc-b3f1-4ed7-abcf-1aac8f00559e
2024-10-22 01:16:38.998 INFO lwsWssCallbackRoutine(): WSS callback with reason 71
2024-10-22 01:16:38.998 DEBUG lwsWssCallbackRoutine(): Client is writable
2024-10-22 01:16:39.337 DEBUG sendLwsMessage(): SDP_ANSWER
2024-10-22 01:16:39.337 DEBUG sendLwsMessage(): {"type": "answer", "sdp": "v=0\r\no=- 2065892765 2 IN IP4 127.0.0.1\r\ns=-\r\nt=0 0\r\na=group:BUNDLE 0 1 2\r\na=ice-options:trickle\r\na=m}
2024-10-22 01:16:39.338 DEBUG sendLwsMessage(): Sending data over web socket: Message type: SDP_ANSWER, RecepientId: 0c2ea6fc-b3f1-4ed7-abcf-1aac8f00559e
2024-10-22 01:16:39.338 INFO lwsWssCallbackRoutine(): WSS callback with reason 71
2024-10-22 01:16:39.339 DEBUG lwsWssCallbackRoutine(): Client is writable
2024-10-22 01:16:39.340 PROFILE signalingSendMessageSync(): [Offer Received to Answer Sent time] Time taken: 826 ms
2024-10-22 01:16:39.341 DEBUG handleOffer(): time taken to IceCandidate(): candidate:55245215 1 udp 41885695 3.111.36.103 65464 typ relay raddr 106.51.36.165 rport 49697 generation 0 ufra0
2024-10-22 01:16:39.387 DEBUG fromCheckConnectionIceAgentState(): Checking pair: gDX8wt7/q KudUk2TpK, state: 1
2024-10-22 01:16:39.635 DEBUG fromCheckConnectionIceAgentState(): Checking pair: gDX8wt7/q IKpnE2ePq, state: 1
2024-10-22 01:16:39.635 DEBUG iceCandidatePairCheckConnection(): remote ip:192.168.1.123, port:49697, local ip:192.168.1.117, port:54655
2024-10-22 01:16:39.635 DEBUG iceUtilsSendStunPacket(): Sending BINDING_REQUEST to ip:192.168.1.123, port:49697
2024-10-22 01:16:39.636 DEBUG iceCandidatePairCheckConnection(): remote ip:106.51.36.165, port:49697, local ip:192.168.1.117, port:54655
2024-10-22 01:16:39.636 DEBUG iceUtilsSendStunPacket(): Sending BINDING_REQUEST to ip:106.51.36.165, port:49697
2024-10-22 01:16:39.637 DEBUG iceUtilsSendStunPacket(): Sending BINDING_RESPONSE_SUCCESS to ip:192.168.1.123, port:49697
2024-10-22 01:16:39.638 DEBUG handleStunPacket(): Pair binding request! gDX8wt7/q KudUk2TpK
2024-10-22 01:16:39.638 DEBUG handleStunPacket(): received candidate with USE_CANDIDATE flag, local candidate type host(gDX8wt7/q:KudUk2TpK).
2024-10-22 01:16:39.638 DEBUG handleStunPacket(): going to change the data sending ice candidate pair.
2024-10-22 01:16:39.639 DEBUG iceAgentLogNewCandidate(): New remote ice candidate discovered. Id: GrnITA6ca. Ip: 3.111.36.103:65464. Type: relay. Protocol: udp.
2024-10-22 01:16:39.639 DEBUG addIceCandidate(): candidate:168630473 1 udp 41885439 13.233.173.212 57627 typ relay raddr 106.51.36.165 rport 49697 generation 0 ufrag ETwm network-id 3 net0
2024-10-22 01:16:39.639 DEBUG iceAgentLogNewCandidate(): New remote ice candidate discovered. Id: lOCvJjwKE. Ip: 13.233.173.212:57627. Type: relay. Protocol: udp.
2024-10-22 01:16:39.643 DEBUG fromCheckConnectionIceAgentState(): Checking pair: gDX8wt7/q KudUk2TpK, state: 2
2024-10-22 01:16:39.644 DEBUG fromCheckConnectionIceAgentState(): Checking pair: gDX8wt7/q IKpnE2ePq, state: 2
2024-10-22 01:16:39.644 DEBUG fromCheckConnectionIceAgentState(): Checking pair: gDX8wt7/q GrnITA6ca, state: 1
2024-10-22 01:16:39.646 DEBUG fromCheckConnectionIceAgentState(): Checking pair: gDX8wt7/q lOCvJjwKE, state: 1
2024-10-22 01:16:39.646 DEBUG fromCheckConnectionIceAgentState(): Checking pair: gDX8wt7/q KudUk2TpK, state: 2
2024-10-22 01:16:39.646 DEBUG fromCheckConnectionIceAgentState(): Checking pair: gDX8wt7/q IKpnE2ePq, state: 2
2024-10-22 01:16:39.647 DEBUG fromCheckConnectionIceAgentState(): Checking pair: gDX8wt7/q GrnITA6ca, state: 1
2024-10-22 01:16:39.647 DEBUG fromCheckConnectionIceAgentState(): Checking pair: gDX8wt7/q lOCvJjwKE, state: 1
2024-10-22 01:16:39.647 DEBUG iceCandidatePairCheckConnection(): remote ip:192.168.1.123, port:49697, local ip:192.168.1.117, port:54655
2024-10-22 01:16:39.648 DEBUG iceUtilsSendStunPacket(): Sending BINDING_REQUEST to ip:192.168.1.123, port:49697
2024-10-22 01:16:39.661 DEBUG iceUtilsSendStunPacket(): Sending BINDING_RESPONSE_SUCCESS to ip:192.168.1.123, port:49697
2024-10-22 01:16:39.661 DEBUG handleStunPacket(): Pair binding request! gDX8wt7/q KudUk2TpK
2024-10-22 01:16:39.662 DEBUG handleStunPacket(): going to change the data sending ice candidate pair.
2024-10-22 01:16:39.662 DEBUG fromCheckConnectionIceAgentState(): Checking pair: gDX8wt7/q KudUk2TpK, state: 2
2024-10-22 01:16:39.662 DEBUG fromCheckConnectionIceAgentState(): Checking pair: gDX8wt7/q IKpnE2ePq, state: 2
2024-10-22 01:16:39.662 DEBUG fromCheckConnectionIceAgentState(): Checking pair: gDX8wt7/q GrnITA6ca, state: 1
2024-10-22 01:16:39.663 DEBUG fromCheckConnectionIceAgentState(): Checking pair: gDX8wt7/q lOCvJjwKE, state: 1
2024-10-22 01:16:39.663 DEBUG handleStunPacket(): Pair binding response! gDX8wt7/q KudUk2TpK
2024-10-22 01:16:39.663 DEBUG handleStunPacket(): Pair succeeded! gDX8wt7/q KudUk2TpK
2024-10-22 01:16:39.663 DEBUG handleStunPacket(): Ice candidate pair gDX8wt7/q_KudUk2TpK is connected. Round trip time: 28ms
2024-10-22 01:16:39.664 DEBUG fromCheckConnectionIceAgentState(): Checking pair: gDX8wt7/q KudUk2TpK, state: 3
2024-10-22 01:16:39.667 DEBUG fromCheckConnectionIceAgentState(): Checking pair: gDX8wt7/q KudUk2TpK, state: 3
2024-10-22 01:16:39.668 INFO stepIceAgentStateMachine(): Ice agent state changed from ICE_AGENT_STATE_CHECK_CONNECTION to ICE_AGENT_STATE_CONNECTED.
2024-10-22 01:16:39.668 DEBUG handleStunPacket(): Pair binding response! gDX8wt7/q KudUk2TpK
2024-10-22 01:16:39.685 PROFILE createRtcCertificate(): [Certificate creation time] Time taken: 44 ms
2024-10-22 01:16:40.003 DEBUG iceCandidatePairCheckConnection(): remote ip:192.168.1.123, port:49697, local ip:192.168.1.117, port:54655
2024-10-22 01:16:40.004 DEBUG iceUtilsSendStunPacket(): Sending BINDING_REQUEST to ip:192.168.1.123, port:49697
2024-10-22 01:16:40.005 INFO stepIceAgentStateMachine(): Ice agent state changed from ICE_AGENT_STATE_CONNECTED to ICE_AGENT_STATE_NOMINATING.
2024-10-22 01:16:40.006 PROFILE iceAgentReadyStateSetup(): Selected pair gDX8wt7/q_KudUk2TpK, local candidate type: host. remote candidate type: host. Round trip time 354 ms. Local candidat9
2024-10-22 01:16:40.006 DEBUG iceAgentReadyStateSetup(): Freeing Turn allocations that are not selected. Total turn allocation count 0
2024-10-22 01:16:40.006 PROFILE executeReadyIceAgentState(): [ICE Agent ready for media exchange from check connection start] Time taken: 1020 ms
2024-10-22 01:16:40.007 INFO stepIceAgentStateMachine(): Ice agent state changed from ICE_AGENT_STATE_NOMINATING to ICE_AGENT_STATE_READY.
2024-10-22 01:16:40.008 DEBUG dtlsSessionHandshakeInThread(): Handshake want READ/WRITE
2024-10-22 01:16:40.009 DEBUG iceUtilsSendStunPacket(): Sending BINDING_RESPONSE_SUCCESS to ip:192.168.1.123, port:49697
2024-10-22 01:16:40.009 DEBUG handleStunPacket(): Pair binding request! gDX8wt7/q KudUk2TpK
[20241022 09:16:40.315] [590] [D] [lc] [masterSessionWait, 328]: count = 1, kvs total_size = 1636810[m]
(none) login: 2024-10-22 01:16:41.008 DEBUG dtlsSessionHandshakeInThread(): DTLS handshake timeout event occurred, going to retransmit
2024-10-22 01:16:41.008 INFO dtlsSessionHandshakeInThread(): Timeout handled successfully, packet retransmitted
[20241022 09:16:42.316] [590] [D] [lc] [masterSessionWait, 328]: count = 1, kvs total_size = 1636810[m]
2024-10-22 01:16:42.541 DEBUG receiveLwsMessage(): Client received message of type: ICE_CANDIDATE
2024-10-22 01:16:42.542 DEBUG lwsWssCallbackRoutine(): Client is writable
2024-10-22 01:16:42.544 DEBUG receiveLwsMessage(): Client received message of type: SDP_OFFER
2024-10-22 01:16:42.546 DEBUG refreshIceConfiguration(): Refreshing the ICE Server Configuration
2024-10-22 01:16:42.546 DEBUG refreshIceConfiguration(): Refreshing the ICE Server Configuration
2024-10-22 01:16:42.547 DEBUG lwsWssCallbackRoutine(): Client is writable
2024-10-22 01:16:42.549 PROFILE createDtlsSession(): [Create SSL Context] Time taken: 1 ms
2024-10-22 01:16:42.550 PROFILE createDtlsSession(): [Create SSL session] Time taken: 0 ms
2024-10-22 01:16:42.551 PROFILE createPeerConnection(): [Create DTLS Session object] Time taken: 2 ms
2024-10-22 01:16:42.551 PROFILE createPeerConnection(): [Create connection listener] Time taken: 0 ms
2024-10-22 01:16:42.553 INFO iceAgentValidateKvsRtcConfig():
iceLocalCandidateGatheringTimeout: 10000 ms
iceConnectionCheckTimeout: 0 ms
iceCandidateNominationTimeout: 12000 ms
iceConnectionCheckPollingInterval: 0 ms
2024-10-22 01:16:42.554 DEBUG onSetStunServerIp(): Exiting from stun server IP callback
2024-10-22 01:16:42.554 INFO getIpWithHostName(): ICE SERVER Hostname received: stun.kinesisvideo.ap-south-1.(null)
2024-10-22 01:16:42.555 WARN getIpAddrFromDnsHostname(): Received unexpected hostname format: stun.kinesisvideo.ap-south-1.(null)
2024-10-22 01:16:42.555 WARN getIpWithHostName(): Parsing for address failed for stun.kinesisvideo.ap-south-1.(null), fallback to getaddrinfo
2024-10-22 01:16:42.564 ERROR getIpWithHostName(): getaddrinfo() with errno Name or service not known
2024-10-22 01:16:42.565 ERROR getIpWithHostName(): operation returned status code: 0x5800001b
2024-10-22 01:16:42.565 PROFILE createIceAgent(): [ICE server parsing] Time taken: 11 ms
2024-10-22 01:16:42.565 ERROR createIceAgent(): Failed to parse ICE servers
2024-10-22 01:16:42.566 INFO getIpWithHostName(): ICE SERVER Hostname received: 65-2-186-155.t-7bac9ed8.kinesisvideo.ap-south-1.amazonaws.com
2024-10-22 01:16:42.567 PROFILE parseIceServer(): ICE Server address for 65-2-186-155.t-7bac9ed8.kinesisvideo.ap-south-1.amazonaws.com: 65.2.186.155
2024-10-22 01:16:42.567 PROFILE createIceAgent(): [ICE server parsing] Time taken: 1 ms
2024-10-22 01:16:42.567 INFO getIpWithHostName(): ICE SERVER Hostname received: 65-2-186-155.t-7bac9ed8.kinesisvideo.ap-south-1.amazonaws.com
2024-10-22 01:16:42.567 PROFILE parseIceServer(): ICE Server address for 65-2-186-155.t-7bac9ed8.kinesisvideo.ap-south-1.amazonaws.com: 65.2.186.155
2024-10-22 01:16:42.568 PROFILE createIceAgent(): [ICE server parsing] Time taken: 0 ms
2024-10-22 01:16:42.568 INFO getIpWithHostName(): ICE SERVER Hostname received: 65-2-186-155.t-7bac9ed8.kinesisvideo.ap-south-1.amazonaws.com
2024-10-22 01:16:42.568 PROFILE parseIceServer(): ICE Server address for 65-2-186-155.t-7bac9ed8.kinesisvideo.ap-south-1.amazonaws.com: 65.2.186.155
2024-10-22 01:16:42.568 PROFILE createIceAgent(): [ICE server parsing] Time taken: 0 ms
2024-10-22 01:16:42.569 PROFILE createPeerConnection(): [Create ICE agent object] Time taken: 16 ms
2024-10-22 01:16:42.569 PROFILE createPeerConnection(): [Peer connection object creation time] Time taken: 22 ms
2024-10-22 01:16:42.569 DEBUG initializePeerConnection(): time taken to create peer connection 22 ms
2024-10-22 01:16:42.584 PROFILE iceAgentStartGathering(): [Host candidate gathering from local interfaces] Time taken: 0 ms
2024-10-22 01:16:42.584 DEBUG createSocketConnection(): create socket with ip: 192.168.1.117:41214. family:1
2024-10-22 01:16:42.585 DEBUG iceAgentCheckConnectionStateSetup(): ice candidate pair count 0
2024-10-22 01:16:42.585 INFO stepIceAgentStateMachine(): Ice agent state changed from ICE_AGENT_STATE_NEW to ICE_AGENT_STATE_CHECK_CONNECTION.
2024-10-22 01:16:42.585 INFO onConnectionStateChange(): New connection state 2
2024-10-22 01:16:42.586 PROFILE iceAgentStartGathering(): [Host candidates setup time] Time taken: 1 ms
2024-10-22 01:16:42.586 PROFILE iceAgentStartGathering(): [Srflx candidates setup time] Time taken: 0 ms
2024-10-22 01:16:42.601 DEBUG receiveLwsMessage(): Client received message of type: ICE_CANDIDATE
2024-10-22 01:16:42.620 DEBUG lwsWssCallbackRoutine(): Client is writable
2024-10-22 01:16:42.621 DEBUG sendLwsMessage(): SDP_ANSWER
2024-10-22 01:16:42.622 DEBUG sendLwsMessage(): {"type": "answer", "sdp": "v=0\r\no=- 479405131 2 IN IP4 127.0.0.1\r\ns=-\r\nt=0 0\r\na=group:BUNDLE 0 1 2\r\na=ice-options:trickle\r\na=ms}
2024-10-22 01:16:42.957 DEBUG sendLwsMessage(): Sending data over web socket: Message type: SDP_ANSWER, RecepientId: 6631a006-a565-4809-a6f5-fffff09307aa
2024-10-22 01:16:42.593 DEBUG iceAgentLogNewCandidate(): New local ice candidate discovered. Id: QuEZLcbX9. Ip: 192.168.1.117:41214. Type: host. Protocol: udp.
2024-10-22 01:16:42.645 DEBUG receiveLwsMessage(): Client received message of type: ICE_CANDIDATE
2024-10-22 01:16:42.958 DEBUG lwsWssCallbackRoutine(): Client is writable
2024-10-22 01:16:42.960 PROFILE signalingSendMessageSync(): [Offer Received to Answer Sent time] Time taken: 414 ms
2024-10-22 01:16:42.961 DEBUG sendLwsMessage(): ICE_CANDIDATE
2024-10-22 01:16:42.961 DEBUG sendLwsMessage(): {"candidate":"candidate:0 1 udp 2130706431 192.168.1.117 41214 typ host raddr 0.0.0.0 rport 0 generation 0 network-cost 999","sdpMid":"0","}
2024-10-22 01:16:42.961 DEBUG sendLwsMessage(): Sending data over web socket: Message type: ICE_CANDIDATE, RecepientId: 6631a006-a565-4809-a6f5-fffff09307aa
2024-10-22 01:16:42.962 DEBUG handleOffer(): time taken to send answer 384 ms
2024-10-22 01:16:42.964 DEBUG addIceCandidate(): candidate:3687888086 1 udp 2122260223 192.168.1.123 39506 typ host generation 0 ufrag HR1j network-id 3 network-cost 10
2024-10-22 01:16:42.965 DEBUG iceAgentLogNewCandidate(): New remote ice candidate discovered. Id: C0AKNAi6e. Ip: 192.168.1.123:39506. Type: host. Protocol: udp.
2024-10-22 01:16:42.966 DEBUG addIceCandidate(): candidate:842163049 1 udp 1686052607 106.51.36.165 39506 typ srflx raddr 192.168.1.123 rport 39506 generation 0 ufrag HR1j network-id 3 ne0
2024-10-22 01:16:42.966 DEBUG iceAgentLogNewCandidate(): New remote ice candidate discovered. Id: gE6IlXhAU. Ip: 106.51.36.165:39506. Type: srflx. Protocol: udp.
2024-10-22 01:16:42.966 DEBUG addIceCandidate(): candidate:2468719576 1 udp 41885695 13.232.94.117 57349 typ relay raddr 106.51.36.165 rport 39506 generation 0 ufrag HR1j network-id 3 net0
2024-10-22 01:16:42.965 DEBUG receiveLwsMessage(): Client received message of type: ICE_CANDIDATE
2024-10-22 01:16:43.301 DEBUG lwsWssCallbackRoutine(): Client is writable
2024-10-22 01:16:43.008 DEBUG dtlsSessionHandshakeInThread(): DTLS handshake timeout event occurred, going to retransmit
2024-10-22 01:16:43.302 INFO dtlsSessionHandshakeInThread(): Timeout handled successfully, packet retransmitted
2024-10-22 01:16:43.129 DEBUG iceUtilsSendStunPacket(): Sending BINDING_RESPONSE_SUCCESS to ip:192.168.1.123, port:39506
2024-10-22 01:16:43.303 DEBUG handleStunPacket(): Pair binding request! QuEZLcbX9 C0AKNAi6e
2024-10-22 01:16:43.303 DEBUG handleStunPacket(): received candidate with USE_CANDIDATE flag, local candidate type host(QuEZLcbX9:C0AKNAi6e).
2024-10-22 01:16:43.304 DEBUG handleStunPacket(): going to change the data sending ice candidate pair.
2024-10-22 01:16:43.304 DEBUG fromCheckConnectionIceAgentState(): Checking pair: QuEZLcbX9 C0AKNAi6e, state: 1
2024-10-22 01:16:43.304 DEBUG fromCheckConnectionIceAgentState(): Checking pair: QuEZLcbX9 gE6IlXhAU, state: 1
2024-10-22 01:16:43.304 DEBUG iceUtilsSendStunPacket(): Sending BINDING_RESPONSE_SUCCESS to ip:192.168.1.123, port:39506
2024-10-22 01:16:43.305 DEBUG handleStunPacket(): Pair binding request! QuEZLcbX9 C0AKNAi6e
2024-10-22 01:16:43.305 DEBUG handleStunPacket(): going to change the data sending ice candidate pair.
2024-10-22 01:16:43.305 DEBUG fromCheckConnectionIceAgentState(): Checking pair: QuEZLcbX9 C0AKNAi6e, state: 1
2024-10-22 01:16:43.306 DEBUG fromCheckConnectionIceAgentState(): Checking pair: QuEZLcbX9 gE6IlXhAU, state: 1
2024-10-22 01:16:43.306 DEBUG iceUtilsSendStunPacket(): Sending BINDING_RESPONSE_SUCCESS to ip:192.168.1.123, port:39506
2024-10-22 01:16:43.306 DEBUG handleStunPacket(): Pair binding request! QuEZLcbX9 C0AKNAi6e
2024-10-22 01:16:43.307 DEBUG handleStunPacket(): going to change the data sending ice candidate pair.
2024-10-22 01:16:43.307 DEBUG fromCheckConnectionIceAgentState(): Checking pair: QuEZLcbX9 C0AKNAi6e, state: 1
2024-10-22 01:16:43.307 DEBUG fromCheckConnectionIceAgentState(): Checking pair: QuEZLcbX9 gE6IlXhAU, state: 1
2024-10-22 01:16:43.307 DEBUG iceUtilsSendStunPacket(): Sending BINDING_RESPONSE_SUCCESS to ip:192.168.1.123, port:39506
2024-10-22 01:16:43.308 DEBUG handleStunPacket(): Pair binding request! QuEZLcbX9 C0AKNAi6e
2024-10-22 01:16:43.308 DEBUG handleStunPacket(): going to change the data sending ice candidate pair.
2024-10-22 01:16:43.308 DEBUG fromCheckConnectionIceAgentState(): Checking pair: QuEZLcbX9 C0AKNAi6e, state: 1
2024-10-22 01:16:43.309 DEBUG fromCheckConnectionIceAgentState(): Checking pair: QuEZLcbX9 gE6IlXhAU, state: 1
2024-10-22 01:16:43.309 DEBUG iceAgentLogNewCandidate(): New remote ice candidate discovered. Id: NJDvSOQd8. Ip: 13.232.94.117:57349. Type: relay. Protocol: udp.
2024-10-22 01:16:43.317 DEBUG fromCheckConnectionIceAgentState(): Checking pair: QuEZLcbX9 C0AKNAi6e, state: 1
2024-10-22 01:16:43.317 DEBUG fromCheckConnectionIceAgentState(): Checking pair: QuEZLcbX9 gE6IlXhAU, state: 1
2024-10-22 01:16:43.318 DEBUG fromCheckConnectionIceAgentState(): Checking pair: QuEZLcbX9 NJDvSOQd8, state: 1
2024-10-22 01:16:43.318 DEBUG iceCandidatePairCheckConnection(): remote ip:192.168.1.123, port:39506, local ip:192.168.1.117, port:41214
2024-10-22 01:16:43.318 DEBUG iceUtilsSendStunPacket(): Sending BINDING_REQUEST to ip:192.168.1.123, port:39506
2024-10-22 01:16:43.343 PROFILE createRtcCertificate(): [Certificate creation time] Time taken: 33 ms
2024-10-22 01:16:43.344 DEBUG addIceCandidate(): candidate:55245215 1 udp 41885439 3.111.36.103 55776 typ relay raddr 106.51.36.165 rport 39506 generation 0 ufrag HR1j network-id 3 networ0
2024-10-22 01:16:43.344 DEBUG iceAgentLogNewCandidate(): New remote ice candidate discovered. Id: s+d9BWcaw. Ip: 3.111.36.103:55776. Type: relay. Protocol: udp.
2024-10-22 01:16:43.348 DEBUG iceUtilsSendStunPacket(): Sending BINDING_RESPONSE_SUCCESS to ip:192.168.1.123, port:39506
2024-10-22 01:16:43.349 DEBUG handleStunPacket(): Pair binding request! QuEZLcbX9 C0AKNAi6e
2024-10-22 01:16:43.349 DEBUG handleStunPacket(): going to change the data sending ice candidate pair.
2024-10-22 01:16:43.683 DEBUG fromCheckConnectionIceAgentState(): Checking pair: QuEZLcbX9 C0AKNAi6e, state: 1
2024-10-22 01:16:43.684 DEBUG fromCheckConnectionIceAgentState(): Checking pair: QuEZLcbX9 gE6IlXhAU, state: 1
2024-10-22 01:16:43.685 DEBUG fromCheckConnectionIceAgentState(): Checking pair: QuEZLcbX9 NJDvSOQd8, state: 1
2024-10-22 01:16:43.685 DEBUG fromCheckConnectionIceAgentState(): Checking pair: QuEZLcbX9 s+d9BWcaw, state: 1
2024-10-22 01:16:43.685 DEBUG fromCheckConnectionIceAgentState(): Checking pair: QuEZLcbX9 C0AKNAi6e, state: 1
2024-10-22 01:16:43.686 DEBUG fromCheckConnectionIceAgentState(): Checking pair: QuEZLcbX9 gE6IlXhAU, state: 1
2024-10-22 01:16:43.686 DEBUG fromCheckConnectionIceAgentState(): Checking pair: QuEZLcbX9 NJDvSOQd8, state: 1
2024-10-22 01:16:43.686 DEBUG fromCheckConnectionIceAgentState(): Checking pair: QuEZLcbX9 s+d9BWcaw, state: 1
2024-10-22 01:16:43.686 DEBUG iceCandidatePairCheckConnection(): remote ip:192.168.1.123, port:39506, local ip:192.168.1.117, port:41214
2024-10-22 01:16:43.687 DEBUG iceUtilsSendStunPacket(): Sending BINDING_REQUEST to ip:192.168.1.123, port:39506
2024-10-22 01:16:43.687 DEBUG fromCheckConnectionIceAgentState(): Checking pair: QuEZLcbX9 C0AKNAi6e, state: 1
2024-10-22 01:16:43.688 DEBUG fromCheckConnectionIceAgentState(): Checking pair: QuEZLcbX9 gE6IlXhAU, state: 1
2024-10-22 01:16:43.688 DEBUG fromCheckConnectionIceAgentState(): Checking pair: QuEZLcbX9 NJDvSOQd8, state: 1
2024-10-22 01:16:43.688 DEBUG fromCheckConnectionIceAgentState(): Checking pair: QuEZLcbX9 s+d9BWcaw, state: 1
2024-10-22 01:16:43.688 DEBUG iceCandidatePairCheckConnection(): remote ip:192.168.1.123, port:39506, local ip:192.168.1.117, port:41214
2024-10-22 01:16:43.689 DEBUG iceUtilsSendStunPacket(): Sending BINDING_REQUEST to ip:192.168.1.123, port:39506
2024-10-22 01:16:43.689 DEBUG handleStunPacket(): Pair binding response! QuEZLcbX9 C0AKNAi6e
2024-10-22 01:16:43.690 DEBUG handleStunPacket(): Pair succeeded! QuEZLcbX9 C0AKNAi6e
2024-10-22 01:16:43.690 DEBUG handleStunPacket(): Ice candidate pair QuEZLcbX9_C0AKNAi6e is connected. Round trip time: 371ms
2024-10-22 01:16:43.693 DEBUG fromCheckConnectionIceAgentState(): Checking pair: QuEZLcbX9 C0AKNAi6e, state: 3
2024-10-22 01:16:43.694 DEBUG fromCheckConnectionIceAgentState(): Checking pair: QuEZLcbX9 C0AKNAi6e, state: 3
2024-10-22 01:16:43.695 INFO stepIceAgentStateMachine(): Ice agent state changed from ICE_AGENT_STATE_CHECK_CONNECTION to ICE_AGENT_STATE_CONNECTED.
2024-10-22 01:16:43.695 DEBUG iceCandidatePairCheckConnection(): remote ip:192.168.1.123, port:39506, local ip:192.168.1.117, port:41214
2024-10-22 01:16:43.696 DEBUG iceUtilsSendStunPacket(): Sending BINDING_REQUEST to ip:192.168.1.123, port:39506
2024-10-22 01:16:43.697 INFO stepIceAgentStateMachine(): Ice agent state changed from ICE_AGENT_STATE_CONNECTED to ICE_AGENT_STATE_NOMINATING.
2024-10-22 01:16:43.697 PROFILE iceAgentReadyStateSetup(): Selected pair QuEZLcbX9_C0AKNAi6e, local candidate type: host. remote candidate type: host. Round trip time 371 ms. Local candidat1
2024-10-22 01:16:43.697 DEBUG iceAgentReadyStateSetup(): Freeing Turn allocations that are not selected. Total turn allocation count 0
2024-10-22 01:16:43.698 PROFILE executeReadyIceAgentState(): [ICE Agent ready for media exchange from check connection start] Time taken: 1112 ms
2024-10-22 01:16:43.698 INFO stepIceAgentStateMachine(): Ice agent state changed from ICE_AGENT_STATE_NOMINATING to ICE_AGENT_STATE_READY.
2024-10-22 01:16:43.699 DEBUG dtlsSessionHandshakeInThread(): Handshake want READ/WRITE
2024-10-22 01:16:43.737 DEBUG handleStunPacket(): Pair binding response! QuEZLcbX9 C0AKNAi6e
2024-10-22 01:16:43.738 DEBUG handleStunPacket(): Pair binding response! QuEZLcbX9 C0AKNAi6e
2024-10-22 01:16:43.738 DEBUG handleStunPacket(): Pair binding response! QuEZLcbX9 C0AKNAi6e
2024-10-22 01:16:43.815 PROFILE dtlsSessionChangeState(): [DTLS initialization completion] Time taken: 117 ms
2024-10-22 01:16:43.816 INFO dtlsSessionHandshakeInThread(): Done with handshake, exiting from this thread
2024-10-22 01:16:43.827 PROFILE changePeerConnectionState(): [ICE Hole Punching Time] Time taken: 1241 ms
2024-10-22 01:16:43.827 INFO onConnectionStateChange(): New connection state 3
2024-10-22 01:16:43.828 DEBUG rtcPeerConnectionGetMetrics(): ICE local candidate Stats requested at 17295688038282676
2024-10-22 01:16:43.828 DEBUG logSelectedIceCandidatesInformation(): Local Candidate IP Address: 192.168.1.117
2024-10-22 01:16:43.828 DEBUG logSelectedIceCandidatesInformation(): Local Candidate type: host
2024-10-22 01:16:43.829 DEBUG logSelectedIceCandidatesInformation(): Local Candidate port: 41214
2024-10-22 01:16:43.829 DEBUG logSelectedIceCandidatesInformation(): Local Candidate priority: 2130706431
2024-10-22 01:16:43.829 DEBUG logSelectedIceCandidatesInformation(): Local Candidate transport protocol: udp
2024-10-22 01:16:43.829 DEBUG logSelectedIceCandidatesInformation(): Local Candidate relay protocol: N/A
2024-10-22 01:16:43.829 DEBUG logSelectedIceCandidatesInformation(): Local Candidate Ice server source: N/A
2024-10-22 01:16:43.830 DEBUG rtcPeerConnectionGetMetrics(): ICE remote candidate Stats requested at 17295688038306085
2024-10-22 01:16:44.165 DEBUG logSelectedIceCandidatesInformation(): Remote Candidate IP Address: 192.168.1.123
2024-10-22 01:16:44.165 DEBUG logSelectedIceCandidatesInformation(): Remote Candidate type: host
2024-10-22 01:16:44.165 DEBUG logSelectedIceCandidatesInformation(): Remote Candidate port: 39506
2024-10-22 01:16:44.166 DEBUG logSelectedIceCandidatesInformation(): Remote Candidate priority: 2122260223
2024-10-22 01:16:44.166 DEBUG logSelectedIceCandidatesInformation(): Remote Candidate transport protocol: udp
2024-10-22 01:16:44.177 INFO audioFrameHandler(): Start up latency from offer to first frame: 1599ms

2024-10-22 01:16:44.187 INFO onSctpInboundPacket(): Unhandled PPID on incoming SCTP message 0
2024-10-22 01:16:44.188 INFO onDataChannel(): New DataChannel has been opened data-channel-of-6631a006-a565-4809-a6f5-fffff09307aa

[20241022 09:16:44.317] [590] [D] [lc] [masterSessionWait, 328]: count = 2, kvs total_size = 3211941[m]
2024-10-22 01:16:44.977 WARN onRtcpPacket(): unhandled packet type 203
2024-10-22 01:16:45.059 INFO dtlsSessionProcessPacket(): Detected DTLS close_notify alert
2024-10-22 01:16:45.059 INFO onConnectionStateChange(): New connection state 6
2024-10-22 01:16:46.318 DEBUG freeSampleStreamingSession(): Freeing streaming session with peer id: 6631a006-a565-4809-a6f5-fffff09307aa
2024-10-22 01:16:46.319 DEBUG socketConnectionClosed(): Close socket 27
2024-10-22 01:16:46.369 PROFILE closePeerConnection(): [Close peer connection] Time taken: 50 ms
375 INFO freeDtlsSession(): Freeing the DTLS session
2024-10-22 01:16:46.378 DEBUG freeSocketConnection(): close socket with ip: 192.168.1.117:41214. family:1
2024-10-22 01:16:46.378 DEBUG freeSocketConnection(): close socket connected with ip: 0000:0000:0000:0000:0000:0000:0000:0000:0. family:0
2024-10-22 01:16:46.379 PROFILE freePeerConnection(): [Free peer connection] Time taken: 9 ms
[20241022 09:16:46.384] [590] [D] [lc] [masterSessionWait, 328]: count = 1, kvs total_size = 1636810[m]
2024-10-22 01:16:46.939 DEBUG lwsWssCallbackRoutine(): Client is writable
2024-10-22 01:16:46.967 INFO lwsWssCallbackRoutine(): WSS callback with reason 9
2024-10-22 01:16:47.302 DEBUG dtlsSessionHandshakeInThread(): DTLS handshake timeout event occurred, going to retransmit
2024-10-22 01:16:47.303 INFO dtlsSessionHandshakeInThread(): Timeout handled successfully, packet retransmitted
[20241022 09:16:48.385] [590] [D] [lc] [masterSessionWait, 328]: count = 1, kvs total_size = 1636810[m]
2024-10-22 01:16:48.996 INFO iceAgentGatherCandidateTimerCallback(): Candidate gathering completed.
2024-10-22 01:16:48.997 PROFILE iceAgentGatherCandidateTimerCallback(): [Candidate gathering time] Time taken: 10013 ms
2024-10-22 01:16:48.997 DEBUG onIceCandidateHandler(): ice candidate gathering finished
[20241022 09:16:50.386] [590] [D] [lc] [masterSessionWait, 328]: count = 1, kvs total_size = 1636810[m]
[20241022 09:16:52.387] [590] [D] [lc] [masterSessionWait, 328]: count = 1, kvs total_size = 1636810[m]
[20241022 09:16:54.388] [590] [D] [lc] [masterSessionWait, 328]: count = 1, kvs total_size = 1636810[m]
2024-10-22 01:16:55.303 DEBUG dtlsSessionHandshakeInThread(): DTLS handshake timeout event occurred, going to retransmit
2024-10-22 01:16:55.303 INFO dtlsSessionHandshakeInThread(): Timeout handled successfully, packet retransmitted
[20241022 09:16:56.389] [590] [D] [lc] [masterSessionWait, 328]: count = 1, kvs total_size = 1636810[m]
2024-10-22 01:16:56.968 DEBUG lwsWssCallbackRoutine(): Client is writable
2024-10-22 01:16:57.083 INFO lwsWssCallbackRoutine(): WSS callback with reason 9
[20241022 09:16:58.390] [590] [D] [lc] [masterSessionWait, 328]: count = 1, kvs total_size = 1612606[m]
[20241022 09:17:00.391] [590] [D] [lc] [masterSessionWait, 328]: count = 1, kvs total_size = 1612606[m]
[20241022 09:17:02.392] [590] [D] [lc] [masterSessionWait, 328]: count = 1, kvs total_size = 1612606[m]
[20241022 09:17:04.394] [590] [D] [lc] [masterSessionWait, 328]: count = 1, kvs total_size = 1612606[m]
[20241022 09:17:06.395] [590] [D] [lc] [masterSessionWait, 328]: count = 1, kvs total_size = 1612606[m]
2024-10-22 01:17:07.095 DEBUG lwsWssCallbackRoutine(): Client is writable
2024-10-22 01:17:07.220 INFO lwsWssCallbackRoutine(): WSS callback with reason 9
[20241022 09:17:08.396] [590] [D] [lc] [masterSessionWait, 328]: count = 1, kvs total_size = 1612606[m]
2024-10-22 01:17:10.018 DEBUG iceAgentStateMachineCheckDisconnection(): detect disconnection
2024-10-22 01:17:10.018 DEBUG executeDisconnectedIceAgentState(): Ice agent detected disconnection. current state ICE_AGENT_STATE_READY. Last data received time 1729568800 s
2024-10-22 01:17:10.018 DEBUG onIceConnectionStateChange(): ice agent disconnected
2024-10-22 01:17:10.019 INFO onConnectionStateChange(): New connection state 4
2024-10-22 01:17:10.397 DEBUG freeSampleStreamingSession(): Freeing streaming session with peer id: 0c2ea6fc-b3f1-4ed7-abcf-1aac8f00559e
2024-10-22 01:17:10.397 DEBUG socketConnectionClosed(): Close socket 24
2024-10-22 01:17:10.447 PROFILE closePeerConnection(): [Close peer connection] Time taken: 50 ms
2024-10-22 01:17:10.448 INFO freeDtlsSession(): Freeing the DTLS session
2024-10-22 01:17:11.303 DEBUG dtlsSessionHandshakeInThread(): DTLS handshake timeout event occurred, going to retransmit
2024-10-22 01:17:11.304 INFO dtlsSessionHandshakeInThread(): Timeout handled successfully, packet retransmitted
2024-10-22 01:17:11.304 ERROR dtlsSessionHandshakeInThread(): operation returned status code: 0x59000007
2024-10-22 01:17:11.349 DEBUG freeSocketConnection(): close socket with ip: 192.168.1.117:54655. family:1
2024-10-22 01:17:11.350 DEBUG freeSocketConnection(): close socket connected with ip: 0000:0000:0000:0000:0000:0000:0000:0000:0. family:0
2024-10-22 01:17:11.351 PROFILE freePeerConnection(): [Free peer connection] Time taken: 902 ms
[20241022 09:17:11.351] [590] [D] [lc] [masterSessionWait, 328]: count = 0, kvs total_size = 92387[m]
[20241022 09:17:12.552] [590] [D] [lc] [masterSessionWait, 328]: count = 0, kvs total_size = 92387[m]
[20241022 09:17:13.642] [591] [I] [lc] [lc_log_trace, 652]: evmsg_io 150 in
[20241022 09:17:13.643] [591] [I] [lc_evmsg] [lc_evmsg_dispatch_msg, 137]: dispach ipc.action.scene.motion
[20241022 09:17:13.643] [591] [I] [lc] [lc_log_trace, 652]: evmsg_io 177 out
[20241022 09:17:14.071] [591] [I] [lc] [lc_log_trace, 652]: evmsg_io 150 in
[20241022 09:17:14.071] [591] [I] [lc_evmsg] [lc_evmsg_dispatch_msg, 137]: dispach ipc.action.scene.motion
[20241022 09:17:14.071] [591] [I] [lc] [lc_log_trace, 652]: evmsg_io 177 out
[20241022 09:17:14.562] [590] [D] [lc] [masterSessionWait, 328]: count = 0, kvs total_size = 92387[m]
[20241022 09:17:16.565] [590] [D] [lc] [masterSessionWait, 328]: count = 0, kvs total_size = 92387[m]

If look above and see first session created and I closed session but this session was closed at last.
Issue: I make connection and again in between I make connection then first connection was closed at last after some time and I observed some time connection was not closed also and event connection closed also live streaming working.

Expected Behavior

Connection should close on the master side while disconnection happens on the client side; it should not take time to close when multiple-time connections happen on the on the client side.

Current Behavior

Connection should close on the master side while disconnection happens on the client side some time not closed also, and some time it takes time to close the first connection on the master side when try to connect multiple times.

Reproduction Steps

  1. Start live streaming.
  2. stop live streaming.
  3. start live streaming.
  4. stop live streaming.
  5. do multiple time

WebRTC C SDK version being used

v1.10.2

If it was working in a previous version, which one?

No response

Compiler and Version used

arm-buildroot-linux-uclibcgnueabihf-gcc

Operating System and version

linux

Platform being used

ARM
@vasoyanikhil vasoyanikhil added bug Something isn't working needs-triage labels Oct 22, 2024
@stefankiesz
Copy link
Contributor

Hi, can you please confirm whether behavior persists using the latest version of the SDK:
https://github.com/awslabs/amazon-kinesis-video-streams-webrtc-sdk-c/releases/tag/v1.11.0

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug Something isn't working needs-triage v1.10.2
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@sirknightj @vasoyanikhil @stefankiesz