amazon-kinesis-video-streams-webrtc-sdk-c icon indicating copy to clipboard operation
amazon-kinesis-video-streams-webrtc-sdk-c copied to clipboard

Published 20 hours ago • verified publisher icon awslabs

[QUESTION] kvsWebrtcClientMaster Sample unable to run on windows

Open vulkan101 opened this issue 2 years ago • 6 comments

I'm trying to run the above sample which I've recently build from master on windows. I run the sample, then try to connect from the webrtc test page . I start the sample application first with the channel name MHTestChannel and see the [KVS Master] Channel MHTestChannel set up done. I then move to the web page and try to connect as viewer. The logs on the sample application then give a lot of warnings as follows: 2022-04-13 16:42:23 WARN connectionListenerReceiveDataRoutine(): poll() failed with errno An invalid argument was supplied. There are some warnings output from lws as well, are these to be expected?

** Logging ** Logs on the application:

this on stdout:

KVS Master] Using trickleICE by default
[KVS Master] Created signaling channel MHTestChannel
[KVS Master] Finished setting audio and video handlers
[KVS Master] Checked sample video frame availability....available
[KVS Master] Checked sample audio frame availability....available
[KVS Master] KVS WebRTC initialization completed successfully
2022-04-13 16:42:16 ERROR   signalingCacheLoadFromFile(): operation returned status code: 0x0000000a
2022-04-13 16:42:16 WARN    createSignalingSync(): Failed to load signaling cache from file
[KVS Master] Signaling client created successfully
2022-04-13 16:42:16 ERROR   signalingCacheSaveToFile(): operation returned status code: 0x0000000a
2022-04-13 16:42:16 WARN    getChannelEndpoint(): Failed to save signaling cache to file
[KVS Master] Signaling client connection to socket established
[KVS Master] Channel MHTestChannel set up done

Then this on stderr:

[2022/04/13 16:42:16:3485] N: lws_create_context: LWS: 4.3.99-v4.3.0-225-g65890372, NET CLI SRV H1 H2 WS SS-JSON-POL ConMon IPv6-absent
[2022/04/13 16:42:16:3524] N: __lws_lc_tag:  ++ [wsi|0|pipe] (1)
[2022/04/13 16:42:16:3555] N: __lws_lc_tag:  ++ [vh|0|default||-1] (1)
[2022/04/13 16:42:16:3595] N: lws_plat_vhost_tls_client_ctx_init: Imported 24 certs from plat store
[2022/04/13 16:42:16:3605] N: __lws_lc_tag:  ++ [wsicli|0|POST/h1/default/kinesisvideo.eu-west-2.amazonaws.com] (1)
[2022/04/13 16:42:16:3625] W: lws_plat_set_socket_options_ip: priority and ip sockets options not implemented on windows platform
[2022/04/13 16:42:16:3625] N: lws_plat_set_socket_options_ip: set use exclusive addresses
[2022/04/13 16:42:16:3625] N: [wsicli|0|POST/h1/default/kinesisvideo.eu-west-2.amazonaws.com]: lws_client_connect_3_connect: trying 3.10.83.154
[2022/04/13 16:42:16:3865] N: __lws_lc_untag:  -- [wsicli|0|POST/h1/default/kinesisvideo.eu-west-2.amazonaws.com] (0) 25.999ms
[2022/04/13 16:42:16:3865] N: __lws_lc_tag:  ++ [wsicli|1|POST/h1/default/kinesisvideo.eu-west-2.amazonaws.com] (1)
[2022/04/13 16:42:16:3875] W: lws_plat_set_socket_options_ip: priority and ip sockets options not implemented on windows platform
[2022/04/13 16:42:16:3875] N: lws_plat_set_socket_options_ip: set use exclusive addresses
[2022/04/13 16:42:16:3875] N: [wsicli|1|POST/h1/default/kinesisvideo.eu-west-2.amazonaws.com]: lws_client_connect_3_connect: trying 3.10.83.154
[2022/04/13 16:42:16:4124] N: __lws_lc_untag:  -- [wsicli|1|POST/h1/default/kinesisvideo.eu-west-2.amazonaws.com] (0) 25.983ms
[2022/04/13 16:42:16:4134] N: __lws_lc_tag:  ++ [wsicli|2|POST/h1/default/r-d29a6cb3.kinesisvideo.eu-west-2.am] (1)
[2022/04/13 16:42:16:4134] W: lws_plat_set_socket_options_ip: priority and ip sockets options not implemented on windows platform
[2022/04/13 16:42:16:4134] N: lws_plat_set_socket_options_ip: set use exclusive addresses
[2022/04/13 16:42:16:4134] N: [wsicli|2|POST/h1/default/r-d29a6cb3.kinesisvideo.eu-west-2.am]: lws_client_connect_3_connect: trying 18.135.169.155
[2022/04/13 16:42:16:5434] N: __lws_lc_untag:  -- [wsicli|2|POST/h1/default/r-d29a6cb3.kinesisvideo.eu-west-2.am] (0) 129.987ms
[2022/04/13 16:42:16:5445] N: __lws_lc_tag:  ++ [wsicli|3|WS/h1/default/m-978ce4ad.kinesisvideo.eu-west-2.amaz] (1)
[2022/04/13 16:42:16:5445] W: lws_plat_set_socket_options_ip: priority and ip sockets options not implemented on windows platform
[2022/04/13 16:42:16:5445] N: lws_plat_set_socket_options_ip: set use exclusive addresses
[2022/04/13 16:42:16:5445] N: [wsicli|3|WS/h1/default/m-978ce4ad.kinesisvideo.eu-west-2.amaz]: lws_client_connect_3_connect: trying 52.56.206.50

Then the following repeats on stdout

2022-04-13 16:42:23 WARN    connectionListenerReceiveDataRoutine(): poll() failed with errno An invalid argument was supplied.

On the Test page, I have this (I've re-run so times won't match):

