Connectivity issues with WS EMS 5.3 and TW 7.2
I have pored over all of the documentation and comments and am totally lost at this point. I have a TLS configured Thingworx 7.2 server running on CentOS 7.2. I am trying to connect a microserver to Thingworx. I have tried with several flavors of microserver on several different platforms (including the Thingworx server itself).
Here is the WSEMS config.json:
"ws_servers": [{
"host": "10.128.134.175",
"port": 8443
}],
"appKey": "93636885-bf28-424f-9329-bc9f7bc41593",
"ws_connection": {
"encryption": "none",
"verbose": true
},
"certificates": {
"validate": false,
"allow_self_signed": true
},
"logger": {
"level": "TRACE",
"publish_level": "TRACE"
},
"auto_bind": [
{
"name": "MyGateway",
"gateway": true
}
]}
Here are the relevant snippets from the trace log:
[DEBUG] 2016-08-29 20:02:16,699 SDK: twWs_Create: Initializing Websocket Client for 10.128.134.175:8443//Thingworx/WS
[DEBUG] 2016-08-29 20:02:16,699 SDK: twTlsClient_Create: Initializing TLS Client
[DEBUG] 2016-08-29 20:27:29,362 SDK: twApi_Initialize: Websocket Established after 0 tries
[DEBUG] 2016-08-29 20:27:29,362 SDK: subscribedPropsMgr_Initialize: Initializing subscribed properties manager
...
[TRACE] 2016-08-29 20:02:16,705 SDK: twApi_Connect: Delaying 1 milliseconds before connecting
[DEBUG] 2016-08-29 20:02:16,705 SDK: twTlsClient_Reconnect: Re-establishing SSL context
[DEBUG] 2016-08-29 20:02:16,705 SDK: twTlsClient_Connect: Connecting to server
[TRACE] 2016-08-29 20:02:16,725 SDK: twWs_Connect: Connected to 10.128.134.175:8443
[TRACE] 2016-08-29 20:02:16,725 SDK: twWs_Connect: Sent request:
GET /Thingworx/WS HTTP/1.1
User-Agent: ThingWorx C SDK
Upgrade: websocket
Connection: Upgrade
Host: 10.128.134.175
Sec-WebSocket-Version: 13
Sec-WebSocket-Key: /g8bnoJyBen64fiUefCMsw==
Max-Frame-Size: 8192
appKey: 93636885-bf28-424f-9329-bc9f7bc41593
[ERROR] 2016-08-29 20:02:26,725 SDK: twWs_Connect: Error trying to connect
[DEBUG] 2016-08-29 20:02:26,726 SDK: twTlsClient_Reconnect: Re-establishing SSL context
[DEBUG] 2016-08-29 20:02:26,727 SDK: twTlsClient_Connect: Connecting to server
The above bit continues to cycle for multiple attempts and finally fails with:
[WARN ] 2016-08-29 20:13:26,744 Main: Unable to connect to server. Trying .booted config file
[WARN ] 2016-08-29 20:13:27,375 WsEmsProxy::execute() : Server connection failed. Error Code: 201
[FORCE] 2016-08-29 20:13:31,805 Main: Shutdown signal received. Restarting ....
[TRACE] 2016-08-29 20:13:31,807 wsEmsProxy::~wsEmsProxy: Destructor called
[TRACE] 2016-08-29 20:13:31,808 WsProxy::~WsProxy: Deleting Thing binding list
[TRACE] 2016-08-29 20:13:31,808 SDK: Sending Msg >>>>>>>>>
Message Details:
Version: 1
Method/Code: 0xb (UNBIND)
RequestID: 1
EndpointID:0
SessionID: 0
Multipart: 0
Count: 1
Name: MyGateway
[DEBUG] 2016-08-29 20:13:31,808 SDK: twMessage_Send: Not authenticated yet
[ERROR] 2016-08-29 20:13:31,809 SDK: twMessage_Send: Error sending Message with RequestId 1
[ERROR] 2016-08-29 20:13:31,809 SDK: twApi_UnbindThing: Error creating sending Unbind message
[DEBUG] 2016-08-29 20:13:31,809 SDK: twMessage_Delete: Deleting BIND Message: 1
[DEBUG] 2016-08-29 20:13:31,849 SDK: Disconnect called. Code: 1000, Reason: Shutting down
[WARN ] 2016-08-29 20:13:31,849 SDK: sendCtlFrame: Not connected
[DEBUG] 2016-08-29 20:13:31,849 SDK: twTlsClient_Close: Disconnecting from server
[WARN ] 2016-08-29 20:13:31,849 SDK: msgHandlerOnClose: WEBSOCKET CLOSED
[DEBUG] 2016-08-29 20:13:31,849 SDK: twTunnelManager_StopAllTunnels: Attempting to stop all tunnels
[INFO ] 2016-08-29 20:13:31,849 SDK: subscribedPropsMgr_Delete: Deleting subscribed propery manager
[DEBUG] 2016-08-29 20:13:31,849 SDK: Disconnect called. Code: 1000, Reason: Message handler shut down
[WARN ] 2016-08-29 20:13:31,849 SDK: sendCtlFrame: Not connected
[DEBUG] 2016-08-29 20:13:31,849 SDK: twTlsClient_Close: Disconnecting from server
[DEBUG] 2016-08-29 20:13:31,849 SDK: twTlsClient_Close: Disconnecting from server
I see no log entries on the Tomcat side of the house that shows anything going on. I have combed through every relevant document and post that I could find with no luck.
I have attempted to turn encryption on ("ssl") at which point, I don't see the connection information like above - and I get a different error set:
[DEBUG] 2016-08-29 20:19:31,345 SDK: twWs_Create: Initializing Websocket Client for 10.128.134.175:8443//Thingworx/WS
[DEBUG] 2016-08-29 20:19:31,345 SDK: twTlsClient_Create: Initializing TLS Client
[DEBUG] 2016-08-29 20:19:31,345 SDK: twApi_Initialize: Websocket Established after 0 tries
...
[INFO ] 2016-08-29 20:19:31,351 ./wsems: Starting the connection.
...
[TRACE] 2016-08-29 20:19:31,353 SDK: twApi_Connect: Delaying 0 milliseconds before connecting
[DEBUG] 2016-08-29 20:19:31,353 SDK: twTlsClient_Reconnect: Re-establishing SSL context
[DEBUG] 2016-08-29 20:19:31,353 SDK: twTlsClient_Connect: Connecting to server
[ERROR] 2016-08-29 20:19:31,471 SDK: Error intializing SSL connection
[ERROR] 2016-08-29 20:19:31,472 SDK: twWs_Connect: Error restarting socket. Error 0
[DEBUG] 2016-08-29 20:19:36,472 SDK: twTlsClient_Reconnect: Re-establishing SSL context
[DEBUG] 2016-08-29 20:19:36,472 SDK: twTlsClient_Connect: Connecting to server
[ERROR] 2016-08-29 20:19:36,569 SDK: Error intializing SSL connection
[ERROR] 2016-08-29 20:19:36,569 SDK: twWs_Connect: Error restarting socket. Error 32
[DEBUG] 2016-08-29 20:19:41,569 SDK: twTlsClient_Reconnect: Re-establishing SSL context
[DEBUG] 2016-08-29 20:19:41,569 SDK: twTlsClient_Connect: Connecting to server
[ERROR] 2016-08-29 20:19:41,656 SDK: Error intializing SSL connection
[ERROR] 2016-08-29 20:19:41,656 SDK: twWs_Connect: Error restarting socket. Error 32
[DEBUG] 2016-08-29 20:19:46,656 SDK: twTlsClient_Reconnect: Re-establishing SSL context
...
[DEBUG] 2016-08-29 20:20:27,497 SDK: twTlsClient_Connect: Connecting to server
[ERROR] 2016-08-29 20:20:27,626 SDK: Error intializing SSL connection
[ERROR] 2016-08-29 20:20:27,627 SDK: twWs_Connect: Error restarting socket. Error 32
[WARN ] 2016-08-29 20:20:31,362 Main: Unable to connect to server. Trying .booted config file
[WARN ] 2016-08-29 20:20:32,627 WsEmsProxy::execute() : Server connection failed. Error Code: 1001
Sorry for the long post, just wanted to be sure I covered my bases. As you can see, it looks like the web socket upgrade is failing, but I have no idea why. If anyone has any suggestions, I'd greatly appreciate hearing them.
Thanks,
Brett
