From SCM utility , after deployment of package there is no file notification in luascriptresource and package is not downloaded, from SCM it shows package deployment status as started.

[ajain1]

Hi Guys,

From the SCM utility, i have tried to download the package and run lua. but lsr was unable to get file notification (for file notification i mean below) and its unable to download the package. From SCM Utility the deployment status always shows as started, and there is no file transfer notification in wsems also, also there is no abort logs at lsr side and nothing happening, tried multiple times but the result is same.(The wsems and lsr are connected succesfully (Please see the logs for details).

Please let me know if any other thing will be helpful.

File Notification in LSR:

zip_dir=C:\Program Files\Kesight\Kesight_EMS_Agent\Sidecar_EMS\CDEMO_EMS\updates

zip_abs_path=C:\Program Files\Kesight\Kesight_EMS_Agent\Sidecar_EMS\CDEMO_EMS\updates\print_1505298209849.zip

updateManager=TW.RSM.SFW.SoftwareManager

unpacked=false

thing=SCM_test_asset

sw_update_abs_dir=C:\Program Files\Kesight\Kesight_EMS_Agent\Sidecar_EMS\CDEMO_EMS\updates

script_loaded=false

script=print.lua

repository=TW.RSM.Thing.FileRepository

path=/print_1505298209849.zip

name=tester4

installDate=1511775431075

id=f07b5fea-d755-4df7-a357-75b37bc68661

error=

downloadDate=1511775431075

current_step=1

These are the logs of wsems and lsr(LuaScriptResource):

LuaScriptResource):

[INFO ] 2017-11-21 13:49:50,918 luaScriptResource.exe: Using config file: C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\config.lua

[FORCE] 2017-11-21 13:49:50,918 luaScriptResource.exe: Starting up ....

[DEBUG] 2017-11-21 13:49:50,923 luaScriptResource.exe: Appending C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\thingworx\clibs;C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\custom\clibs;C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\community\clibs to current path C:\ProgramData\Oracle\Java\javapath;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\System32\Wbem;C:\WINDOWS\System32\WindowsPowerShell\v1.0\;C:\Program Files (x86)\Windows Live\Shared;C:\Windows\CCM;C:\Users\26947\.dnx\bin;C:\Program Files\Microsoft DNX\Dnvm\;C:\Program Files (x86)\Windows Kits\8.1\Windows Performance Toolkit\;C:\Program Files\Java\jdk1.8.0_131\bin;C:\Program Files (x86)\Lua\5.1;C:\Program Files (x86)\Lua\5.1\clibs;C:\Program Files (x86)\PuTTY\

[INFO ] 2017-11-21 13:49:50,923 luaScriptResource.exe: New path is C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\thingworx\clibs;C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\custom\clibs;C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\community\clibs;C:\ProgramData\Oracle\Java\javapath;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\System32\Wbem;C:\WINDOWS\System32\WindowsPowerShell\v1.0\;C:\Program Files (x86)\Windows Live\Shared;C:\Windows\CCM;C:\Users\26947\.dnx\bin;C:\Program Files\Microsoft DNX\Dnvm\;C:\Program Files (x86)\Windows Kits\8.1\Windows Performance Toolkit\;C:\Program Files\Java\jdk1.8.0_131\bin;C:\Program Files (x86)\Lua\5.1;C:\Program Files (x86)\Lua\5.1\clibs;C:\Program Files (x86)\PuTTY\

[DEBUG] 2017-11-21 13:49:50,923 luaScriptProxy: Constructor Called

[DEBUG] 2017-11-21 13:49:50,923 luaScriptProxy::initialize: Name = 11_10000010-WSEMS

File = C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\thingworx\scripts\thing.lua

LibraryPath = C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\?.lua;C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\thingworx\?.lua;C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\thingworx\lua\?.lua;C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\custom\?.lua;C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\custom\lua\?.lua;C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\community\lua\?.lua

InitData Ptr = 0

Persisted Props:

file = thing.lua

sw_update_dir = C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\Downloads\updates

template = MyRemoteThingTemplate

GlobalProps:

config_file_path = C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc

log_level = DEBUG

rap_host = localhost

rap_port = 8000

script_clib_path = C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\thingworx\clibs\?.dll;C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\custom\clibs\?.dll;C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\community\clibs\?.dll

script_directory = C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\custom\scripts

script_library_path = C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\?.lua;C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\thingworx\?.lua;C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\thingworx\lua\?.lua;C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\custom\?.lua;C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\custom\lua\?.lua;C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\community\lua\?.lua

script_resource_host = localhost

script_resource_port = 8001

[DEBUG] 2017-11-21 13:49:50,923 luaScriptProxy::runScript: Starting Script

[DEBUG] 2017-11-21 13:49:50,923 luaScriptProxy::getStatus: Script 11_10000010-WSEMS status = Ready

[DEBUG] 2017-11-21 13:49:50,923 luaScriptProxy::execute: Script 11_10000010-WSEMS now executing

[DEBUG] 2017-11-21 13:49:50,923 luaScriptProxy: Constructor Called

[DEBUG] 2017-11-21 13:49:50,923 luaScriptProxy::initialize: Name = softwareupdate

File = C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\thingworx\scripts\softwareupdate.lua

LibraryPath = C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\?.lua;C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\thingworx\?.lua;C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\thingworx\lua\?.lua;C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\custom\?.lua;C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\custom\lua\?.lua;C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\community\lua\?.lua

InitData Ptr = 0

Persisted Props:

file = softwareupdate.lua

max_run_time = 20

GlobalProps:

config_file_path = C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc

log_level = DEBUG

rap_host = localhost

rap_port = 8000

script_clib_path = C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\thingworx\clibs\?.dll;C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\custom\clibs\?.dll;C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\community\clibs\?.dll

script_directory = C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\custom\scripts

script_library_path = C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\?.lua;C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\thingworx\?.lua;C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\thingworx\lua\?.lua;C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\custom\?.lua;C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\custom\lua\?.lua;C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\community\lua\?.lua

script_resource_host = localhost

script_resource_port = 8001

[DEBUG] 2017-11-21 13:49:50,923 luaScriptProxy::runScript: Starting Script

[DEBUG] 2017-11-21 13:49:50,928 luaScriptProxy::getStatus: Script softwareupdate status = Ready

[DEBUG] 2017-11-21 13:49:50,928 luaScriptProxy::execute: Script softwareupdate now executing

[DEBUG] 2017-11-21 13:49:50,928 luaScriptProxy: Constructor Called

[DEBUG] 2017-11-21 13:49:50,928 luaScriptProxy::initialize: Name = Thingworx

File = C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\thingworx\scripts\thingworx.lua

LibraryPath = C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\?.lua;C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\thingworx\?.lua;C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\thingworx\lua\?.lua;C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\custom\?.lua;C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\custom\lua\?.lua;C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\community\lua\?.lua

InitData Ptr = 0

Persisted Props:

file = thingworx.lua

max_run_time = 20

GlobalProps:

config_file_path = C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc

log_level = DEBUG

rap_host = localhost

rap_port = 8000

script_clib_path = C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\thingworx\clibs\?.dll;C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\custom\clibs\?.dll;C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\community\clibs\?.dll

script_directory = C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\custom\scripts

script_library_path = C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\?.lua;C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\thingworx\?.lua;C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\thingworx\lua\?.lua;C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\custom\?.lua;C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\custom\lua\?.lua;C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\community\lua\?.lua

script_resource_host = localhost

script_resource_port = 8001

[DEBUG] 2017-11-21 13:49:50,928 luaScriptProxy::runScript: Starting Script

[DEBUG] 2017-11-21 13:49:50,928 luaScriptProxy::getStatus: Script Thingworx status = Ready

[DEBUG] 2017-11-21 13:49:50,928 luaScriptProxy::execute: Script Thingworx now executing

[FORCE] 2017-11-21 13:49:50,928 httpServer: starting http server port=8001

[DEBUG] 2017-11-21 13:49:50,933 ScriptResource::registerScriptCallback: Registered path /scripts/Thingworx/ with callback handle_request

[DEBUG] 2017-11-21 13:49:50,933 luaHttpBinding::l_registerCallback: Registered path '/' with callback 'handle_request' for script 'Thingworx'

[DEBUG] 2017-11-21 13:49:50,933 ScriptResource::registerScriptCallback: Registered path /scripts/Thingworx/registerIdentifier/ with callback register_identifier

[DEBUG] 2017-11-21 13:49:50,933 luaHttpBinding::l_registerCallback: Registered path '/registerIdentifier' with callback 'register_identifier' for script 'Thingworx'

[DEBUG] 2017-11-21 13:49:50,933 httpServer: http server bound to port=8001.

[DEBUG] 2017-11-21 13:49:50,953 utils: Adding utils functions to tw_utils

[DEBUG] 2017-11-21 13:49:50,953 utils: Adding utils functions to tw_utils

[DEBUG] 2017-11-21 13:49:50,958 ScriptResource::registerScriptCallback: Registered path /scripts/softwareupdate/start/ with callback start

[DEBUG] 2017-11-21 13:49:50,958 luaHttpBinding::l_registerCallback: Registered path '/start' with callback 'start' for script 'softwareupdate'

[DEBUG] 2017-11-21 13:49:50,958 ScriptResource::registerScriptCallback: Registered path /scripts/softwareupdate/abort/ with callback abort

[DEBUG] 2017-11-21 13:49:50,958 luaHttpBinding::l_registerCallback: Registered path '/abort' with callback 'abort' for script 'softwareupdate'

[DEBUG] 2017-11-21 13:49:50,958 ScriptResource::registerScriptCallback: Registered path /scripts/softwareupdate/download/ with callback download

[DEBUG] 2017-11-21 13:49:50,958 luaHttpBinding::l_registerCallback: Registered path '/download' with callback 'download' for script 'softwareupdate'

[DEBUG] 2017-11-21 13:49:50,958 ScriptResource::registerScriptCallback: Registered path /scripts/softwareupdate/downloaded/ with callback downloaded

[DEBUG] 2017-11-21 13:49:50,958 luaHttpBinding::l_registerCallback: Registered path '/downloaded' with callback 'downloaded' for script 'softwareupdate'

[DEBUG] 2017-11-21 13:49:50,958 ScriptResource::registerScriptCallback: Registered path /scripts/softwareupdate/scheduleDownload/ with callback scheduleDownload

[DEBUG] 2017-11-21 13:49:50,958 luaHttpBinding::l_registerCallback: Registered path '/scheduleDownload' with callback 'scheduleDownload' for script 'softwareupdate'

[DEBUG] 2017-11-21 13:49:50,958 ScriptResource::registerScriptCallback: Registered path /scripts/softwareupdate/scheduleInstall/ with callback scheduleInstall

[DEBUG] 2017-11-21 13:49:50,958 luaHttpBinding::l_registerCallback: Registered path '/scheduleInstall' with callback 'scheduleInstall' for script 'softwareupdate'

[INFO ] 2017-11-21 13:49:50,958 thingworx.shape: Creating a new shape.

[INFO ] 2017-11-21 13:49:50,958 11_10000010-WSEMS: -- Configuration -------------------------------

[INFO ] 2017-11-21 13:49:50,958 11_10000010-WSEMS: scanRate: 60000

[INFO ] 2017-11-21 13:49:50,958 11_10000010-WSEMS: scanRateResolution: 500

[INFO ] 2017-11-21 13:49:50,958 11_10000010-WSEMS: taskRate: 15000

[INFO ] 2017-11-21 13:49:50,958 11_10000010-WSEMS: keepAliveRate: 60000

[INFO ] 2017-11-21 13:49:50,958 11_10000010-WSEMS: requestTimeout: 15000

[INFO ] 2017-11-21 13:49:50,958 11_10000010-WSEMS: registerRate: 43200000

[INFO ] 2017-11-21 13:49:50,958 11_10000010-WSEMS: register: true

[INFO ] 2017-11-21 13:49:50,958 11_10000010-WSEMS: getPropertySubscriptionOnReconnect: false

[INFO ] 2017-11-21 13:49:50,958 11_10000010-WSEMS: maxConcurrentPropertyUpdates: 100

[INFO ] 2017-11-21 13:49:50,958 11_10000010-WSEMS: defaultPushType: VALUE