[2022-04-13T16:52:49.913Z] [INFO] Page loaded
[2022-04-13T16:53:02.904Z] [INFO] [VIEWER] Channel ARN:  arn:aws:kinesisvideo:eu-west-2:798325461281:channel/MHTestChannel/1649777026515
[2022-04-13T16:53:02.936Z] [INFO] [VIEWER] Endpoints:  {
  "HTTPS": "https://r-d29a6cb3.kinesisvideo.eu-west-2.amazonaws.com",
  "WSS": "wss://v-fe304e5e.kinesisvideo.eu-west-2.amazonaws.com"
}
[2022-04-13T16:53:03.218Z] [INFO] [VIEWER] ICE servers:  [
  {
    "urls": "stun:stun.kinesisvideo.eu-west-2.amazonaws.com:443"
  },
  {
    "urls": [
      "turn:18-133-119-73.t-e13eec8d.kinesisvideo.eu-west-2.amazonaws.com:443?transport=udp",
      "turns:18-133-119-73.t-e13eec8d.kinesisvideo.eu-west-2.amazonaws.com:443?transport=udp",
      "turns:18-133-119-73.t-e13eec8d.kinesisvideo.eu-west-2.amazonaws.com:443?transport=tcp"
    ],
    "username": "CREDENTIALSREMOVED",
    "credential": "CREDENTIALSREMOVED"
  }
]
[2022-04-13T16:53:03.221Z] [INFO] [VIEWER] Starting viewer connection
[2022-04-13T16:53:03.422Z] [INFO] [VIEWER] Connected to signaling service
[2022-04-13T16:53:04.290Z] [INFO] [VIEWER] Creating SDP offer
[2022-04-13T16:53:04.295Z] [INFO] [VIEWER] Sending SDP offer
[2022-04-13T16:53:04.296Z] [INFO] [VIEWER] Generating ICE candidates
[2022-04-13T16:53:04.302Z] [INFO] [VIEWER] Generated ICE candidate
[2022-04-13T16:53:04.302Z] [INFO] [VIEWER] Sending ICE candidate
[2022-04-13T16:53:04.303Z] [INFO] [VIEWER] Generated ICE candidate
[2022-04-13T16:53:04.303Z] [INFO] [VIEWER] Sending ICE candidate
[2022-04-13T16:53:04.304Z] [INFO] [VIEWER] Generated ICE candidate
[2022-04-13T16:53:04.304Z] [INFO] [VIEWER] Sending ICE candidate
[2022-04-13T16:53:04.304Z] [INFO] [VIEWER] Generated ICE candidate
[2022-04-13T16:53:04.304Z] [INFO] [VIEWER] Sending ICE candidate
[2022-04-13T16:53:04.305Z] [INFO] [VIEWER] Generated ICE candidate
[2022-04-13T16:53:04.305Z] [INFO] [VIEWER] Sending ICE candidate
[2022-04-13T16:53:04.305Z] [INFO] [VIEWER] Generated ICE candidate
[2022-04-13T16:53:04.305Z] [INFO] [VIEWER] Sending ICE candidate
[2022-04-13T16:53:04.306Z] [INFO] [VIEWER] Generated ICE candidate
[2022-04-13T16:53:04.306Z] [INFO] [VIEWER] Sending ICE candidate
[2022-04-13T16:53:04.306Z] [INFO] [VIEWER] Generated ICE candidate
[2022-04-13T16:53:04.306Z] [INFO] [VIEWER] Sending ICE candidate
[2022-04-13T16:53:04.307Z] [INFO] [VIEWER] Generated ICE candidate
[2022-04-13T16:53:04.307Z] [INFO] [VIEWER] Sending ICE candidate
[2022-04-13T16:53:04.307Z] [INFO] [VIEWER] Generated ICE candidate
[2022-04-13T16:53:04.307Z] [INFO] [VIEWER] Sending ICE candidate
[2022-04-13T16:53:04.405Z] [INFO] [VIEWER] Generated ICE candidate
[2022-04-13T16:53:04.405Z] [INFO] [VIEWER] Sending ICE candidate
[2022-04-13T16:53:04.405Z] [INFO] [VIEWER] Generated ICE candidate
[2022-04-13T16:53:04.406Z] [INFO] [VIEWER] Sending ICE candidate
[2022-04-13T16:53:04.406Z] [INFO] [VIEWER] Generated ICE candidate
[2022-04-13T16:53:04.406Z] [INFO] [VIEWER] Sending ICE candidate
[2022-04-13T16:53:04.407Z] [INFO] [VIEWER] Generated ICE candidate
[2022-04-13T16:53:04.407Z] [INFO] [VIEWER] Sending ICE candidate
[2022-04-13T16:53:04.407Z] [INFO] [VIEWER] Generated ICE candidate
[2022-04-13T16:53:04.407Z] [INFO] [VIEWER] Sending ICE candidate
[2022-04-13T16:53:04.407Z] [INFO] [VIEWER] Generated ICE candidate
[2022-04-13T16:53:04.407Z] [INFO] [VIEWER] Sending ICE candidate
[2022-04-13T16:53:04.408Z] [INFO] [VIEWER] Generated ICE candidate
[2022-04-13T16:53:04.408Z] [INFO] [VIEWER] Sending ICE candidate
[2022-04-13T16:53:04.408Z] [INFO] [VIEWER] Generated ICE candidate
[2022-04-13T16:53:04.409Z] [INFO] [VIEWER] Sending ICE candidate
[2022-04-13T16:53:04.409Z] [INFO] [VIEWER] Generated ICE candidate
[2022-04-13T16:53:04.409Z] [INFO] [VIEWER] Sending ICE candidate
[2022-04-13T16:53:04.409Z] [INFO] [VIEWER] Generated ICE candidate
[2022-04-13T16:53:04.410Z] [INFO] [VIEWER] Sending ICE candidate
[2022-04-13T16:53:04.411Z] [INFO] [VIEWER] Generated ICE candidate
[2022-04-13T16:53:04.412Z] [INFO] [VIEWER] Sending ICE candidate
[2022-04-13T16:53:04.412Z] [INFO] [VIEWER] Generated ICE candidate
[2022-04-13T16:53:04.412Z] [INFO] [VIEWER] Sending ICE candidate
[2022-04-13T16:53:04.559Z] [INFO] [VIEWER] Generated ICE candidate
[2022-04-13T16:53:04.559Z] [INFO] [VIEWER] Sending ICE candidate
[2022-04-13T16:53:04.563Z] [INFO] [VIEWER] Generated ICE candidate
[2022-04-13T16:53:04.563Z] [INFO] [VIEWER] Sending ICE candidate
[2022-04-13T16:53:04.667Z] [INFO] [VIEWER] Generated ICE candidate
[2022-04-13T16:53:04.667Z] [INFO] [VIEWER] Sending ICE candidate
[2022-04-13T16:53:04.681Z] [INFO] [VIEWER] Generated ICE candidate
[2022-04-13T16:53:04.681Z] [INFO] [VIEWER] Sending ICE candidate
[2022-04-13T16:53:04.731Z] [INFO] [VIEWER] Generated ICE candidate
[2022-04-13T16:53:04.731Z] [INFO] [VIEWER] Sending ICE candidate
[2022-04-13T16:53:04.740Z] [INFO] [VIEWER] Generated ICE candidate
[2022-04-13T16:53:04.741Z] [INFO] [VIEWER] Sending ICE candidate

