The ThingWorx Websockets MicroServer stops suddenly after 10 hours working, without any special reason. It looks like a problem with the authentication, because one of the last ERROR messages that appears is:
[ERROR] 2017-06-30 13:29:46,157 WsProxy::Connect: Error trying to authenticate
But, it is weird that it only fails after around 10 hours.
The version is of the ThingWorx Websockets MicroServer is 5.1.0.8
The logs with the maximum log level (trace) is attached. These are the last lines:
[DEBUG] 2017-06-30 13:29:46,158 [+0000] HTTP Server: 127.0.0.1 - SeqId 1482 - "POST /Thingworx/Things/Wasp3c113f57c105/Services/GetPropertySubscriptions HTTP/1.1" 503 47 "-"
[TRACE] 2017-06-30 13:29:46,159 httpServer: Allocating new client: 1483
[TRACE] 2017-06-30 13:29:46,159 client_thread::execute: Starting request handler thread 1484
[DEBUG] 2017-06-30 13:29:46,159 RestThingworx::callback: Handling request
[TRACE] 2017-06-30 13:29:46,159 WsRequestMessage::setBodyBinary: New request message created. [id: 1667, code: NOT_SET uri: /Unknown//Custom/]
[TRACE] 2017-06-30 13:29:46,159 WsRequestMessage::setBodyBinary: New request message has 0 headers.
[TRACE] 2017-06-30 13:29:46,159 WsRequestMessage::WsRequestMessage: New request message has 0 headers.
[DEBUG] 2017-06-30 13:29:46,159 RestThingworx: Executing LocalEms request isConnected
[TRACE] 2017-06-30 13:29:46,159 jsonConfigurator::getString: Key = host, Parent = rest_interface
[DEBUG] 2017-06-30 13:29:46,159 jsonConfigurator::getValueByType: Parent rest_interface not found
[TRACE] 2017-06-30 13:29:46,159 InfoTable::InfoTable: No rows found
[TRACE] 2017-06-30 13:29:46,159 twInfoTable::~twInfoTable: Destructor called
[DEBUG] 2017-06-30 13:29:46,159 WsResponseMessage::getReason: No reason string found
[TRACE] 2017-06-30 13:29:46,160 twInfoTable::getDataShapeJSON: Parsing data shape starting at bs index 1
[TRACE] 2017-06-30 13:29:46,160 twInfoTable::getDataShapeJSON: Adding DataShape field result
[TRACE] 2017-06-30 13:29:46,160 twInfoTable::parseRows: Parsing rows starting a bs index 14
[TRACE] 2017-06-30 13:29:46,160 twInfoTable::parseRows: Found 1 rows of data
[TRACE] 2017-06-30 13:29:46,160 twInfoTable::getDataShapeJSON: Parsing data shape starting at bs index 0
[TRACE] 2017-06-30 13:29:46,160 twInfoTable::getDataShapeJSON: Adding DataShape field result
[TRACE] 2017-06-30 13:29:46,160 twInfoTable::~twInfoTable: Destructor called
[TRACE] 2017-06-30 13:29:46,160 RestThingworx: Responding with content: {"dataShape":{"fieldDefinitions":{"result":{"name":"result","description":"","baseType":"BOOLEAN","aspects":{}}}},"rows":[{"result":false}]}
[DEBUG] 2017-06-30 13:29:46,160 [+0000] HTTP Server: 127.0.0.1 - SeqId 1484 - "GET /Thingworx/Things/LocalEms/Properties/isConnected HTTP/1.1" 200 140 "-"
thx.ocea-smart-building.fr:443-->
thx.ocea-smart-building.fr:443-->[DEBUG] 2017-06-30 13:29:53,753 WsStream::execute: Attempting connection
[TRACE] 2017-06-30 13:29:53,753 WsStream::connect: Delaying 0 milliseconds before connecting
[DEBUG] 2017-06-30 13:29:53,753 WsStream::connect: Sending Request:
GET /Thingworx/WS HTTP/1.1
User-Agent: ThingWorx Edge Server
Upgrade: websocket
Connection: Upgrade
Host: thx.ocea-smart-building.fr
Sec-WebSocket-Version: 13
Sec-WebSocket-Key: SgngCwQuGp3s1cTXZdLC+A==
Max-Frame-Size: 8192
appKey: 3e2169b6-c9e3-4ee6-9421-260b9fdac78d
thx.ocea-smart-building.fr:443-->thx.ocea-smart-building.fr:443-->[DEBUG] 2017-06-30 13:29:53,775 TlsStream:: doopen: Setting SO_RCVTIMEO
[TRACE] 2017-06-30 13:29:53,775 TlsStream::doopen: Opening new SSL CLIENT STREAM
thx.ocea-smart-building.fr:443-->thx.ocea-smart-building.fr:443-->thx.ocea-smart-building.fr:443-->thx.ocea-smart-building.fr:443-->thx.ocea-smart-building.fr:443-->thx.ocea-smart-building.fr:443-->thx.ocea-smart-building.fr:443-->thx.ocea-smart-building.fr:443-->thx.ocea-smart-building.fr:443-->thx.ocea-smart-building.fr:443-->thx.ocea-smart-building.fr:443-->thx.ocea-smart-building.fr:443-->thx.ocea-smart-building.fr:443-->[TRACE] 2017-06-30 13:29:53,910 WsStream::connect: Read 191 bytes
[TRACE] 2017-06-30 13:29:53,910 WsStream::on_message_begin: Response started
[DEBUG] 2017-06-30 13:29:53,910 WsStream::on_header_field: Got new header- :
[DEBUG] 2017-06-30 13:29:53,910 WsStream::on_header_field: Got new header- Server : nginx
[DEBUG] 2017-06-30 13:29:53,910 WsStream::on_header_field: Got new header- Date : Fri, 30 Jun 2017 11:29:55 GMT
[DEBUG] 2017-06-30 13:29:53,910 WsStream::on_header_field: Got new header- Connection : upgrade
[DEBUG] 2017-06-30 13:29:53,910 WsStream::on_header_field: Got new header- X-FRAME-OPTIONS : SAMEORIGIN
[DEBUG] 2017-06-30 13:29:53,911 WsStream::on_header_field: Got new header- Upgrade : websocket
[DEBUG] 2017-06-30 13:29:53,911 WsStream::on_headers_complete: Passed all header checks.
[FORCE] 2017-06-30 13:29:53,911 WsStream::on_connected: Web Socket connected!
[INFO ] 2017-06-30 13:29:53,911 WsProxy::handleConnect: Web Socket connected!
[TRACE] 2017-06-30 13:29:53,911 WsStream::connect: Parsed 191 bytes out of 191
[INFO ] 2017-06-30 13:29:53,911 WsProxy::execute: Not authenticated yet - sending Auth message
[INFO ] 2017-06-30 13:29:53,911 WsProxy::Connect: Creating Auth message
[TRACE] 2017-06-30 13:29:53,911 WsProxy::SendMessage: Method entered. Priority = true
[TRACE] 2017-06-30 13:29:53,911 WsProxy::SendRequest: Sending binary message
[TRACE] 2017-06-30 13:29:53,912 WsStream::sendDataFrame: >>>>>> Sending Binary Frame
01 14 00 00 06 85 00 00 00 00 00 00 00 00 00 01 06 61 70 70 4B 65 79 24 33 65 32 31 36 39 62 36 2D 63 39 65 33 2D 34 65 65 36 2D 39 34 32 31 2D 32 36 30 62 39 66 64 61 63 37 38 64
[DEBUG] 2017-06-30 13:29:53,912 WsStream::sendMessage: Sent 60 bytes using 1 frames.
[TRACE] 2017-06-30 13:29:53,912 WsProxy::SendRequest: Message Data:
01 14 00 00 06 85 00 00 00 00 00 00 00 00 00 01 06 61 70 70 4b 65 79 24 33 65 32 31 36 39 62 36 2d 63 39 65 33 2d 34 65 65 36 2d 39 34 32 31 2d 32 36 30 62 39 66 64 61 63 37 38 64
[TRACE] 2017-06-30 13:29:53,912 WsProxy::SendRequest: Message Detail:
Version: 0x01
Method/Code: 0x14 (AUTH)
Request ID: 00000685
Endpoint ID: 00000000
Session ID: 00000000
Total Message Length: 45
Claim Count: 1
Claim Name: appKey Claim Value: 3e2169b6-c9e3-4ee6-9421-260b9fdac78d
thx.ocea-smart-building.fr:443++>thx.ocea-smart-building.fr:443++>thx.ocea-smart-building.fr:443++>thx.ocea-smart-building.fr:443++>thx.ocea-smart-building.fr:443++>[TRACE] 2017-06-30 13:29:53,995 WsStream::execute: Read 19 bytes into 0xf3400638
[TRACE] 2017-06-30 13:29:53,995 WsStream::on_framelength: Got frame length. Length = 17
[TRACE] 2017-06-30 13:29:53,995 WsStream::on_binaryframe: Received new frame. Length: 17, Final: 0
[TRACE] 2017-06-30 13:29:53,995 WsStream::on_binaryframe: <<<<<< Received Binary Frame
01 40 00 00 06 85 00 00 30 31 20 0D 0A 53 65 72 76
[TRACE] 2017-06-30 13:29:53,995 WsProxy::handleBinaryFrame: Received new start frame
[TRACE] 2017-06-30 13:29:53,996 WsProxy::handleBinaryFrame: Complete message received
[TRACE] 2017-06-30 13:29:53,996 WsProxy::checkMsgOverload: Adding message 1 to queue.
[TRACE] 2017-06-30 13:29:53,996 WsStream::execute: Parsed 19 bytes out of 19
[TRACE] 2017-06-30 13:29:53,996 MsgHandler::processMessage: Message received
[WARN ] 2017-06-30 13:29:53,996 WsPartialMessage::setBodyBinary: This is not part of a multipart message or not long enough to contain one
[TRACE] 2017-06-30 13:29:53,996 MsgHandler::processMessage: Multipart Message Chunk Received. Data:
01 40 00 00 06 85 00 00 30 31 20 0d 0a 53 65 00 ff 00 00 20 00
[TRACE] 2017-06-30 13:29:53,996 MsgHandler::processMessage: Multipart Message Chunk Details:
Version: 0x01
Method/Code: 0x40 (200)
Request ID: 00000685
Endpoint ID: 00003031
Session ID: 200D0A53
Body: No Body Found
[DEBUG] 2017-06-30 13:29:53,996 MsgHandler::addIfAbsent: Creating new multipart message store for ID 1669
[WARN ] 2017-06-30 13:29:53,996 WsMessageBase::getMsgBinary: message has no body
[ERROR] 2017-06-30 13:29:53,996 WsMultipartMessageStore: Msg is not long enough
[TRACE] 2017-06-30 13:29:53,996 WsMultipartMessageStore::reassembleMessage: Recevied 0 of 0 messages
Please, could somebody help us?
Thanks in advance