[INFO ] 2017-11-21 13:49:50,958 11_10000010-WSEMS: useShapes: true

[INFO ] 2017-11-21 13:49:50,958 11_10000010-WSEMS: identifier: Not Specififed

[INFO ] 2017-11-21 13:49:50,958 11_10000010-WSEMS: ------------------------------------------------

[INFO ] 2017-11-21 13:49:50,963 thingworx.shape: Creating a new shape.

[INFO ] 2017-11-21 13:49:50,963 thingworx.template: Adding shape 'shapes.metadata' to template 'thingworx.template'

[INFO ] 2017-11-21 13:49:50,963 thingworx.template: Adding shape 'shapes.swupdate' to template 'thingworx.template'

[INFO ] 2017-11-21 13:49:50,963 thingworx.template: Adding shape 'shapes.propsubscribe' to template 'thingworx.template'

[INFO ] 2017-11-21 13:49:50,963 thingworx.template: Creating new templates.MyRemoteThingTemplate named '11_10000010-WSEMS'

[INFO ] 2017-11-21 13:49:50,963 11_10000010-WSEMS: -- Initializing properties ---------------------

[INFO ] 2017-11-21 13:49:50,963 11_10000010-WSEMS: Initialized property upToDate [baseType: BOOLEAN, pushType: NEVER, handler: nil, value: true]

[INFO ] 2017-11-21 13:49:50,963 11_10000010-WSEMS: ------------------------------------------------

[DEBUG] 2017-11-21 13:49:50,963 luaScriptProxy::getStatus: Script 11_10000010-WSEMS status = Running

[DEBUG] 2017-11-21 13:49:50,963 luaScriptProxy::getStatus: Script softwareupdate status = Running

[DEBUG] 2017-11-21 13:49:50,963 luaScriptProxy::getStatus: Script Thingworx status = Running

[DEBUG] 2017-11-21 13:49:50,963 luaScriptProxy::getStatus: Script Thingworx status = Running

[INFO ] 2017-11-21 13:49:53,930 11_10000010-WSEMS: -- Starting script --------------------------

[INFO ] 2017-11-21 13:49:53,930 11_10000010-WSEMS: Registering core callback handler

[DEBUG] 2017-11-21 13:49:53,930 ScriptResource::registerScriptCallback: Registered path /scripts/11_10000010-WSEMS/ with callback core_handler

[DEBUG] 2017-11-21 13:49:53,930 luaHttpBinding::l_registerCallback: Registered path '/' with callback 'core_handler' for script '11_10000010-WSEMS'

[INFO ] 2017-11-21 13:49:53,930 11_10000010-WSEMS: Starting main loop

[INFO ] 2017-11-21 13:49:53,930 11_10000010-WSEMS: Calling lifecycle start listeners.

[DEBUG] 2017-11-21 13:49:53,930 11_10000010-WSEMS: Executing lifecycle start event: shapes.swupdate_start

[DEBUG] 2017-11-21 13:49:53,930 luaScriptProxy::getStatus: Script 11_10000010-WSEMS status = Running

[DEBUG] 2017-11-21 13:49:53,930 luaScriptProxy::getStatus: Script softwareupdate status = Running

[DEBUG] 2017-11-21 13:49:53,930 luaScriptProxy::getStatus: Script Thingworx status = Running

[DEBUG] 2017-11-21 13:49:53,930 luaScriptProxy::getStatus: Script softwareupdate status = Running

[DEBUG] 2017-11-21 13:49:53,930 11_10000010-WSEMS: Executing lifecycle start event: shapes.propsubscribe_start

[INFO ] 2017-11-21 13:49:53,930 shapes.propsubscribe: Initialized

[DEBUG] 2017-11-21 13:49:53,930 thingworx.server: Invoking /Thingworx/Things/LocalEms/Services/AddEdgeThing on server. content: {"keepalive":60000,"port":"8001","timeout":15000,"host":"localhost","proto":"http","name":"11_10000010-WSEMS","path":"/scripts/Thingworx"}

[DEBUG] 2017-11-21 13:49:53,930 SDK: twTlsClient_Create: Initializing TLS Client

[DEBUG] 2017-11-21 13:49:53,940 TlsStream::doclose: Disconeccting socket

[DEBUG] 2017-11-21 13:49:53,940 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:49:53,940 SDK: twTlsClient_Close: Disconnecting from server

[INFO ] 2017-11-21 13:49:53,940 11_10000010-WSEMS: MicroServer is now available.

[INFO ] 2017-11-21 13:49:53,940 11_10000010-WSEMS: MicroServer is online.

[INFO ] 2017-11-21 13:49:53,940 11_10000010-WSEMS: Successfully registered 11_10000010-WSEMS with MicroServer.

[DEBUG] 2017-11-21 13:49:53,940 thingworx.server: Invoking /Thingworx/Things/11_10000010-WSEMS/Services/GetPropertySubscriptions on server. content: {}

[DEBUG] 2017-11-21 13:49:53,940 SDK: twTlsClient_Create: Initializing TLS Client

[DEBUG] 2017-11-21 13:49:54,455 TlsStream::doclose: Disconeccting socket

[DEBUG] 2017-11-21 13:49:54,455 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:49:54,455 SDK: twTlsClient_Close: Disconnecting from server

[INFO ] 2017-11-21 13:49:54,465 thingworx.handler: Creating a new handler.

[DEBUG] 2017-11-21 13:49:54,465 11_10000010-WSEMS: Wrote property: upToDate Updated updateTime to 3718873104

[INFO ] 2017-11-21 13:49:54,470 11_10000010-WSEMS: GetPropertySubscriptions called. 0 properties updated.

[FORCE] 2017-11-21 13:49:54,470 11_10000010-WSEMS: *

[DEBUG] 2017-11-21 13:49:54,975 thingworx.server: Invoking /Thingworx/Things/LocalEms/Services/HasEdgeThing on server. content: {"name":"11_10000010-WSEMS"}

[DEBUG] 2017-11-21 13:49:54,975 SDK: twTlsClient_Create: Initializing TLS Client

[DEBUG] 2017-11-21 13:49:54,980 TlsStream::doclose: Disconeccting socket

[DEBUG] 2017-11-21 13:49:54,980 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:49:54,985 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:50:54,349 SDK: twTlsClient_Create: Initializing TLS Client

[DEBUG] 2017-11-21 13:50:54,354 TlsStream:: doopen: Setting SO_RCVTIMEO

[DEBUG] 2017-11-21 13:50:54,354 TlsStream::doclose: Disconeccting socket

[DEBUG] 2017-11-21 13:50:54,354 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 21/Nov/2017:13:50:54 [+0530] HTTP Server: 1.0.0.127 - SeqId 2 - "" 400 376 "-"

[DEBUG] 2017-11-21 13:50:54,354 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:50:55,257 thingworx.server: Invoking /Thingworx/Things/LocalEms/Services/HasEdgeThing on server. content: {"name":"11_10000010-WSEMS"}

[DEBUG] 2017-11-21 13:50:55,257 SDK: twTlsClient_Create: Initializing TLS Client

[DEBUG] 2017-11-21 13:50:55,262 TlsStream::doclose: Disconeccting socket

[DEBUG] 2017-11-21 13:50:55,262 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:50:55,267 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:51:54,853 SDK: twTlsClient_Create: Initializing TLS Client

[DEBUG] 2017-11-21 13:51:54,853 TlsStream:: doopen: Setting SO_RCVTIMEO

[DEBUG] 2017-11-21 13:51:54,854 TlsStream::doclose: Disconeccting socket

[DEBUG] 2017-11-21 13:51:54,854 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 21/Nov/2017:13:51:54 [+0530] HTTP Server: 1.0.0.127 - SeqId 4 - "" 400 376 "-"

[DEBUG] 2017-11-21 13:51:54,854 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:51:56,10 thingworx.server: Invoking /Thingworx/Things/LocalEms/Services/HasEdgeThing on server. content: {"name":"11_10000010-WSEMS"}

[DEBUG] 2017-11-21 13:51:56,10 SDK: twTlsClient_Create: Initializing TLS Client

[DEBUG] 2017-11-21 13:51:56,15 TlsStream::doclose: Disconeccting socket

[DEBUG] 2017-11-21 13:51:56,15 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:51:56,15 SDK: twTlsClient_Close: Disconnecting from server

[FORCE] 2017-11-21 13:52:50,349 11_10000010-WSEMS: *

[DEBUG] 2017-11-21 13:52:55,568 SDK: twTlsClient_Create: Initializing TLS Client

[DEBUG] 2017-11-21 13:52:55,568 TlsStream:: doopen: Setting SO_RCVTIMEO

[DEBUG] 2017-11-21 13:52:55,569 TlsStream::doclose: Disconeccting socket

[DEBUG] 2017-11-21 13:52:55,569 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 21/Nov/2017:13:52:55 [+0530] HTTP Server: 1.0.0.127 - SeqId 6 - "" 400 376 "-"

[DEBUG] 2017-11-21 13:52:55,569 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:52:57,378 thingworx.server: Invoking /Thingworx/Things/LocalEms/Services/HasEdgeThing on server. content: {"name":"11_10000010-WSEMS"}

[DEBUG] 2017-11-21 13:52:57,378 SDK: twTlsClient_Create: Initializing TLS Client

[DEBUG] 2017-11-21 13:52:57,387 TlsStream::doclose: Disconeccting socket

[DEBUG] 2017-11-21 13:52:57,387 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:52:57,387 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:53:56,277 SDK: twTlsClient_Create: Initializing TLS Client

[DEBUG] 2017-11-21 13:53:56,282 TlsStream:: doopen: Setting SO_RCVTIMEO

[DEBUG] 2017-11-21 13:53:56,282 TlsStream::doclose: Disconeccting socket

[DEBUG] 2017-11-21 13:53:56,282 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 21/Nov/2017:13:53:56 [+0530] HTTP Server: 1.0.0.127 - SeqId 8 - "" 400 376 "-"

[DEBUG] 2017-11-21 13:53:56,282 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:53:58,375 thingworx.server: Invoking /Thingworx/Things/LocalEms/Services/HasEdgeThing on server. content: {"name":"11_10000010-WSEMS"}

[DEBUG] 2017-11-21 13:53:58,375 SDK: twTlsClient_Create: Initializing TLS Client

[DEBUG] 2017-11-21 13:53:58,380 TlsStream::doclose: Disconeccting socket

[DEBUG] 2017-11-21 13:53:58,385 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:53:58,385 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:54:56,908 SDK: twTlsClient_Create: Initializing TLS Client

[DEBUG] 2017-11-21 13:54:56,912 TlsStream:: doopen: Setting SO_RCVTIMEO

[DEBUG] 2017-11-21 13:54:56,912 TlsStream::doclose: Disconeccting socket

[DEBUG] 2017-11-21 13:54:56,912 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 21/Nov/2017:13:54:56 [+0530] HTTP Server: 1.0.0.127 - SeqId 10 - "" 400 376 "-"

[DEBUG] 2017-11-21 13:54:56,912 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:54:59,430 thingworx.server: Invoking /Thingworx/Things/LocalEms/Services/HasEdgeThing on server. content: {"name":"11_10000010-WSEMS"}

[DEBUG] 2017-11-21 13:54:59,430 SDK: twTlsClient_Create: Initializing TLS Client

[DEBUG] 2017-11-21 13:54:59,435 TlsStream::doclose: Disconeccting socket

[DEBUG] 2017-11-21 13:54:59,435 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:54:59,440 SDK: twTlsClient_Close: Disconnecting from server

[FORCE] 2017-11-21 13:55:46,345 11_10000010-WSEMS: *

[DEBUG] 2017-11-21 13:55:57,519 SDK: twTlsClient_Create: Initializing TLS Client

[DEBUG] 2017-11-21 13:55:57,519 TlsStream:: doopen: Setting SO_RCVTIMEO

[DEBUG] 2017-11-21 13:55:57,519 TlsStream::doclose: Disconeccting socket

[DEBUG] 2017-11-21 13:55:57,519 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 21/Nov/2017:13:55:57 [+0530] HTTP Server: 1.0.0.127 - SeqId 12 - "" 400 376 "-"