Would really appreciate any pointers in diagnosing this

vulkan101 avatar Apr 13 '22 16:04 vulkan101

@vulkan101 ,

Can you attach complete DEBUG/VERBOSE logs?

disa6302 avatar Apr 14 '22 18:04 disa6302

@disa6302 here's a verbose log from the master application: master_log.txt

[KVS Master] Using trickleICE by default
[KVS Master] Created signaling channel MHTestChannel
[KVS Master] Finished setting audio and video handlers
[KVS Master] Checked sample video frame availability....available
[KVS Master] Checked sample audio frame availability....available
2022-04-19 13:27:10 VERBOSE pregenerateCertTimerCallback(): New certificate has been pre-generated and added to the queue
2022-04-19 13:27:10 INFO    initKvsWebRtc(): SDK version: faaa714d5c0191083e09a195ceb3a8db86d2590d
[KVS Master] KVS WebRTC initialization completed successfully
2022-04-19 13:27:10 VERBOSE createSignalingClientSync(): Creating Signaling Client Sync
2022-04-19 13:27:10 VERBOSE createRetryStrategyForCreatingSignalingClient(): Using exponential backoff retry strategy for creating signaling client
2022-04-19 13:27:10 VERBOSE normalizeExponentialBackoffConfig(): Thread Id [18446744073709551614]. Exponential backoff retry strategy config - maxRetryCount: [0], maxRetryWaitTime: [160000000], retryFactorTime: [10000000], minTimeToResetRetryState: [900000000], jitterType: [1], jitterFactor: [0], 
2022-04-19 13:27:10 VERBOSE resetExponentialBackoffRetryState(): Thread Id [18446744073709551614]. Resetting Exponential Backoff State. Last retry system time [0], retry count so far [0], Current system time [16503748308286986]
2022-04-19 13:27:10 VERBOSE exponentialBackoffRetryStrategyWithDefaultConfigCreate(): Created exponential backoff retry strategy state with default configuration.
2022-04-19 13:27:10 ERROR   signalingCacheLoadFromFile(): operation returned status code: 0x0000000a
2022-04-19 13:27:10 WARN    createSignalingSync(): Failed to load signaling cache from file
2022-04-19 13:27:10 VERBOSE normalizeExponentialBackoffConfig(): Thread Id [18446744073709551614]. Exponential backoff retry strategy config - maxRetryCount: [0], maxRetryWaitTime: [100000000], retryFactorTime: [1000000], minTimeToResetRetryState: [900000000], jitterType: [1], jitterFactor: [0], 
2022-04-19 13:27:10 VERBOSE resetExponentialBackoffRetryState(): Thread Id [18446744073709551614]. Resetting Exponential Backoff State. Last retry system time [0], retry count so far [0], Current system time [16503748308297210]
2022-04-19 13:27:10 VERBOSE exponentialBackoffRetryStrategyCreate(): Created exponential backoff retry strategy state with provided retry configuration.
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 21
2022-04-19 13:27:10 VERBOSE signalingClientStateChanged(): Signaling client state changed to 1 - 'New'
2022-04-19 13:27:10 VERBOSE stepStateMachine(): State Machine - Current state: 0x0000000000000001, Next state: 0x0000000000000002, Current local state retry count [0], Max local state retry count [1], State transition wait time [0] ms
2022-04-19 13:27:10 VERBOSE signalingClientStateChanged(): Signaling client state changed to 2 - 'Get Security Credentials'
[KVS Master] Signaling client created successfully
2022-04-19 13:27:10 VERBOSE signalingClientFetchSync(): Signaling Client Fetch Sync
2022-04-19 13:27:10 VERBOSE createRetryStrategyForCreatingSignalingClient(): Using exponential backoff retry strategy for creating signaling client
2022-04-19 13:27:10 VERBOSE normalizeExponentialBackoffConfig(): Thread Id [18446744073709551614]. Exponential backoff retry strategy config - maxRetryCount: [0], maxRetryWaitTime: [160000000], retryFactorTime: [10000000], minTimeToResetRetryState: [900000000], jitterType: [1], jitterFactor: [0], 
2022-04-19 13:27:10 VERBOSE resetExponentialBackoffRetryState(): Thread Id [18446744073709551614]. Resetting Exponential Backoff State. Last retry system time [0], retry count so far [0], Current system time [16503748308457651]
2022-04-19 13:27:10 VERBOSE exponentialBackoffRetryStrategyWithDefaultConfigCreate(): Created exponential backoff retry strategy state with default configuration.
2022-04-19 13:27:10 VERBOSE stepStateMachine(): State Machine - Current state: 0x0000000000000002, Next state: 0x0000000000000004, Current local state retry count [0], Max local state retry count [1], State transition wait time [0] ms
2022-04-19 13:27:10 VERBOSE signalingClientStateChanged(): Signaling client state changed to 3 - 'Describe Channel'
2022-04-19 13:27:10 VERBOSE lwsCompleteSync(): Perform secure synchronous call for URL: https://kinesisvideo.eu-west-2.amazonaws.com/describeSignalingChannel
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 27
2022-04-19 13:27:10 VERBOSE lwsWssCallbackRoutine(): WSS callback with reason 27
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 85
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 105
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 19
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 31
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 29
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 71
2022-04-19 13:27:10 VERBOSE lwsWssCallbackRoutine(): WSS callback with reason 71
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 58
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 58
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 58
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 24
2022-04-19 13:27:10 DEBUG   lwsHttpCallbackRoutine(): Client append handshake header

