PropertiesState - Version: '0.11.0-SNAPSHOT', commit hash: ''
09:46:10.233 [main] INFO o.k.k.c.p.KaaClientPropertiesState - First SDK start
09:46:10.242 [main] DEBUG o.k.k.c.p.KaaClientPropertiesState - Check if key pair exists .\key.public, .\key.private
09:46:11.308 [Thread-0] DEBUG o.k.k.c.c.impl.DefaultChannelManager - [default_bootstrap_channel] Worker started
09:46:11.309 [main] DEBUG o.k.k.c.c.impl.DefaultChannelManager - Applying server GenericTransportInfo [serverType=BOOTSTRAP, transportId=TransportProtocolId [id=-73777936, version=1], md={"accessPointId": 812883061, "protocolVersionInfo": {"id": -73777936, "version": 1}, "connectionInfo": {"bytes": "0000012630820122300d06092a864886f70d01010105000382010f003082010a0282010100cc8a5174ccd27d519ff6951cfe300000d31302e32382e3132302e313436000026a1"}}] for channel [default_bootstrap_channel] type TransportProtocolId [id=-73777936, version=1]
09:46:11.310 [main] INFO o.k.k.c.c.i.c.AbstractHttpChannel - Creating a new executor for channel default_bootstrap_channel
09:46:11.312 [main] DEBUG o.k.k.c.p.KaaClientPropertiesState - Check if key pair exists .\key.public, .\key.private
09:46:11.312 [main] DEBUG o.k.k.c.p.KaaClientPropertiesState - Check if key pair exists .\key.public, .\key.private
09:46:11.479 [main] INFO o.k.k.c.c.impl.DefaultChannelManager - Failed to find operations service for channel [default_operation_tcp_channel] type TransportProtocolId [id=1456013202, version=1]
09:46:11.479 [Thread-1] DEBUG o.k.k.c.c.impl.DefaultChannelManager - [default_operation_tcp_channel] Worker started
09:46:11.492 [main] DEBUG o.k.k.c.c.FlexibleExecutorContext - Creating executor services
09:46:11.494 [main] DEBUG o.k.k.c.c.FlexibleExecutorContext - Creation of executor services is finished
09:46:11.496 [pool-2-thread-1] DEBUG o.k.kaa.client.AbstractKaaClient - Client startup initiated
09:46:11.496 [pool-2-thread-1] DEBUG o.k.k.c.c.b.AbstractConfigurationManager - Loading configuration data from defaults null
09:46:11.496 [pool-2-thread-1] DEBUG o.k.k.c.b.DefaultBootstrapManager - Going to invoke sync method of assigned transport
09:46:11.496 [pool-2-thread-1] DEBUG o.k.k.c.c.impl.DefaultChannelManager - Lookup channel by type BOOTSTRAP
09:46:11.497 [Thread-0] DEBUG o.k.k.c.c.impl.DefaultChannelManager - [default_bootstrap_channel] Going to invoke sync method
09:46:11.497 [Thread-0] INFO o.k.k.c.c.i.c.AbstractHttpChannel - Processing sync BOOTSTRAP for channel default_bootstrap_channel
09:46:11.499 [pool-1-thread-1] DEBUG o.k.kaa.client.AbstractKaaClient - Adding transport with id -73777936 and version 1 to resolve request
09:46:11.499 [pool-1-thread-1] DEBUG o.k.kaa.client.AbstractKaaClient - Adding transport with id 1456013202 and version 1 to resolve request
添加数据23
09:46:11.507 [pool-3-thread-1] DEBUG o.k.k.c.logging.memory.MemLogStorage - Consumed volume: 3
09:46:11.507 [pool-3-thread-1] DEBUG o.k.k.c.logging.memory.MemLogStorage - Record count: 1
09:46:11.508 [pool-3-thread-1] DEBUG o.k.k.c.logging.memory.MemLogStorage - Record count: 1
09:46:11.546 [pool-1-thread-1] DEBUG o.a.h.c.protocol.RequestAddCookies - CookieSpec selected: best-match
09:46:11.557 [pool-1-thread-1] DEBUG o.a.h.c.protocol.RequestAuthCache - Auth cache not set in the context
09:46:11.559 [pool-1-thread-1] DEBUG o.a.h.i.c.PoolingHttpClientConnectionManager - Connection request: [route: {}->http://10.28.120.146:9889][total kept alive: 0; route allocated: 0 of 2; total allocated: 0 of 20]
09:46:11.573 [pool-1-thread-1] DEBUG o.a.h.i.c.PoolingHttpClientConnectionManager - Connection leased: [id: 0][route: {}->http://10.28.120.146:9889][total kept alive: 0; route allocated: 1 of 2; total allocated: 1 of 20]
09:46:11.589 [pool-1-thread-1] DEBUG o.a.h.c.HttpClientConnectionManager - Connecting to /
10.28.120.146:988909:46:11.598 [pool-1-thread-1] DEBUG o.a.h.impl.execchain.MainClientExec - Executing request POST /BS/Sync HTTP/1.1
09:46:11.598 [pool-1-thread-1] DEBUG o.a.h.impl.execchain.MainClientExec - Target auth state: UNCHALLENGED
09:46:11.599 [pool-1-thread-1] DEBUG o.a.h.impl.execchain.MainClientExec - Proxy auth state: UNCHALLENGED
09:46:11.603 [pool-1-thread-1] DEBUG org.apache.http.headers - http-outgoing-0 >> POST /BS/Sync HTTP/1.1
09:46:11.603 [pool-1-thread-1] DEBUG org.apache.http.headers - http-outgoing-0 >> Content-Length: 859
09:46:11.603 [pool-1-thread-1] DEBUG org.apache.http.headers - http-outgoing-0 >> Content-Type: multipart/form-data; boundary=bsf8Z4Dzw4FEDEYBcnbw_4z_v181Hwp
09:46:11.603 [pool-1-thread-1] DEBUG org.apache.http.headers - http-outgoing-0 >> Host:
10.28.120.146:988909:46:11.603 [pool-1-thread-1] DEBUG org.apache.http.headers - http-outgoing-0 >> Connection: Keep-Alive
09:46:11.603 [pool-1-thread-1] DEBUG org.apache.http.headers - http-outgoing-0 >> User-Agent: Apache-HttpClient/4.3.2 (java 1.5)
09:46:11.603 [pool-1-thread-1] DEBUG org.apache.http.headers - http-outgoing-0 >> Accept-Encoding: gzip,deflate
09:46:11.605 [pool-1-thread-1] DEBUG org.apache.http.wire - http-outgoing-0 >> "POST /BS/Sync HTTP/1.1[\r][\n]"
09:46:11.605 [pool-1-thread-1] DEBUG org.apache.http.wire - http-outgoing-0 >> "Content-Length: 859[\r][\n]"
09:46:11.605 [pool-1-thread-1] DEBUG org.apache.http.wire - http-outgoing-0 >> "Content-Type: multipart/form-data; boundary=bsf8Z4Dzw4FEDEYBcnbw_4z_v181Hwp[\r][\n]"
09:46:11.605 [pool-1-thread-1] DEBUG org.apache.http.wire - http-outgoing-0 >> "Host: 10.28.120.146:9889[\r][\n]"
09:46:11.605 [pool-1-thread-1] DEBUG org.apache.http.wire - http-outgoing-0 >> "Connection: Keep-Alive[\r][\n]"
09:46:11.605 [pool-1-thread-1] DEBUG org.apache.http.wire - http-outgoing-0 >> "User-Agent: Apache-HttpClient/4.3.2 (java 1.5)[\r][\n]"
09:46:11.605 [pool-1-thread-1] DEBUG org.apache.http.wire - http-outgoing-0 >> "Accept-Encoding: gzip,deflate[\r][\n]"
09:46:11.605 [pool-1-thread-1] DEBUG org.apache.http.wire - http-outgoing-0 >> "[\r][\n]"
09:46:11.605 [pool-1-thread-1] DEBUG org.apache.http.wire - http-outgoing-0 >> "--bsf8Z4Dzw4FEDEYBcnbw_4z_v181Hwp[\r][\n]"
09:46:11.605 [pool-1-thread-1] DEBUG org.apache.http.wire - http-outgoing-0 >> "Content-Disposition: form-data; name="requestKey"[\r][\n]"
09:46:11.605 [pool-1-thread-1] DEBUG org.apache.http.wire - http-outgoing-0 >> "Content-Type: application/octet-stream[\r][\n]"
09:46:11.605 [pool-1-thread-1] DEBUG org.apache.http.wire - http-outgoing-0 >> "Content-Transfer-Encoding: binary[\r][\n]"
09:46:11.605 [pool-1-thread-1] DEBUG org.apache.http.wire - http-outgoing-0 >> "[\r][\n]"
09:46:11.606 [pool-1-thread-1] DEBUG org.apache.http.wire - http-outgoing-0 >> "[0x9][8[0xe7][0xc3]O[0xf0][0xf7][0x80]h[0xff]K[0xbd][0xe8][0xe5]`[0xb1]8[0x9].d1][0x1f][0xd6]X[0xca]|[0x8b][0xc9]n8[\n]"
09:46:11.606 [pool-1-thread-1] DEBUG org.apache.http.wire - http-outgoing-0 >> "[0xd3][0x19]][0xed][0xa9]0x96][0x1]>[0x9d]l[0x8d][0xc4];F[0xcf][0xa4]hu[0xba][0xaf][0xba]^V[0xb3].D[0xcd][0xba]H[0x92][0xc9][0xf3][0xa6]\[0xb9][0xa4][0x82][0x1f][0xbc]}-[0xc8]|[0xc1][0xd1][0xef][0x13]SF[0xfb]4<[\r][\n]"
09:46:11.606 [pool-1-thread-1] DEBUG org.apache.http.wire - http-outgoing-0 >> "--bsf8Z4Dzw4FEDEYBcnbw_4z_v181Hwp[\r][\n]"
09:46:11.606 [pool-1-thread-1] DEBUG org.apache.http.wire - http-outgoing-0 >> "Content-Disposition: form-data; name="requestData"[\r][\n]"
09:46:11.606 [pool-1-thread-1] DEBUG org.apache.http.wire - http-outgoing-0 >> "Content-Type: application/octet-stream[\r][\n]"
09:46:11.606 [pool-1-thread-1] DEBUG org.apache.http.wire - http-outgoing-0 >> "Content-Transfer-Encoding: binary[\r][\n]"
09:46:11.607 [pool-1-thread-1] DEBUG org.apache.http.wire - http-outgoing-0 >> "[\r][\n]"
09:46:11.607 [pool-1-thread-1] DEBUG org.apache.http.wire - http-outgoing-0 >> "8[0x17][0xb6][0xb6]n[0xe5][0x1f][0x8f]A1[0x9e][\n]"
09:46:11.607 [pool-1-thread-1] DEBUG org.apache.http.wire - http-outgoing-0 >> "[0xcb]z5[0x8e][0x11][0xa7][0xf0][\n]"
09:46:11.607 [pool-1-thread-1] DEBUG org.apache.http.wire - http-outgoing-0 >> "[0xe2]:^w[0xd4][0xd1][0x1b][0xb]x[0xad][0x9b][0xaa]R[0x19],s[0xc5][0x8e][0xab]<[0x12]*[0x8e]X3[0xcd][0xff][0x3][0xe8][0xdb]u[0xc6][0x9a][0x84][0x94][0x86][0xe9]$[0xe][0x85][0xae][0xcd]?z[\r][\n]"
09:46:11.607 [pool-1-thread-1] DEBUG org.apache.http.wire - http-outgoing-0 >> "--bsf8Z4Dzw4FEDEYBcnbw_4z_v181Hwp[\r][\n]"
09:46:11.607 [pool-1-thread-1] DEBUG org.apache.http.wire - http-outgoing-0 >> "Content-Disposition: form-data; name="nextProtocol"[\r][\n]"
09:46:11.607 [pool-1-thread-1] DEBUG org.apache.http.wire - http-outgoing-0 >> "Content-Type: application/octet-stream[\r][\n]"
09:46:11.607 [pool-1-thread-1] DEBUG org.apache.http.wire - http-outgoing-0 >> "Content-Transfer-Encoding: binary[\r][\n]"
09:46:11.607 [pool-1-thread-1] DEBUG org.apache.http.wire - http-outgoing-0 >> "[\r][\n]"
09:46:11.607 [pool-1-thread-1] DEBUG org.apache.http.wire - http-outgoing-0 >> "[0xe0][0xc0][0xc1]x[\r][\n]"
09:46:11.607 [pool-1-thread-1] DEBUG org.apache.http.wire - http-outgoing-0 >> "--bsf8Z4Dzw4FEDEYBcnbw_4z_v181Hwp--[\r][\n]"
09:46:11.618 [pool-1-thread-1] DEBUG org.apache.http.wire - http-outgoing-0 << "HTTP/1.1 200 OK[\r][\n]"
09:46:11.618 [pool-1-thread-1] DEBUG org.apache.http.wire - http-outgoing-0 << "Content-Type: "application/x-kaa"[\r][\n]"
09:46:11.618 [pool-1-thread-1] DEBUG org.apache.http.wire - http-outgoing-0 << "Content-Length: 1344[\r][\n]"
09:46:11.618 [pool-1-thread-1] DEBUG org.apache.http.wire - http-outgoing-0 << "X-RESPONSETYPE: operation[\r][\n]"
09:46:11.618 [pool-1-thread-1] DEBUG org.apache.http.wire - http-outgoing-0 << "X-SIGNATURE: A9DZfQriBlm1Q1sJzRJKqU9FFuxQoHNGdKGt7iO3Vzlv3qcXb0by95F8q3IPMdqBN6zSIXNGPPXBHfFecGGhVwNfL47Uvsi7wTpRgO86TOzqdTTwxojaLxL5PAbK7jqGo3/UBOmHn416hP5C8qNd7p6dzna5whsPKNgYYyUa24ZAuHh/3PE74lzjBAoSMTF1aiichIXawJ1gX/r4TMGU/ZVqOPJUeX/c7N/+3L
09:46:11.618 [pool-1-thread-1] DEBUG org.apache.http.wire - http-outgoing-0 << "Connection: close[\r][\n]"
09:46:11.618 [pool-1-thread-1] DEBUG org.apache.http.wire - http-outgoing-0 << "[\r][\n]"
09:46:11.624 [pool-1-thread-1] DEBUG org.apache.http.headers - http-outgoing-0 << HTTP/1.1 200 OK
09:46:11.624 [pool-1-thread-1] DEBUG org.apache.http.headers - http-outgoing-0 << Content-Type: "application/x-kaa"
09:46:11.624 [pool-1-thread-1] DEBUG org.apache.http.headers - http-outgoing-0 << Content-Length: 1344
09:46:11.624 [pool-1-thread-1] DEBUG org.apache.http.headers - http-outgoing-0 << X-RESPONSETYPE: operation
09:46:11.624 [pool-1-thread-1] DEBUG org.apache.http.headers - http-outgoing-0 << X-SIGNATURE: A9DZfQriBlm1Q1sJzRJKqU9FFuxQPMdqBN6zSIXNGPPXBHfFecGGhVwNfL47Uvsi7wTpRgO86TOzqdTTwxojaLxL5PAbK7jqGo3/UBOmHn416hP5C8qNd7p6dzna5whsPKNgYYyUa24ZAuHh/3PE74lzjBAoSMTF1aiichIXawJ1gX/r4TMGU/ZVqOPJUeX/c7N/+3LWjA7Puk9yTWZUxEuZFv33zddzs8I23vS5bPP+bfKxGRvdMncdzgGHegCDm4W+CKO+DZw9QWHdkOcOdjBy1z5WYZVxZLUHdMHiyOD/DrqCU9IZWxg==
09:46:11.624 [pool-1-thread-1] DEBUG org.apache.http.headers - http-outgoing-0 << Connection: close
09:46:11.636 [pool-1-thread-1] DEBUG o.k.k.c.transport.DesktopHttpClient - Received HTTP/1.1 200 OK
09:46:11.637 [pool-1-thread-1] DEBUG o.a.h.i.c.DefaultManagedHttpClientConnection - http-outgoing-0: Shutdown connection
09:46:11.638 [pool-1-thread-1] DEBUG o.a.h.impl.execchain.MainClientExec - Connection discarded
09:46:11.638 [pool-1-thread-1] DEBUG o.a.h.i.c.DefaultManagedHttpClientConnection - http-outgoing-0: Close connection
09:46:11.638 [pool-1-thread-1] DEBUG o.a.h.i.c.PoolingHttpClientConnectionManager - Connection released: [id: 0][route: {}->http://10.28.120.146:9889][total kept alive: 0; route allocated: 0 of 2; total allocated: 0 of 20]
09:46:11.667 [pool-1-thread-1] DEBUG o.k.k.c.c.impl.DefaultChannelManager - Transport connection info updated for server: GenericTransportInfo [serverType=OPERATIONS, transportId=TransportProtocolId [id=1456013202, version=1], md={"accessPointId": 812883061, "protocolVersionInfo": {"id": 1456013202, "version": 1}, "connectionInfo": {"bytes": "5253dd6b5ebffd02030100010000000d31302e32382e3132302e3134360000270d"}}]
09:46:11.667 [pool-1-thread-1] INFO o.k.k.c.c.impl.DefaultChannelManager - Adding new operations service: GenericTransportInfo [serverType=OPERATIONS, transportId=TransportProtocolId [id=1456013202, version=1], md={"accessPointId": 812883061, "protocolVersionInfo": {"id": 1456013202, "version": 1}, "connectionInfo": {"bytes": "d7eeec73abba21771364fa47f83614d959c9a0585253dd6b5ebffd02030100010000000d31302e32382e3132302e3134360000270d"}}]
09:46:11.668 [pool-1-thread-1] DEBUG o.k.k.c.c.impl.DefaultChannelManager - Applying server GenericTransportInfo [serverType=OPERATIONS, transportId=TransportProtocolId [id=1456013202, version=1], md={"accessPointId": 812883061, "protocolVersionInfo": {"id": 1456013202, "version": 1}, "connectionInfo": {"bytes": "14d959c9a0585253dd6b5ebffd02030100010000000d31302e32382e3132302e3134360000270d"}}] for channel [default_operation_tcp_channel] type TransportProtocolId [id=1456013202, version=1]
09:46:11.668 [pool-1-thread-1] INFO o.k.k.c.c.i.c.DefaultOperationTcpChannel - Setting server [GenericTransportInfo [serverType=OPERATIONS, transportId=TransportProtocolId [id=1456013202, version=1], md={"accessPointId": 812883061, "protocolVersionInfo": {"id": 1456013202, "version": 1}, "connectionInfo": {"bytes": "d959c9a0585253dd6b5ebffd02030100010000000d31302e32382e3132302e3134360000270d"}}]] for channel [default_operation_tcp_channel]
09:46:11.668 [pool-1-thread-1] DEBUG o.k.k.c.p.KaaClientPropertiesState - Check if key pair exists .\key.public, .\key.private
09:46:11.668 [pool-1-thread-1] DEBUG o.k.k.c.p.KaaClientPropertiesState - Check if key pair exists .\key.public, .\key.private
09:46:11.668 [pool-1-thread-1] INFO o.k.k.c.c.i.c.DefaultOperationTcpChannel - Creating a new executor for channel [default_operation_tcp_channel]
09:46:11.669 [pool-1-thread-1] INFO o.k.k.c.c.i.c.DefaultOperationTcpChannel - New server's: IpTransportInfo [host=10.28.120.146, port=9997] host or ip is different from the old null, reconnecting
09:46:11.669 [pool-1-thread-1] INFO o.k.k.c.c.i.c.DefaultOperationTcpChannel - Scheduling open connection task
09:46:11.669 [pool-1-thread-1] DEBUG o.k.k.c.c.impl.DefaultChannelManager - Transport connection info updated for server: GenericTransportInfo [serverType=OPERATIONS, transportId=TransportProtocolId [id=-73777936, version=1], md={"accessPointId": -1226314021, "protocolVersionInfo": {"id": -73777936, "version": 1}, "connectionInfo": {"bytes": "169a29c3bf7223b02030100010000000d31302e32382e3132302e3134350000270f"}}]
09:46:11.669 [pool-1-thread-1] INFO o.k.k.c.c.impl.DefaultChannelManager - Adding new operations service: GenericTransportInfo [serverType=OPERATIONS, transportId=TransportProtocolId [id=-73777936, version=1], md={"accessPointId": -1226314021, "protocolVersionInfo": {"id": -73777936, "version": 1}, "connectionInfo": {"bytes": "9a29c3bf7223b02030100010000000d31302e32382e3132302e3134350000270f"}}]
09:46:11.670 [pool-1-thread-1] DEBUG o.k.k.c.c.f.s.DefaultFailoverStrategy - SDK recovered after failover with connection info: IpTransportInfo [host=10.28.120.146, port=9889]
09:46:11.670 [pool-6-thread-1] INFO o.k.k.c.c.i.c.DefaultOperationTcpChannel - Channel [default_operation_tcp_channel]: opening connection to server IpTransportInfo [host=10.28.120.146, port=9997]
09:46:11.676 [pool-6-thread-1] DEBUG o.k.k.c.c.i.c.DefaultOperationTcpChannel - Sending Connect to channel [default_operation_tcp_channel]
09:46:11.681 [pool-6-thread-1] DEBUG o.k.k.c.logging.memory.MemLogStorage - Return record block with records count: [1]
09:46:11.682 [pool-6-thread-1] INFO o.k.k.c.logging.AbstractLogCollector - Adding following bucket id [0] for timeout tracking
09:46:11.684 [pool-6-thread-1] DEBUG o.k.k.c.p.KaaClientPropertiesState - Check if key pair exists .\key.public, .\key.private
09:46:11.686 [pool-6-thread-1] INFO o.k.k.c.c.i.DefaultOperationDataProcessor - Created Sync request: {"requestId": 1, "syncRequestMetaData": {"sdkToken": "Jj0y8ubrOp6NuqhH54UTq0zFrfQ", "endpointPublicKeyHash": {"bytes": "4b5fd7e82dcebd941d07a93e33c653e1cb235618"}, "profileHash": {"bytes": ""}, "timeout": 60000}, "bootstrapSyncRequest": null, "profileSyncRequest": {"endpointPublicKey": {"bytes": "c2f9a41bba28e72b89780c266a402f0c94634ec547b46a4dbaa96fbda40ffd9cba29786941f0d2da71b3ceef94c68bc367d0084381965b62d86aee932c66d2ba3f2d3fa61247d8a9345b099ca76c2784fe3db48b0203010001"}, "profileBody": {"bytes": ""}, "endpointAccessToken": "cd9bdc8f-c5ca-4d41-a483-f6f027c7f4c2"}, "configurationSyncRequest": {"configurationHash": {"bytes": "c4ea21bb365bbeeaf5f2c654883e56d11e43c44e"}, "resyncOnly": true}, "notificationSyncRequest": {"topicListHash": 0, "topicStates": null, "acceptedUnicastNotifications": null, "subscriptionCommands": []}, "userSyncRequest": {"userAttachRequest": null, "endpointAttachRequests": [], "endpointDetachRequests": []}, "eventSyncRequest": {"eventSequenceNumberRequest": {}, "eventListenersRequests": null, "events": null}, "logSyncRequest": {"requestId": 0, "logEntries": [{"data": {"bytes": "2ef601"}}]}, "extensionSyncRequests": null}
09:46:11.746 [pool-6-thread-1] DEBUG o.k.k.c.c.p.kaatcp.messages.Connect - Created Connect message: session key size = 256, signature size = 256, sync request size = 448
09:46:11.750 [pool-6-thread-1] DEBUG o.k.k.c.c.i.c.DefaultOperationTcpChannel - Submitting a read task for channel [default_operation_tcp_channel]
09:46:11.750 [pool-6-thread-1] DEBUG o.k.k.c.c.i.c.DefaultOperationTcpChannel - Scheduling a ping task (100 seconds) for channel [default_operation_tcp_channel]
09:46:11.752 [pool-6-thread-1] INFO o.k.k.c.c.i.c.DefaultOperationTcpChannel - Channel [default_operation_tcp_channel] is reading data from stream using [1024] byte buffer
09:46:41.509 [pool-5-thread-1] DEBUG o.k.k.c.logging.memory.MemLogStorage - Consumed volume: 0
09:46:41.509 [pool-5-thread-1] DEBUG o.k.k.c.logging.memory.MemLogStorage - Record count: 0
09:46:41.509 [pool-5-thread-1] DEBUG o.k.k.c.logging.memory.MemLogStorage - Record count: 0
09:46:41.766 [pool-6-thread-1] INFO o.k.k.c.c.i.c.DefaultOperationTcpChannel - ConnAck (REFUSE_SERVER_UNAVAILABLE) message received for channel [default_operation_tcp_channel]
09:46:41.766 [pool-6-thread-1] ERROR o.k.k.c.c.i.c.DefaultOperationTcpChannel - Connection for channel [default_operation_tcp_channel] was rejected: REFUSE_SERVER_UNAVAILABLE
09:46:41.766 [pool-6-thread-1] INFO o.k.k.c.c.i.c.DefaultOperationTcpChannel - Cleaning client state
09:46:41.772 [pool-6-thread-1] INFO o.k.k.c.c.i.c.DefaultOperationTcpChannel - [default_operation_tcp_channel] has failed
09:46:41.772 [pool-6-thread-1] INFO o.k.k.c.c.i.c.DefaultOperationTcpChannel - Channel "default_operation_tcp_channel": closing current connection
09:46:41.772 [pool-6-thread-1] DEBUG o.k.k.c.c.i.c.DefaultOperationTcpChannel - Sending Disconnect from channel [default_operation_tcp_channel]
09:46:44.788 [pool-6-thread-1] WARN o.k.k.c.c.PingConnectivityChecker - Host
www.google.com is unreachable
java.net.SocketTimeoutException: connect timed out
at java.net.DualStackPlainSocketImpl.waitForConnect(Native Method) ~[na:1.8.0_65]
at java.net.DualStackPlainSocketImpl.socketConnect(DualStackPlainSocketImpl.java:85) ~[na:1.8.0_65]
at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350) ~[na:1.8.0_65]
at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206) ~[na:1.8.0_65]
at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188) ~[na:1.8.0_65]
at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:172) ~[na:1.8.0_65]
at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) ~[na:1.8.0_65]
at java.net.Socket.connect(Socket.java:589) ~[na:1.8.0_65]
at org.kaaproject.kaa.client.connectivity.PingConnectivityChecker.checkConnectivity(PingConnectivityChecker.java:54) ~[kaa-java-ep-sdk-Jj0y8ubrOp6NuqhH54UTq0zFrfQ.jar:na]
at org.kaaproject.kaa.client.channel.impl.channels.DefaultOperationTcpChannel.onServerFailed(DefaultOperationTcpChannel.java:327) [kaa-java-ep-sdk-Jj0y8ubrOp6NuqhH54UTq0zFrfQ.jar:na]
at org.kaaproject.kaa.client.channel.impl.channels.DefaultOperationTcpChannel.onServerFailed(DefaultOperationTcpChannel.java:321) [kaa-java-ep-sdk-Jj0y8ubrOp6NuqhH54UTq0zFrfQ.jar:na]
at org.kaaproject.kaa.client.channel.impl.channels.DefaultOperationTcpChannel.access$800(DefaultOperationTcpChannel.java:70) [kaa-java-ep-sdk-Jj0y8ubrOp6NuqhH54UTq0zFrfQ.jar:na]
at org.kaaproject.kaa.client.channel.impl.channels.DefaultOperationTcpChannel$4.onMessage(DefaultOperationTcpChannel.java:168) [kaa-java-ep-sdk-Jj0y8ubrOp6NuqhH54UTq0zFrfQ.jar:na]
at org.kaaproject.kaa.client.channel.impl.channels.DefaultOperationTcpChannel$4.onMessage(DefaultOperationTcpChannel.java:153) [kaa-java-ep-sdk-Jj0y8ubrOp6NuqhH54UTq0zFrfQ.jar:na]
at org.kaaproject.kaa.common.channels.protocols.kaatcp.messages.MessageFactory.onMqttFrame(MessageFactory.java:82) [kaa-java-ep-sdk-Jj0y8ubrOp6NuqhH54UTq0zFrfQ.jar:na]
at org.kaaproject.kaa.common.channels.protocols.kaatcp.Framer.callListeners(Framer.java:115) [kaa-java-ep-sdk-Jj0y8ubrOp6NuqhH54UTq0zFrfQ.jar:na]
at org.kaaproject.kaa.common.channels.protocols.kaatcp.Framer.pushBytes(Framer.java:103) [kaa-java-ep-sdk-Jj0y8ubrOp6NuqhH54UTq0zFrfQ.jar:na]
at org.kaaproject.kaa.client.channel.impl.channels.DefaultOperationTcpChannel$SocketReadTask.run(DefaultOperationTcpChannel.java:641) [kaa-java-ep-sdk-Jj0y8ubrOp6NuqhH54UTq0zFrfQ.jar:na]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [na:1.8.0_65]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [na:1.8.0_65]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [na:1.8.0_65]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [na:1.8.0_65]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0_65]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0_65]
at java.lang.Thread.run(Thread.java:745) [na:1.8.0_65]
09:46:44.789 [pool-6-thread-1] WARN o.k.k.c.c.i.c.DefaultOperationTcpChannel - Loss of connectivity detected
09:46:44.791 [pool-6-thread-1] WARN o.k.k.c.c.i.c.DefaultOperationTcpChannel - Attempt to reconnect will be made in 5000 ms according to failover strategy decision
09:46:44.792 [pool-6-thread-1] INFO o.k.k.c.c.i.c.DefaultOperationTcpChannel - Scheduling open connection task
09:46:44.792 [pool-6-thread-1] INFO o.k.k.c.c.i.c.DefaultOperationTcpChannel - Read Task is interrupted for channel [default_operation_tcp_channel]
09:46:49.793 [pool-6-thread-1] INFO o.k.k.c.c.i.c.DefaultOperationTcpChannel - Channel [default_operation_tcp_channel]: opening connection to server IpTransportInfo [host=10.28.120.146, port=9997]
09:46:49.796 [pool-6-thread-1] DEBUG o.k.k.c.c.i.c.DefaultOperationTcpChannel - Sending Connect to channel [default_operation_tcp_channel]
09:46:49.796 [pool-6-thread-1] DEBUG o.k.k.c.p.KaaClientPropertiesState - Check if key pair exists .\key.public, .\key.private
09:46:49.798 [pool-6-thread-1] INFO o.k.k.c.c.i.DefaultOperationDataProcessor - Created Sync request: {"requestId": 2, "syncRequestMetaData": {"sdkToken": "Jj0y8ubrOp6NuqhH54UTq0zFrfQ", "endpointPublicKeyHash": {"bytes": "4b5fd7e82dcebd941d07a93e33c653e1cb235618"}, "profileHash": {"bytes": "da39a3ee5e6b4b0d3255bfef95601890afd80709"}, "timeout": 60000}, "bootstrapSyncRequest": null, "profileSyncRequest": {"endpointPublicKey": {"bytes": "a24e37af081b849a754e4c2f9a41bba28e72b89780c266a402f0c94634ec547b46a4dbaa96fbda40ffd9cba29786941f0d2da71b3ceef94c68bc367d0084381965b62d86aee932c66d2ba3f2d3fa61247d8a9345b099ca76c2784fe3db48b0203010001"}, "profileBody": {"bytes": ""}, "endpointAccessToken": "cd9bdc8f-c5ca-4d41-a483-f6f027c7f4c2"}, "configurationSyncRequest": {"configurationHash": {"bytes": "c4ea21bb365bbeeaf5f2c654883e56d11e43c44e"}, "resyncOnly": true}, "notificationSyncRequest": {"topicListHash": 0, "topicStates": null, "acceptedUnicastNotifications": null, "subscriptionCommands": []}, "userSyncRequest": {"userAttachRequest": null, "endpointAttachRequests": [], "endpointDetachRequests": []}, "eventSyncRequest": {"eventSequenceNumberRequest": {}, "eventListenersRequests": null, "events": null}, "logSyncRequest": {"requestId": 0, "logEntries": null}, "extensionSyncRequests": null}
09:46:49.828 [pool-6-thread-1] DEBUG o.k.k.c.c.p.kaatcp.messages.Connect - Created Connect message: session key size = 256, signature size = 256, sync request size = 464
09:46:49.828 [pool-6-thread-1] DEBUG o.k.k.c.c.i.c.DefaultOperationTcpChannel - Submitting a read task for channel [default_operation_tcp_channel]
09:46:49.830 [pool-6-thread-1] DEBUG o.k.k.c.c.i.c.DefaultOperationTcpChannel - Scheduling a ping task (100 seconds) for channel [default_operation_tcp_channel]
09:46:49.830 [pool-6-thread-1] INFO o.k.k.c.c.i.c.DefaultOperationTcpChannel - Channel [default_operation_tcp_channel] is reading data from stream using [1024] byte buffer
09:47:19.836 [pool-6-thread-1] INFO o.k.k.c.c.i.c.DefaultOperationTcpChannel - ConnAck (REFUSE_SERVER_UNAVAILABLE) message received for channel [default_operation_tcp_channel]
09:47:19.836 [pool-6-thread-1] ERROR o.k.k.c.c.i.c.DefaultOperationTcpChannel - Connection for channel [default_operation_tcp_channel] was rejected: REFUSE_SERVER_UNAVAILABLE
09:47:19.836 [pool-6-thread-1] INFO o.k.k.c.c.i.c.DefaultOperationTcpChannel - Cleaning client state
09:47:19.837 [pool-6-thread-1] INFO o.k.k.c.c.i.c.DefaultOperationTcpChannel - [default_operation_tcp_channel] has failed
09:47:19.837 [pool-6-thread-1] INFO o.k.k.c.c.i.c.DefaultOperationTcpChannel - Channel "default_operation_tcp_channel": closing current connection
09:47:19.837 [pool-6-thread-1] DEBUG o.k.k.c.c.i.c.DefaultOperationTcpChannel - Sending Disconnect from channel [default_operation_tcp_channel]
09:47:22.839 [pool-6-thread-1] WARN o.k.k.c.c.PingConnectivityChecker - Host
www.google.com is unreachable