[DEBUG] 2017-11-21 13:55:57,519 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:56:00,442 thingworx.server: Invoking /Thingworx/Things/LocalEms/Services/HasEdgeThing on server. content: {"name":"11_10000010-WSEMS"}

[DEBUG] 2017-11-21 13:56:00,442 SDK: twTlsClient_Create: Initializing TLS Client

[DEBUG] 2017-11-21 13:56:00,447 TlsStream::doclose: Disconeccting socket

[DEBUG] 2017-11-21 13:56:00,447 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:56:00,447 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:56:58,130 SDK: twTlsClient_Create: Initializing TLS Client

[DEBUG] 2017-11-21 13:56:58,134 TlsStream:: doopen: Setting SO_RCVTIMEO

[DEBUG] 2017-11-21 13:56:58,134 TlsStream::doclose: Disconeccting socket

[DEBUG] 2017-11-21 13:56:58,134 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 21/Nov/2017:13:56:58 [+0530] HTTP Server: 1.0.0.127 - SeqId 14 - "" 400 376 "-"

[DEBUG] 2017-11-21 13:56:58,134 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:57:01,407 thingworx.server: Invoking /Thingworx/Things/LocalEms/Services/HasEdgeThing on server. content: {"name":"11_10000010-WSEMS"}

[DEBUG] 2017-11-21 13:57:01,407 SDK: twTlsClient_Create: Initializing TLS Client

[DEBUG] 2017-11-21 13:57:01,412 TlsStream::doclose: Disconeccting socket

[DEBUG] 2017-11-21 13:57:01,412 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:57:01,417 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:57:58,739 SDK: twTlsClient_Create: Initializing TLS Client

[DEBUG] 2017-11-21 13:57:58,744 TlsStream:: doopen: Setting SO_RCVTIMEO

[DEBUG] 2017-11-21 13:57:58,744 TlsStream::doclose: Disconeccting socket

[DEBUG] 2017-11-21 13:57:58,744 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 21/Nov/2017:13:57:58 [+0530] HTTP Server: 1.0.0.127 - SeqId 16 - "" 400 376 "-"

[DEBUG] 2017-11-21 13:57:58,744 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:58:02,416 thingworx.server: Invoking /Thingworx/Things/LocalEms/Services/HasEdgeThing on server. content: {"name":"11_10000010-WSEMS"}

[DEBUG] 2017-11-21 13:58:02,416 SDK: twTlsClient_Create: Initializing TLS Client

[DEBUG] 2017-11-21 13:58:02,416 TlsStream::doclose: Disconeccting socket

[DEBUG] 2017-11-21 13:58:02,416 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:58:02,416 SDK: twTlsClient_Close: Disconnecting from server

[FORCE] 2017-11-21 13:58:42,184 11_10000010-WSEMS: *

[DEBUG] 2017-11-21 13:58:

WSEMS logs:

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getString: Key = audit_target, Parent = logger

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getValueByType: Key audit_target not found

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getString: Key = publish_directory, Parent = logger

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getUnsignedInteger: Key = max_file_storage, Parent = logger

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getString: Key = publish_level, Parent = logger

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getBoolean: Key = auto_flush, Parent = logger

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getUnsignedInteger: Key = buffer_size, Parent = logger

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getValueByType: Key buffer_size not found

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getUnsignedInteger: Key = flush_chunk_size, Parent = logger

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getValueByType: Key flush_chunk_size not found

[FORCE] 2017-11-21 13:49:36,339 wsems.exe: Initializing EMS ....

[FORCE] 2017-11-21 13:49:36,339 main: Using config file C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\etc\config.json

[INFO ] 2017-11-21 13:49:36,339 wsems.exe: Creating the WsEms proxy.

[TRACE] 2017-11-21 13:49:36,339 wsEmsProxy::wsEmsProxy: Constructor called

[INFO ] 2017-11-21 13:49:36,339 wsems.exe: Starting HTTP Server.

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getInteger: Key = port, Parent = http_server

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getValueByType: Parent http_server not found

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getString: Key = host, Parent = http_server

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getValueByType: Parent http_server not found

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getBoolean: Key = ssl, Parent = http_server

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getValueByType: Parent http_server not found

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getString: Key = certificate, Parent = http_server

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getValueByType: Parent http_server not found

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getBoolean: Key = authenticate, Parent = http_server

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getValueByType: Parent http_server not found

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getInteger: Key = content_read_timeout, Parent = http_server

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getValueByType: Parent http_server not found

[INFO ] 2017-11-21 13:49:36,339 wsems.exe: Initializing the ThingWorx REST interface.

[TRACE] 2017-11-21 13:49:36,339 wsEmsProxy::initialize: Method entered

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getString: Key = level, Parent = logger

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getBoolean: Key = verbose, Parent = ws_connection

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getValueByType: Key verbose not found

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getString: Key = encryption, Parent = ws_connection

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getString: Key = appkey, Parent =

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getString: Key = resource, Parent =

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getValueByType: Key resource not found

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getInteger: Key = port, Parent = proxy

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getValueByType: Parent proxy not found

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getString: Key = host, Parent = proxy

[FORCE] 2017-11-21 13:49:36,339 httpServer: starting http server port=8000

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getValueByType: Parent proxy not found

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getString: Key = user, Parent = proxy

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getValueByType: Parent proxy not found

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getString: Key = password, Parent = proxy

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getValueByType: Parent proxy not found

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getUnsignedInteger: Key = socket_read_timeout, Parent = ws_connection

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getValueByType: Key socket_read_timeout not found

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getUnsignedInteger: Key = frame_read_timeout, Parent = ws_connection

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getValueByType: Key frame_read_timeout not found

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getUnsignedInteger: Key = ssl_read_timeout, Parent = ws_connection

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getValueByType: Key ssl_read_timeout not found

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getUnsignedInteger: Key = msg_timeout, Parent = ws_connection

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getValueByType: Key msg_timeout not found

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getUnsignedInteger: Key = ping_rate, Parent = ws_connection

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getValueByType: Key ping_rate not found

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getUnsignedInteger: Key = pingpong_timeout, Parent = ws_connection

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getValueByType: Key pingpong_timeout not found

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getUnsignedInteger: Key = max_threads, Parent = ws_connection

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getValueByType: Key max_threads not found

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getUnsignedInteger: Key = max_msg_size, Parent = ws_connection

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getValueByType: Key max_msg_size not found

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getUnsignedInteger: Key = max_messages, Parent = ws_connection

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getValueByType: Key max_messages not found

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getBoolean: Key = verbose, Parent = ws_connection

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getValueByType: Key verbose not found

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getBoolean: Key = connect_on_demand, Parent = ws_connection

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getValueByType: Key connect_on_demand not found

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getUnsignedInteger: Key = max_connect_delay, Parent = ws_connection

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getValueByType: Key max_connect_delay not found

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getUnsignedInteger: Key = connect_period, Parent = ws_connection

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getValueByType: Key connect_period not found

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getUnsignedInteger: Key = duty_cycle, Parent = ws_connection

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getValueByType: Key duty_cycle not found

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getUnsignedInteger: Key = message_idle_time, Parent = ws_connection

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getValueByType: Key message_idle_time not found

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getUnsignedInteger: Key = connect_timeout, Parent = ws_connection

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getValueByType: Key connect_timeout not found

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getUnsignedInteger: Key = connect_retry_interval, Parent = ws_connection

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getValueByType: Key connect_retry_interval not found

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getInteger: Key = connect_retries, Parent = ws_connection

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getValueByType: Key connect_retries not found

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getBoolean: Key = enabled, Parent = offline_msg_store

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getValueByType: Parent offline_msg_store not found

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getString: Key = directory, Parent = offline_msg_store

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getValueByType: Parent offline_msg_store not found

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getUnsignedInteger: Key = max_size, Parent = offline_msg_store

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getValueByType: Parent offline_msg_store not found

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getUnsignedInteger: Key = message_chunk_size, Parent = ws_connection

[TRACE] 2017-11-21 13:49:36,339 jsonConfigurator::getValueByType: Key message_chunk_size not found

[DEBUG] 2017-11-21 13:49:36,339 SDK: twWs_Create: Initializing Websocket Client for hyraxqa2-262012472.us-west-1.elb.amazonaws.com:443//Thingworx/WS

[DEBUG] 2017-11-21 13:49:36,339 SDK: twTlsClient_Create: Initializing TLS Client

[DEBUG] 2017-11-21 13:49:36,339 httpServer: http server bound to port=8000.

[DEBUG] 2017-11-21 13:49:36,354 SDK: twApi_Initialize: Websocket Established after 0 tries

[DEBUG] 2017-11-21 13:49:36,354 SDK: subscribedPropsMgr_Initialize: Initializing subscribed properties manager

[TRACE] 2017-11-21 13:49:36,354 jsonConfigurator::getBoolean: Key = validate, Parent = certificates

[TRACE] 2017-11-21 13:49:36,354 jsonConfigurator::getBoolean: Key = deny_self_signed, Parent = certificates

[TRACE] 2017-11-21 13:49:36,354 jsonConfigurator::getValueByType: Key deny_self_signed not found

[TRACE] 2017-11-21 13:49:36,354 jsonConfigurator::getBoolean: Key = allow_self_signed, Parent = certificates

[TRACE] 2017-11-21 13:49:36,354 jsonConfigurator::getString: Key = client_cert, Parent = certificates

[TRACE] 2017-11-21 13:49:36,354 jsonConfigurator::getValueByType: Key client_cert not found

[TRACE] 2017-11-21 13:49:36,354 jsonConfigurator::getString: Key = key_file, Parent = certificates

[TRACE] 2017-11-21 13:49:36,354 jsonConfigurator::getValueByType: Key key_file not found

[TRACE] 2017-11-21 13:49:36,354 jsonConfigurator::getString: Key = key_passphrase, Parent = certificates

[TRACE] 2017-11-21 13:49:36,354 jsonConfigurator::getValueByType: Key key_passphrase not found

[DEBUG] 2017-11-21 13:49:36,354 jsonConfigurator::getJsonEntity: Key cert_chain not found

[DEBUG] 2017-11-21 13:49:36,354 jsonConfigurator::getJsonEntity: Key validation_criteria not found

[TRACE] 2017-11-21 13:49:36,354 jsonConfigurator::getString: Key = staging_dir, Parent = file

[TRACE] 2017-11-21 13:49:36,354 jsonConfigurator::getUnsignedInteger: Key = buffer_size, Parent = file

[TRACE] 2017-11-21 13:49:36,354 jsonConfigurator::getDouble: Key = max_file_size, Parent = file

[TRACE] 2017-11-21 13:49:36,354 jsonConfigurator::getUnsignedInteger: Key = idle_timeout, Parent = file

[TRACE] 2017-11-21 13:49:36,354 jsonConfigurator::getValueByType: Key idle_timeout not found

[TRACE] 2017-11-21 13:49:36,354 SDK: twFileManager_AddVirtualDir: Adding __staging__ to vdir list

[TRACE] 2017-11-21 13:49:36,354 jsonConfigurator::getUnsignedInteger: Key = tick_resolution, Parent = tunnel

[TRACE] 2017-11-21 13:49:36,354 jsonConfigurator::getValueByType: Key tick_resolution not found

[DEBUG] 2017-11-21 13:49:36,370 SDK: twTunnelManager_Create: Tunnel Manager singleton already exists

[TRACE] 2017-11-21 13:49:36,370 WsEmsProxy::bindThing: Adding Thing 11_10000010-WSEMS to binding list

[TRACE] 2017-11-21 13:49:36,370 SDK: twSubscribedPropsMgr_PurgeCurrentValuesForThing: Could not find an existing current values dict for entity 11_10000010-WSEMS

[DEBUG] 2017-11-21 13:49:36,370 SDK: added 11_10000010-WSEMS to boundList

[DEBUG] 2017-11-21 13:49:36,370 SDK: twApi_BindThings: not currently connected, only binding things to api

[TRACE] 2017-11-21 13:49:36,370 SDK: All property subscriptions have been received from the server. Subscribed properties can now be updated.

[DEBUG] 2017-11-21 13:49:36,370 SDK: twMessage_Delete:  Deleting BIND Message: 1