2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): Appending header - Authorization: AWS4-HMAC-SHA256 Credential=xxx/20220419/eu-west-2/kinesisvideo/aws4_request, SignedHeaders=host;user-agent;x-amz-date, Signature=40785092dbee0c5ed4b0ba8d620d9d7720bd9419e73ffe8bb99851a38d7284ff
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): Appending header - content-length: 35
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): Appending header - content-type: application/json
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): Appending header - user-agent: AWS-SDK-KVS/3.0.0 MSVC/1929 Windows/6.2.9200 AMD64
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): Appending header - X-Amz-Date: 20220419T132710Z
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 57
2022-04-19 13:27:10 DEBUG   lwsHttpCallbackRoutine(): Sending the body {
	"ChannelName": "MHTestChannel"
}, size 35
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 2
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 44
2022-04-19 13:27:10 DEBUG   lwsHttpCallbackRoutine(): Connected with server response: 200
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): Date Header Returned By Server:  Tue, 19 Apr 2022 13:27:11 GMT
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 46
2022-04-19 13:27:10 DEBUG   lwsHttpCallbackRoutine(): Received client http
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 48
2022-04-19 13:27:10 DEBUG   lwsHttpCallbackRoutine(): Received client http read: 344 bytes
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): Received client http read response:  {"ChannelInfo":{"ChannelARN":"arn:aws:kinesisvideo:eu-west-2:798325461281:channel/MHTestChannel/1649777026515","ChannelName":"MHTestChannel","ChannelStatus":"ACTIVE","ChannelType":"SINGLE_MASTER","CreationTime":1.649777026515E9,"FullMeshConfiguration":null,"SingleMasterConfiguration":{"MessageTtlSeconds":60},"Version":"aLovJteJ5y1Sd9ENLmaL"}}
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 47
2022-04-19 13:27:10 DEBUG   lwsHttpCallbackRoutine(): Http client completed
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 45
2022-04-19 13:27:10 DEBUG   lwsHttpCallbackRoutine(): Client http closed
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 30
2022-04-19 13:27:10 VERBOSE stepStateMachine(): State Machine - Current state: 0x0000000000000004, Next state: 0x0000000000000010, Current local state retry count [0], Max local state retry count [1], State transition wait time [0] ms
2022-04-19 13:27:10 VERBOSE signalingClientStateChanged(): Signaling client state changed to 5 - 'Get Channel Endpoint'
2022-04-19 13:27:10 VERBOSE lwsCompleteSync(): Perform secure synchronous call for URL: https://kinesisvideo.eu-west-2.amazonaws.com/getSignalingChannelEndpoint
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 85
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 105
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 19
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 29
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 58
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 58
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 58
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 24
2022-04-19 13:27:10 DEBUG   lwsHttpCallbackRoutine(): Client append handshake header

2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): Appending header - Authorization: AWS4-HMAC-SHA256 Credential=xxx/20220419/eu-west-2/kinesisvideo/aws4_request, SignedHeaders=host;user-agent;x-amz-date, Signature=d9306881eec307ea3de0006d63d7b3f1139aebd99b0aed50a6ff20fe44ddc7ce
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): Appending header - content-length: 203
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): Appending header - content-type: application/json
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): Appending header - user-agent: AWS-SDK-KVS/3.0.0 MSVC/1929 Windows/6.2.9200 AMD64
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): Appending header - X-Amz-Date: 20220419T132710Z
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 57
2022-04-19 13:27:10 DEBUG   lwsHttpCallbackRoutine(): Sending the body {
	"ChannelARN": "arn:aws:kinesisvideo:eu-west-2:798325461281:channel/MHTestChannel/1649777026515",
	"SingleMasterChannelEndpointConfiguration": {
		"Protocols": ["WSS", "HTTPS"],
		"Role": "MASTER"
	}
}, size 203
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 2
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 44
2022-04-19 13:27:10 DEBUG   lwsHttpCallbackRoutine(): Connected with server response: 200
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): Date Header Returned By Server:  Tue, 19 Apr 2022 13:27:10 GMT
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 46
2022-04-19 13:27:10 DEBUG   lwsHttpCallbackRoutine(): Received client http
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 48
2022-04-19 13:27:10 DEBUG   lwsHttpCallbackRoutine(): Received client http read: 218 bytes
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): Received client http read response:  {"ResourceEndpointList":[{"Protocol":"HTTPS","ResourceEndpoint":"https://r-d29a6cb3.kinesisvideo.eu-west-2.amazonaws.com"},{"Protocol":"WSS","ResourceEndpoint":"wss://m-978ce4ad.kinesisvideo.eu-west-2.amazonaws.com"}]}
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 47
2022-04-19 13:27:10 DEBUG   lwsHttpCallbackRoutine(): Http client completed
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 45
2022-04-19 13:27:10 DEBUG   lwsHttpCallbackRoutine(): Client http closed
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 30
2022-04-19 13:27:10 ERROR   signalingCacheSaveToFile(): operation returned status code: 0x0000000a
2022-04-19 13:27:10 WARN    getChannelEndpoint(): Failed to save signaling cache to file
2022-04-19 13:27:10 VERBOSE stepStateMachine(): State Machine - Current state: 0x0000000000000010, Next state: 0x0000000000000020, Current local state retry count [0], Max local state retry count [1], State transition wait time [0] ms
2022-04-19 13:27:10 VERBOSE signalingClientStateChanged(): Signaling client state changed to 6 - 'Get ICE Server Configuration'
2022-04-19 13:27:10 VERBOSE lwsCompleteSync(): Perform secure synchronous call for URL: https://r-d29a6cb3.kinesisvideo.eu-west-2.amazonaws.com/v1/get-ice-server-config
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 85
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 105
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 19
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 29
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 58
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 58
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 58
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 24
2022-04-19 13:27:10 DEBUG   lwsHttpCallbackRoutine(): Client append handshake header

