Closed Nomidia closed 4 years ago
MushMal
commented
4 years ago 0x5a00000d is STATUS_ICE_NO_CONNECTED_CANDIDATE_PAIR which is issued when the ICE agent is unable to find suitable candidate pair within the allotted timeout. I am wondering whether there is a firewall or any other network setting that has changed since. Any network topology changes?
Also, are you able to connect JS test page to JS test page? Are you able to run C SDK master vs viewer samples?
Nomidia
commented
4 years ago JS test page as master and viewer was ok. C SDK as master, JS test past as viewer failed. After I increased the check timeout, the log changed as follows:
2020-05-15 03:44:16 DEBUG iceAgentLogNewCandidate(): New remote ice candidate discovered. Id: DSR08/LwD. Ip: 192.168.2.101:39406. Type: host 2020-05-15 03:44:16 DEBUG iceAgentLogNewCandidate(): New remote ice candidate discovered. Id: VJ4pXpepe. Ip: 3.228.0.169:65160. Type: host 2020-05-15 03:44:16 DEBUG iceAgentLogNewCandidate(): New remote ice candidate discovered. Id: 3hd8sEUhx. Ip: 3.228.0.169:63578. Type: host 2020-05-15 03:44:16 DEBUG iceAgentLogNewCandidate(): New remote ice candidate discovered. Id: Va9/9iQRM. Ip: 118.191.224.151:20027. Type: host 2020-05-15 03:44:16 DEBUG iceAgentLogNewCandidate(): New remote ice candidate discovered. Id: ZNYPrbaSn. Ip: 118.191.224.151:20026. Type: host 2020-05-15 03:44:16 DEBUG iceAgentLogNewCandidate(): New local ice candidate discovered. Id: 4Gy3nGCqL. Ip: 118.191.224.151:20033. Type: srflx 2020-05-15 03:44:16 INFO signalingClientSendMessageSync(): Signaling Client Sending Message Sync 2020-05-15 03:44:16 DEBUG writeLwsData(): Sending data over web socket: { "action": "ICE_CANDIDATE", "RecipientClientId": "R0XAG301K3K", "MessagePayload": "eyJjYW5kaWRhdGUiOiJjYW5kaWRhdGU6MSAxIHVkcCA2NTgyMDUgMTE4LjE5MS4yMjQuMTUxIDIwMDMzIHR5cCBzcmZseCByYWRkciAwLjAuMC4wIHJwb3J0IDAgZ2VuZXJhdGlvbiAwIG5ldHdvcmstY29zdCA5OTkiLCJzZHBNaWQiOiIwIiwic2RwTUxpbmVJbmRleCI6MH0=" } 2020-05-15 03:44:16 DEBUG lwsWssCallbackRoutine(): Client is writable 2020-05-15 03:44:17 DEBUG handleStunPacket(): Ice candidate pair 9SnQ1hxo3_9YTSJIIpi is connected. Round trip time: 281ms 2020-05-15 03:44:17 DEBUG stepStateMachine(): State Machine - Current state: 0x0000000000000002, Next state: 0x0000000000000004 2020-05-15 03:44:17 DEBUG stepIceAgentStateMachine(): Ice agent state changed from ICE_AGENT_STATE_CHECK_CONNECTION to ICE_AGENT_STATE_CONNECTED. 2020-05-15 03:44:17 DEBUG lwsWssCallbackRoutine(): Client receive 2020-05-15 03:44:17 WARN receiveLwsMessage(): Signaling received an empty message 2020-05-15 03:44:17 DEBUG lwsWssCallbackRoutine(): Client is writable 2020-05-15 03:44:17 INFO onConnectionStateChange(): New connection state 3 2020-05-15 03:44:17 DEBUG handleStunPacket(): Ice candidate pair 9SnQ1hxo3_DSR08/LwD is connected. Round trip time: 231ms 2020-05-15 03:44:17 DEBUG lwsWssCallbackRoutine(): Client receive {"messagePayload":"eyJjYW5kaWRhdGUiOiJjYW5kaWRhdGU6MzY2NDMyNjU1OSAxIHVkcCA0MTc1NDYyMyAzLjg3LjEyNy4yMjkgNTMxNTYgdHlwIHJlbGF5IHJhZGRyIDExOC4xOTEuMjI0LjE1MSBycG9ydCAyMDAyOCBnZW5lcmF0aW9uIDAgdWZyYWcgWHE2dSBuZXR3b3JrLWlkIDMgbmV0d29yay1jb3N0IDEwIiwic2RwTWlkIjoiMCIsInNkcE1MaW5lSW5kZXgiOjB9","messageType":"ICE_CANDIDATE","senderClientId":"R0XAG301K3K"} 2020-05-15 03:44:17 DEBUG lwsWssCallbackRoutine(): Client is writable 2020-05-15 03:44:17 DEBUG turnConnectionStepState(): TurnConnection state changed from TURN_STATE_GET_CREDENTIALS to TURN_STATE_ALLOCATION 2020-05-15 03:44:17 DEBUG iceAgentLogNewCandidate(): New remote ice candidate discovered. Id: 9f8vCTzPg. Ip: 3.87.127.229:53156. Type: host 2020-05-15 03:44:17 DEBUG stepStateMachine(): State Machine - Current state: 0x0000000000000004, Next state: 0x0000000000000008 2020-05-15 03:44:17 DEBUG lwsWssCallbackRoutine(): Client receive 2020-05-15 03:44:17 WARN receiveLwsMessage(): Signaling received an empty message 2020-05-15 03:44:17 DEBUG lwsWssCallbackRoutine(): Client is writable 2020-05-15 03:44:17 DEBUG lwsWssCallbackRoutine(): Client receive {"messagePayload":"eyJjYW5kaWRhdGUiOiJjYW5kaWRhdGU6MzY2NDMyNjU1OSAxIHVkcCA0MTc1NDYyMyAzLjg3LjEyNy4yMjkgNTA1MzkgdHlwIHJlbGF5IHJhZGRyIDExOC4xOTEuMjI0LjE1MSBycG9ydCAyMDAyOSBnZW5lcmF0aW9uIDAgdWZyYWcgWHE2dSBuZXR3b3JrLWlkIDMgbmV0d29yay1jb3N0IDEwIiwic2RwTWlkIjoiMSIsInNkcE1MaW5lSW5kZXgiOjF9","messageType":"ICE_CANDIDATE","senderClientId":"R0XAG301K3K"} 2020-05-15 03:44:17 DEBUG lwsWssCallbackRoutine(): Client is writable 2020-05-15 03:44:17 DEBUG stepIceAgentStateMachine(): Ice agent state changed from ICE_AGENT_STATE_CONNECTED to ICE_AGENT_STATE_NOMINATING. 2020-05-15 03:44:17 DEBUG iceAgentLogNewCandidate(): New remote ice candidate discovered. Id: +LA2/q1LO. Ip: 3.87.127.229:50539. Type: host 2020-05-15 03:44:17 DEBUG handleStunPacket(): received candidate with USE_CANDIDATE flag, local candidate type host. 2020-05-15 03:44:17 DEBUG stepStateMachine(): State Machine - Current state: 0x0000000000000008, Next state: 0x0000000000000010 2020-05-15 03:44:17 DEBUG iceAgentReadyStateSetup(): Selected pair 9SnQ1hxo3_9YTSJIIpi, local candidate type: host. Round trip time 0 ms 2020-05-15 03:44:17 DEBUG iceAgentReadyStateSetup(): Freeing Turn allocations that are not selected. Total turn allocation count 1 2020-05-15 03:44:17 DEBUG stepIceAgentStateMachine(): Ice agent state changed from ICE_AGENT_STATE_NOMINATING to ICE_AGENT_STATE_READY. 2020-05-15 03:44:17 DEBUG turnConnectionStepState(): TurnConnection state changed from TURN_STATE_ALLOCATION to TURN_STATE_NEW 2020-05-15 03:44:17 DEBUG iceAgentGatherCandidateTimerCallback(): Candidate gathering completed. 2020-05-15 03:44:17 DEBUG onIceCandidateHandler(): ice candidate gathering finished 2020-05-15 03:44:17 DEBUG lwsWssCallbackRoutine(): Client receive 2020-05-15 03:44:17 WARN receiveLwsMessage(): Signaling received an empty message 2020-05-15 03:44:17 DEBUG lwsWssCallbackRoutine(): Client is writable
MushMal
commented
4 years ago Seems that you get to ready state. Are you able to see the master samples output in the JS page after you bump up the timeout? It does seem to be a network topology issue. Are you using some sort of device or you are running the C SDK on your computer? Can you try using TURN only?
Nomidia
commented
4 years ago I still can not preview from viewer although the master seems to get ready. The log from JS page is same with the beginning. The master is running on my IOT device .
InvalidAccessError: Failed to execute 'setRemoteDescription' on 'RTCPeerConnection': Failed to set remote answer sdp: Failed to set remote video description send parameters.
MushMal
commented
4 years ago Not sure why this fails yet. Are you able to run the master from the C SDK on your computer and connect to JS fine?
Nomidia
commented
4 years ago I run the master on my Ubuntu and the problem also exists.
Nomidia
commented
4 years ago The viewer under another network is OK. Maybe it is related with network issue.
MushMal
commented
4 years ago @Nomidia yes, this is certainly a network issue but using TURN it should work just fine. Perhaps you can enforce turn on the device/master and see how it connects? We have seen some firewalls/VPNs block certain ports silently
chehefen
commented
4 years ago @Nomidia, can you share with us the answer that master sent when js page failed? Thanks.
Nomidia
commented
4 years ago @chehefen These are logs. Device.log js page.log
chehefen
commented
4 years ago @Nomidia can you include the offer in Device log too?
chehefen
commented
4 years ago I want to look at the offer that master received. It seems like you were using the viewer sample in dev.log but the question is about error in the WebRTC Test Page. Can you show me the offer that WebRTC Test Page sent? Also which browser are you using? Does that happen on chrome?
Nomidia
commented
4 years ago I am using chrome brower. I tested in two different computers and one cellphone, but only one computer can preview sucessfully. Please take a look of this, I added printf at here. Or please tell me the location where I should add the printf. https://github.com/awslabs/amazon-kinesis-video-streams-webrtc-sdk-c/blob/6acd517830d97ae6142a6b9b097c758ebe5da09e/samples/Common.c#L203
PRINTF("%s\n", pSignalingMessage->payload); PRINTF("offer %s\n", offerSessionDescriptionInit.sdp); PRINTF("answer %s\n", pSampleStreamingSession->answerSessionDescriptionInit.sdp); master.log
chehefen
commented
4 years ago @Nomidia can you swap LN406 with LN409 here: https://github.com/awslabs/amazon-kinesis-video-streams-webrtc-sdk-c/blob/master/src/source/PeerConnection/SessionDescription.c#L406 and see what happens? Thanks.
Nomidia
commented
4 years ago @chehefen The phenomenon is same as before.
chehefen
commented
4 years ago same as before as browser print this error again?
InvalidAccessError: Failed to execute 'setRemoteDescription' on 'RTCPeerConnection': Failed to set remote answer sdp: Failed to set remote video description send parameters.
Can you show us the offer and answer that was exchanged?
Nomidia
commented
4 years ago @chehefen Here it is the log.
05-21-10 failed.log
When I switch to firefox browser, it behaves differently.
firefox.log
Then I print the 'pKvsRtpTransceiver->transceiver.direction', and find the value is RTC_RTP_TRANSCEIVER_DIRECTION_SENDRECV.
So I change the code as follows:
case RTC_RTP_TRANSCEIVER_DIRECTION_SENDRECV: STRCPY(pSdpMediaDescription->sdpAttributes[attributeCount].attributeName, "sendonly");
Then the firefox is ok to watch the video stream, but there is still some problems with chrome.
When I failed to view the video stream, I tried to sign out and sign in, then I succeeded to view the video stream. However when I tried to view again I failed like before. I can only view the video stream unless I log out every time and log in again or reopen the browser window. May be caused by browser caching. It's chrome browser(83.0.4103.61). success&&fail_chrome.log
MushMal
commented
4 years ago What's the latest on this issue?
disa6302
commented
4 years ago @Nomidia ,
Can you try the top of master to see if you still face the issue?
disa6302
commented
4 years ago Closing this ticket since its been stale for a while. @Nomidia , feel free to reach out with any questions you might have.
I have ran the demo successfully already several days before, but now I encountered a ICE error as follows. No matter I use aws console or WebRTC Test Page. Even I updated the lasted code. WebRTC Test Page log:
InvalidAccessError: Failed to execute 'setRemoteDescription' on 'RTCPeerConnection': Failed to set remote answer sdp: Failed to set remote video description send parameters.Device log:
2020-05-15 02:39:44 DEBUG iceAgentGatherCandidateTimerCallback(): Candidate gathering completed. 2020-05-15 02:39:44 DEBUG onIceCandidateHandler(): ice candidate gathering finished 2020-05-15 02:39:44 DEBUG turnConnectionHandleStun(): TURN Allocation succeeded. Life time: 600 seconds. Allocation expiration epoch 158951098413392 2020-05-15 02:39:44 DEBUG turnConnectionHandleStun(): TURN Allocation succeeded. Life time: 599 seconds. Allocation expiration epoch 158951098319404 2020-05-15 02:39:44 DEBUG turnConnectionHandleStun(): TURN Allocation succeeded. Life time: 599 seconds. Allocation expiration epoch 158951098325387 2020-05-15 02:39:44 DEBUG turnConnectionHandleStun(): TURN Allocation succeeded. Life time: 599 seconds. Allocation expiration epoch 158951098331395 2020-05-15 02:39:44 DEBUG turnConnectionHandleStun(): create permission succeeded for peer 3.228.0.169 2020-05-15 02:39:44 DEBUG turnConnectionHandleStun(): create permission succeeded for peer 18.207.123.65 2020-05-15 02:39:44 DEBUG turnConnectionHandleStun(): create permission succeeded for peer 18.207.123.65 2020-05-15 02:39:44 DEBUG turnConnectionHandleStun(): create permission succeeded for peer 3.228.0.169 2020-05-15 02:39:44 DEBUG lwsWssCallbackRoutine(): Client receive 2020-05-15 02:39:44 WARN receiveLwsMessage(): Signaling received an empty message 2020-05-15 02:39:44 DEBUG lwsWssCallbackRoutine(): Client is writable 2020-05-15 02:39:44 DEBUG turnConnectionHandleStun(): Channel bind succeeded with peer 3.228.0.169, port: 65332, channel number 16385 2020-05-15 02:39:44 DEBUG turnConnectionHandleStun(): Channel bind succeeded with peer 18.207.123.65, port: 54868, channel number 16386 2020-05-15 02:39:44 DEBUG turnConnectionHandleStun(): Channel bind succeeded with peer 18.207.123.65, port: 57332, channel number 16387 2020-05-15 02:39:44 DEBUG turnConnectionHandleStun(): Channel bind succeeded with peer 3.228.0.169, port: 49399, channel number 16388 2020-05-15 02:39:46 DEBUG turnConnectionStepState(): TurnConnection state changed from TURN_STATE_CREATE_PERMISSION to TURN_STATE_BIND_CHANNEL 2020-05-15 02:39:46 DEBUG turnConnectionStepState(): TurnConnection state changed from TURN_STATE_BIND_CHANNEL to TURN_STATE_READY 2020-05-15 02:39:52 DEBUG stepStateMachine(): State Machine - Current state: 0x0000000000000002, Next state: 0x0000000000000040 2020-05-15 02:39:52 ERROR executeFailedIceAgentState(): IceAgent failed with 0x5a00000d 2020-05-15 02:39:52 DEBUG stepIceAgentStateMachine(): Ice agent state changed from ICE_AGENT_STATE_CHECK_CONNECTION to ICE_AGENT_STATE_FAILED. 2020-05-15 02:39:52 INFO onConnectionStateChange(): New connection state 5 2020-05-15 02:39:52 DEBUG freeSampleStreamingSession(): Freeing streaming session with peer id: gydfvgofcsw8wtwm209dcm 2020-05-15 02:39:52 DEBUG socketConnectionClosed(): Close socket 12 2020-05-15 02:39:52 DEBUG socketConnectionClosed(): Close socket 11 2020-05-15 02:39:54 DEBUG lwsWssCallbackRoutine(): Client is writable 2020-05-15 02:39:54 DEBUG turnConnectionStepState(): TurnConnection state changed from TURN_STATE_READY to TURN_STATE_CLEAN_UP 2020-05-15 02:39:55 WARN iceAgentShutdown(): TurnConnection shutdown did not complete within 1 seconds 2020-05-15 02:39:55 DEBUG socketConnectionClosed(): Close socket 13 2020-05-15 02:39:55 WARN socketConnectionSendData(): Failed to send data. Socket closed already 2020-05-15 02:39:55 ERROR iceUtilsSendData(): operation returned status code: 0x58000022 2020-05-15 02:39:55 ERROR iceUtilsSendStunPacket(): operation returned status code: 0x58000022 2020-05-15 02:39:55 ERROR turnConnectionTimerCallback(): TurnConnection socket 13 closed unexpectedly 2020-05-15 02:39:55 WARN turnConnectionStepState(): TurnConnection in TURN_STATE_FAILED due to 0x58000022. Aborting TurnConnection 2020-05-15 02:39:55 DEBUG turnConnectionStepState(): TurnConnection state changed from TURN_STATE_FAILED to TURN_STATE_NEW