[INFO ] 2017-11-21 13:49:36,370 WsEmsProxy::registerVirtualDirs: Adding virtual dir uploads: C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\Downloads\uploads

[TRACE] 2017-11-21 13:49:36,370 SDK: twFileManager_AddVirtualDir: Adding uploads to vdir list

[INFO ] 2017-11-21 13:49:36,370 WsEmsProxy::registerVirtualDirs: Adding virtual dir media: C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\Downloads\media

[TRACE] 2017-11-21 13:49:36,370 SDK: twFileManager_AddVirtualDir: Adding media to vdir list

[INFO ] 2017-11-21 13:49:36,370 WsEmsProxy::registerVirtualDirs: Adding virtual dir updates: C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\Downloads\updates

[TRACE] 2017-11-21 13:49:36,370 SDK: twFileManager_AddVirtualDir: Adding updates to vdir list

[INFO ] 2017-11-21 13:49:36,370 wsEmsProxy::initialize: Initialization complete!

[INFO ] 2017-11-21 13:49:36,370 wsems.exe: Starting the connection.

[TRACE] 2017-11-21 13:49:36,370 jsonConfigurator::getInteger: Key = connect_retry_interval, Parent = ws_connection

[TRACE] 2017-11-21 13:49:36,370 jsonConfigurator::getValueByType: Key connect_retry_interval not found

[TRACE] 2017-11-21 13:49:36,370 jsonConfigurator::getInteger: Key = max_connect_delay, Parent = ws_connection

[TRACE] 2017-11-21 13:49:36,370 jsonConfigurator::getValueByType: Key max_connect_delay not found

[TRACE] 2017-11-21 13:49:36,370 SDK: twApi_Connect: Delaying 12 milliseconds before connecting

[DEBUG] 2017-11-21 13:49:36,385 SDK: twTlsClient_Reconnect: Re-establishing SSL context

[DEBUG] 2017-11-21 13:49:36,385 SDK: twTlsClient_Connect: Connecting to server

[DEBUG] 2017-11-21 13:49:37,280 SDK: twTlsClient_Connect: TLS connection established

[TRACE] 2017-11-21 13:49:37,280 SDK: twWs_Connect: Connected to hyraxqa2-262012472.us-west-1.elb.amazonaws.com:443

[TRACE] 2017-11-21 13:49:37,280 SDK: twWs_Connect: Sent request:

GET /Thingworx/WS HTTP/1.1

User-Agent: ThingWorx C SDK

Upgrade: websocket

Connection: Upgrade

Host: hyraxqa2-262012472.us-west-1.elb.amazonaws.com

Sec-WebSocket-Version: 13

Sec-WebSocket-Key: D8AAfL6Eg8S0dm0CQTgoDg==

Max-Frame-Size: 8192

appKey: b5ee5226-da01-48df-8401-4194ac7cf9d7

[TRACE] 2017-11-21 13:49:37,500 SDK: twTlsClient_Read: Read: 352, Asked for: 8192

[TRACE] 2017-11-21 13:49:37,500 SDK: twWs_Connect: Got Response from Server:

HTTP/1.1 101 Switching Protocols

Date: Tue, 21 Nov 2017 08:19:37 GMT

Connection: upgrade

Server: Apache-Coyote/1.1

Cache-Control: private

Expires: Wed, 31 Dec 1969 19:00:00 EST

X-Content-Type-Options: nosniff

X-XSS-Protection: 1; mode=block

X-FRAME-OPTIONS: SAMEORIGIN

Upgrade: websocket

Sec-WebSocket-Accept: 38suFIQ4AQ7Pi7naE1hugcdB8q8=

[TRACE] 2017-11-21 13:49:37,500 SDK: ws_on_header_value: Header->date : Tue, 21 Nov 2017 08:19:37 GMT

[TRACE] 2017-11-21 13:49:37,500 SDK: ws_on_header_value: Header->connection : upgrade

[TRACE] 2017-11-21 13:49:37,500 SDK: ws_on_header_value: Header->server : Apache-Coyote/1.1

[TRACE] 2017-11-21 13:49:37,500 SDK: ws_on_header_value: Header->cache-control : private

[TRACE] 2017-11-21 13:49:37,500 SDK: ws_on_header_value: Header->expires : Wed, 31 Dec 1969 19:00:00 EST

[TRACE] 2017-11-21 13:49:37,500 SDK: ws_on_header_value: Header->x-content-type-options : nosniff

[TRACE] 2017-11-21 13:49:37,500 SDK: ws_on_header_value: Header->x-xss-protection : 1; mode=block

[TRACE] 2017-11-21 13:49:37,500 SDK: ws_on_header_value: Header->x-frame-options : SAMEORIGIN

[TRACE] 2017-11-21 13:49:37,500 SDK: ws_on_header_value: Header->upgrade : websocket

[TRACE] 2017-11-21 13:49:37,500 SDK: ws_on_header_value: Header->sec-websocket-accept : 38suFIQ4AQ7Pi7naE1hugcdB8q8=

[DEBUG] 2017-11-21 13:49:37,500 SDK: ws_on_headers_complete: Websocket connected!

[INFO ] 2017-11-21 13:49:37,500 SDK: twWs_Connect: Websocket connected!

[TRACE] 2017-11-21 13:49:37,500 SDK: msgHandlerOnConnect: WEBSOCKET CONNECTED

[DEBUG] 2017-11-21 13:49:37,505 SDK: twWs_SendMessage: Sent 60 bytes using 1 frames.

[TRACE] 2017-11-21 13:49:37,505 SDK: twMessage_Send: Message with RequestId 2 sent successfully

[TRACE] 2017-11-21 13:49:37,970 SDK: twTlsClient_Read: Read: 2, Asked for: 2

[TRACE] 2017-11-21 13:49:37,970 SDK: twWs_Receive: Read 2 bytes into header buffer

[TRACE] 2017-11-21 13:49:37,970 SDK: twWs_Receive: Got Header: Body length = 17

[TRACE] 2017-11-21 13:49:37,970 SDK: twTlsClient_Read: Read: 17, Asked for: 17

[TRACE] 2017-11-21 13:49:37,970 SDK: twWs_Receive: Read 17 bytes into Frame buffer

[TRACE] 2017-11-21 13:49:37,970 SDK: twWs_Receive: Received Binary Message in Single Frame

[TRACE] 2017-11-21 13:49:37,975 SDK: msgHandlerOnBinaryMessage: Inserted message onto queue. ID: 2, Type: 2, Queue Total: 1

[TRACE] 2017-11-21 13:49:37,975 SDK: twMessageHandler_msgHandlerTask: Processing Incoming Message Queue, Queue Total: 1

[TRACE] 2017-11-21 13:49:37,975 SDK: twMessageHandler_msgHandlerTask: Processing Incoming Message Queue, Queue Total: 1

[TRACE] 2017-11-21 13:49:37,975 SDK: twMessageHandler_msgHandlerTask: Processing Incoming Message Queue, Queue Total: 1

[TRACE] 2017-11-21 13:49:37,975 SDK: twMessageHandler_msgHandlerTask: Processing Incoming Message Queue, Queue Total: 1

[TRACE] 2017-11-21 13:49:37,975 SDK: twMessageHandler_msgHandlerTask: Processing Incoming Message Queue, Queue Total: 1

[TRACE] 2017-11-21 13:49:37,975 SDK: twMessageHandler_msgHandlerTask: Removing Message ID: 2 from Incoming Messages Queue

[TRACE] 2017-11-21 13:49:37,975 SDK: twMessageHandler_msgHandlerTask: Received Binary Message ID: 2, Queue Total: 0

[TRACE] 2017-11-21 13:49:37,975 SDK: handleMessage: Received Response to Message ID: 2

[TRACE] 2017-11-21 13:49:37,975 SDK: handleMessage: Got response for message 2

[TRACE] 2017-11-21 13:49:37,975 SDK: handleMessage: Marked message 2 as received

[DEBUG] 2017-11-21 13:49:37,975 SDK: twMessage_Delete:  Deleting RESPONSE Message: 2

[TRACE] 2017-11-21 13:49:38,80 SDK: twMessageHandler_GetCompletedResponseStruct: Found Message ID: 2

[TRACE] 2017-11-21 13:49:38,80 SDK: api:sendMessageBlocking: Received Response to Message 2.  Code: 64

[TRACE] 2017-11-21 13:49:38,80 SDK: api:sendMessageBlocking: AUTH Message 2 succeeded

[DEBUG] 2017-11-21 13:49:38,80 SDK: twMessage_Delete:  Deleting AUTH Message: 2

[TRACE] 2017-11-21 13:49:38,80 SDK: twOfflineMsgStore_Flush: Creating buffer for reading offline message store. size = 8220

[WARN ] 2017-11-21 13:49:38,80 SDK: twBindBody_Delete: NULL body or stream pointer

[DEBUG] 2017-11-21 13:49:38,80 SDK: twMessage_Delete:  Deleting BIND Message: 0

[DEBUG] 2017-11-21 13:49:38,80 SDK: twWs_SendMessage: Sent 36 bytes using 1 frames.

[TRACE] 2017-11-21 13:49:38,80 SDK: twMessage_Send: Message with RequestId 3 sent successfully

[DEBUG] 2017-11-21 13:49:38,85 SDK: sendCtlFrame: >>>>> Sending Ping. Msg: 08:19:38

[INFO ] 2017-11-21 13:49:38,115 Main: Succesfully connected.  Saving .booted config file

[TRACE] 2017-11-21 13:49:38,551 SDK: twTlsClient_Read: Read: 2, Asked for: 2

[TRACE] 2017-11-21 13:49:38,551 SDK: twWs_Receive: Read 2 bytes into header buffer

[TRACE] 2017-11-21 13:49:38,551 SDK: twWs_Receive: Got Header: Body length = 17

[TRACE] 2017-11-21 13:49:38,551 SDK: twTlsClient_Read: Read: 17, Asked for: 17

[TRACE] 2017-11-21 13:49:38,551 SDK: twWs_Receive: Read 17 bytes into Frame buffer

[TRACE] 2017-11-21 13:49:38,551 SDK: twWs_Receive: Received Binary Message in Single Frame

[TRACE] 2017-11-21 13:49:38,551 SDK: msgHandlerOnBinaryMessage: Inserted message onto queue. ID: 3, Type: 2, Queue Total: 1

[TRACE] 2017-11-21 13:49:38,551 SDK: twMessageHandler_msgHandlerTask: Processing Incoming Message Queue, Queue Total: 1

[TRACE] 2017-11-21 13:49:38,551 SDK: twMessageHandler_msgHandlerTask: Removing Message ID: 3 from Incoming Messages Queue

[TRACE] 2017-11-21 13:49:38,551 SDK: twMessageHandler_msgHandlerTask: Received Binary Message ID: 3, Queue Total: 0

[TRACE] 2017-11-21 13:49:38,551 SDK: handleMessage: Received Response to Message ID: 3

[TRACE] 2017-11-21 13:49:38,551 SDK: handleMessage: Got response for message 3

[TRACE] 2017-11-21 13:49:38,551 SDK: handleMessage: Marked message 3 as received

[DEBUG] 2017-11-21 13:49:38,551 SDK: twMessage_Delete:  Deleting RESPONSE Message: 3

[TRACE] 2017-11-21 13:49:38,551 SDK: twMessageHandler_GetCompletedResponseStruct: Found Message ID: 3

[TRACE] 2017-11-21 13:49:38,551 SDK: api:sendMessageBlocking: Received Response to Message 3.  Code: 64

[DEBUG] 2017-11-21 13:49:38,551 SDK: twMessage_Delete:  Deleting BIND Message: 3

[TRACE] 2017-11-21 13:49:38,556 SDK: twTlsClient_Read: Read: 2, Asked for: 2

[TRACE] 2017-11-21 13:49:38,556 SDK: twWs_Receive: Read 2 bytes into header buffer

[TRACE] 2017-11-21 13:49:38,556 SDK: twWs_Receive: Got Header: Body length = 8

[TRACE] 2017-11-21 13:49:38,556 SDK: twTlsClient_Read: Read: 8, Asked for: 8

[TRACE] 2017-11-21 13:49:38,556 SDK: twWs_Receive: Read 8 bytes into Frame buffer