2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): Appending header - Authorization: AWS4-HMAC-SHA256 Credential=xxx/20220419/eu-west-2/kinesisvideo/aws4_request, SignedHeaders=host;user-agent;x-amz-date, Signature=e35326755c6105c3d81dfeb1808f04b6dcd06f821463a8b4cbad6626786c51e0
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): Appending header - content-length: 151
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): Appending header - content-type: application/json
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): Appending header - user-agent: AWS-SDK-KVS/3.0.0 MSVC/1929 Windows/6.2.9200 AMD64
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): Appending header - X-Amz-Date: 20220419T132710Z
2022-04-19 13:27:10 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 57
2022-04-19 13:27:10 DEBUG   lwsHttpCallbackRoutine(): Sending the body {
	"ChannelARN": "arn:aws:kinesisvideo:eu-west-2:798325461281:channel/MHTestChannel/1649777026515",
	"ClientId": "ProducerMaster",
	"Service": "TURN"
}, size 151
2022-04-19 13:27:11 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 2
2022-04-19 13:27:11 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 44
2022-04-19 13:27:11 DEBUG   lwsHttpCallbackRoutine(): Connected with server response: 200
2022-04-19 13:27:11 VERBOSE lwsHttpCallbackRoutine(): Date Header Returned By Server:  Tue, 19 Apr 2022 13:27:11 GMT
2022-04-19 13:27:11 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 46
2022-04-19 13:27:11 DEBUG   lwsHttpCallbackRoutine(): Received client http
2022-04-19 13:27:11 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 48
2022-04-19 13:27:11 DEBUG   lwsHttpCallbackRoutine(): Received client http read: 498 bytes
2022-04-19 13:27:11 VERBOSE lwsHttpCallbackRoutine(): Received client http read response:  {"IceServerList":[{"Password":"qarDeoPGW0TbrgcYUiQQ1XimeHd/LYbqeQC2MbTTzwk=","Ttl":300,"Uris":["turn:35-179-96-205.t-e13eec8d.kinesisvideo.eu-west-2.amazonaws.com:443?transport=udp","turns:35-179-96-205.t-e13eec8d.kinesisvideo.eu-west-2.amazonaws.com:443?transport=udp","turns:35-179-96-205.t-e13eec8d.kinesisvideo.eu-west-2.amazonaws.com:443?transport=tcp"],"Username":"1650375131:djE6YXJuOmF3czpraW5lc2lzdmlkZW86ZXUtd2VzdC0yOjc5ODMyNTQ2MTI4MTpjaGFubmVsL01IVGVzdENoYW5uZWwvMTY0OTc3NzAyNjUxNQ=="}]}
2022-04-19 13:27:11 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 47
2022-04-19 13:27:11 DEBUG   lwsHttpCallbackRoutine(): Http client completed
2022-04-19 13:27:11 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 45
2022-04-19 13:27:11 DEBUG   lwsHttpCallbackRoutine(): Client http closed
2022-04-19 13:27:11 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 30
2022-04-19 13:27:11 VERBOSE stepStateMachine(): State Machine - Current state: 0x0000000000000020, Next state: 0x0000000000000040, Current local state retry count [0], Max local state retry count [0], State transition wait time [0] ms
2022-04-19 13:27:11 VERBOSE signalingClientStateChanged(): Signaling client state changed to 7 - 'Ready'
2022-04-19 13:27:11 VERBOSE signalingClientConnectSync(): Signaling Client Connect Sync
2022-04-19 13:27:11 VERBOSE stepStateMachine(): State Machine - Current state: 0x0000000000000040, Next state: 0x0000000000000080, Current local state retry count [0], Max local state retry count [0], State transition wait time [0] ms
2022-04-19 13:27:11 VERBOSE signalingClientStateChanged(): Signaling client state changed to 8 - 'Connecting'
2022-04-19 13:27:11 VERBOSE lwsCompleteSync(): Perform secure synchronous call for URL: wss://m-978ce4ad.kinesisvideo.eu-west-2.amazonaws.com?X-Amz-ChannelARN=arn:aws:kinesisvideo:eu-west-2:798325461281:channel/MHTestChannel/1649777026515
2022-04-19 13:27:11 VERBOSE lwsWssCallbackRoutine(): WSS callback with reason 85
2022-04-19 13:27:11 VERBOSE lwsWssCallbackRoutine(): WSS callback with reason 105
2022-04-19 13:27:11 VERBOSE lwsWssCallbackRoutine(): WSS callback with reason 19
2022-04-19 13:27:11 VERBOSE lwsWssCallbackRoutine(): WSS callback with reason 29
2022-04-19 13:27:11 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 58
2022-04-19 13:27:11 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 58
2022-04-19 13:27:11 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 58
2022-04-19 13:27:11 VERBOSE lwsWssCallbackRoutine(): WSS callback with reason 24
2022-04-19 13:27:11 VERBOSE lwsWssCallbackRoutine(): WSS callback with reason 44
2022-04-19 13:27:11 VERBOSE lwsWssCallbackRoutine(): WSS callback with reason 2
2022-04-19 13:27:11 VERBOSE lwsWssCallbackRoutine(): WSS callback with reason 3
2022-04-19 13:27:11 DEBUG   lwsWssCallbackRoutine(): Connection established
2022-04-19 13:27:11 VERBOSE stepStateMachine(): State Machine - Current state: 0x0000000000000080, Next state: 0x0000000000000100, Current local state retry count [0], Max local state retry count [0], State transition wait time [0] ms
2022-04-19 13:27:11 VERBOSE signalingClientStateChanged(): Signaling client state changed to 9 - 'Connected'
[KVS Master] Signaling client connection to socket established
[KVS Master] Channel MHTestChannel set up done 
2022-04-19 13:27:11 VERBOSE signalingClientGetCurrentState(): Signaling Client Get Current State
2022-04-19 13:27:11 VERBOSE pregenerateCertTimerCallback(): New certificate has been pre-generated and added to the queue
2022-04-19 13:27:12 VERBOSE pregenerateCertTimerCallback(): New certificate has been pre-generated and added to the queue
2022-04-19 13:27:15 VERBOSE lwsHttpCallbackRoutine(): HTTPS callback with reason 72
2022-04-19 13:27:15 VERBOSE lwsWssCallbackRoutine(): WSS callback with reason 72
2022-04-19 13:27:16 VERBOSE signalingClientGetCurrentState(): Signaling Client Get Current State
2022-04-19 13:27:18 VERBOSE lwsWssCallbackRoutine(): WSS callback with reason 8
2022-04-19 13:27:18 VERBOSE lwsWssCallbackRoutine(): WSS callback with reason 8
2022-04-19 13:27:18 DEBUG   receiveLwsMessage(): Client received message of type: SDP_OFFER
2022-04-19 13:27:18 VERBOSE lwsWssCallbackRoutine(): WSS callback with reason 10
2022-04-19 13:27:18 DEBUG   lwsWssCallbackRoutine(): Client is writable
2022-04-19 13:27:18 VERBOSE signalingClientGetIceConfigInfoCount(): Signaling Client Get ICE Config Info Count
2022-04-19 13:27:18 DEBUG   refreshIceConfiguration(): Refreshing the ICE Server Configuration
2022-04-19 13:27:18 VERBOSE signalingClientGetIceConfigInfo(): Signaling Client Get ICE Config Info
2022-04-19 13:27:18 DEBUG   refreshIceConfiguration(): Refreshing the ICE Server Configuration
2022-04-19 13:27:18 DEBUG   iceAgentValidateKvsRtcConfig(): 
	iceLocalCandidateGatheringTimeout: 10000 ms
	iceConnectionCheckTimeout: 10000 ms
	iceCandidateNominationTimeout: 10000 ms
	iceConnectionCheckPollingInterval: 50 ms