[TRACE] 2017-11-21 13:49:38,556 SDK: twWs_Receive: Received Pong

[TRACE] 2017-11-21 13:49:38,556 SDK: msgHandlerOnPong: Received Pong.  Data: 08:19:38

[TRACE] 2017-11-21 13:49:39,549 SDK: twTlsClient_Read: Read: 2, Asked for: 2

[TRACE] 2017-11-21 13:49:39,549 SDK: twWs_Receive: Read 2 bytes into header buffer

[TRACE] 2017-11-21 13:49:39,549 SDK: twWs_Receive: Got Header: Body length = 58

[TRACE] 2017-11-21 13:49:39,549 SDK: twTlsClient_Read: Read: 58, Asked for: 58

[TRACE] 2017-11-21 13:49:39,549 SDK: twWs_Receive: Read 58 bytes into Frame buffer

[TRACE] 2017-11-21 13:49:39,549 SDK: twWs_Receive: Received Binary Message in Single Frame

[TRACE] 2017-11-21 13:49:39,549 SDK: msgHandlerOnBinaryMessage: Inserted message onto queue. ID: 867, Type: 1, Queue Total: 1

[TRACE] 2017-11-21 13:49:39,559 SDK: twMessageHandler_msgHandlerTask: Processing Incoming Message Queue, Queue Total: 1

[TRACE] 2017-11-21 13:49:39,559 SDK: twMessageHandler_msgHandlerTask: Processing Incoming Message Queue, Queue Total: 1

[TRACE] 2017-11-21 13:49:39,559 SDK: twMessageHandler_msgHandlerTask: Processing Incoming Message Queue, Queue Total: 1

[TRACE] 2017-11-21 13:49:39,559 SDK: twMessageHandler_msgHandlerTask: Processing Incoming Message Queue, Queue Total: 1

[TRACE] 2017-11-21 13:49:39,559 SDK: twMessageHandler_msgHandlerTask: Removing Message ID: 867 from Incoming Messages Queue

[TRACE] 2017-11-21 13:49:39,559 SDK: twMessageHandler_msgHandlerTask: Received Binary Message ID: 867, Queue Total: 0

[TRACE] 2017-11-21 13:49:39,559 SDK: handleMessage: Received Request Message ID: 867

[TRACE] 2017-11-21 13:49:39,559 emsRequestHandler: Function entered.  Making call to hyraxqa2-262012472.us-west-1.elb.amazonaws.com:443/Things/11_10000010-WSEMS/Services/NotifyPropertyUpdate. Params:

[DEBUG] 2017-11-21 13:49:39,559 SDK: twTlsClient_Create: Initializing TLS Client

[TRACE] 2017-11-21 13:49:39,785 HttpClient::processReq: POST //Things/11_10000010-WSEMS/Services/NotifyPropertyUpdate HTTP/1.1

[TRACE] 2017-11-21 13:49:39,785 httpClient::processReq: Adding default header content-type: application/json

[TRACE] 2017-11-21 13:49:39,785 httpClient::processReq: Adding default header Host: hyraxqa2-262012472.us-west-1.elb.amazonaws.com

[TRACE] 2017-11-21 13:49:40,15 HttpResponse::on_message_begin: Response started

[TRACE] 2017-11-21 13:49:40,15 HttpResponse::on_message_complete: Response complete.  Code: 400 Reason:

[DEBUG] 2017-11-21 13:49:40,15 TlsStream::doclose: Disconeccting socket

[DEBUG] 2017-11-21 13:49:40,15 SDK: twTlsClient_Close: Disconnecting from server

[TRACE] 2017-11-21 13:49:40,15 HttpClient::processReq: Response received. Response code = 400

[DEBUG] 2017-11-21 13:49:40,15 emsRequestHandler: Got 400 response code from POST request on Things/11_10000010-WSEMS/Services/NotifyPropertyUpdate

[TRACE] 2017-11-21 13:49:40,15 HttpResponse::getBody: Attempting to read body as single string. m_contentLength: 236

[TRACE] 2017-11-21 13:49:40,15 HttpResponse::getBody: Read body as single string. m_body: <html>

<head><title>400 The plain HTTP request was sent to HTTPS port</title></head>

<body bgcolor="white">

<center><h1>400 Bad Request</h1></center>

<center>The plain HTTP request was sent to HTTPS port</center>

</body>

</html>

[DEBUG] 2017-11-21 13:49:40,15 SDK: twTlsClient_Close: Disconnecting from server

[WARN ] 2017-11-21 13:49:40,15 SDK: InfoTable precheck: Name not found in datashape

[TRACE] 2017-11-21 13:49:40,15 SDK: twOfflineMsgStore_Flush: Creating buffer for reading offline message store. size = 8220

[DEBUG] 2017-11-21 13:49:40,15 SDK: twMessage_Delete:  Deleting RESPONSE Message: 0

[TRACE] 2017-11-21 13:49:40,15 SDK: twStream_AddBytes: adding 236 bytes would exceed the length of 256. Expanding stream.

[TRACE] 2017-11-21 13:49:40,15 SDK: twStream_AddBytes: adding 259 bytes would exceed the length of 256. Expanding stream.

[DEBUG] 2017-11-21 13:49:40,115 SDK: twWs_SendMessage: Sent 274 bytes using 1 frames.

[TRACE] 2017-11-21 13:49:40,115 SDK: twMessage_Send: Message with RequestId 867 sent successfully

[DEBUG] 2017-11-21 13:49:40,115 SDK: twMessage_Delete:  Deleting RESPONSE Message: 867

[DEBUG] 2017-11-21 13:49:40,115 SDK: twMessage_Delete:  Deleting REQUEST Message: 867

[DEBUG] 2017-11-21 13:49:53,935 SDK: twTlsClient_Create: Initializing TLS Client

[DEBUG] 2017-11-21 13:49:53,935 TlsStream:: doopen: Setting SO_RCVTIMEO

[TRACE] 2017-11-21 13:49:53,935 TlsStream:: doopen: Non-SSL server socket opened

[TRACE] 2017-11-21 13:49:53,935 httpServer: Allocating new client: 1

[TRACE] 2017-11-21 13:49:53,935 client_thread::execute: Starting request handler thread 2

[DEBUG] 2017-11-21 13:49:53,935 RestThingworx::callback: Handling request

[DEBUG] 2017-11-21 13:49:53,935 SDK: twInfoTable_CreateFromJson: Non-infotable format passed in.  Using single entry '_content_'

[DEBUG] 2017-11-21 13:49:53,935 RestThingworx: Executing request AddEdgeThing

[TRACE] 2017-11-21 13:49:53,935 jsonConfigurator::getString: Key = host, Parent = rest_interface

[TRACE] 2017-11-21 13:49:53,935 jsonConfigurator::getValueByType: Parent rest_interface not found

[DEBUG] 2017-11-21 13:49:53,940 WsEmsProxy::bindThing: Host specified as 'localhost'.  Testing IPV6/IPV4 connectivity

[TRACE] 2017-11-21 13:49:53,940 WsEmsProxy::bindThing: Adding Thing 11_10000010-WSEMS to binding list

[DEBUG] 2017-11-21 13:49:53,940 WsEmsProxy::bindThing: Entity 11_10000010-WSEMS already in Binding list.  Updating info.

[TRACE] 2017-11-21 13:49:53,940 SDK: twSubscribedPropsMgr_PurgeCurrentValuesForThing: Could not find an existing current values dict for entity 11_10000010-WSEMS

[INFO ] 2017-11-21 13:49:53,940 WsEmsProxy::registerVirtualDirs: Adding virtual dir uploads: C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\Downloads\uploads

[TRACE] 2017-11-21 13:49:53,940 SDK: twFileManager_AddVirtualDir: Adding uploads to vdir list

[INFO ] 2017-11-21 13:49:53,940 WsEmsProxy::registerVirtualDirs: Adding virtual dir media: C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\Downloads\media

[TRACE] 2017-11-21 13:49:53,940 SDK: twFileManager_AddVirtualDir: Adding media to vdir list

[INFO ] 2017-11-21 13:49:53,940 WsEmsProxy::registerVirtualDirs: Adding virtual dir updates: C:\Program Files\Keysight\Keysight_EMS_Agent\SideCar_EMS\Downloads\updates

[TRACE] 2017-11-21 13:49:53,940 SDK: twFileManager_AddVirtualDir: Adding updates to vdir list

[TRACE] 2017-11-21 13:49:53,940 RestThingworx: Responding with content:

[DEBUG] 2017-11-21 13:49:53,940 TlsStream::doclose: Disconeccting socket

[DEBUG] 2017-11-21 13:49:53,940 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 21/Nov/2017:13:49:53 [+0530] HTTP Server: 1.0.0.127 - SeqId 2 - "POST /Thingworx/Things/LocalEms/Services/AddEdgeThing HTTP/1.1" 200 0 "-"

[DEBUG] 2017-11-21 13:49:53,940 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:49:53,945 SDK: twTlsClient_Create: Initializing TLS Client

[DEBUG] 2017-11-21 13:49:53,945 TlsStream:: doopen: Setting SO_RCVTIMEO

[TRACE] 2017-11-21 13:49:53,945 TlsStream:: doopen: Non-SSL server socket opened

[TRACE] 2017-11-21 13:49:53,945 httpServer: Allocating new client: 3

[TRACE] 2017-11-21 13:49:53,945 client_thread::execute: Starting request handler thread 4

[DEBUG] 2017-11-21 13:49:53,945 RestThingworx::callback: Handling request

[DEBUG] 2017-11-21 13:49:53,945 SDK: twInfoTable_CreateFromJson: Non-infotable format passed in.  Using single entry '_content_'

[DEBUG] 2017-11-21 13:49:53,945 RestThingworx: Executing request GetPropertySubscriptions

[TRACE] 2017-11-21 13:49:53,950 SDK: twOfflineMsgStore_Flush: Creating buffer for reading offline message store. size = 8220

[DEBUG] 2017-11-21 13:49:53,950 SDK: twMessage_Delete:  Deleting REQUEST Message: 0

[DEBUG] 2017-11-21 13:49:54,25 SDK: twWs_SendMessage: Sent 86 bytes using 1 frames.

[TRACE] 2017-11-21 13:49:54,25 SDK: twMessage_Send: Message with RequestId 5 sent successfully

[TRACE] 2017-11-21 13:49:54,455 SDK: twTlsClient_Read: Read: 2, Asked for: 2

[TRACE] 2017-11-21 13:49:54,455 SDK: twWs_Receive: Read 2 bytes into header buffer

[TRACE] 2017-11-21 13:49:54,455 SDK: twTlsClient_Read: Read: 2, Asked for: 2

[TRACE] 2017-11-21 13:49:54,455 SDK: twWs_Receive: Read 2 bytes into header buffer

[TRACE] 2017-11-21 13:49:54,455 SDK: twWs_Receive: Got 2 byte length. 0x0 0xdf

[TRACE] 2017-11-21 13:49:54,455 SDK: twWs_Receive: Got Header: Body length = 223

[TRACE] 2017-11-21 13:49:54,455 SDK: twTlsClient_Read: Read: 223, Asked for: 223

[TRACE] 2017-11-21 13:49:54,455 SDK: twWs_Receive: Read 223 bytes into Frame buffer

[TRACE] 2017-11-21 13:49:54,455 SDK: twWs_Receive: Received Binary Message in Single Frame

[TRACE] 2017-11-21 13:49:54,455 SDK: twInfoTableRow_CreateFromStream: Marker is empty. No more rows in stream

[TRACE] 2017-11-21 13:49:54,455 SDK: msgHandlerOnBinaryMessage: Inserted message onto queue. ID: 5, Type: 2, Queue Total: 1

[TRACE] 2017-11-21 13:49:54,455 SDK: twMessageHandler_msgHandlerTask: Processing Incoming Message Queue, Queue Total: 1

[TRACE] 2017-11-21 13:49:54,455 SDK: twMessageHandler_msgHandlerTask: Removing Message ID: 5 from Incoming Messages Queue

[TRACE] 2017-11-21 13:49:54,455 SDK: twMessageHandler_msgHandlerTask: Received Binary Message ID: 5, Queue Total: 0

[TRACE] 2017-11-21 13:49:54,455 SDK: handleMessage: Received Response to Message ID: 5

[TRACE] 2017-11-21 13:49:54,455 SDK: handleMessage: Got response for message 5

[TRACE] 2017-11-21 13:49:54,455 SDK: handleMessage: Marked message 5 as received

[DEBUG] 2017-11-21 13:49:54,455 SDK: twMessage_Delete:  Deleting RESPONSE Message: 5

[TRACE] 2017-11-21 13:49:54,455 SDK: twMessageHandler_GetCompletedResponseStruct: Found Message ID: 5

[TRACE] 2017-11-21 13:49:54,455 SDK: api:sendMessageBlocking: Received Response to Message 5.  Code: 64

[DEBUG] 2017-11-21 13:49:54,455 SDK: twMessage_Delete:  Deleting REQUEST Message: 5

[TRACE] 2017-11-21 13:49:54,455 RestThingworx: Responding with content: {"rows":[],"datashape":{"fieldDefinitions":{"edgeName":{"name":"edgeName","description":"Edge property name","baseType":"STRING","aspects":{"isPrimaryKey":true}},"pushThreshold":{"name":"pushThreshold","description":"Change threshold to generate event for numeric properties","baseType":"NUMBER","aspects":{}},"pushType":{"name":"pushType","description":"String representing push type for event notification to subscribers","baseType":"STRING","aspects":{}}}}}

[DEBUG] 2017-11-21 13:49:54,455 TlsStream::doclose: Disconeccting socket

[DEBUG] 2017-11-21 13:49:54,455 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 21/Nov/2017:13:49:54 [+0530] HTTP Server: 1.0.0.127 - SeqId 4 - "POST /Thingworx/Things/11_10000010-WSEMS/Services/GetPropertySubscriptions HTTP/1.1" 200 460 "-"

[DEBUG] 2017-11-21 13:49:54,455 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:49:54,975 SDK: twTlsClient_Create: Initializing TLS Client

[DEBUG] 2017-11-21 13:49:54,980 TlsStream:: doopen: Setting SO_RCVTIMEO

[TRACE] 2017-11-21 13:49:54,980 TlsStream:: doopen: Non-SSL server socket opened

[TRACE] 2017-11-21 13:49:54,980 httpServer: Allocating new client: 5

[TRACE] 2017-11-21 13:49:54,980 client_thread::execute: Starting request handler thread 6

[DEBUG] 2017-11-21 13:49:54,980 RestThingworx::callback: Handling request

[DEBUG] 2017-11-21 13:49:54,980 SDK: twInfoTable_CreateFromJson: Non-infotable format passed in.  Using single entry '_content_'

[DEBUG] 2017-11-21 13:49:54,980 RestThingworx: Executing request HasEdgeThing

[TRACE] 2017-11-21 13:49:54,980 jsonConfigurator::getString: Key = host, Parent = rest_interface

[TRACE] 2017-11-21 13:49:54,980 jsonConfigurator::getValueByType: Parent rest_interface not found

[TRACE] 2017-11-21 13:49:54,980 RestThingworx: Responding with content: {"rows":[{"result":true}],"datashape":{"fieldDefinitions":{"result":{"name":"result","description":"","baseType":"BOOLEAN","aspects":{}}}}}

[DEBUG] 2017-11-21 13:49:54,980 TlsStream::doclose: Disconeccting socket

[DEBUG] 2017-11-21 13:49:54,980 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 21/Nov/2017:13:49:54 [+0530] HTTP Server: 1.0.0.127 - SeqId 6 - "POST /Thingworx/Things/LocalEms/Services/HasEdgeThing HTTP/1.1" 200 139 "-"

[DEBUG] 2017-11-21 13:49:54,980 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:50:33,138 SDK: sendCtlFrame: >>>>> Sending Ping. Msg: 08:20:33

[TRACE] 2017-11-21 13:50:33,353 SDK: twTlsClient_Read: Read: 2, Asked for: 2

[TRACE] 2017-11-21 13:50:33,353 SDK: twWs_Receive: Read 2 bytes into header buffer

[TRACE] 2017-11-21 13:50:33,353 SDK: twWs_Receive: Got Header: Body length = 8

[TRACE] 2017-11-21 13:50:33,353 SDK: twTlsClient_Read: Read: 8, Asked for: 8

[TRACE] 2017-11-21 13:50:33,353 SDK: twWs_Receive: Read 8 bytes into Frame buffer

[TRACE] 2017-11-21 13:50:33,353 SDK: twWs_Receive: Received Pong

[TRACE] 2017-11-21 13:50:33,353 SDK: msgHandlerOnPong: Received Pong.  Data: 08:20:33

[TRACE] 2017-11-21 13:50:54,349 WsEmsProxy::testBoundThing: Testing availability of bound thing: 11_10000010-WSEMS, host: localhost, port: 8001

[DEBUG] 2017-11-21 13:50:54,349 SDK: twTlsClient_Create: Initializing TLS Client

[TRACE] 2017-11-21 13:50:54,349 WsEmsProxy::testBoundThing: Successfully contacted bound thing: 11_10000010-WSEMS, host: localhost, port: 8001

[DEBUG] 2017-11-21 13:50:54,349 TlsStream::doclose: Disconeccting socket

[DEBUG] 2017-11-21 13:50:54,349 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:50:54,349 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:50:55,257 SDK: twTlsClient_Create: Initializing TLS Client

[DEBUG] 2017-11-21 13:50:55,262 TlsStream:: doopen: Setting SO_RCVTIMEO

[TRACE] 2017-11-21 13:50:55,262 TlsStream:: doopen: Non-SSL server socket opened

[TRACE] 2017-11-21 13:50:55,262 httpServer: Allocating new client: 7

[TRACE] 2017-11-21 13:50:55,262 client_thread::execute: Starting request handler thread 8

[DEBUG] 2017-11-21 13:50:55,262 RestThingworx::callback: Handling request

[DEBUG] 2017-11-21 13:50:55,262 SDK: twInfoTable_CreateFromJson: Non-infotable format passed in.  Using single entry '_content_'

[DEBUG] 2017-11-21 13:50:55,262 RestThingworx: Executing request HasEdgeThing

[TRACE] 2017-11-21 13:50:55,262 jsonConfigurator::getString: Key = host, Parent = rest_interface

[TRACE] 2017-11-21 13:50:55,262 jsonConfigurator::getValueByType: Parent rest_interface not found

[TRACE] 2017-11-21 13:50:55,262 RestThingworx: Responding with content: {"rows":[{"result":true}],"datashape":{"fieldDefinitions":{"result":{"name":"result","description":"","baseType":"BOOLEAN","aspects":{}}}}}

[DEBUG] 2017-11-21 13:50:55,262 TlsStream::doclose: Disconeccting socket

[DEBUG] 2017-11-21 13:50:55,262 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 21/Nov/2017:13:50:55 [+0530] HTTP Server: 1.0.0.127 - SeqId 8 - "POST /Thingworx/Things/LocalEms/Services/HasEdgeThing HTTP/1.1" 200 139 "-"

[DEBUG] 2017-11-21 13:50:55,262 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:51:28,144 SDK: sendCtlFrame: >>>>> Sending Ping. Msg: 08:21:28

[TRACE] 2017-11-21 13:51:28,365 SDK: twTlsClient_Read: Read: 2, Asked for: 2

[TRACE] 2017-11-21 13:51:28,365 SDK: twWs_Receive: Read 2 bytes into header buffer

[TRACE] 2017-11-21 13:51:28,365 SDK: twWs_Receive: Got Header: Body length = 8

[TRACE] 2017-11-21 13:51:28,365 SDK: twTlsClient_Read: Read: 8, Asked for: 8

[TRACE] 2017-11-21 13:51:28,365 SDK: twWs_Receive: Read 8 bytes into Frame buffer

[TRACE] 2017-11-21 13:51:28,365 SDK: twWs_Receive: Received Pong

[TRACE] 2017-11-21 13:51:28,365 SDK: msgHandlerOnPong: Received Pong.  Data: 08:21:28

[TRACE] 2017-11-21 13:51:54,852 WsEmsProxy::testBoundThing: Testing availability of bound thing: 11_10000010-WSEMS, host: localhost, port: 8001

[DEBUG] 2017-11-21 13:51:54,852 SDK: twTlsClient_Create: Initializing TLS Client

[TRACE] 2017-11-21 13:51:54,853 WsEmsProxy::testBoundThing: Successfully contacted bound thing: 11_10000010-WSEMS, host: localhost, port: 8001

[DEBUG] 2017-11-21 13:51:54,853 TlsStream::doclose: Disconeccting socket

[DEBUG] 2017-11-21 13:51:54,853 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:51:54,853 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:51:56,10 SDK: twTlsClient_Create: Initializing TLS Client

[DEBUG] 2017-11-21 13:51:56,15 TlsStream:: doopen: Setting SO_RCVTIMEO

[TRACE] 2017-11-21 13:51:56,15 TlsStream:: doopen: Non-SSL server socket opened

[TRACE] 2017-11-21 13:51:56,15 httpServer: Allocating new client: 9

[TRACE] 2017-11-21 13:51:56,15 client_thread::execute: Starting request handler thread 10

[DEBUG] 2017-11-21 13:51:56,15 RestThingworx::callback: Handling request

[DEBUG] 2017-11-21 13:51:56,15 SDK: twInfoTable_CreateFromJson: Non-infotable format passed in.  Using single entry '_content_'

[DEBUG] 2017-11-21 13:51:56,15 RestThingworx: Executing request HasEdgeThing

[TRACE] 2017-11-21 13:51:56,15 jsonConfigurator::getString: Key = host, Parent = rest_interface

[TRACE] 2017-11-21 13:51:56,15 jsonConfigurator::getValueByType: Parent rest_interface not found

[TRACE] 2017-11-21 13:51:56,15 RestThingworx: Responding with content: {"rows":[{"result":true}],"datashape":{"fieldDefinitions":{"result":{"name":"result","description":"","baseType":"BOOLEAN","aspects":{}}}}}

[DEBUG] 2017-11-21 13:51:56,15 TlsStream::doclose: Disconeccting socket

[DEBUG] 2017-11-21 13:51:56,15 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 21/Nov/2017:13:51:56 [+0530] HTTP Server: 1.0.0.127 - SeqId 10 - "POST /Thingworx/Things/LocalEms/Services/HasEdgeThing HTTP/1.1" 200 139 "-"

[DEBUG] 2017-11-21 13:51:56,20 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:52:23,192 SDK: sendCtlFrame: >>>>> Sending Ping. Msg: 08:22:23

[TRACE] 2017-11-21 13:52:23,414 SDK: twTlsClient_Read: Read: 2, Asked for: 2

[TRACE] 2017-11-21 13:52:23,414 SDK: twWs_Receive: Read 2 bytes into header buffer

[TRACE] 2017-11-21 13:52:23,414 SDK: twWs_Receive: Got Header: Body length = 8

[TRACE] 2017-11-21 13:52:23,414 SDK: twTlsClient_Read: Read: 8, Asked for: 8

[TRACE] 2017-11-21 13:52:23,414 SDK: twWs_Receive: Read 8 bytes into Frame buffer

[TRACE] 2017-11-21 13:52:23,414 SDK: twWs_Receive: Received Pong

[TRACE] 2017-11-21 13:52:23,414 SDK: msgHandlerOnPong: Received Pong.  Data: 08:22:23

[TRACE] 2017-11-21 13:52:55,565 WsEmsProxy::testBoundThing: Testing availability of bound thing: 11_10000010-WSEMS, host: localhost, port: 8001

[DEBUG] 2017-11-21 13:52:55,565 SDK: twTlsClient_Create: Initializing TLS Client

[TRACE] 2017-11-21 13:52:55,567 WsEmsProxy::testBoundThing: Successfully contacted bound thing: 11_10000010-WSEMS, host: localhost, port: 8001

[DEBUG] 2017-11-21 13:52:55,568 TlsStream::doclose: Disconeccting socket

[DEBUG] 2017-11-21 13:52:55,568 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:52:55,568 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:52:57,378 SDK: twTlsClient_Create: Initializing TLS Client