2022-04-19 13:27:18 DEBUG   initializePeerConnection(): time taken to create peer connection 4 ms
2022-04-19 13:27:18 VERBOSE setPayloadTypesFromOffer(): Found H264 payload type 127 with score 2: level-asymmetry-allowed=1;packetization-mode=1;profile-level-id=42001f
2022-04-19 13:27:18 VERBOSE setPayloadTypesFromOffer(): Found H264 payload type 108 with score 3: level-asymmetry-allowed=1;packetization-mode=1;profile-level-id=42e01f
2022-04-19 13:27:18 VERBOSE lwsWssCallbackRoutine(): WSS callback with reason 8
2022-04-19 13:27:18 DEBUG   receiveLwsMessage(): Client received message of type: ICE_CANDIDATE
2022-04-19 13:27:18 VERBOSE lwsWssCallbackRoutine(): WSS callback with reason 10
2022-04-19 13:27:18 DEBUG   lwsWssCallbackRoutine(): Client is writable
2022-04-19 13:27:18 VERBOSE lwsWssCallbackRoutine(): WSS callback with reason 8
2022-04-19 13:27:18 DEBUG   receiveLwsMessage(): Client received message of type: ICE_CANDIDATE
2022-04-19 13:27:18 VERBOSE lwsWssCallbackRoutine(): WSS callback with reason 10
2022-04-19 13:27:18 DEBUG   lwsWssCallbackRoutine(): Client is writable
2022-04-19 13:27:18 VERBOSE stepStateMachine(): State Machine - Current state: 0x0000000000000001, Next state: 0x0000000000000002, Current local state retry count [0], Max local state retry count [0], State transition wait time [0] ms
2022-04-19 13:27:18 DEBUG   iceAgentCheckConnectionStateSetup(): ice candidate pair count 0
2022-04-19 13:27:18 DEBUG   stepIceAgentStateMachine(): Ice agent state changed from ICE_AGENT_STATE_NONE to ICE_AGENT_STATE_CHECK_CONNECTION.
2022-04-19 13:27:18 INFO    onConnectionStateChange(): New connection state 2
2022-04-19 13:27:18 DEBUG   createSocket(): setsockopt() NO_SIGNAL failed with errno An invalid argument was supplied.


2022-04-19 13:27:18 DEBUG   createSocket(): setsockopt() NO_SIGNAL failed with errno An invalid argument was supplied.


2022-04-19 13:27:18 DEBUG   createSocket(): setsockopt() NO_SIGNAL failed with errno An invalid argument was supplied.


2022-04-19 13:27:18 DEBUG   createSocket(): setsockopt() NO_SIGNAL failed with errno An invalid argument was supplied.


2022-04-19 13:27:18 DEBUG   createSocket(): setsockopt() NO_SIGNAL failed with errno An invalid argument was supplied.


2022-04-19 13:27:18 DEBUG   createSocket(): setsockopt() NO_SIGNAL failed with errno An invalid argument was supplied.


2022-04-19 13:27:18 DEBUG   createSocket(): setsockopt() NO_SIGNAL failed with errno An unknown, invalid, or unsupported option or level was specified in a getsockopt or setsockopt call.


2022-04-19 13:27:18 WARN    connectionListenerReceiveDataRoutine(): poll() failed with errno An invalid argument was supplied.


2022-04-19 13:27:18 WARN    connectionListenerReceiveDataRoutine(): poll() failed with errno An invalid argument was supplied.


2022-04-19 13:27:18 WARN    connectionListenerReceiveDataRoutine(): poll() failed with errno An invalid argument was supplied.


2022-04-19 13:27:18 WARN    connectionListenerReceiveDataRoutine(): poll() failed with errno An invalid argument was supplied.


2022-04-19 13:27:18 WARN    connectionListenerReceiveDataRoutine(): poll() failed with errno An invalid argument was supplied.


2022-04-19 13:27:18 WARN    connectionListenerReceiveDataRoutine(): poll() failed with errno An invalid argument was supplied.


2022-04-19 13:27:18 WARN    connectionListenerReceiveDataRoutine(): poll() failed with errno An invalid argument was supplied.


2022-04-19 13:27:18 WARN    connectionListenerReceiveDataRoutine(): poll() failed with errno An invalid argument was supplied.


2022-04-19 13:27:18 WARN    connectionListenerReceiveDataRoutine(): poll() failed with errno An invalid argument was supplied.


2022-04-19 13:27:18 WARN    connectionListenerReceiveDataRoutine(): poll() failed with errno An invalid argument was supplied.


2022-04-19 13:27:18 WARN    connectionListenerReceiveDataRoutine(): poll() failed with errno An invalid argument was supplied.


2022-04-19 13:27:18 WARN    connectionListenerReceiveDataRoutine(): poll() failed with errno An invalid argument was supplied.


2022-04-19 13:27:18 WARN    connectionListenerReceiveDataRoutine(): poll() failed with errno An invalid argument was supplied.


2022-04-19 13:27:18 WARN    connectionListenerReceiveDataRoutine(): poll() failed with errno An invalid argument was supplied.


2022-04-19 13:27:18 WARN    connectionListenerReceiveDataRoutine(): poll() failed with errno An invalid argument was supplied.


2022-04-19 13:27:18 WARN    connectionListenerReceiveDataRoutine(): poll() failed with errno An invalid argument was supplied.


2022-04-19 13:27:18 WARN    connectionListenerReceiveDataRoutine(): poll() failed with errno An invalid argument was supplied.


2022-04-19 13:27:18 WARN    connectionListenerReceiveDataRoutine(): poll() failed with errno An invalid argument was supplied.


2022-04-19 13:27:18 WARN    connectionListenerReceiveDataRoutine(): poll() failed with errno An invalid argument was supplied.


2022-04-19 13:27:18 WARN    connectionListenerReceiveDataRoutine(): poll() failed with errno An invalid argument was supplied.


2022-04-19 13:27:18 WARN    connectionListenerReceiveDataRoutine(): poll() failed with errno An invalid argument was supplied.


2022-04-19 13:27:18 WARN    connectionListenerReceiveDataRoutine(): poll() failed with errno An invalid argument was supplied.


2022-04-19 13:27:18 WARN    connectionListenerReceiveDataRoutine(): poll() failed with errno An invalid argument was supplied.


2022-04-19 13:27:18 VERBOSE signalingClientSendMessageSync(): Signaling Client Sending Message Sync
2022-04-19 13:27:18 WARN    connectionListenerReceiveDataRoutine(): poll() failed with errno An invalid argument was supplied.


2022-04-19 13:27:18 WARN    connectionListenerReceiveDataRoutine(): poll() failed with errno An invalid argument was supplied.


2022-04-19 13:27:18 WARN    connectionListenerReceiveDataRoutine(): poll() failed with errno An invalid argument was supplied.


2022-04-19 13:27:18 WARN    connectionListenerReceiveDataRoutine(): poll() failed with errno An invalid argument was supplied.


2022-04-19 13:27:18 DEBUG   sendLwsMessage(): Sending data over web socket: Message type: SDP_ANSWER, RecepientId: MPDNKAFT34L
2022-04-19 13:27:18 WARN    connectionListenerReceiveDataRoutine(): poll() failed with errno An invalid argument was supplied.


2022-04-19 13:27:18 WARN    connectionListenerReceiveDataRoutine(): poll() failed with errno An invalid argument was supplied.

*** ABOVE REPEATS APPROX 100MB ***

2022-04-19 13:27:28 WARN    connectionListenerReceiveDataRoutine(): poll() failed with errno An invalid argument was supplied.