[DEBUG] 2017-11-21 13:52:57,382 TlsStream:: doopen: Setting SO_RCVTIMEO

[TRACE] 2017-11-21 13:52:57,382 TlsStream:: doopen: Non-SSL server socket opened

[TRACE] 2017-11-21 13:52:57,382 httpServer: Allocating new client: 11

[TRACE] 2017-11-21 13:52:57,382 client_thread::execute: Starting request handler thread 12

[DEBUG] 2017-11-21 13:52:57,382 RestThingworx::callback: Handling request

[DEBUG] 2017-11-21 13:52:57,382 SDK: twInfoTable_CreateFromJson: Non-infotable format passed in.  Using single entry '_content_'

[DEBUG] 2017-11-21 13:52:57,382 RestThingworx: Executing request HasEdgeThing

[TRACE] 2017-11-21 13:52:57,382 jsonConfigurator::getString: Key = host, Parent = rest_interface

[TRACE] 2017-11-21 13:52:57,382 jsonConfigurator::getValueByType: Parent rest_interface not found

[TRACE] 2017-11-21 13:52:57,382 RestThingworx: Responding with content: {"rows":[{"result":true}],"datashape":{"fieldDefinitions":{"result":{"name":"result","description":"","baseType":"BOOLEAN","aspects":{}}}}}

[DEBUG] 2017-11-21 13:52:57,382 TlsStream::doclose: Disconeccting socket

[DEBUG] 2017-11-21 13:52:57,387 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 21/Nov/2017:13:52:57 [+0530] HTTP Server: 1.0.0.127 - SeqId 12 - "POST /Thingworx/Things/LocalEms/Services/HasEdgeThing HTTP/1.1" 200 139 "-"

[DEBUG] 2017-11-21 13:52:57,387 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:53:18,233 SDK: sendCtlFrame: >>>>> Sending Ping. Msg: 08:23:18

[TRACE] 2017-11-21 13:53:18,453 SDK: twTlsClient_Read: Read: 2, Asked for: 2

[TRACE] 2017-11-21 13:53:18,453 SDK: twWs_Receive: Read 2 bytes into header buffer

[TRACE] 2017-11-21 13:53:18,453 SDK: twWs_Receive: Got Header: Body length = 8

[TRACE] 2017-11-21 13:53:18,453 SDK: twTlsClient_Read: Read: 8, Asked for: 8

[TRACE] 2017-11-21 13:53:18,453 SDK: twWs_Receive: Read 8 bytes into Frame buffer

[TRACE] 2017-11-21 13:53:18,453 SDK: twWs_Receive: Received Pong

[TRACE] 2017-11-21 13:53:18,453 SDK: msgHandlerOnPong: Received Pong.  Data: 08:23:18

[TRACE] 2017-11-21 13:53:56,277 WsEmsProxy::testBoundThing: Testing availability of bound thing: 11_10000010-WSEMS, host: localhost, port: 8001

[DEBUG] 2017-11-21 13:53:56,277 SDK: twTlsClient_Create: Initializing TLS Client

[TRACE] 2017-11-21 13:53:56,277 WsEmsProxy::testBoundThing: Successfully contacted bound thing: 11_10000010-WSEMS, host: localhost, port: 8001

[DEBUG] 2017-11-21 13:53:56,277 TlsStream::doclose: Disconeccting socket

[DEBUG] 2017-11-21 13:53:56,277 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:53:56,277 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:53:58,375 SDK: twTlsClient_Create: Initializing TLS Client

[DEBUG] 2017-11-21 13:53:58,380 TlsStream:: doopen: Setting SO_RCVTIMEO

[TRACE] 2017-11-21 13:53:58,380 TlsStream:: doopen: Non-SSL server socket opened

[TRACE] 2017-11-21 13:53:58,380 httpServer: Allocating new client: 13

[TRACE] 2017-11-21 13:53:58,380 client_thread::execute: Starting request handler thread 14

[DEBUG] 2017-11-21 13:53:58,380 RestThingworx::callback: Handling request

[DEBUG] 2017-11-21 13:53:58,380 SDK: twInfoTable_CreateFromJson: Non-infotable format passed in.  Using single entry '_content_'

[DEBUG] 2017-11-21 13:53:58,380 RestThingworx: Executing request HasEdgeThing

[TRACE] 2017-11-21 13:53:58,380 jsonConfigurator::getString: Key = host, Parent = rest_interface

[TRACE] 2017-11-21 13:53:58,380 jsonConfigurator::getValueByType: Parent rest_interface not found

[TRACE] 2017-11-21 13:53:58,380 RestThingworx: Responding with content: {"rows":[{"result":true}],"datashape":{"fieldDefinitions":{"result":{"name":"result","description":"","baseType":"BOOLEAN","aspects":{}}}}}

[DEBUG] 2017-11-21 13:53:58,380 TlsStream::doclose: Disconeccting socket

[DEBUG] 2017-11-21 13:53:58,380 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 21/Nov/2017:13:53:58 [+0530] HTTP Server: 1.0.0.127 - SeqId 14 - "POST /Thingworx/Things/LocalEms/Services/HasEdgeThing HTTP/1.1" 200 139 "-"

[DEBUG] 2017-11-21 13:53:58,385 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:54:13,263 SDK: sendCtlFrame: >>>>> Sending Ping. Msg: 08:24:13

[TRACE] 2017-11-21 13:54:13,483 SDK: twTlsClient_Read: Read: 2, Asked for: 2

[TRACE] 2017-11-21 13:54:13,483 SDK: twWs_Receive: Read 2 bytes into header buffer

[TRACE] 2017-11-21 13:54:13,483 SDK: twWs_Receive: Got Header: Body length = 8

[TRACE] 2017-11-21 13:54:13,483 SDK: twTlsClient_Read: Read: 8, Asked for: 8

[TRACE] 2017-11-21 13:54:13,483 SDK: twWs_Receive: Read 8 bytes into Frame buffer

[TRACE] 2017-11-21 13:54:13,483 SDK: twWs_Receive: Received Pong

[TRACE] 2017-11-21 13:54:13,483 SDK: msgHandlerOnPong: Received Pong.  Data: 08:24:13

[TRACE] 2017-11-21 13:54:56,908 WsEmsProxy::testBoundThing: Testing availability of bound thing: 11_10000010-WSEMS, host: localhost, port: 8001

[DEBUG] 2017-11-21 13:54:56,908 SDK: twTlsClient_Create: Initializing TLS Client

[TRACE] 2017-11-21 13:54:56,908 WsEmsProxy::testBoundThing: Successfully contacted bound thing: 11_10000010-WSEMS, host: localhost, port: 8001

[DEBUG] 2017-11-21 13:54:56,908 TlsStream::doclose: Disconeccting socket

[DEBUG] 2017-11-21 13:54:56,908 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:54:56,908 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:54:59,430 SDK: twTlsClient_Create: Initializing TLS Client

[DEBUG] 2017-11-21 13:54:59,435 TlsStream:: doopen: Setting SO_RCVTIMEO

[TRACE] 2017-11-21 13:54:59,435 TlsStream:: doopen: Non-SSL server socket opened

[TRACE] 2017-11-21 13:54:59,435 httpServer: Allocating new client: 15

[TRACE] 2017-11-21 13:54:59,435 client_thread::execute: Starting request handler thread 16

[DEBUG] 2017-11-21 13:54:59,435 RestThingworx::callback: Handling request

[DEBUG] 2017-11-21 13:54:59,435 SDK: twInfoTable_CreateFromJson: Non-infotable format passed in.  Using single entry '_content_'

[DEBUG] 2017-11-21 13:54:59,435 RestThingworx: Executing request HasEdgeThing

[TRACE] 2017-11-21 13:54:59,435 jsonConfigurator::getString: Key = host, Parent = rest_interface

[TRACE] 2017-11-21 13:54:59,435 jsonConfigurator::getValueByType: Parent rest_interface not found

[TRACE] 2017-11-21 13:54:59,435 RestThingworx: Responding with content: {"rows":[{"result":true}],"datashape":{"fieldDefinitions":{"result":{"name":"result","description":"","baseType":"BOOLEAN","aspects":{}}}}}

[DEBUG] 2017-11-21 13:54:59,435 TlsStream::doclose: Disconeccting socket

[DEBUG] 2017-11-21 13:54:59,435 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 21/Nov/2017:13:54:59 [+0530] HTTP Server: 1.0.0.127 - SeqId 16 - "POST /Thingworx/Things/LocalEms/Services/HasEdgeThing HTTP/1.1" 200 139 "-"

[DEBUG] 2017-11-21 13:54:59,435 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:55:08,280 SDK: sendCtlFrame: >>>>> Sending Ping. Msg: 08:25:08

[TRACE] 2017-11-21 13:55:08,500 SDK: twTlsClient_Read: Read: 2, Asked for: 2

[TRACE] 2017-11-21 13:55:08,500 SDK: twWs_Receive: Read 2 bytes into header buffer

[TRACE] 2017-11-21 13:55:08,500 SDK: twWs_Receive: Got Header: Body length = 8

[TRACE] 2017-11-21 13:55:08,500 SDK: twTlsClient_Read: Read: 8, Asked for: 8

[TRACE] 2017-11-21 13:55:08,500 SDK: twWs_Receive: Read 8 bytes into Frame buffer

[TRACE] 2017-11-21 13:55:08,500 SDK: twWs_Receive: Received Pong

[TRACE] 2017-11-21 13:55:08,500 SDK: msgHandlerOnPong: Received Pong.  Data: 08:25:08

[TRACE] 2017-11-21 13:55:57,519 WsEmsProxy::testBoundThing: Testing availability of bound thing: 11_10000010-WSEMS, host: localhost, port: 8001

[DEBUG] 2017-11-21 13:55:57,519 SDK: twTlsClient_Create: Initializing TLS Client

[TRACE] 2017-11-21 13:55:57,519 WsEmsProxy::testBoundThing: Successfully contacted bound thing: 11_10000010-WSEMS, host: localhost, port: 8001

[DEBUG] 2017-11-21 13:55:57,519 TlsStream::doclose: Disconeccting socket

[DEBUG] 2017-11-21 13:55:57,519 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:55:57,519 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:56:00,442 SDK: twTlsClient_Create: Initializing TLS Client

[DEBUG] 2017-11-21 13:56:00,442 TlsStream:: doopen: Setting SO_RCVTIMEO

[TRACE] 2017-11-21 13:56:00,442 TlsStream:: doopen: Non-SSL server socket opened

[TRACE] 2017-11-21 13:56:00,442 httpServer: Allocating new client: 17

[TRACE] 2017-11-21 13:56:00,442 client_thread::execute: Starting request handler thread 18

[DEBUG] 2017-11-21 13:56:00,442 RestThingworx::callback: Handling request

[DEBUG] 2017-11-21 13:56:00,442 SDK: twInfoTable_CreateFromJson: Non-infotable format passed in.  Using single entry '_content_'

[DEBUG] 2017-11-21 13:56:00,442 RestThingworx: Executing request HasEdgeThing

[TRACE] 2017-11-21 13:56:00,442 jsonConfigurator::getString: Key = host, Parent = rest_interface

[TRACE] 2017-11-21 13:56:00,442 jsonConfigurator::getValueByType: Parent rest_interface not found

[TRACE] 2017-11-21 13:56:00,447 RestThingworx: Responding with content: {"rows":[{"result":true}],"datashape":{"fieldDefinitions":{"result":{"name":"result","description":"","baseType":"BOOLEAN","aspects":{}}}}}

[DEBUG] 2017-11-21 13:56:00,447 TlsStream::doclose: Disconeccting socket

[DEBUG] 2017-11-21 13:56:00,447 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 21/Nov/2017:13:56:00 [+0530] HTTP Server: 1.0.0.127 - SeqId 18 - "POST /Thingworx/Things/LocalEms/Services/HasEdgeThing HTTP/1.1" 200 139 "-"

[DEBUG] 2017-11-21 13:56:00,447 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:56:03,323 SDK: sendCtlFrame: >>>>> Sending Ping. Msg: 08:26:03

[TRACE] 2017-11-21 13:56:03,543 SDK: twTlsClient_Read: Read: 2, Asked for: 2