2022-04-19 13:27:28 VERBOSE signalingClientGetCurrentState(): Signaling Client Get Current State
2022-04-19 13:27:31 VERBOSE lwsWssCallbackRoutine(): WSS callback with reason 10
2022-04-19 13:27:31 DEBUG   lwsWssCallbackRoutine(): Client is writable
2022-04-19 13:27:31 VERBOSE lwsWssCallbackRoutine(): WSS callback with reason 9
2022-04-19 13:27:33 VERBOSE signalingClientGetCurrentState(): Signaling Client Get Current State
2022-04-19 13:27:38 VERBOSE signalingClientGetCurrentState(): Signaling Client Get Current State
2022-04-19 13:27:41 VERBOSE lwsWssCallbackRoutine(): WSS callback with reason 10
2022-04-19 13:27:41 DEBUG   lwsWssCallbackRoutine(): Client is writable
2022-04-19 13:27:41 VERBOSE lwsWssCallbackRoutine(): WSS callback with reason 9
2022-04-19 13:27:43 VERBOSE signalingClientGetCurrentState(): Signaling Client Get Current State
2022-04-19 13:27:48 VERBOSE signalingClientGetCurrentState(): Signaling Client Get Current State
2022-04-19 13:27:51 VERBOSE lwsWssCallbackRoutine(): WSS callback with reason 10
2022-04-19 13:27:51 DEBUG   lwsWssCallbackRoutine(): Client is writable
2022-04-19 13:27:51 VERBOSE lwsWssCallbackRoutine(): WSS callback with reason 9
2022-04-19 13:27:53 VERBOSE signalingClientGetCurrentState(): Signaling Client Get Current State
2022-04-19 13:27:58 VERBOSE signalingClientGetCurrentState(): Signaling Client Get Current State
2022-04-19 13:28:01 VERBOSE lwsWssCallbackRoutine(): WSS callback with reason 10
2022-04-19 13:28:01 DEBUG   lwsWssCallbackRoutine(): Client is writable
2022-04-19 13:28:01 VERBOSE lwsWssCallbackRoutine(): WSS callback with reason 9
2022-04-19 13:28:03 VERBOSE signalingClientGetCurrentState(): Signaling Client Get Current State

vulkan101 avatar Apr 19 '22 13:04 vulkan101

@vulkan101 ,

We have not seen this error in the past. Could be Windows machine specific. Do you see any error in the poll call on other platforms?

disa6302 avatar Apr 25 '22 00:04 disa6302

Hi @disa6302, I'm constrained to the windows platform in this case, but I can try it on another machine and see if that makes any difference. I'll get back to you.

vulkan101 avatar Apr 25 '22 08:04 vulkan101

@disa6302 just to confirm I am seeing this on my windows 10 machine as well as an AWS instance (windows server 2019)

vulkan101 avatar Apr 26 '22 11:04 vulkan101

@disa6302 I have responded to your question, can this be moved out of "pending-response"?

vulkan101 avatar May 04 '22 09:05 vulkan101

@vulkan101 Did you find any solution for this issue. I am also facing the same issue in windows and cannot find a solution. Its realy helpfull if you can share your comments.

itzzmearungmailcom avatar Nov 08 '22 05:11 itzzmearungmailcom

@itzzmearungmailcom Few months ago, I found a trick. In Windows, the connectionListenerReceiveDataRoutine function doesn't seem to work properly. This is a trick anyway.

Please fix it... AWS