[TRACE] 2017-11-21 13:56:03,543 SDK: twWs_Receive: Read 2 bytes into header buffer

[TRACE] 2017-11-21 13:56:03,543 SDK: twWs_Receive: Got Header: Body length = 8

[TRACE] 2017-11-21 13:56:03,543 SDK: twTlsClient_Read: Read: 8, Asked for: 8

[TRACE] 2017-11-21 13:56:03,543 SDK: twWs_Receive: Read 8 bytes into Frame buffer

[TRACE] 2017-11-21 13:56:03,543 SDK: twWs_Receive: Received Pong

[TRACE] 2017-11-21 13:56:03,543 SDK: msgHandlerOnPong: Received Pong.  Data: 08:26:03

[TRACE] 2017-11-21 13:56:58,130 WsEmsProxy::testBoundThing: Testing availability of bound thing: 11_10000010-WSEMS, host: localhost, port: 8001

[DEBUG] 2017-11-21 13:56:58,130 SDK: twTlsClient_Create: Initializing TLS Client

[TRACE] 2017-11-21 13:56:58,130 WsEmsProxy::testBoundThing: Successfully contacted bound thing: 11_10000010-WSEMS, host: localhost, port: 8001

[DEBUG] 2017-11-21 13:56:58,130 TlsStream::doclose: Disconeccting socket

[DEBUG] 2017-11-21 13:56:58,130 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:56:58,130 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:56:58,428 SDK: sendCtlFrame: >>>>> Sending Ping. Msg: 08:26:58

[TRACE] 2017-11-21 13:56:58,648 SDK: twTlsClient_Read: Read: 2, Asked for: 2

[TRACE] 2017-11-21 13:56:58,648 SDK: twWs_Receive: Read 2 bytes into header buffer

[TRACE] 2017-11-21 13:56:58,648 SDK: twWs_Receive: Got Header: Body length = 8

[TRACE] 2017-11-21 13:56:58,648 SDK: twTlsClient_Read: Read: 8, Asked for: 8

[TRACE] 2017-11-21 13:56:58,648 SDK: twWs_Receive: Read 8 bytes into Frame buffer

[TRACE] 2017-11-21 13:56:58,648 SDK: twWs_Receive: Received Pong

[TRACE] 2017-11-21 13:56:58,648 SDK: msgHandlerOnPong: Received Pong.  Data: 08:26:58

[DEBUG] 2017-11-21 13:57:01,407 SDK: twTlsClient_Create: Initializing TLS Client

[DEBUG] 2017-11-21 13:57:01,412 TlsStream:: doopen: Setting SO_RCVTIMEO

[TRACE] 2017-11-21 13:57:01,412 TlsStream:: doopen: Non-SSL server socket opened

[TRACE] 2017-11-21 13:57:01,412 httpServer: Allocating new client: 19

[TRACE] 2017-11-21 13:57:01,412 client_thread::execute: Starting request handler thread 20

[DEBUG] 2017-11-21 13:57:01,412 RestThingworx::callback: Handling request

[DEBUG] 2017-11-21 13:57:01,412 SDK: twInfoTable_CreateFromJson: Non-infotable format passed in.  Using single entry '_content_'

[DEBUG] 2017-11-21 13:57:01,412 RestThingworx: Executing request HasEdgeThing

[TRACE] 2017-11-21 13:57:01,412 jsonConfigurator::getString: Key = host, Parent = rest_interface

[TRACE] 2017-11-21 13:57:01,412 jsonConfigurator::getValueByType: Parent rest_interface not found

[TRACE] 2017-11-21 13:57:01,412 RestThingworx: Responding with content: {"rows":[{"result":true}],"datashape":{"fieldDefinitions":{"result":{"name":"result","description":"","baseType":"BOOLEAN","aspects":{}}}}}

[DEBUG] 2017-11-21 13:57:01,412 TlsStream::doclose: Disconeccting socket

[DEBUG] 2017-11-21 13:57:01,412 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 21/Nov/2017:13:57:01 [+0530] HTTP Server: 1.0.0.127 - SeqId 20 - "POST /Thingworx/Things/LocalEms/Services/HasEdgeThing HTTP/1.1" 200 139 "-"

[DEBUG] 2017-11-21 13:57:01,417 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:57:53,532 SDK: sendCtlFrame: >>>>> Sending Ping. Msg: 08:27:53

[TRACE] 2017-11-21 13:57:53,757 SDK: twTlsClient_Read: Read: 2, Asked for: 2

[TRACE] 2017-11-21 13:57:53,757 SDK: twWs_Receive: Read 2 bytes into header buffer

[TRACE] 2017-11-21 13:57:53,757 SDK: twWs_Receive: Got Header: Body length = 8

[TRACE] 2017-11-21 13:57:53,757 SDK: twTlsClient_Read: Read: 8, Asked for: 8

[TRACE] 2017-11-21 13:57:53,757 SDK: twWs_Receive: Read 8 bytes into Frame buffer

[TRACE] 2017-11-21 13:57:53,757 SDK: twWs_Receive: Received Pong

[TRACE] 2017-11-21 13:57:53,757 SDK: msgHandlerOnPong: Received Pong.  Data: 08:27:53

[TRACE] 2017-11-21 13:57:58,739 WsEmsProxy::testBoundThing: Testing availability of bound thing: 11_10000010-WSEMS, host: localhost, port: 8001

[DEBUG] 2017-11-21 13:57:58,739 SDK: twTlsClient_Create: Initializing TLS Client

[TRACE] 2017-11-21 13:57:58,739 WsEmsProxy::testBoundThing: Successfully contacted bound thing: 11_10000010-WSEMS, host: localhost, port: 8001

[DEBUG] 2017-11-21 13:57:58,739 TlsStream::doclose: Disconeccting socket

[DEBUG] 2017-11-21 13:57:58,739 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:57:58,739 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:58:02,416 SDK: twTlsClient_Create: Initializing TLS Client

[DEBUG] 2017-11-21 13:58:02,416 TlsStream:: doopen: Setting SO_RCVTIMEO

[TRACE] 2017-11-21 13:58:02,416 TlsStream:: doopen: Non-SSL server socket opened

[TRACE] 2017-11-21 13:58:02,416 httpServer: Allocating new client: 21

[TRACE] 2017-11-21 13:58:02,416 client_thread::execute: Starting request handler thread 22

[DEBUG] 2017-11-21 13:58:02,416 RestThingworx::callback: Handling request

[DEBUG] 2017-11-21 13:58:02,416 SDK: twInfoTable_CreateFromJson: Non-infotable format passed in.  Using single entry '_content_'

[DEBUG] 2017-11-21 13:58:02,416 RestThingworx: Executing request HasEdgeThing

[TRACE] 2017-11-21 13:58:02,416 jsonConfigurator::getString: Key = host, Parent = rest_interface

[TRACE] 2017-11-21 13:58:02,416 jsonConfigurator::getValueByType: Parent rest_interface not found

[TRACE] 2017-11-21 13:58:02,416 RestThingworx: Responding with content: {"rows":[{"result":true}],"datashape":{"fieldDefinitions":{"result":{"name":"result","description":"","baseType":"BOOLEAN","aspects":{}}}}}

[DEBUG] 2017-11-21 13:58:02,416 TlsStream::doclose: Disconeccting socket

[DEBUG] 2017-11-21 13:58:02,416 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 21/Nov/2017:13:58:02 [+0530] HTTP Server: 1.0.0.127 - SeqId 22 - "POST /Thingworx/Things/LocalEms/Services/HasEdgeThing HTTP/1.1" 200 139 "-"

[DEBUG] 2017-11-21 13:58:02,416 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:58:48,635 SDK: sendCtlFrame: >>>>> Sending Ping. Msg: 08:28:48

[TRACE] 2017-11-21 13:58:48,855 SDK: twTlsClient_Read: Read: 2, Asked for: 2

[TRACE] 2017-11-21 13:58:48,855 SDK: twWs_Receive: Read 2 bytes into header buffer

[TRACE] 2017-11-21 13:58:48,855 SDK: twWs_Receive: Got Header: Body length = 8

[TRACE] 2017-11-21 13:58:48,855 SDK: twTlsClient_Read: Read: 8, Asked for: 8

[TRACE] 2017-11-21 13:58:48,855 SDK: twWs_Receive: Read 8 bytes into Frame buffer

[TRACE] 2017-11-21 13:58:48,855 SDK: twWs_Receive: Received Pong

[TRACE] 2017-11-21 13:58:48,855 SDK: msgHandlerOnPong: Received Pong.  Data: 08:28:48

[TRACE] 2017-11-21 13:58:59,457 WsEmsProxy::testBoundThing: Testing availability of bound thing: 11_10000010-WSEMS, host: localhost, port: 8001

[DEBUG] 2017-11-21 13:58:59,457 SDK: twTlsClient_Create: Initializing TLS Client

[TRACE] 2017-11-21 13:58:59,457 WsEmsProxy::testBoundThing: Successfully contacted bound thing: 11_10000010-WSEMS, host: localhost, port: 8001

[DEBUG] 2017-11-21 13:58:59,457 TlsStream::doclose: Disconeccting socket

[DEBUG] 2017-11-21 13:58:59,457 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:58:59,457 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:59:03,312 SDK: twTlsClient_Create: Initializing TLS Client

[DEBUG] 2017-11-21 13:59:03,317 TlsStream:: doopen: Setting SO_RCVTIMEO

[TRACE] 2017-11-21 13:59:03,317 TlsStream:: doopen: Non-SSL server socket opened

[TRACE] 2017-11-21 13:59:03,317 httpServer: Allocating new client: 23

[TRACE] 2017-11-21 13:59:03,317 client_thread::execute: Starting request handler thread 24

[DEBUG] 2017-11-21 13:59:03,317 RestThingworx::callback: Handling request

[DEBUG] 2017-11-21 13:59:03,317 SDK: twInfoTable_CreateFromJson: Non-infotable format passed in.  Using single entry '_content_'

[DEBUG] 2017-11-21 13:59:03,317 RestThingworx: Executing request HasEdgeThing

[TRACE] 2017-11-21 13:59:03,317 jsonConfigurator::getString: Key = host, Parent = rest_interface

[TRACE] 2017-11-21 13:59:03,317 jsonConfigurator::getValueByType: Parent rest_interface not found

[TRACE] 2017-11-21 13:59:03,317 RestThingworx: Responding with content: {"rows":[{"result":true}],"datashape":{"fieldDefinitions":{"result":{"name":"result","description":"","baseType":"BOOLEAN","aspects":{}}}}}

[DEBUG] 2017-11-21 13:59:03,317 TlsStream::doclose: Disconeccting socket

[DEBUG] 2017-11-21 13:59:03,317 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 21/Nov/2017:13:59:03 [+0530] HTTP Server: 1.0.0.127 - SeqId 24 - "POST /Thingworx/Things/LocalEms/Services/HasEdgeThing HTTP/1.1" 200 139 "-"

[DEBUG] 2017-11-21 13:59:03,322 SDK: twTlsClient_Close: Disconnecting from server

[DEBUG] 2017-11-21 13:59:43,662 SDK: sendCtlFrame: >>>>> Sending Ping. Msg: 08:29:43

[TRACE] 2017-11-21 13:59:43,887 SDK: twTlsClient_Read: Read: 2, Asked for: 2

[TRACE] 2017-11-21 13:59:43,887 SDK: twWs_Receive: Read 2 bytes into header buffer

[TRACE] 2017-11-21 13:59:43,887 SDK: twWs_Receive: Got Header: Body length = 8

[TRACE] 2017-11-21 13:59:43,887 SDK: twTlsClient_Read: Read: 8, Asked for: 8

[TRACE] 2017-11-21 13:59:43,887 SDK: twWs_Receive: Read 8 bytes into Frame buffer

[TRACE] 2017-11-21 13:59:43,887 SDK: twWs_Receive: Received Pong

[TRACE] 2017-11-21 13:59:43,887 SDK: msgHandlerOnPong: Received Pong.  Data: 08:29:43

[TRACE] 2017-11-21 14:00:00,202 WsEmsProxy::testBoundThing: Testing availability of bound thing: 11_10000010-WSEMS, host: localhost, port: 8001

Thanks And Regards,

Ayush Jain