PVOID connectionListenerReceiveDataRoutine(PVOID arg)
{
    STATUS retStatus = STATUS_SUCCESS;
    PConnectionListener pConnectionListener = (PConnectionListener) arg;
    PSocketConnection pSocketConnection;
    BOOL iterate = TRUE;
    PSocketConnection sockets[CONNECTION_LISTENER_DEFAULT_MAX_LISTENING_CONNECTION];
    UINT32 i, socketCount;

    INT32 nfds = 0;
    struct pollfd rfds[CONNECTION_LISTENER_DEFAULT_MAX_LISTENING_CONNECTION];
    INT32 retval, localSocket;
    INT64 readLen;
    // the source address is put here. sockaddr_storage can hold either sockaddr_in or sockaddr_in6
    struct sockaddr_storage srcAddrBuff;
    socklen_t srcAddrBuffLen = SIZEOF(srcAddrBuff);
    struct sockaddr_in* pIpv4Addr;
    struct sockaddr_in6* pIpv6Addr;
    KvsIpAddress srcAddr;
    PKvsIpAddress pSrcAddr = NULL;

    CHK(pConnectionListener != NULL, STATUS_NULL_ARG);

    /* Ensure that memory sanitizers consider
     * rfds initialized even if FD_ZERO is
     * implemented in assembly. */
    MEMSET(&rfds, 0x00, SIZEOF(rfds));

    srcAddr.isPointToPoint = FALSE;

    while (!ATOMIC_LOAD_BOOL(&pConnectionListener->terminate)) {
        nfds = 0;
        Sleep(10);

        // Perform the socket connection gathering under the lock
        // NOTE: There is no cleanup jump from the lock/unlock block
        // so we don't need to use a boolean indicator whether locked
        MUTEX_LOCK(pConnectionListener->lock);
        for (i = 0, socketCount = 0; i < CONNECTION_LISTENER_DEFAULT_MAX_LISTENING_CONNECTION; i++) {
            pSocketConnection = pConnectionListener->sockets[i];
            if (pSocketConnection != NULL) {
                if (!socketConnectionIsClosed(pSocketConnection)) {
                    MUTEX_LOCK(pSocketConnection->lock);
                    localSocket = pSocketConnection->localSocket;
                    MUTEX_UNLOCK(pSocketConnection->lock);
                    rfds[nfds].fd = localSocket;
                    rfds[nfds].events = POLLIN | POLLPRI;
                    rfds[nfds].revents = 0;
                    nfds++;

                    // Store the sockets locally while in use and mark it as in use
                    sockets[socketCount++] = pSocketConnection;
                    ATOMIC_STORE_BOOL(&pSocketConnection->inUse, TRUE);
                } else {
                    // Remove the connection
                    pConnectionListener->sockets[i] = NULL;
                    pConnectionListener->socketCount--;
                }
            }
        }

        // Need to unlock the mutex to ensure other racing threads unblock
        MUTEX_UNLOCK(pConnectionListener->lock);

        // blocking call until resolves as a timeout, an error, a signal or data received
        //retval = POLL(rfds, nfds, CONNECTION_LISTENER_SOCKET_WAIT_FOR_DATA_TIMEOUT / HUNDREDS_OF_NANOS_IN_A_MILLISECOND);
        
        //retval = POLL(rfds, nfds, INFINITE);
        retval = 1;
        
        // In case of 0 we have a timeout and should re-lock to allow for other
        // interlocking operations to proceed. A positive return means we received data
        if (retval == -1) {
            DLOGW("poll() failed with errno %s", getErrorString(getErrorCode()));
        } else if (retval > 0) {
            for (i = 0; i < socketCount; i++) {
                pSocketConnection = sockets[i];
                if (!socketConnectionIsClosed(pSocketConnection)) {
                    MUTEX_LOCK(pSocketConnection->lock);
                    localSocket = pSocketConnection->localSocket;
                    MUTEX_UNLOCK(pSocketConnection->lock);

                    //if (canReadFd(localSocket, rfds, nfds)) {
                    if (1) {
                        iterate = TRUE;
                        while (iterate) 
                        {
                            readLen = recvfrom(localSocket, pConnectionListener->pBuffer, pConnectionListener->bufferLen, 0,
                                               (struct sockaddr*) &srcAddrBuff, &srcAddrBuffLen);
                            if (readLen < 0) 
                            {
                                switch (getErrorCode()) {
                                    case EWOULDBLOCK:
                                        break;
                                    default:
                                        /* on any other error, close connection */
                                        CHK_STATUS(socketConnectionClosed(pSocketConnection));
                                        DLOGD("recvfrom() failed with errno %s for socket %d", getErrorString(getErrorCode()), localSocket);
                                        break;
                                }

                                iterate = FALSE;
                            } 
                            else if (readLen == 0) {
                                CHK_STATUS(socketConnectionClosed(pSocketConnection));
                                iterate = FALSE;
                            } 
                            else if (/* readLen > 0 */
                                       ATOMIC_LOAD_BOOL(&pSocketConnection->receiveData) && pSocketConnection->dataAvailableCallbackFn != NULL &&
                                       /* data could be encrypted so they need to be decrypted through socketConnectionReadData
                                        * and get the decrypted data length. */
                                       STATUS_SUCCEEDED(socketConnectionReadData(pSocketConnection, pConnectionListener->pBuffer,
                                                                                 pConnectionListener->bufferLen, (PUINT32) &readLen))) 
                            {
                                if (pSocketConnection->protocol == KVS_SOCKET_PROTOCOL_UDP) {
                                    if (srcAddrBuff.ss_family == AF_INET) {
                                        srcAddr.family = KVS_IP_FAMILY_TYPE_IPV4;
                                        pIpv4Addr = (struct sockaddr_in*) &srcAddrBuff;
                                        MEMCPY(srcAddr.address, (PBYTE) &pIpv4Addr->sin_addr, IPV4_ADDRESS_LENGTH);
                                        srcAddr.port = pIpv4Addr->sin_port;
                                    } else if (srcAddrBuff.ss_family == AF_INET6) {
                                        srcAddr.family = KVS_IP_FAMILY_TYPE_IPV6;
                                        pIpv6Addr = (struct sockaddr_in6*) &srcAddrBuff;
                                        MEMCPY(srcAddr.address, (PBYTE) &pIpv6Addr->sin6_addr, IPV6_ADDRESS_LENGTH);
                                        srcAddr.port = pIpv6Addr->sin6_port;
                                    }
                                    pSrcAddr = &srcAddr;
                                } else {
                                    // srcAddr is ignored in TCP callback handlers
                                    pSrcAddr = NULL;
                                }

                                // readLen may be 0 if SSL does not emit any application data.
                                // in that case, no need to call dataAvailable callback
                                if (readLen > 0) {
                                    pSocketConnection->dataAvailableCallbackFn(pSocketConnection->dataAvailableCallbackCustomData, pSocketConnection,
                                                                               pConnectionListener->pBuffer, (UINT32) readLen, pSrcAddr,
                                                                               NULL); // no dest information available right now.
                                }
                            }

                            // reset srcAddrBuffLen to actual size
                            srcAddrBuffLen = SIZEOF(srcAddrBuff);
                        }
                    }
                }
            }
        }

        // Mark as unused
        for (i = 0; i < socketCount; i++) {
            ATOMIC_STORE_BOOL(&sockets[i]->inUse, FALSE);
        }
    }

CleanUp:

    // The check for valid mutex is necessary because when we're in freeConnectionListener
    // we may free the mutex in another thread so by the time we get here accessing the lock
    // will result in accessing a resource after it has been freed
    if (pConnectionListener != NULL && IS_VALID_MUTEX_VALUE(pConnectionListener->lock)) {
        // As TID is 64 bit we can't atomically update it and need to do it under the lock
        MUTEX_LOCK(pConnectionListener->lock);
        pConnectionListener->receiveDataRoutine = INVALID_TID_VALUE;
        MUTEX_UNLOCK(pConnectionListener->lock);
    }

    CHK_LOG_ERR(retStatus);

    return (PVOID) (ULONG_PTR) retStatus;
}

Say-Y avatar Nov 08 '22 06:11 Say-Y

@itzzmearungmailcom - Just to answer your question to me, I haven't found a solution or had the chance to try out @Say-Y's fix. I had to move on to something that did work (libdatachannel)

vulkan101 avatar Nov 08 '22 08:11 vulkan101

@Say-Y @vulkan101 Thank you for your help and comments. I have checked your updates. Warnings regarding connectionListenerReceiveDataRoutine() are no longer coming.

But the Socket creation issue still exists and like below.

2022-11-08 09:23:08 DEBUG createSocket(): setsockopt() NO_SIGNAL failed with errno An invalid argument was supplied. 2022-11-08 09:23:08 WARN socketBind(): bind() failed for ip address: 169.254.200.70, port 0 with errno The requested address is not valid in its context. 2022-11-08 09:23:08 ERROR createSocketConnection(): operation returned status code: 0x58000018

This issue seems because of my Wifi connection and can be solved by switching the network. Let me try

Thank you once again :)

itzzmearungmailcom avatar Nov 08 '22 10:11 itzzmearungmailcom

Hi @vulkan101, can you please use the develop branch to build on Windows now, try running the sample application without any modifications to the SDK and see if this issue still persists?

niyatim23 avatar Jul 28 '23 18:07 niyatim23

It looks like this issue has not been active for 10 days. If the issue is not resolved, please add an update to the ticket, else it will be automatically resolved in a few days.

github-actions[bot] avatar Aug 05 '23 00:08 github-actions[bot]

Please use develop and refer to the windows-openssl-msvc CI build for steps to build correctly. Closing this issue due to no response. Feel free to reopen / open a new issue if this persists.

niyatim23 avatar Aug 08 '23 16:08 niyatim23