9 Replies Latest reply on Nov 15, 2016 10:45 AM by aanjan RSS
    qflyer Newbie

    How to Communication of Lua and ThingWorx  platform

    Hello

    I'm a beginner for ThingWorx, and I'm not a  native speaker of english. I've had a lot of problems, and it's great if anyone can help me. anyway Thank you for your answer.

     

    I have created an Instances in ThingWorx Dashboard, and setting up the EMS on my device. the config.json file is as below:

    {

      "http_server": {

      "host": "127.0.0.1",

      "port": 8000

      },

      "ws_servers": [{

      "host": "52.199.8.0",

      "port": 80

      }],

      "appKey": "44ddf820-e22f-4348-8517-f6bffd8eadse",

      "logger": {

      "level": "INFO"

      },

      "ws_connection": {

      "encryption": "none",

      "verbose": true

      },

      "certificates": {

      "validate": false,

      "allow_self_signed": true

      },

      "auto_bind": [{

      "name": "myEMSGateway",

      "gateway": true

      }],

      "file": {

      "virtual_dirs": [{

      "BaseFolder": "/mnt/baseFolder"

      }],

      "staging_dir": "/mnt/staging_dir"

      },

      "tunnel": {

      "buffer_size": 8192,

      "read_timeout": 10,

      "idle_timeout": 300000,

      "max_concurrent": 4

      }

    }

    I can connected with the ThingWorx plateform when I run ./wsems , the thing myEMSGatewayThing's property "isConnected" will be true while it's false default.

     

    But i don't konw how to use the Lua script.

    my etc/config.lua file :

    scripts.log_level = "INFO"

     

    -- under template = specify name of your *.lua resource file specified in path etc/custom/template/, example in EMS is called example.lua

    -- under sw_update_dir = specify local path of our SW Update directory for SCM module

     

    scripts.myEMSGatewayThing = {

        file = "myEMSGatewayThing.lua",

        template = "myEMSGateway",

        sw_update_dir = "/mnt/update"

      }

     

     

      my etc/custom/template/myEMSGateway file is same as etc/custom/template/example.lua but line 23 :

      module ("templates.myEMSGateway", thingworx.template.extend)

     

      my etc/custom/scripts/myEMSGatewayThing.lua file is same as etc/custom/scripts/sample.lua.

     

     

    1. how can i send a property of myEMSGateThing to the plateform and plateform can refresh it.

    2. I create an myEMSGateThing in ThingWorx Composer, Should i create another thing(e.g. myEMSThing01)

    3. My LSR is runing on the device where EMS runing, is that right? if not what should i do?

     

     

    Thank you!

      • Re: How to Communication of Lua and ThingWorx  platform
        ttielebein Collaborator

        Hello,

         

        You can know if the LSR is working by going to the Properties tab of your remote thing and clicking "Manage Bindings". There should be a Remote tab next to Local there which would have all of the remote properties added to your thing by your LSR. You can add remote properties by clicking the blue arrow next to the property names on this screen.

         

        To create and bind more things, just create the remote things in ThingWorx, and then add them to the config.lua file in the same way you have the gateway. Normally, you'd have the EMS running on some server somewhere, and then the LSR running on all of the devices. The LSR sends properties to the EMS, which converts it to the AlwaysOn Protocol, and sends it to the Platform.

         

        For more information, check out the Edge Help Center. I hope this helps!

        • Re: How to Communication of Lua and ThingWorx  platform
          qflyer Newbie

          Hello Tori, thank you for your answer.

           

           

          I'm sure the LSR doesn't work, when i clicking the Remote tab, it shows below :

          Error browsing properties. Be sure the remote device/server is connected and configured properly.

           

           

          I have changed the level in etc/config.lua file to TRACE follow @Aanjan’s advice , and the log is in the luaScriptResourceLog.txt file below:

          luaScriptResourceLog.txt

           

           

          All the file I have edited is listed before:

          etc/config.json

          etc/config.lua

          etc/custom/template/myEMSGateway

          etc/custom/scripts/myEMSGatewayThing.lua

           

           

          I know LSR doesn't work, so which steps and operation I'm missing ?or which steps is wrong ?

          what mean luaConfigurator::doGetItem: Global property or script log_level not found in the log ?

          my EMS and LSR is in the same device, is that any problems?

           

           

          thank you for your help.

            • Re: How to Communication of Lua and ThingWorx  platform
              aanjan Heavyweight Champ

              Qiu, as a quick test, can you try adding an Identifier to your config.lua? So, now it should read -

               

              scripts.myEMSGatewayThing = {

                  file = "myEMSGatewayThing.lua",

                  template = "myEMSGateway",

                  identifier = "myEMSGatewayTest",

                  sw_update_dir = "/mnt/update"

                }

               

              Once you run both your EMS and Lua, can you click on the 'Browse' button on the Identifier section (under General Information) in your myEMSGateway Thing and see if this identifier shows up? If so, please select that, save your Thing, and now try browsing properties.

                • Re: How to Communication of Lua and ThingWorx  platform
                  qflyer Newbie

                  Hello Aanjan,Thank you.

                  I have tried , but when I click Browse, the identifier doesn't show up.

                  I think it's my Lua script that doesn't work at all because it doesn't produce any results or make any differences when i run luaScriptResources.

                   

                  my device's ip is IPv6,and i changed host to localhost and ipv6 address,but it doesn't work either.

                   

                  That would be great, if you can use your language to describe briefly how to make an example.

                   

                  what i want to do is just connected the Thing and ThingWorx, so i can see the properties of Thing on ThingWorx. What are the specific needs of the configuration file?how to modify the config files based on the example config.

                   

                  thank you!

                    • Re: How to Communication of Lua and ThingWorx  platform
                      aanjan Heavyweight Champ

                      Can you let the luaScriptResource run a little longer and post the logs? The one you've attached seems to cut out pretty soon. You don't actually need any additional thing, as long as you have your config.json connecting to the platform, and use a simple config.lua (I've attached mine), you should be good to go. I'm using the default example template that comes with the download.

                       

                      scripts.log_level = "TRACE"

                      scripts.scanRate = 10000

                      scripts.TestRemoteThing1 = {

                          file = "thing.lua",

                          template = "example",

                          identifier = "TestRemoteThing1",

                          updateRate = 2000

                           }

                      scripts.sample = {

                        file = "sample.lua"

                           }

                        • Re: How to Communication of Lua and ThingWorx  platform
                          qflyer Newbie

                          Aanjan thank you  for your help.

                           

                          i have try your advice, but it doesn't  work. and i find that EMS is not available or online on my device.

                          so i run EMS on windows now, and ems is available and online just like bellow :

                           

                          [DEBUG] 2016-11-14 23:00:00, 88 SDK: twTlsClient_Close: Disconnecting from server

                          [INFO ] 2016-11-14 23:00:00, 88 TestRemoteThing1: EMS is available: true, online: true

                          [INFO ] 2016-11-14 23:00:00, 88 TestRemoteThing1: Attempting to GetPropertySubscriptions from server failed. code: 500, result:

                          [TRACE] 2016-11-14 23:00:00, 88 TestRemoteThing1: Attempting to set property upToDate

                          [TRACE] 2016-11-14 23:00:00, 91 TestRemoteThing1: Found handler inmemory

                          [DEBUG] 2016-11-14 23:00:00, 91 TestRemoteThing1: Wrote property: upToDate Updated updateTime to 1666850176

                          [TRACE] 2016-11-14 23:00:00, 91 setProperty: Code: 200 Msg nil

                          [TRACE] 2016-11-14 23:00:00, 91 GetPropertySubscriptions: Code: 500 Msg Attempting to GetPropertySubscriptions from server failed. code: 500, result:

                           

                           

                          But it read GetpropertySubscriptions from server failed ,code is 500.

                          and i can not get remote properties neither :

                          Error browsing properties. Be sure the remote device/server is connected and configured properly

                           

                          part of wsems' log is bellow :

                           

                          52.199.8.0:80-->[INFO ] 2016-11-14 22:37:12,625 wsEmsProxy::initialize: Initialization complete!

                          [INFO ] 2016-11-14 22:37:12,625 C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\wsems.exe: Starting the connection.

                          [AUDIT] 2016-11-14 22:37:13, 80 SDK: twWs_Connect: Websocket connected!

                          [INFO ] 2016-11-14 22:37:13,350 Main: Succesfully connected.  Saving .booted config file

                          [ERROR] 2016-11-14 22:37:17,590 SDK: twApi_BindThing: Error sending Bind message

                          [ERROR] 2016-11-14 22:37:17,590 WsEmsProxy::bindThing: Error binding thing to twApi.

                          [WARN ] 2016-11-14 22:37:18,610 SDK: twWs_Connect: Already connected

                          [WARN ] 2016-11-14 22:37:24, 26 SDK: twWs_Connect: Already connected

                           

                           

                          luaScriptResources log:

                           

                          [FORCE] 2016-11-14 22:54:03, 39 C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\luaScriptResource.exe: Starting up ....

                          [TRACE] 2016-11-14 22:54:03, 47 luaConfigurator::doGetItem: Global property or script log_level not found

                          [TRACE] 2016-11-14 22:54:03, 47 luaConfigurator::doGetItem: Global property or script rap_host not found

                          [TRACE] 2016-11-14 22:54:03, 47 luaConfigurator::doGetItem: Global property or script rap_host not found

                          [TRACE] 2016-11-14 22:54:03, 47 luaConfigurator::doGetItem: Global property or script rap_host not found

                          [TRACE] 2016-11-14 22:54:03, 47 luaConfigurator::doGetItem: Global property or script rap_host not found

                          [TRACE] 2016-11-14 22:54:03, 47 luaConfigurator::doGetItem: Global property or script rap_port not found

                          [TRACE] 2016-11-14 22:54:03, 47 luaConfigurator::doGetItem: Global property or script rap_port not found

                          [TRACE] 2016-11-14 22:54:03, 47 luaConfigurator::doGetItem: Global property or script rap_port not found

                          [TRACE] 2016-11-14 22:54:03, 47 luaConfigurator::doGetItem: Global property or script rap_port not found

                          [TRACE] 2016-11-14 22:54:03, 47 luaConfigurator::doGetItem: Global property or script rap_ssl not found

                          [TRACE] 2016-11-14 22:54:03, 47 luaConfigurator::doGetItem: Global property or script rap_ssl not found

                          [TRACE] 2016-11-14 22:54:03, 47 luaConfigurator::doGetItem: Global property or script rap_ssl not found

                          [TRACE] 2016-11-14 22:54:03, 47 luaConfigurator::doGetItem: Global property or script rap_ssl not found

                          [TRACE] 2016-11-14 22:54:03, 47 luaConfigurator::setItem: rap_ssl already set to .  Nothing to do.

                          [TRACE] 2016-11-14 22:54:03, 47 luaConfigurator::doGetItem: Global property or script script_resource_host not found

                          [TRACE] 2016-11-14 22:54:03, 47 luaConfigurator::doGetItem: Global property or script script_resource_host not found

                          [TRACE] 2016-11-14 22:54:03, 47 luaConfigurator::doGetItem: Global property or script script_resource_host not found

                          [TRACE] 2016-11-14 22:54:03, 47 luaConfigurator::doGetItem: Global property or script script_resource_host not found

                          [TRACE] 2016-11-14 22:54:03, 47 luaConfigurator::doGetItem: Global property or script script_resource_port not found

                          [TRACE] 2016-11-14 22:54:03, 47 luaConfigurator::doGetItem: Global property or script script_resource_port not found

                          [TRACE] 2016-11-14 22:54:03, 47 luaConfigurator::doGetItem: Global property or script script_resource_port not found

                          [TRACE] 2016-11-14 22:54:03, 47 luaConfigurator::doGetItem: Global property or script script_resource_port not found

                          [TRACE] 2016-11-14 22:54:03, 47 luaConfigurator::doGetItem: Global property or script script_directory not found

                          [TRACE] 2016-11-14 22:54:03, 47 luaConfigurator::doGetItem: Global property or script script_directory not found

                          [TRACE] 2016-11-14 22:54:03, 47 luaConfigurator::doGetItem: Global property or script script_directory not found

                          [TRACE] 2016-11-14 22:54:03, 47 luaConfigurator::doGetItem: Global property or script script_directory not found

                          [TRACE] 2016-11-14 22:54:03, 51 luaConfigurator::doGetItem: Global property or script config_file_path not found

                          [TRACE] 2016-11-14 22:54:03, 55 luaConfigurator::doGetItem: Global property or script config_file_path not found

                          [TRACE] 2016-11-14 22:54:03, 55 luaConfigurator::doGetItem: Global property or script script_library_path not found

                          [TRACE] 2016-11-14 22:54:03, 55 luaConfigurator::doGetItem: Global property or script script_library_path not found

                          [TRACE] 2016-11-14 22:54:03, 59 luaConfigurator::doGetItem: Global property or script script_library_path not found

                          [TRACE] 2016-11-14 22:54:03, 59 luaConfigurator::doGetItem: Global property or script script_library_path not found

                          [TRACE] 2016-11-14 22:54:03, 59 luaConfigurator::doGetItem: Global property or script script_clib_path not found

                          [TRACE] 2016-11-14 22:54:03, 59 luaConfigurator::doGetItem: Global property or script script_clib_path not found

                          [TRACE] 2016-11-14 22:54:03, 63 luaConfigurator::doGetItem: Global property or script script_clib_path not found

                          [TRACE] 2016-11-14 22:54:03, 66 luaConfigurator::doGetItem: Global property or script script_clib_path not found

                          [TRACE] 2016-11-14 22:54:03, 66 luaConfigurator::doGetItem: Global property or script script_clib_path not found

                          [DEBUG] 2016-11-14 22:54:03, 66 C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\luaScriptResource.exe: Appending C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\thingworx\clibs;C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\custom\clibs;C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\community\clibs to current path C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\System32\Wbem;C:\WINDOWS\System32\WindowsPowerShell\v1.0\;C:\Users\flyerqiu\AppData\Local\Microsoft\WindowsApps;

                          [INFO ] 2016-11-14 22:54:03, 70 C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\luaScriptResource.exe: New path is C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\thingworx\clibs;C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\custom\clibs;C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\community\clibs;C:\WINDOWS\system32;C:\WINDOWS;C:\WINDOWS\System32\Wbem;C:\WINDOWS\System32\WindowsPowerShell\v1.0\;C:\Users\flyerqiu\AppData\Local\Microsoft\WindowsApps;

                          [TRACE] 2016-11-14 22:54:03, 70 luaConfigurator::doGetItem: Global property or script loglevel not found

                          [TRACE] 2016-11-14 22:54:03, 70 luaConfigurator::doGetItem: Global property or script loglevel not found

                          [TRACE] 2016-11-14 22:54:03, 77 luaConfigurator::doGetItem: Global property or script log_level not found

                          [TRACE] 2016-11-14 22:54:03, 79 luaConfigurator::doGetItem: Global property or script log_level not found

                          [TRACE] 2016-11-14 22:54:03, 79 luaConfigurator::doGetItem: Global property or script log_level not found

                          [TRACE] 2016-11-14 22:54:03, 81 luaConfigurator::setItem: log_level already set to TRACE.  Nothing to do.

                          [TRACE] 2016-11-14 22:54:03, 82 luaConfigurator::doGetItem: Global property or script script_directory not found

                          [TRACE] 2016-11-14 22:54:03, 84 luaConfigurator::doGetItem: Global property or script script_directory not found

                          [TRACE] 2016-11-14 22:54:03, 86 luaConfigurator::doGetItem: Global property or script script_resource_port not found

                          [TRACE] 2016-11-14 22:54:03, 87 luaConfigurator::doGetItem: Global property or script script_resource_host not found

                          [TRACE] 2016-11-14 22:54:03, 88 luaConfigurator::doGetItem: Global property or script max_clients not found

                          [TRACE] 2016-11-14 22:54:03, 88 luaConfigurator::doGetItem: Global property or script max_clients not found

                          [TRACE] 2016-11-14 22:54:03, 88 luaConfigurator::doGetItem: Global property or script script_resource_port not found

                          [TRACE] 2016-11-14 22:54:03, 92 luaConfigurator::doGetItem: Global property or script script_resource_host not found

                          [TRACE] 2016-11-14 22:54:03, 92 luaConfigurator::doGetItem: Global property or script script_resource_ssl not found

                          [TRACE] 2016-11-14 22:54:03, 92 luaConfigurator::doGetItem: Global property or script script_resource_ssl not found

                          [TRACE] 2016-11-14 22:54:03, 96 luaConfigurator::doGetItem: Global property or script script_resource_cert not found

                          [TRACE] 2016-11-14 22:54:03, 96 luaConfigurator::doGetItem: Global property or script script_resource_cert not found

                          [TRACE] 2016-11-14 22:54:03,100 luaConfigurator::doGetItem: Global property or script script_resource_userid not found

                          [TRACE] 2016-11-14 22:54:03,100 luaConfigurator::doGetItem: Global property or script script_resource_userid not found

                          [TRACE] 2016-11-14 22:54:03,100 luaConfigurator::doGetItem: Global property or script script_resource_password not found

                          [TRACE] 2016-11-14 22:54:03,100 luaConfigurator::doGetItem: Global property or script script_resource_password not found

                          [TRACE] 2016-11-14 22:54:03,104 luaConfigurator::doGetItem: Global property or script index_page not found

                          [TRACE] 2016-11-14 22:54:03,104 luaConfigurator::doGetItem: Global property or script index_page not found

                          [TRACE] 2016-11-14 22:54:03,104 luaConfigurator::doGetItem: Global property or script new_script_page not found

                          [TRACE] 2016-11-14 22:54:03,104 luaConfigurator::doGetItem: Global property or script new_script_page not found

                          [TRACE] 2016-11-14 22:54:03,108 luaConfigurator::getFilteredConfigData: Getting config data filtered by script

                          [TRACE] 2016-11-14 22:54:03,108 luaConfigurator::getFilteredConfigData: Checking config data filtered by script (Pass 1)

                          [TRACE] 2016-11-14 22:54:03,112 luaConfigurator::getFilteredConfigData: Checking config data filtered by script (Persisted Pass 2)

                          [TRACE] 2016-11-14 22:54:03,112 luaConfigurator::getFilteredConfigData: Getting config data filtered by sample

                          [TRACE] 2016-11-14 22:54:03,112 luaConfigurator::getFilteredConfigData: Checking config data filtered by sample (Pass 1)

                          [TRACE] 2016-11-14 22:54:03,112 luaConfigurator::doGetItem: Global property or script sample not found

                          [TRACE] 2016-11-14 22:54:03,112 luaConfigurator::getFilteredConfigData: Checking config data filtered by sample (Persisted Pass 2)

                          [TRACE] 2016-11-14 22:54:03,116 luaConfigurator::doGetItem: Global property or script config_file_path not found

                          [DEBUG] 2016-11-14 22:54:03,116 ScriptResource::addScript: File C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\thingworx\scripts\sample.lua does not exist. Using custom script directory

                          [DEBUG] 2016-11-14 22:54:03,116 luaScriptProxy: Constructor Called

                          [TRACE] 2016-11-14 22:54:03,120 luaConfigurator::getFilteredConfigData: Getting config data filtered by _GLOBAL_

                          [TRACE] 2016-11-14 22:54:03,120 luaConfigurator::getFilteredConfigData: Checking config data filtered by _GLOBAL_ (Pass 1)

                          [TRACE] 2016-11-14 22:54:03,120 luaConfigurator::doGetItem: Global property or script log_level not found

                          [TRACE] 2016-11-14 22:54:03,123 luaConfigurator::doGetItem: Global property or script script_resource_port not found

                          [TRACE] 2016-11-14 22:54:03,123 luaConfigurator::doGetItem: Global property or script script_resource_host not found

                          [TRACE] 2016-11-14 22:54:03,123 luaConfigurator::doGetItem: Global property or script script_clib_path not found

                          [TRACE] 2016-11-14 22:54:03,127 luaConfigurator::doGetItem: Global property or script script_library_path not found

                          [TRACE] 2016-11-14 22:54:03,127 luaConfigurator::doGetItem: Global property or script scanRate not found

                          [TRACE] 2016-11-14 22:54:03,127 luaConfigurator::doGetItem: Global property or script script_directory not found

                          [TRACE] 2016-11-14 22:54:03,127 luaConfigurator::doGetItem: Global property or script rap_port not found

                          [TRACE] 2016-11-14 22:54:03,127 luaConfigurator::doGetItem: Global property or script rap_host not found

                          [TRACE] 2016-11-14 22:54:03,131 luaConfigurator::doGetItem: Global property or script config_file_path not found

                          [TRACE] 2016-11-14 22:54:03,131 luaConfigurator::getFilteredConfigData: Checking config data filtered by _GLOBAL_ (Persisted Pass 2)

                          [TRACE] 2016-11-14 22:54:03,135 luaConfigurator::getFilteredConfigData: Getting config data filtered by script

                          [TRACE] 2016-11-14 22:54:03,135 luaConfigurator::getFilteredConfigData: Checking config data filtered by script (Pass 1)

                          [TRACE] 2016-11-14 22:54:03,135 luaConfigurator::getFilteredConfigData: Checking config data filtered by script (Persisted Pass 2)

                          [TRACE] 2016-11-14 22:54:03,135 luaConfigurator::doGetItem: Global property or script script_clib_path not found

                          [TRACE] 2016-11-14 22:54:03,139 luaConfigurator::doGetItem: Global property or script script_library_path not found

                          [DEBUG] 2016-11-14 22:54:03,139 luaScriptProxy::initialize: Name = sample

                          File = C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\custom\scripts\sample.lua

                          LibraryPath = C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\?.lua;C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\thingworx\?.lua;C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\thingworx\lua\?.lua;C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\custom\?.lua;C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\custom\lua\?.lua;C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\community\lua\?.lua

                          InitData Ptr = 0

                           

                           

                          Persisted Props:

                          file = sample.lua

                           

                           

                          GlobalProps:

                          config_file_path = C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc

                          log_level = TRACE

                          rap_host = localhost

                          rap_port = 8000

                          scanRate = 10000

                          script_clib_path = C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\thingworx\clibs\?.dll;C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\custom\clibs\?.dll;C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\community\clibs\?.dll

                          script_directory = C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\custom\scripts

                          script_library_path = C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\?.lua;C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\thingworx\?.lua;C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\thingworx\lua\?.lua;C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\custom\?.lua;C:\Users\flyerqiu\Downl

                          [DEBUG] 2016-11-14 22:54:03,139 luaScriptProxy::runScript: Starting Script

                          [TRACE] 2016-11-14 22:54:03,139 luaConfigurator::doGetItem: Global property or script sample not found

                          [TRACE] 2016-11-14 22:54:03,139 luaConfigurator::setItem: script.sample already set to sample.lua.  Nothing to do.

                          [TRACE] 2016-11-14 22:54:03,143 luaConfigurator::doGetItem: Global property or script sample not found

                          [TRACE] 2016-11-14 22:54:03,143 luaConfigurator::setItem: sample.file already set to sample.lua.  Nothing to do.

                          [DEBUG] 2016-11-14 22:54:03,143 luaScriptProxy::getStatus: Script sample status = Ready

                          [TRACE] 2016-11-14 22:54:03,147 luaConfigurator::getFilteredConfigData: Getting config data filtered by TestRemoteThing1

                          [TRACE] 2016-11-14 22:54:03,147 luaConfigurator::getFilteredConfigData: Checking config data filtered by TestRemoteThing1 (Pass 1)

                          [TRACE] 2016-11-14 22:54:03,147 luaConfigurator::doGetItem: Global property or script TestRemoteThing1 not found

                          [TRACE] 2016-11-14 22:54:03,147 luaConfigurator::doGetItem: Global property or script TestRemoteThing1 not found

                          [TRACE] 2016-11-14 22:54:03,151 luaConfigurator::doGetItem: Global property or script TestRemoteThing1 not found

                          [TRACE] 2016-11-14 22:54:03,151 luaConfigurator::doGetItem: Global property or script TestRemoteThing1 not found

                          [TRACE] 2016-11-14 22:54:03,151 luaConfigurator::getFilteredConfigData: Checking config data filtered by TestRemoteThing1 (Persisted Pass 2)

                          [TRACE] 2016-11-14 22:54:03,151 luaConfigurator::doGetItem: Global property or script config_file_path not found

                          [DEBUG] 2016-11-14 22:54:03,151 luaScriptProxy: Constructor Called

                          [TRACE] 2016-11-14 22:54:03,155 luaConfigurator::getFilteredConfigData: Getting config data filtered by _GLOBAL_

                          [TRACE] 2016-11-14 22:54:03,155 luaConfigurator::getFilteredConfigData: Checking config data filtered by _GLOBAL_ (Pass 1)

                          [TRACE] 2016-11-14 22:54:03,155 luaConfigurator::doGetItem: Global property or script log_level not found

                          [TRACE] 2016-11-14 22:54:03,159 luaConfigurator::doGetItem: Global property or script script_resource_port not found

                          [TRACE] 2016-11-14 22:54:03,159 luaConfigurator::doGetItem: Global property or script script_resource_host not found

                          [TRACE] 2016-11-14 22:54:03,159 luaConfigurator::doGetItem: Global property or script script_clib_path not found

                          [TRACE] 2016-11-14 22:54:03,159 luaConfigurator::doGetItem: Global property or script script_library_path not found

                          [TRACE] 2016-11-14 22:54:03,159 luaConfigurator::doGetItem: Global property or script scanRate not found

                          [TRACE] 2016-11-14 22:54:03,159 luaConfigurator::doGetItem: Global property or script script_directory not found

                          [TRACE] 2016-11-14 22:54:03,163 luaConfigurator::doGetItem: Global property or script rap_port not found

                          [TRACE] 2016-11-14 22:54:03,163 luaConfigurator::doGetItem: Global property or script rap_host not found

                          [TRACE] 2016-11-14 22:54:03,163 luaConfigurator::doGetItem: Global property or script config_file_path not found

                          [TRACE] 2016-11-14 22:54:03,163 luaConfigurator::getFilteredConfigData: Checking config data filtered by _GLOBAL_ (Persisted Pass 2)

                          [TRACE] 2016-11-14 22:54:03,166 luaConfigurator::getFilteredConfigData: Getting config data filtered by script

                          [TRACE] 2016-11-14 22:54:03,166 luaConfigurator::getFilteredConfigData: Checking config data filtered by script (Pass 1)

                          [TRACE] 2016-11-14 22:54:03,170 luaConfigurator::getFilteredConfigData: Checking config data filtered by script (Persisted Pass 2)

                          [TRACE] 2016-11-14 22:54:03,170 luaConfigurator::doGetItem: Global property or script script_clib_path not found

                          [TRACE] 2016-11-14 22:54:03,170 luaConfigurator::doGetItem: Global property or script script_library_path not found

                          [DEBUG] 2016-11-14 22:54:03,170 luaScriptProxy::initialize: Name = TestRemoteThing1

                          File = C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\thingworx\scripts\thing.lua

                          LibraryPath = C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\?.lua;C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\thingworx\?.lua;C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\thingworx\lua\?.lua;C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\custom\?.lua;C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\custom\lua\?.lua;C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\community\lua\?.lua

                          InitData Ptr = 0

                           

                           

                          Persisted Props:

                          file = thing.lua

                          identifier = TestRemoteThing1

                          template = example

                          updateRate = 2000

                           

                           

                          GlobalProps:

                          config_file_path = C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc

                          log_level = TRACE

                          rap_host = localhost

                          rap_port = 8000

                          scanRate = 10000

                          script_clib_path = C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\thingworx\clibs\?.dll;C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\custom\clibs\?.dll;C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\community\clibs\?.dll

                          script_directory = C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\custom\scripts

                          script_library_path = C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\?.lua;C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\thingworx\?.lua;C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\thingworx\lua\?.lua;C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_Mic

                          [DEBUG] 2016-11-14 22:54:03,170 luaScriptProxy::runScript: Starting Script

                          [TRACE] 2016-11-14 22:54:03,175 luaConfigurator::doGetItem: Global property or script TestRemoteThing1 not found

                          [TRACE] 2016-11-14 22:54:03,176 luaConfigurator::setItem: script.TestRemoteThing1 already set to thing.lua.  Nothing to do.

                          [TRACE] 2016-11-14 22:54:03,176 luaConfigurator::doGetItem: Global property or script TestRemoteThing1 not found

                          [TRACE] 2016-11-14 22:54:03,177 luaConfigurator::setItem: TestRemoteThing1.file already set to thing.lua.  Nothing to do.

                          [TRACE] 2016-11-14 22:54:03,179 luaConfigurator::doGetItem: Global property or script TestRemoteThing1 not found

                          [TRACE] 2016-11-14 22:54:03,180 luaConfigurator::setItem: TestRemoteThing1.identifier already set to TestRemoteThing1.  Nothing to do.

                          [TRACE] 2016-11-14 22:54:03,181 luaConfigurator::doGetItem: Global property or script TestRemoteThing1 not found

                          [TRACE] 2016-11-14 22:54:03,182 luaConfigurator::setItem: TestRemoteThing1.template already set to example.  Nothing to do.

                          [TRACE] 2016-11-14 22:54:03,183 luaConfigurator::doGetItem: Global property or script TestRemoteThing1 not found

                          [TRACE] 2016-11-14 22:54:03,185 luaConfigurator::setItem: TestRemoteThing1.updateRate already set to 2000.  Nothing to do.

                          [DEBUG] 2016-11-14 22:54:03,185 luaScriptProxy::getStatus: Script TestRemoteThing1 status = Ready

                          [TRACE] 2016-11-14 22:54:03,186 luaConfigurator::getFilteredConfigData: Getting config data filtered by Thingworx

                          [TRACE] 2016-11-14 22:54:03,187 luaConfigurator::getFilteredConfigData: Checking config data filtered by Thingworx (Pass 1)

                          [TRACE] 2016-11-14 22:54:03,188 luaConfigurator::getFilteredConfigData: Checking config data filtered by Thingworx (Persisted Pass 2)

                          [TRACE] 2016-11-14 22:54:03,188 luaConfigurator::doGetItem: Global property or script config_file_path not found

                          [DEBUG] 2016-11-14 22:54:03,188 luaScriptProxy: Constructor Called

                          [TRACE] 2016-11-14 22:54:03,188 luaConfigurator::getFilteredConfigData: Getting config data filtered by _GLOBAL_

                          [TRACE] 2016-11-14 22:54:03,188 luaConfigurator::getFilteredConfigData: Checking config data filtered by _GLOBAL_ (Pass 1)

                          [TRACE] 2016-11-14 22:54:03,192 luaConfigurator::doGetItem: Global property or script log_level not found

                          [TRACE] 2016-11-14 22:54:03,192 luaConfigurator::doGetItem: Global property or script script_resource_port not found

                          [TRACE] 2016-11-14 22:54:03,196 luaConfigurator::doGetItem: Global property or script script_resource_host not found

                          [TRACE] 2016-11-14 22:54:03,196 luaConfigurator::doGetItem: Global property or script script_clib_path not found

                          [TRACE] 2016-11-14 22:54:03,196 luaConfigurator::doGetItem: Global property or script script_library_path not found

                          [TRACE] 2016-11-14 22:54:03,196 luaConfigurator::doGetItem: Global property or script scanRate not found

                          [TRACE] 2016-11-14 22:54:03,196 luaConfigurator::doGetItem: Global property or script script_directory not found

                          [TRACE] 2016-11-14 22:54:03,200 luaConfigurator::doGetItem: Global property or script rap_port not found

                          [TRACE] 2016-11-14 22:54:03,200 luaConfigurator::doGetItem: Global property or script rap_host not found

                          [TRACE] 2016-11-14 22:54:03,200 luaConfigurator::doGetItem: Global property or script config_file_path not found

                          [TRACE] 2016-11-14 22:54:03,200 luaConfigurator::getFilteredConfigData: Checking config data filtered by _GLOBAL_ (Persisted Pass 2)

                          [TRACE] 2016-11-14 22:54:03,200 luaConfigurator::getFilteredConfigData: Getting config data filtered by script

                          [TRACE] 2016-11-14 22:54:03,200 luaConfigurator::getFilteredConfigData: Checking config data filtered by script (Pass 1)

                          [TRACE] 2016-11-14 22:54:03,200 luaConfigurator::getFilteredConfigData: Checking config data filtered by script (Persisted Pass 2)

                          [TRACE] 2016-11-14 22:54:03,200 luaConfigurator::doGetItem: Global property or script script_clib_path not found

                          [TRACE] 2016-11-14 22:54:03,200 luaConfigurator::doGetItem: Global property or script script_library_path not found

                          [DEBUG] 2016-11-14 22:54:03,200 luaScriptProxy::initialize: Name = Thingworx

                          File = C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\thingworx\scripts\thingworx.lua

                          LibraryPath = C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\?.lua;C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\thingworx\?.lua;C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\thingworx\lua\?.lua;C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\custom\?.lua;C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\custom\lua\?.lua;C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\community\lua\?.lua

                          InitData Ptr = 0

                           

                           

                          Persisted Props:

                          file = thingworx.lua

                          max_run_time = 20

                           

                           

                          GlobalProps:

                          config_file_path = C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc

                          log_level = TRACE

                          rap_host = localhost

                          rap_port = 8000

                          scanRate = 10000

                          script_clib_path = C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\thingworx\clibs\?.dll;C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\custom\clibs\?.dll;C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\community\clibs\?.dll

                          script_directory = C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\custom\scripts

                          script_library_path = C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\?.lua;C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\thingworx\?.lua;C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\thingworx\lua\?.lua;C:\Users\flyerqiu\Downloads\MED-61060-CD-053_M010_MicroServer-5-3-1-1113-Win32\microserver\etc\custom

                          [DEBUG] 2016-11-14 22:54:03,200 luaScriptProxy::runScript: Starting Script

                          [TRACE] 2016-11-14 22:54:03,200 luaConfigurator::setItem: script.Thingworx already set to thingworx.lua.  Nothing to do.

                          [TRACE] 2016-11-14 22:54:03,200 luaConfigurator::setItem: Thingworx.file already set to thingworx.lua.  Nothing to do.

                          [TRACE] 2016-11-14 22:54:03,200 luaConfigurator::setItem: Thingworx.max_run_time already set to 20.  Nothing to do.

                          [DEBUG] 2016-11-14 22:54:03,200 luaScriptProxy::getStatus: Script Thingworx status = Ready

                          [TRACE] 2016-11-14 22:54:03,200 luaConfigurator::getFilteredConfigData: Getting config data filtered by script

                          [TRACE] 2016-11-14 22:54:03,200 luaConfigurator::getFilteredConfigData: Checking config data filtered by script (Pass 1)

                          [TRACE] 2016-11-14 22:54:03,200 luaConfigurator::getFilteredConfigData: Checking config data filtered by script (Persisted Pass 2)

                          [TRACE] 2016-11-14 22:54:03,200 luaConfigurator::getFilteredConfigData: Getting config data filtered by sample

                          [TRACE] 2016-11-14 22:54:03,200 luaConfigurator::getFilteredConfigData: Checking config data filtered by sample (Pass 1)

                          [TRACE] 2016-11-14 22:54:03,200 luaConfigurator::doGetItem: Global property or script sample not found

                          [TRACE] 2016-11-14 22:54:03,200 luaConfigurator::getFilteredConfigData: Checking config data filtered by sample (Persisted Pass 2)

                          [TRACE] 2016-11-14 22:54:03,200 luaConfigurator::getFilteredConfigData: Getting config data filtered by TestRemoteThing1

                          [TRACE] 2016-11-14 22:54:03,200 luaConfigurator::getFilteredConfigData: Checking config data filtered by TestRemoteThing1 (Pass 1)

                          [TRACE] 2016-11-14 22:54:03,200 luaConfigurator::doGetItem: Global property or script TestRemoteThing1 not found

                          [TRACE] 2016-11-14 22:54:03,200 luaConfigurator::doGetItem: Global property or script TestRemoteThing1 not found

                          [TRACE] 2016-11-14 22:54:03,200 luaConfigurator::doGetItem: Global property or script TestRemoteThing1 not found

                          [TRACE] 2016-11-14 22:54:03,200 luaConfigurator::doGetItem: Global property or script TestRemoteThing1 not found

                          [TRACE] 2016-11-14 22:54:03,200 luaConfigurator::getFilteredConfigData: Checking config data filtered by TestRemoteThing1 (Persisted Pass 2)

                          [TRACE] 2016-11-14 22:54:03,200 luaConfigurator::getFilteredConfigData: Getting config data filtered by Thingworx

                          [TRACE] 2016-11-14 22:54:03,200 luaConfigurator::getFilteredConfigData: Script sample now executing

                          [DEBUG] 2016-11-14 22:54:03,200 luaScriptProxy::execute: Script sample now executing

                          [DEBUG] 2016-11-14 22:54:03,200 luaScriptProxy::execute: Checking config data filtered by Thingworx (Persisted Pass 2)

                          [TRACE] 2016-11-14 22:54:03,200 luaConfigurator::getFilteredConfigData: Checking config data filtered by Thingworx (Persisted Pass 2)

                          [DEBUG] 2016-11-14 22:54:03,200 luaScriptProxy::execute: Script Thingworx now executing

                          [FORCE] 2016-11-14 22:54:03,200 httpServer: starting http server port=8001

                          [DEBUG] 2016-11-14 22:54:03,200 ScriptResource::registerScriptCallback: Registered path /scripts/Thingworx/ with callback handle_request

                          [DEBUG] 2016-11-14 22:54:03,200 luaHttpBinding::l_registerCallback: Registered path '/' with callback 'handle_request' for script 'Thingworx'

                          [DEBUG] 2016-11-14 22:54:03,200 ScriptResource::registerScriptCallback: Registered path /scripts/Thingworx/registerIdentifier/ with callback register_identifier

                          [DEBUG] 2016-11-14 22:54:03,200 luaHttpBinding::l_registerCallback: Registered path '/registerIdentifier' with callback 'register_identifier' for script 'Thingworx'

                          [DEBUG] 2016-11-14 22:54:03,200 utils: Adding utils functions to tw_utils

                          [INFO ] 2016-11-14 22:54:03,200 sample: Registering HTTP callbacks

                          [DEBUG] 2016-11-14 22:54:03,200 ScriptResource::registerScriptCallback: Registered path /scripts/sample/property/number/ with callback property_number

                          [DEBUG] 2016-11-14 22:54:03,200 utils: Registered path '/property/number'

                          [DEBUG] 2016-11-14 22:54:03,200 luaHttpBinding::l_registerCallback: Registered path '/property/number' with callback 'property_number' for script 'sample'

                          [DEBUG] 2016-11-14 22:54:03,200 ScriptResource::registerScriptCallback: Registered path /scripts/sample/property/string/ with callback property_string

                          [DEBUG] 2016-11-14 22:54:03,200 luaHttpBinding::l_registerCallback: Registered path '/property/string' with callback 'property_string' for script 'sample'

                          [DEBUG] 2016-11-14 22:54:03,200 ScriptResource::registerScriptCallback: Registered path /scripts/sample/property/boolean/ with callback property_boolean

                          [DEBUG] 2016-11-14 22:54:03,200 luaHttpBinding::l_registerCallback: Registered path '/property/boolean' with callback 'property_boolean' for script 'sample'

                          [DEBUG] 2016-11-14 22:54:03,200 ScriptResource::registerScriptCallback: Registered path /scripts/sample/property/datetime/ with callback property_datetime

                          [DEBUG] 2016-11-14 22:54:03,200 luaHttpBinding::l_registerCallback: Registered path '/property/datetime' with callback 'property_datetime' for script 'sample'

                          [DEBUG] 2016-11-14 22:54:03,200 ScriptResource::registerScriptCallback: Registered path /scripts/sample/property/location/ with callback property_location

                          [DEBUG] 2016-11-14 22:54:03,200 luaHttpBinding::l_registerCallback: Registered path '/property/location' with callback 'property_location' for script 'sample'

                          [DEBUG] 2016-11-14 22:54:03,200 ScriptResource::registerScriptCallback: Registered path /scripts/sample/property/xml/ with callback property_xml

                          [DEBUG] 2016-11-14 22:54:03,200 luaHttpBinding::l_registerCallback: Registered path '/property/xml' with callback 'property_xml' for script 'sample'

                          [DEBUG] 2016-11-14 22:54:03,200 ScriptResource::registerScriptCallback: Registered path /scripts/sample/generate/json/ with callback generate_json

                          [DEBUG] 2016-11-14 22:54:03,200 luaHttpBinding::l_registerCallback: Registered path '/generate/json' with callback 'generate_json' for script 'sample'

                          [DEBUG] 2016-11-14 22:54:03,200 ScriptResource::registerScriptCallback: Registered path /scripts/sample/generate/xml/ with callback generate_xml

                          [DEBUG] 2016-11-14 22:54:03,200 luaHttpBinding::l_registerCallback: Registered path '/generate/xml' with callback 'generate_xml' for script 'sample'

                          [DEBUG] 2016-11-14 22:54:03,200 ScriptResource::registerScriptCallback: Registered path /scripts/sample/generate/text/ with callback generate_text

                          [DEBUG] 2016-11-14 22:54:03,200 luaHttpBinding::l_registerCallback: Registered path '/generate/text' with callback 'generate_text' for script 'sample'

                          [INFO ] 2016-11-14 22:54:03,200 sample: Beginning main loop

                          [INFO ] 2016-11-14 22:54:03,200 thingworx.shape: Creating a new shape.

                          [INFO ] 2016-11-14 22:54:03,203 TestRemoteThing1: -- Configuration -------------------------------

                          [INFO ] 2016-11-14 22:54:03,203 TestRemoteThing1: scanRate: 10000

                          [INFO ] 2016-11-14 22:54:03,203 TestRemoteThing1: scanRateResolution: 500

                          [INFO ] 2016-11-14 22:54:03,203 TestRemoteThing1: taskRate: 15000

                          [INFO ] 2016-11-14 22:54:03,203 TestRemoteThing1: keepAliveRate: 60000

                          [INFO ] 2016-11-14 22:54:03,203 TestRemoteThing1: requestTimeout: 15000

                          [INFO ] 2016-11-14 22:54:03,203 TestRemoteThing1: registerRate: 43200000

                          [INFO ] 2016-11-14 22:54:03,203 TestRemoteThing1: register: true

                          [INFO ] 2016-11-14 22:54:03,203 TestRemoteThing1: getPropertySubscriptionOnReconnect: false

                          [INFO ] 2016-11-14 22:54:03,203 TestRemoteThing1: maxConcurrentPropertyUpdates: 100

                          [INFO ] 2016-11-14 22:54:03,203 TestRemoteThing1: defaultPushType: VALUE

                          [INFO ] 2016-11-14 22:54:03,203 TestRemoteThing1: useShapes: true

                          [INFO ] 2016-11-14 22:54:03,203 TestRemoteThing1: identifier: TestRemoteThing1

                          [INFO ] 2016-11-14 22:54:03,203 TestRemoteThing1: ------------------------------------------------

                          [INFO ] 2016-11-14 22:54:03,203 thingworx.template: Adding shape 'shapes.metadata' to template 'thingworx.template'

                          [INFO ] 2016-11-14 22:54:03,203 thingworx.template: Adding shape 'shapes.propsubscribe' to template 'thingworx.template'

                          [DEBUG] 2016-11-14 22:54:03,203 tw_infoTable:luaInfoTable::addAspectsFromTable: Invalid or missing parameter

                          [DEBUG] 2016-11-14 22:54:03,203 tw_infoTable:luaInfoTable::addAspectsFromTable: Invalid or missing parameter

                          [TRACE] 2016-11-14 22:54:03,203 l_dsAddField: Added field to datashape

                          [TRACE] 2016-11-14 22:54:03,203 l_dsAddField: Added field to datashape

                          [DEBUG] 2016-11-14 22:54:03,203 tw_infoTable:luaInfoTable::addAspectsFromTable: Invalid or missing parameter

                          [TRACE] 2016-11-14 22:54:03,203 l_dsAddField: Added field to datashape

                          [DEBUG] 2016-11-14 22:54:03,203 tw_infoTable:luaInfoTable::addAspectsFromTable: Invalid or missing parameter

                          [TRACE] 2016-11-14 22:54:03,203 l_dsAddField: Added field to datashape

                          [DEBUG] 2016-11-14 22:54:03,203 tw_infoTable:luaInfoTable::addAspectsFromTable: Invalid or missing parameter

                          [DEBUG] 2016-11-14 22:54:03,203 tw_infoTable:luaInfoTable::addAspectsFromTable: Invalid or missing parameter

                          [TRACE] 2016-11-14 22:54:03,203 l_dsAddField: Added field to datashape

                          [DEBUG] 2016-11-14 22:54:03,203 tw_infoTable:luaInfoTable::addAspectsFromTable: Invalid or missing parameter

                          [DEBUG] 2016-11-14 22:54:03,203 tw_infoTable:luaInfoTable::addAspectsFromTable: Invalid or missing parameter

                          [TRACE] 2016-11-14 22:54:03,203 l_dsAddField: Added field to datashape

                          [DEBUG] 2016-11-14 22:54:03,203 tw_infoTable:luaInfoTable::addAspectsFromTable: Invalid or missing parameter

                          [TRACE] 2016-11-14 22:54:03,203 l_dsAddField: Added field to datashape

                          [DEBUG] 2016-11-14 22:54:03,203 tw_infoTable:luaInfoTable::addAspectsFromTable: Invalid or missing parameter

                          [TRACE] 2016-11-14 22:54:03,203 l_dsAddField: Added field to datashape

                          [DEBUG] 2016-11-14 22:54:03,203 tw_infoTable:luaInfoTable::addAspectsFromTable: Invalid or missing parameter

                          [TRACE] 2016-11-14 22:54:03,203 l_dsAddField: Added field to datashape

                          [DEBUG] 2016-11-14 22:54:03,203 tw_infoTable:luaInfoTable::addAspectsFromTable: Invalid or missing parameter

                          [TRACE] 2016-11-14 22:54:03,203 l_dsAddField: Added field to datashape

                          [DEBUG] 2016-11-14 22:54:03,203 tw_infoTable:luaInfoTable::addAspectsFromTable: Invalid or missing parameter

                          [TRACE] 2016-11-14 22:54:03,203 l_dsAddField: Added field to datashape

                          [DEBUG] 2016-11-14 22:54:03,203 tw_infoTable:luaInfoTable::addAspectsFromTable: Invalid or missing parameter

                          [TRACE] 2016-11-14 22:54:03,203 l_dsAddField: Added field to datashape

                          [DEBUG] 2016-11-14 22:54:03,203 tw_infoTable:luaInfoTable::addAspectsFromTable: Invalid or missing parameter

                          [TRACE] 2016-11-14 22:54:03,203 l_dsAddField: Added field to datashape

                          [DEBUG] 2016-11-14 22:54:03,203 tw_infoTable:luaInfoTable::addAspectsFromTable: Invalid or missing parameter

                          [TRACE] 2016-11-14 22:54:03,203 l_dsAddField: Added field to datashape

                          [DEBUG] 2016-11-14 22:54:03,207 tw_infoTable:luaInfoTable::addAspectsFromTable: Invalid or missing parameter

                          [TRACE] 2016-11-14 22:54:03,207 l_dsAddField: Added field to datashape

                          [DEBUG] 2016-11-14 22:54:03,207 tw_infoTable:luaInfoTable::addAspectsFromTable: Invalid or missing parameter

                          [TRACE] 2016-11-14 22:54:03,207 l_dsAddField: Added field to datashape

                          [DEBUG] 2016-11-14 22:54:03,207 tw_infoTable:luaInfoTable::addAspectsFromTable: Invalid or missing parameter

                          [TRACE] 2016-11-14 22:54:03,207 l_dsAddField: Added field to datashape

                          [DEBUG] 2016-11-14 22:54:03,207 tw_infoTable:luaInfoTable::addAspectsFromTable: Invalid or missing parameter

                          [TRACE] 2016-11-14 22:54:03,207 l_dsAddField: Added field to datashape

                          [DEBUG] 2016-11-14 22:54:03,207 tw_infoTable:luaInfoTable::addAspectsFromTable: Invalid or missing parameter

                          [TRACE] 2016-11-14 22:54:03,207 l_dsAddField: Added field to datashape

                          [DEBUG] 2016-11-14 22:54:03,207 tw_infoTable:luaInfoTable::addAspectsFromTable: Invalid or missing parameter

                          [TRACE] 2016-11-14 22:54:03,207 l_dsAddField: Added field to datashape

                          [DEBUG] 2016-11-14 22:54:03,207 tw_infoTable:luaInfoTable::addAspectsFromTable: Invalid or missing parameter

                          [TRACE] 2016-11-14 22:54:03,207 l_dsAddField: Added field to datashape

                          [DEBUG] 2016-11-14 22:54:03,207 tw_infoTable:luaInfoTable::addAspectsFromTable: Invalid or missing parameter

                          [TRACE] 2016-11-14 22:54:03,207 l_dsAddField: Added field to datashape

                          [DEBUG] 2016-11-14 22:54:03,207 tw_infoTable:luaInfoTable::addAspectsFromTable: Invalid or missing parameter

                          [TRACE] 2016-11-14 22:54:03,207 l_dsAddField: Added field to datashape

                          [DEBUG] 2016-11-14 22:54:03,207 tw_infoTable:luaInfoTable::addAspectsFromTable: Invalid or missing parameter

                          [DEBUG] 2016-11-14 22:54:03,207 tw_infoTable:luaInfoTable::addAspectsFromTable: Invalid or missing parameter

                          [TRACE] 2016-11-14 22:54:03,207 l_dsAddField: Added field to datashape

                          [DEBUG] 2016-11-14 22:54:03,207 tw_infoTable:luaInfoTable::addAspectsFromTable: Invalid or missing parameter

                          [TRACE] 2016-11-14 22:54:03,207 l_dsAddField: Added field to datashape

                          [DEBUG] 2016-11-14 22:54:03,207 tw_infoTable:luaInfoTable::addAspectsFromTable: Invalid or missing parameter

                          [TRACE] 2016-11-14 22:54:03,207 l_dsAddField: Added field to datashape

                          [INFO ] 2016-11-14 22:54:03,207 thingworx.template: Creating new templates.example named 'TestRemoteThing1'

                          [INFO ] 2016-11-14 22:54:03,207 TestRemoteThing1: -- Initializing properties ---------------------

                          [INFO ] 2016-11-14 22:54:03,207 TestRemoteThing1: Initialized property InMemory_Large_String [baseType: STRING, pushType: NEVER, handler: nil, value: Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem ipsum dolorsi Lorem i

                          [INFO ] 2016-11-14 22:54:03,207 TestRemoteThing1: Initialized property Pushed_InMemory_XML [baseType: XML, pushType: VALUE, handler: nil, value: <?xml version="1.0" encoding="utf-8" standalone="no"?><Root><Child>Test</Child></Root>]

                          [INFO ] 2016-11-14 22:54:03,207 thingworx.handler: Creating a new handler.

                          [TRACE] 2016-11-14 22:54:03,207 TestRemoteThing1: Found handler generator

                          [INFO ] 2016-11-14 22:54:03,207 TestRemoteThing1: Initialized property Pushed_Random_Number [baseType: NUMBER, pushType: VALUE, handler: generator, value: 0]

                          [INFO ] 2016-11-14 22:54:03,207 TestRemoteThing1: Initialized property InMemory_Datetime [baseType: DATETIME, pushType: NEVER, handler: nil, value: 1479135243000]

                          [INFO ] 2016-11-14 22:54:03,207 TestRemoteThing1: Initialized property InMemory_UserName [baseType: USERNAME, pushType: NEVER, handler: nil, value: UserName]

                          [INFO ] 2016-11-14 22:54:03,207 TestRemoteThing1: Initialized property Pushed_InMemory_Image [baseType: IMAGE, pushType: VALUE, handler: nil, value: ]

                          [INFO ] 2016-11-14 22:54:03,207 thingworx.handler: Creating a new handler.

                          [TRACE] 2016-11-14 22:54:03,207 TestRemoteThing1: Found handler script

                          [INFO ] 2016-11-14 22:54:03,207 TestRemoteThing1: Initialized property Script_Pushed_Boolean [baseType: BOOLEAN, pushType: ALWAYS, handler: script, value: 0]

                          [INFO ] 2016-11-14 22:54:03,207 TestRemoteThing1: Initialized property Pushed_InMemory_HTML [baseType: HTML, pushType: VALUE, handler: nil, value: <html><body><h1>Default Value</h1></body></html>]

                          [TRACE] 2016-11-14 22:54:03,207 TestRemoteThing1: Found handler generator

                          [INFO ] 2016-11-14 22:54:03,207 TestRemoteThing1: Initialized property Random_String [baseType: STRING, pushType: NEVER, handler: generator, value: ]

                          [TRACE] 2016-11-14 22:54:03,207 TestRemoteThing1: Found handler generator

                          [INFO ] 2016-11-14 22:54:03,207 TestRemoteThing1: Initialized property Pushed_Random_Location [baseType: LOCATION, pushType: ALWAYS, handler: generator, value: table: 0305BFB0]

                          [INFO ] 2016-11-14 22:54:03,207 TestRemoteThing1: Initialized property Pushed_InMemory_Query [baseType: QUERY, pushType: VALUE, handler: nil, value: {}]

                          [INFO ] 2016-11-14 22:54:03,207 TestRemoteThing1: Initialized property InMemory_String [baseType: STRING, pushType: NEVER, handler: nil, value: Default value 1]

                          [TRACE] 2016-11-14 22:54:03,207 TestRemoteThing1: Found handler generator

                          [INFO ] 2016-11-14 22:54:03,207 TestRemoteThing1: Initialized property Pushed_Random_String [baseType: STRING, pushType: ALWAYS, handler: generator, value: ]

                          [TRACE] 2016-11-14 22:54:03,207 TestRemoteThing1: Found handler generator

                          [INFO ] 2016-11-14 22:54:03,207 TestRemoteThing1: Initialized property Pushed_Random_DateTime [baseType: DATETIME, pushType: ALWAYS, handler: generator, value: 0]

                          [INFO ] 2016-11-14 22:54:03,207 TestRemoteThing1: Initialized property InMemory_Query [baseType: QUERY, pushType: NEVER, handler: nil, value: {}]

                          [INFO ] 2016-11-14 22:54:03,207 thingworx.handler: Creating a new handler.

                          [TRACE] 2016-11-14 22:54:03,207 TestRemoteThing1: Found handler http

                          [INFO ] 2016-11-14 22:54:03,207 TestRemoteThing1: Initialized property Script_Datetime [baseType: DATETIME, pushType: NEVER, handler: http, value: 0]

                          [INFO ] 2016-11-14 22:54:03,207 TestRemoteThing1: Initialized property Pushed_InMemory_Location [baseType: LOCATION, pushType: VALUE, handler: nil, value: table: 02E07CB8]

                          [INFO ] 2016-11-14 22:54:03,207 TestRemoteThing1: Initialized property InMemory_Image [baseType: IMAGE, pushType: NEVER, handler: nil, value: ]

                          [INFO ] 2016-11-14 22:54:03,207 TestRemoteThing1: Initialized property Pushed_InMemory_Hyperlink [baseType: HYPERLINK, pushType: VALUE, handler: nil, value: http://www.thingworx.com]

                          [INFO ] 2016-11-14 22:54:03,207 TestRemoteThing1: Initialized property SAF_Client_Number [baseType: NUMBER, pushType: VALUE, handler: nil, value: 0]

                          [INFO ] 2016-11-14 22:54:03,207 TestRemoteThing1: Initialized property InMemory_InfoTable [baseType: INFOTABLE, pushType: NEVER, handler: nil, value: table: 02E4C8C0]

                          [TRACE] 2016-11-14 22:54:03,207 TestRemoteThing1: Found handler generator

                          [INFO ] 2016-11-14 22:54:03,207 TestRemoteThing1: Initialized property Incrementing_Number [baseType: NUMBER, pushType: VALUE, handler: generator, value: 0]

                          [TRACE] 2016-11-14 22:54:03,207 TestRemoteThing1: Found handler generator

                          [INFO ] 2016-11-14 22:54:03,207 TestRemoteThing1: Initialized property Incrementing_DateTime [baseType: DATETIME, pushType: VALUE, handler: generator, value: 0]

                          [INFO ] 2016-11-14 22:54:03,207 TestRemoteThing1: Initialized property InMemory_XML [baseType: XML, pushType: NEVER, handler: nil, value: <?xml version="1.0" encoding="utf-8" standalone="no"?><Root><Child>Test</Child></Root>]

                          [TRACE] 2016-11-14 22:54:03,207 TestRemoteThing1: Found handler generator

                          [INFO ] 2016-11-14 22:54:03,207 TestRemoteThing1: Initialized property Pushed_Incrementing_Location [baseType: LOCATION, pushType: VALUE, handler: generator, value: table: 02E4BD58]

                          [INFO ] 2016-11-14 22:54:03,207 TestRemoteThing1: Initialized property Pushed_InMemory_MenuName [baseType: MENUNAME, pushType: VALUE, handler: nil, value: MenuName]

                          [INFO ] 2016-11-14 22:54:03,207 TestRemoteThing1: Initialized property InMemory_MashupName [baseType: MASHUPNAME, pushType: NEVER, handler: nil, value: MashupName]

                          [INFO ] 2016-11-14 22:54:03,207 TestRemoteThing1: Initialized property Pushed_InMemory_Text [baseType: TEXT, pushType: VALUE, handler: nil, value: Default value 1]

                          [INFO ] 2016-11-14 22:54:03,207 TestRemoteThing1: Initialized property InMemory_Location [baseType: LOCATION, pushType: NEVER, handler: nil, value: table: 02E07790]

                          [TRACE] 2016-11-14 22:54:03,207 TestRemoteThing1: Found handler generator

                          [INFO ] 2016-11-14 22:54:03,207 TestRemoteThing1: Initialized property AutoPush [baseType: INTEGER, pushType: VALUE, handler: generator, value: 0]

                          [INFO ] 2016-11-14 22:54:03,207 TestRemoteThing1: Initialized property InMemory_GroupName [baseType: GROUPNAME, pushType: NEVER, handler: nil, value: Administrators]

                          [INFO ] 2016-11-14 22:54:03,207 TestRemoteThing1: Initialized property Pushed_InMemory_Integer [baseType: INTEGER, pushType: VALUE, handler: nil, value: 1]

                          [INFO ] 2016-11-14 22:54:03,207 TestRemoteThing1: Initialized property InMemory_Text [baseType: TEXT, pushType: NEVER, handler: nil, value: Default value 1]

                          [INFO ] 2016-11-14 22:54:03,207 TestRemoteThing1: Initialized property InMemory_Json [baseType: JSON, pushType: NEVER, handler: nil, value: {}]

                          [TRACE] 2016-11-14 22:54:03,207 TestRemoteThing1: Found handler script

                          [INFO ] 2016-11-14 22:54:03,207 TestRemoteThing1: Initialized property Script_String [baseType: STRING, pushType: NEVER, handler: script, value: ]

                          [INFO ] 2016-11-14 22:54:03,207 TestRemoteThing1: Initialized property upToDate [baseType: BOOLEAN, pushType: NEVER, handler: nil, value: true]

                          [INFO ] 2016-11-14 22:54:03,207 TestRemoteThing1: Initialized property InMemory_HTML [baseType: HTML, pushType: NEVER, handler: nil, value: <html><body><h1>Default Value</h1></body></html>]

                          [INFO ] 2016-11-14 22:54:03,207 TestRemoteThing1: Initialized property Pushed_InMemory_Json [baseType: JSON, pushType: VALUE, handler: nil, value: {}]

                          [INFO ] 2016-11-14 22:54:03,207 TestRemoteThing1: Initialized property Pushed_InMemory_GroupName [baseType: GROUPNAME, pushType: VALUE, handler: nil, value: Administrators]

                          [INFO ] 2016-11-14 22:54:03,207 TestRemoteThing1: Initialized property Pushed_InMemory_Datetime [baseType: DATETIME, pushType: VALUE, handler: nil, value: 1479135243000]

                          [INFO ] 2016-11-14 22:54:03,207 TestRemoteThing1: Initialized property InMemory_Number [baseType: NUMBER, pushType: NEVER, handler: nil, value: 1]

                          [INFO ] 2016-11-14 22:54:03,207 TestRemoteThing1: Initialized property Pushed_InMemory_MashupName [baseType: MASHUPNAME, pushType: VALUE, handler: nil, value: MashupName]

                          [TRACE] 2016-11-14 22:54:03,207 TestRemoteThing1: Found handler script

                          [INFO ] 2016-11-14 22:54:03,207 TestRemoteThing1: Initialized property Script_Pushed_Location [baseType: LOCATION, pushType: ALWAYS, handler: script, value: table: 02E55660]

                          [TRACE] 2016-11-14 22:54:03,207 TestRemoteThing1: Found handler generator

                          [INFO ] 2016-11-14 22:54:03,207 TestRemoteThing1: Initialized property Random_Location [baseType: LOCATION, pushType: NEVER, handler: generator, value: table: 02E55610]

                          [TRACE] 2016-11-14 22:54:03,207 TestRemoteThing1: Found handler script

                          [INFO ] 2016-11-14 22:54:03,207 TestRemoteThing1: Initialized property Script_Number [baseType: NUMBER, pushType: NEVER, handler: script, value: 0]

                          [TRACE] 2016-11-14 22:54:03,207 TestRemoteThing1: Found handler script

                          [INFO ] 2016-11-14 22:54:03,207 TestRemoteThing1: Initialized property Script_Pushed_Datetime [baseType: DATETIME, pushType: ALWAYS, handler: script, value: 0]

                          [TRACE] 2016-11-14 22:54:03,207 TestRemoteThing1: Found handler script

                          [INFO ] 2016-11-14 22:54:03,211 TestRemoteThing1: Initialized property Script_Pushed_String [baseType: STRING, pushType: ALWAYS, handler: script, value: ]

                          [TRACE] 2016-11-14 22:54:03,211 TestRemoteThing1: Found handler script

                          [INFO ] 2016-11-14 22:54:03,211 TestRemoteThing1: Initialized property Script_Pushed_Number [baseType: NUMBER, pushType: ALWAYS, handler: script, value: 0]

                          [TRACE] 2016-11-14 22:54:03,211 TestRemoteThing1: Found handler http

                          [INFO ] 2016-11-14 22:54:03,211 TestRemoteThing1: Initialized property Script_Location [baseType: LOCATION, pushType: NEVER, handler: http, value: table: 02E564E8]

                          [TRACE] 2016-11-14 22:54:03,211 TestRemoteThing1: Found handler script

                          [INFO ] 2016-11-14 22:54:03,211 TestRemoteThing1: Initialized property Script_Boolean [baseType: BOOLEAN, pushType: NEVER, handler: script, value: 0]

                          [INFO ] 2016-11-14 22:54:03,211 TestRemoteThing1: Initialized property Pushed_InMemory_ThingName [baseType: THINGNAME, pushType: VALUE, handler: nil, value: ThingName]

                          [INFO ] 2016-11-14 22:54:03,211 TestRemoteThing1: Initialized property InMemory_Boolean [baseType: BOOLEAN, pushType: NEVER, handler: nil, value: true]

                          [INFO ] 2016-11-14 22:54:03,211 TestRemoteThing1: Initialized property Pushed_InMemory_Number [baseType: NUMBER, pushType: VALUE, handler: nil, value: 2]

                          [TRACE] 2016-11-14 22:54:03,211 TestRemoteThing1: Found handler generator

                          [INFO ] 2016-11-14 22:54:03,211 TestRemoteThing1: Initialized property Random_DateTime [baseType: DATETIME, pushType: NEVER, handler: generator, value: 0]

                          [INFO ] 2016-11-14 22:54:03,211 TestRemoteThing1: Initialized property InMemory_ThingName [baseType: THINGNAME, pushType: NEVER, handler: nil, value: ThingName]

                          [TRACE] 2016-11-14 22:54:03,211 TestRemoteThing1: Found handler generator

                          [INFO ] 2016-11-14 22:54:03,211 TestRemoteThing1: Initialized property Random_Number [baseType: NUMBER, pushType: NEVER, handler: generator, value: 0]

                          [INFO ] 2016-11-14 22:54:03,211 TestRemoteThing1: Initialized property InMemory_Hyperlink [baseType: HYPERLINK, pushType: NEVER, handler: nil, value: http://www.thingworx.com]

                          [TRACE] 2016-11-14 22:54:03,211 TestRemoteThing1: Found handler generator

                          [INFO ] 2016-11-14 22:54:03,211 TestRemoteThing1: Initialized property Pushed_Incrementing_DateTime [baseType: DATETIME, pushType: VALUE, handler: generator, value: 0]

                          [TRACE] 2016-11-14 22:54:03,211 TestRemoteThing1: Found handler generator

                          [INFO ] 2016-11-14 22:54:03,211 TestRemoteThing1: Initialized property Pushed_Square_Number [baseType: NUMBER, pushType: ALWAYS, handler: generator, value: 0]

                          [TRACE] 2016-11-14 22:54:03,211 TestRemoteThing1: Found handler generator

                          [INFO ] 2016-11-14 22:54:03,211 TestRemoteThing1: Initialized property Pushed_Incrementing_Number [baseType: NUMBER, pushType: VALUE, handler: generator, value: 0]

                          [INFO ] 2016-11-14 22:54:03,211 TestRemoteThing1: Initialized property Pushed_InMemory_Boolean [baseType: BOOLEAN, pushType: VALUE, handler: nil, value: false]

                          [TRACE] 2016-11-14 22:54:03,211 TestRemoteThing1: Found handler generator

                          [INFO ] 2016-11-14 22:54:03,211 TestRemoteThing1: Initialized property Pushed_Cos_Number [baseType: NUMBER, pushType: ALWAYS, handler: generator, value: 0]

                          [INFO ] 2016-11-14 22:54:03,211 TestRemoteThing1: Initialized property Pushed_InMemory_InfoTable [baseType: INFOTABLE, pushType: VALUE, handler: nil, value: table: 02E53360]

                          [TRACE] 2016-11-14 22:54:03,211 TestRemoteThing1: Found handler generator

                          [INFO ] 2016-11-14 22:54:03,211 TestRemoteThing1: Initialized property Pushed_Sin_Number [baseType: NUMBER, pushType: ALWAYS, handler: generator, value: 0]

                          [INFO ] 2016-11-14 22:54:03,211 TestRemoteThing1: Initialized property SAF_Server_Number [baseType: NUMBER, pushType: NEVER, handler: nil, value: 0]

                          [INFO ] 2016-11-14 22:54:03,211 TestRemoteThing1: Initialized property Pushed_InMemory_String [baseType: STRING, pushType: VALUE, handler: nil, value: Default value 2]

                          [INFO ] 2016-11-14 22:54:03,211 TestRemoteThing1: Initialized property ValidationString [baseType: STRING, pushType: VALUE, handler: nil, value: 00000000]

                          [INFO ] 2016-11-14 22:54:03,211 TestRemoteThing1: Initialized property Pushed_InMemory_Imagelink [baseType: IMAGELINK, pushType: VALUE, handler: nil, value: http://www.thingworx.com]

                          [INFO ] 2016-11-14 22:54:03,211 TestRemoteThing1: Initialized property InMemory_MenuName [baseType: MENUNAME, pushType: NEVER, handler: nil, value: MenuName]

                          [INFO ] 2016-11-14 22:54:03,211 TestRemoteThing1: Initialized property InMemory_Integer [baseType: INTEGER, pushType: NEVER, handler: nil, value: 1]

                          [INFO ] 2016-11-14 22:54:03,211 TestRemoteThing1: Initialized property InMemory_Imagelink [baseType: IMAGELINK, pushType: NEVER, handler: nil, value: http://www.thingworx.com]

                          [INFO ] 2016-11-14 22:54:03,211 TestRemoteThing1: Initialized property Pushed_InMemory_UserName [baseType: USERNAME, pushType: VALUE, handler: nil, value: UserName]

                          [INFO ] 2016-11-14 22:54:03,211 TestRemoteThing1: ------------------------------------------------

                          [DEBUG] 2016-11-14 22:54:03,211 luaScriptProxy::getStatus: Script sample status = Running

                          [DEBUG] 2016-11-14 22:54:03,211 luaScriptProxy::getStatus: Script TestRemoteThing1 status = Running

                          [DEBUG] 2016-11-14 22:54:03,211 luaScriptProxy::getStatus: Script Thingworx status = Running

                          [DEBUG] 2016-11-14 22:54:03,211 luaScriptProxy::getStatus: Script Thingworx status = Running

                          [TRACE] 2016-11-14 22:54:03,211 ScriptResource::executeScriptRequest: Checking path /scripts/

                          [TRACE] 2016-11-14 22:54:03,211 ScriptResource::executeScriptRequest: Checking path /scripts/Thingworx/

                          [DEBUG] 2016-11-14 22:54:03,211 ScriptResource::executeScriptRequest: Found callback handle_request for path /scripts/Thingworx/

                          [TRACE] 2016-11-14 22:54:03,211 ScriptResource::executeScriptRequest: Checking path /scripts/Thingworx/registerIdentifier/

                          [DEBUG] 2016-11-14 22:54:03,211 ScriptResource::executeScriptRequest: Found callback register_identifier for path /scripts/Thingworx/registerIdentifier/

                          [INFO ] 2016-11-14 22:54:03,211 Thingworx: Registering identifier *TestRemoteThing1 for thing TestRemoteThing1

                          [DEBUG] 2016-11-14 22:54:03,211 luaScriptProxy::executeScriptCallback: Executed POST request on register_identifier

                          [DEBUG] 2016-11-14 22:54:03,211 httpServer: http server bound to port=8001.

                          [INFO ] 2016-11-14 22:54:04, 97 TestRemoteThing1: Identifier *TestRemoteThing1 registered with main Thingworx script for for Thing TestRemoteThing1

                          [INFO ] 2016-11-14 22:54:07, 61 TestRemoteThing1: -- Starting script --------------------------

                          [INFO ] 2016-11-14 22:54:07, 61 TestRemoteThing1: Registering core callback handler

                          [DEBUG] 2016-11-14 22:54:07, 61 ScriptResource::registerScriptCallback: Registered path /scripts/TestRemoteThing1/ with callback core_handler

                          [DEBUG] 2016-11-14 22:54:07, 61 luaHttpBinding::l_registerCallback: Registered path '/' with callback 'core_handler' for script 'TestRemoteThing1'

                          [INFO ] 2016-11-14 22:54:07, 65 TestRemoteThing1: Starting main loop

                          [INFO ] 2016-11-14 22:54:07, 65 TestRemoteThing1: Calling lifecycle start listeners.

                          [DEBUG] 2016-11-14 22:54:07, 65 TestRemoteThing1: Executing lifecycle start event: handlers.http_open

                          [INFO ] 2016-11-14 22:54:07, 65 handlers.http: Opened

                          [DEBUG] 2016-11-14 22:54:07, 69 TestRemoteThing1: Executing lifecycle start event: handlers.script_open

                          [INFO ] 2016-11-14 22:54:07, 69 handlers.script: Opened

                          [DEBUG] 2016-11-14 22:54:07, 69 TestRemoteThing1: Executing lifecycle start event: handlers.generator_open

                          [INFO ] 2016-11-14 22:54:07, 69 handlers.generator: Opened

                          [DEBUG] 2016-11-14 22:54:07, 69 TestRemoteThing1: Executing lifecycle start event: shapes.propsubscribe_start

                          [INFO ] 2016-11-14 22:54:07, 73 shapes.propsubscribe: Initialized

                          [INFO ] 2016-11-14 22:54:07, 73 thingworx.handler: Creating a new handler.

                          [TRACE] 2016-11-14 22:54:07, 73 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:07, 78 TestRemoteThing1: Read property: Pushed_InMemory_XML

                          [TRACE] 2016-11-14 22:54:07, 79 TestRemoteThing1: Found handler generator

                          [TRACE] 2016-11-14 22:54:07, 81 TestRemoteThing1: Read property: Pushed_Random_Number

                          [TRACE] 2016-11-14 22:54:07, 82 utils::evaluateChange: Property Pushed_Random_Number change of 83 exceeds pushThreshold of 50

                          [TRACE] 2016-11-14 22:54:07, 83 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:07, 85 TestRemoteThing1: Read property: Pushed_InMemory_Image

                          [TRACE] 2016-11-14 22:54:07, 86 TestRemoteThing1: Found handler script

                          [DEBUG] 2016-11-14 22:54:07, 87 TestRemoteThing1: Executing property read via script handler. script: sample, path: property/boolean

                          [TRACE] 2016-11-14 22:54:07, 88 ScriptResource::executeScriptRequest: Checking path /scripts/

                          [TRACE] 2016-11-14 22:54:07, 89 ScriptResource::executeScriptRequest: Checking path /scripts/sample/

                          [TRACE] 2016-11-14 22:54:07, 89 ScriptResource::executeScriptRequest: Checking path /scripts/sample/property/

                          [TRACE] 2016-11-14 22:54:07, 90 ScriptResource::executeScriptRequest: Checking path /scripts/sample/property/boolean/

                          [DEBUG] 2016-11-14 22:54:07, 91 ScriptResource::executeScriptRequest: Found callback property_boolean for path /scripts/sample/property/boolean/

                          [DEBUG] 2016-11-14 22:54:07, 91 luaScriptProxy::executeScriptCallback: Executed GET request on property_boolean

                          [TRACE] 2016-11-14 22:54:07, 91 TestRemoteThing1: Read property: Script_Pushed_Boolean

                          [TRACE] 2016-11-14 22:54:07, 91 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:07, 91 TestRemoteThing1: Read property: Pushed_InMemory_HTML

                          [TRACE] 2016-11-14 22:54:07, 95 TestRemoteThing1: Found handler generator

                          [TRACE] 2016-11-14 22:54:07, 95 TestRemoteThing1: Read property: Pushed_Random_Location

                          [TRACE] 2016-11-14 22:54:07, 95 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:07, 99 TestRemoteThing1: Read property: Pushed_InMemory_Query

                          [TRACE] 2016-11-14 22:54:07, 99 TestRemoteThing1: Found handler generator

                          [TRACE] 2016-11-14 22:54:07, 99 TestRemoteThing1: Read property: Pushed_Random_String

                          [TRACE] 2016-11-14 22:54:07, 99 TestRemoteThing1: Found handler generator

                          [TRACE] 2016-11-14 22:54:07, 99 TestRemoteThing1: Read property: Pushed_Random_DateTime

                          [TRACE] 2016-11-14 22:54:07, 99 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:07,103 TestRemoteThing1: Read property: Pushed_InMemory_Location

                          [TRACE] 2016-11-14 22:54:07,103 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:07,103 TestRemoteThing1: Read property: Pushed_InMemory_Hyperlink

                          [TRACE] 2016-11-14 22:54:07,103 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:07,103 TestRemoteThing1: Read property: SAF_Client_Number

                          [TRACE] 2016-11-14 22:54:07,103 TestRemoteThing1: Found handler generator

                          [TRACE] 2016-11-14 22:54:07,106 TestRemoteThing1: Read property: Incrementing_Number

                          [TRACE] 2016-11-14 22:54:07,106 utils::evaluateChange: Property Incrementing_Number change of 11 exceeds pushThreshold of 0

                          [TRACE] 2016-11-14 22:54:07,106 TestRemoteThing1: Found handler generator

                          [TRACE] 2016-11-14 22:54:07,106 TestRemoteThing1: Read property: Incrementing_DateTime

                          [TRACE] 2016-11-14 22:54:07,110 TestRemoteThing1: Found handler generator

                          [TRACE] 2016-11-14 22:54:07,110 TestRemoteThing1: Read property: Pushed_Incrementing_Location

                          [TRACE] 2016-11-14 22:54:07,110 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:07,114 TestRemoteThing1: Read property: Pushed_InMemory_MenuName

                          [TRACE] 2016-11-14 22:54:07,114 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:07,114 TestRemoteThing1: Read property: Pushed_InMemory_Text

                          [TRACE] 2016-11-14 22:54:07,114 TestRemoteThing1: Found handler generator

                          [TRACE] 2016-11-14 22:54:07,114 TestRemoteThing1: Read property: AutoPush

                          [TRACE] 2016-11-14 22:54:07,118 utils::evaluateChange: Property AutoPush change of 1 exceeds pushThreshold of 0

                          [TRACE] 2016-11-14 22:54:07,118 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:07,118 TestRemoteThing1: Read property: Pushed_InMemory_Integer

                          [TRACE] 2016-11-14 22:54:07,122 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:07,122 TestRemoteThing1: Read property: Pushed_InMemory_Json

                          [TRACE] 2016-11-14 22:54:07,122 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:07,122 TestRemoteThing1: Read property: Pushed_InMemory_GroupName

                          [TRACE] 2016-11-14 22:54:07,122 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:07,126 TestRemoteThing1: Read property: Pushed_InMemory_Datetime

                          [TRACE] 2016-11-14 22:54:07,126 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:07,126 TestRemoteThing1: Read property: Pushed_InMemory_MashupName

                          [TRACE] 2016-11-14 22:54:07,126 TestRemoteThing1: Found handler script

                          [DEBUG] 2016-11-14 22:54:07,130 TestRemoteThing1: Executing property read via script handler. script: sample, path: property/location

                          [TRACE] 2016-11-14 22:54:07,130 ScriptResource::executeScriptRequest: Checking path /scripts/

                          [TRACE] 2016-11-14 22:54:07,130 ScriptResource::executeScriptRequest: Checking path /scripts/sample/

                          [TRACE] 2016-11-14 22:54:07,134 ScriptResource::executeScriptRequest: Checking path /scripts/sample/property/

                          [TRACE] 2016-11-14 22:54:07,134 ScriptResource::executeScriptRequest: Checking path /scripts/sample/property/location/

                          [DEBUG] 2016-11-14 22:54:07,134 ScriptResource::executeScriptRequest: Found callback property_location for path /scripts/sample/property/location/

                          [DEBUG] 2016-11-14 22:54:07,134 luaScriptProxy::executeScriptCallback: Executed GET request on property_location

                          [TRACE] 2016-11-14 22:54:07,134 TestRemoteThing1: Read property: Script_Pushed_Location

                          [TRACE] 2016-11-14 22:54:07,138 TestRemoteThing1: Found handler script

                          [DEBUG] 2016-11-14 22:54:07,138 TestRemoteThing1: Executing property read via script handler. script: sample, path: property/datetime

                          [TRACE] 2016-11-14 22:54:07,138 ScriptResource::executeScriptRequest: Checking path /scripts/

                          [TRACE] 2016-11-14 22:54:07,138 ScriptResource::executeScriptRequest: Checking path /scripts/sample/

                          [TRACE] 2016-11-14 22:54:07,138 ScriptResource::executeScriptRequest: Checking path /scripts/sample/property/

                          [TRACE] 2016-11-14 22:54:07,142 ScriptResource::executeScriptRequest: Checking path /scripts/sample/property/datetime/

                          [DEBUG] 2016-11-14 22:54:07,142 ScriptResource::executeScriptRequest: Found callback property_datetime for path /scripts/sample/property/datetime/

                          [DEBUG] 2016-11-14 22:54:07,142 luaScriptProxy::executeScriptCallback: Executed GET request on property_datetime

                          [TRACE] 2016-11-14 22:54:07,145 TestRemoteThing1: Read property: Script_Pushed_Datetime

                          [TRACE] 2016-11-14 22:54:07,145 TestRemoteThing1: Found handler script

                          [DEBUG] 2016-11-14 22:54:07,145 TestRemoteThing1: Executing property read via script handler. script: sample, path: property/string

                          [TRACE] 2016-11-14 22:54:07,145 ScriptResource::executeScriptRequest: Checking path /scripts/

                          [TRACE] 2016-11-14 22:54:07,145 ScriptResource::executeScriptRequest: Checking path /scripts/sample/

                          [TRACE] 2016-11-14 22:54:07,149 ScriptResource::executeScriptRequest: Checking path /scripts/sample/property/

                          [TRACE] 2016-11-14 22:54:07,149 ScriptResource::executeScriptRequest: Checking path /scripts/sample/property/string/

                          [DEBUG] 2016-11-14 22:54:07,149 ScriptResource::executeScriptRequest: Found callback property_string for path /scripts/sample/property/string/

                          [DEBUG] 2016-11-14 22:54:07,149 luaScriptProxy::executeScriptCallback: Executed GET request on property_string

                          [TRACE] 2016-11-14 22:54:07,149 TestRemoteThing1: Read property: Script_Pushed_String

                          [TRACE] 2016-11-14 22:54:07,153 TestRemoteThing1: Found handler script

                          [DEBUG] 2016-11-14 22:54:07,153 TestRemoteThing1: Executing property read via script handler. script: sample, path: property/number

                          [TRACE] 2016-11-14 22:54:07,157 ScriptResource::executeScriptRequest: Checking path /scripts/

                          [TRACE] 2016-11-14 22:54:07,157 ScriptResource::executeScriptRequest: Checking path /scripts/sample/

                          [TRACE] 2016-11-14 22:54:07,157 ScriptResource::executeScriptRequest: Checking path /scripts/sample/property/

                          [TRACE] 2016-11-14 22:54:07,157 ScriptResource::executeScriptRequest: Checking path /scripts/sample/property/number/

                          [DEBUG] 2016-11-14 22:54:07,161 ScriptResource::executeScriptRequest: Found callback property_number for path /scripts/sample/property/number/

                          [DEBUG] 2016-11-14 22:54:07,161 luaScriptProxy::executeScriptCallback: Executed GET request on property_number

                          [TRACE] 2016-11-14 22:54:07,161 TestRemoteThing1: Read property: Script_Pushed_Number

                          [TRACE] 2016-11-14 22:54:07,161 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:07,161 TestRemoteThing1: Read property: Pushed_InMemory_ThingName

                          [TRACE] 2016-11-14 22:54:07,165 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:07,165 TestRemoteThing1: Read property: Pushed_InMemory_Number

                          [TRACE] 2016-11-14 22:54:07,165 TestRemoteThing1: Found handler generator

                          [TRACE] 2016-11-14 22:54:07,169 TestRemoteThing1: Read property: Pushed_Incrementing_DateTime

                          [TRACE] 2016-11-14 22:54:07,169 TestRemoteThing1: Found handler generator

                          [TRACE] 2016-11-14 22:54:07,169 TestRemoteThing1: Read property: Pushed_Square_Number

                          [TRACE] 2016-11-14 22:54:07,169 TestRemoteThing1: Found handler generator

                          [TRACE] 2016-11-14 22:54:07,169 TestRemoteThing1: Read property: Pushed_Incrementing_Number

                          [TRACE] 2016-11-14 22:54:07,173 utils::evaluateChange: Property Pushed_Incrementing_Number change of 2 exceeds pushThreshold of 0

                          [TRACE] 2016-11-14 22:54:07,173 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:07,173 TestRemoteThing1: Read property: Pushed_InMemory_Boolean

                          [TRACE] 2016-11-14 22:54:07,173 TestRemoteThing1: Found handler generator

                          [TRACE] 2016-11-14 22:54:07,177 TestRemoteThing1: Read property: Pushed_Cos_Number

                          [TRACE] 2016-11-14 22:54:07,179 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:07,180 TestRemoteThing1: Read property: Pushed_InMemory_InfoTable

                          [TRACE] 2016-11-14 22:54:07,181 TestRemoteThing1: Found handler generator

                          [TRACE] 2016-11-14 22:54:07,182 TestRemoteThing1: Read property: Pushed_Sin_Number

                          [TRACE] 2016-11-14 22:54:07,183 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:07,183 TestRemoteThing1: Read property: Pushed_InMemory_String

                          [TRACE] 2016-11-14 22:54:07,184 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:07,185 TestRemoteThing1: Read property: ValidationString

                          [TRACE] 2016-11-14 22:54:07,186 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:07,186 TestRemoteThing1: Read property: Pushed_InMemory_Imagelink

                          [TRACE] 2016-11-14 22:54:07,187 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:07,190 TestRemoteThing1: Read property: Pushed_InMemory_UserName

                          [TRACE] 2016-11-14 22:54:07,190 TestRemoteThing1: Calling registerEdgeThing. currently registered: false

                          [DEBUG] 2016-11-14 22:54:07,191 thingworx.server: Invoking /Thingworx/Things/LocalEms/Services/AddEdgeThing on server. content: {"keepalive":60000,"port":"8001","timeout":15000,"host":"localhost","proto":"http","name":"*TestRemoteThing1","path":"/scripts/Thingworx"}

                          [TRACE] 2016-11-14 22:54:07,191 luaBindings:newRapClient: Found RAP at localhost:8000

                          [TRACE] 2016-11-14 22:54:07,191 luaBindings: Got RAP timeout: 0

                          [DEBUG] 2016-11-14 22:54:07,191 SDK: twTlsClient_Create: Initializing TLS Client

                          [TRACE] 2016-11-14 22:54:07,191 HttpClient::processReq: POST /Thingworx/Things/LocalEms/Services/AddEdgeThing HTTP/1.1

                          [TRACE] 2016-11-14 22:54:07,195 httpClient::processReq: Adding default header content-type: application/json

                           

                           

                          [TRACE] 2016-11-14 22:54:07,195 httpClient::processReq: Adding default header host: localhost

                           

                           

                          [DEBUG] 2016-11-14 22:54:07,195 SDK: twTlsClient_Create: Initializing TLS Client

                          [DEBUG] 2016-11-14 22:54:07,195 TlsStream:: doopen: Setting SO_RCVTIMEO

                          [TRACE] 2016-11-14 22:54:07,195 TlsStream:: doopen: Non-SSL server socket opened

                          [TRACE] 2016-11-14 22:54:07,199 httpServer: Allocating new client: 1

                          [TRACE] 2016-11-14 22:54:07,199 HttpResponse::on_message_begin: Response started

                          [TRACE] 2016-11-14 22:54:07,199 HttpResponse::on_message_complete: Response complete.  Code: 200 Reason:

                          [DEBUG] 2016-11-14 22:54:07,202 TlsStream::doclose: Disconeccting socket

                          [DEBUG] 2016-11-14 22:54:07,202 SDK: twTlsClient_Close: Disconnecting from server

                          [TRACE] 2016-11-14 22:54:07,202 HttpClient::processReq: Response received. Response code = 200

                          [TRACE] 2016-11-14 22:54:07,202 HttpResponse::getBody: Attempting to read body as single string. m_contentLength: 0

                          [DEBUG] 2016-11-14 22:54:07,202 SDK: twTlsClient_Close: Disconnecting from server

                          [TRACE] 2016-11-14 22:54:07,206 thingworx.server: Results - code: 200, resp:

                          [INFO ] 2016-11-14 22:54:07,206 TestRemoteThing1: MicroServer is now available.

                          [INFO ] 2016-11-14 22:54:07,206 TestRemoteThing1: MicroServer is online.

                          [INFO ] 2016-11-14 22:54:07,206 TestRemoteThing1: Successfully registered TestRemoteThing1 with MicroServer.

                          [TRACE] 2016-11-14 22:54:07,206 TestRemoteThing1:  Previous state - available: false, online: false

                          [DEBUG] 2016-11-14 22:54:07,206 thingworx.server: Invoking /Thingworx/Things/*TestRemoteThing1/Services/GetPropertySubscriptions on server. content: {}

                          [TRACE] 2016-11-14 22:54:07,210 luaBindings:newRapClient: Found RAP at localhost:8000

                          [TRACE] 2016-11-14 22:54:07,210 luaBindings: Got RAP timeout: 0

                          [DEBUG] 2016-11-14 22:54:07,210 SDK: twTlsClient_Create: Initializing TLS Client

                          [TRACE] 2016-11-14 22:54:07,214 client_thread::execute: Starting request handler thread 2

                          [DEBUG] 2016-11-14 22:54:07,214 TlsStream::doclose: Disconeccting socket

                          [DEBUG] 2016-11-14 22:54:07,214 SDK: twTlsClient_Close: Disconnecting from server

                          [DEBUG] 2016-11-14 22:54:07,214 [+0800] HTTP Server: 0.0.0.0 - SeqId 2 - "" 400 376 "-"

                           

                           

                          [DEBUG] 2016-11-14 22:54:07,214 SDK: twTlsClient_Close: Disconnecting from server

                          [TRACE] 2016-11-14 22:54:07,218 HttpClient::processReq: POST /Thingworx/Things/*TestRemoteThing1/Services/GetPropertySubscriptions HTTP/1.1

                          [TRACE] 2016-11-14 22:54:07,218 httpClient::processReq: Adding default header content-type: application/json

                           

                           

                          [TRACE] 2016-11-14 22:54:07,218 httpClient::processReq: Adding default header host: localhost

                           

                           

                          [TRACE] 2016-11-14 22:54:07,291 HttpResponse::on_message_begin: Response started

                          [TRACE] 2016-11-14 22:54:07,291 HttpResponse::on_message_complete: Response complete.  Code: 500 Reason:

                          [DEBUG] 2016-11-14 22:54:07,295 TlsStream::doclose: Disconeccting socket

                          [DEBUG] 2016-11-14 22:54:07,295 SDK: twTlsClient_Close: Disconnecting from server

                          [TRACE] 2016-11-14 22:54:07,295 HttpClient::processReq: Response received. Response code = 500

                          [TRACE] 2016-11-14 22:54:07,299 HttpResponse::getBody: Attempting to read body as single string. m_contentLength: 0

                          [DEBUG] 2016-11-14 22:54:07,299 SDK: twTlsClient_Close: Disconnecting from server

                          [TRACE] 2016-11-14 22:54:07,299 thingworx.server: Results - code: 500, resp:

                          [INFO ] 2016-11-14 22:54:07,302 TestRemoteThing1: Error occured while accessing EMS. Checking isConnected.

                          [TRACE] 2016-11-14 22:54:07,302 luaBindings:newRapClient: Found RAP at localhost:8000

                          [TRACE] 2016-11-14 22:54:07,302 luaBindings: Got RAP timeout: 0

                          [DEBUG] 2016-11-14 22:54:07,302 SDK: twTlsClient_Create: Initializing TLS Client

                          [TRACE] 2016-11-14 22:54:07,302 HttpClient::processReq: GET /Thingworx/Things/LocalEms/Properties/isConnected HTTP/1.1

                          [TRACE] 2016-11-14 22:54:07,306 httpClient::processReq: Adding default header Host: localhost

                           

                           

                          [TRACE] 2016-11-14 22:54:07,306 HttpResponse::on_message_begin: Response started

                          [TRACE] 2016-11-14 22:54:07,306 HttpResponse::on_message_complete: Response complete.  Code: 200 Reason:

                          [DEBUG] 2016-11-14 22:54:07,306 TlsStream::doclose: Disconeccting socket

                          [DEBUG] 2016-11-14 22:54:07,310 SDK: twTlsClient_Close: Disconnecting from server

                          [TRACE] 2016-11-14 22:54:07,310 HttpClient::processReq: Response received. Response code = 200

                          [TRACE] 2016-11-14 22:54:07,310 HttpResponse::getBody: Attempting to read body as single string. m_contentLength: 154

                          [TRACE] 2016-11-14 22:54:07,310 HttpResponse::getBody: Read body as single string. m_body: {"rows":[{"isConnected":true}],"datashape":{"fieldDefinitions":{"isConnected":{"name":"isConnected","description":"","baseType":"BOOLEAN","aspects":{}}}}}

                          [DEBUG] 2016-11-14 22:54:07,314 SDK: twTlsClient_Close: Disconnecting from server

                          [INFO ] 2016-11-14 22:54:07,314 TestRemoteThing1: EMS is available: true, online: true

                          [INFO ] 2016-11-14 22:54:07,314 TestRemoteThing1: Attempting to GetPropertySubscriptions from server failed. code: 500, result:

                          [TRACE] 2016-11-14 22:54:07,314 TestRemoteThing1: Attempting to set property upToDate

                          [TRACE] 2016-11-14 22:54:07,314 TestRemoteThing1: Found handler inmemory

                          [DEBUG] 2016-11-14 22:54:07,318 TestRemoteThing1: Wrote property: upToDate Updated updateTime to 1666497176

                          [TRACE] 2016-11-14 22:54:07,318 setProperty: Code: 200 Msg nil

                          [TRACE] 2016-11-14 22:54:07,318 GetPropertySubscriptions: Code: 500 Msg Attempting to GetPropertySubscriptions from server failed. code: 500, result:

                          [TRACE] 2016-11-14 22:54:07,322 TestRemoteThing1: Executing task RunStoreAndForwardTest

                          [TRACE] 2016-11-14 22:54:07,322 TestRemoteThing1: Executing task UpdatePropertyMap

                          [TRACE] 2016-11-14 22:54:07,322 TestRemoteThing1: Checking properties.upToDate: true

                          [TRACE] 2016-11-14 22:54:07,322 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:07,322 TestRemoteThing1: Read property: upToDate

                          [DEBUG] 2016-11-14 22:54:07,327 thingworx.server: Invoking /Thingworx/Things/*TestRemoteThing1/Services/GetPropertySubscriptions on server. content: {}

                          [TRACE] 2016-11-14 22:54:07,328 luaBindings:newRapClient: Found RAP at localhost:8000

                          [TRACE] 2016-11-14 22:54:07,328 luaBindings: Got RAP timeout: 0

                          [DEBUG] 2016-11-14 22:54:07,329 SDK: twTlsClient_Create: Initializing TLS Client

                          [TRACE] 2016-11-14 22:54:07,330 HttpClient::processReq: POST /Thingworx/Things/*TestRemoteThing1/Services/GetPropertySubscriptions HTTP/1.1

                          [TRACE] 2016-11-14 22:54:07,332 httpClient::processReq: Adding default header content-type: application/json

                           

                           

                          [TRACE] 2016-11-14 22:54:07,333 httpClient::processReq: Adding default header host: localhost

                           

                           

                          [TRACE] 2016-11-14 22:54:07,503 HttpResponse::on_message_begin: Response started

                          [TRACE] 2016-11-14 22:54:07,503 HttpResponse::on_message_complete: Response complete.  Code: 500 Reason:

                          [DEBUG] 2016-11-14 22:54:07,507 TlsStream::doclose: Disconeccting socket

                          [DEBUG] 2016-11-14 22:54:07,507 SDK: twTlsClient_Close: Disconnecting from server

                          [TRACE] 2016-11-14 22:54:07,507 HttpClient::processReq: Response received. Response code = 500

                          [TRACE] 2016-11-14 22:54:07,507 HttpResponse::getBody: Attempting to read body as single string. m_contentLength: 0

                          [DEBUG] 2016-11-14 22:54:07,511 SDK: twTlsClient_Close: Disconnecting from server

                          [TRACE] 2016-11-14 22:54:07,511 thingworx.server: Results - code: 500, resp:

                          [INFO ] 2016-11-14 22:54:07,511 TestRemoteThing1: Error occured while accessing EMS. Checking isConnected.

                          [TRACE] 2016-11-14 22:54:07,511 luaBindings:newRapClient: Found RAP at localhost:8000

                          [TRACE] 2016-11-14 22:54:07,511 luaBindings: Got RAP timeout: 0

                          [DEBUG] 2016-11-14 22:54:07,511 SDK: twTlsClient_Create: Initializing TLS Client

                          [TRACE] 2016-11-14 22:54:07,515 HttpClient::processReq: GET /Thingworx/Things/LocalEms/Properties/isConnected HTTP/1.1

                          [TRACE] 2016-11-14 22:54:07,515 httpClient::processReq: Adding default header Host: localhost

                           

                           

                          [TRACE] 2016-11-14 22:54:07,515 HttpResponse::on_message_begin: Response started

                          [TRACE] 2016-11-14 22:54:07,515 HttpResponse::on_message_complete: Response complete.  Code: 200 Reason:

                          [DEBUG] 2016-11-14 22:54:07,518 TlsStream::doclose: Disconeccting socket

                          [DEBUG] 2016-11-14 22:54:07,518 SDK: twTlsClient_Close: Disconnecting from server

                          [TRACE] 2016-11-14 22:54:07,518 HttpClient::processReq: Response received. Response code = 200

                          [TRACE] 2016-11-14 22:54:07,522 HttpResponse::getBody: Attempting to read body as single string. m_contentLength: 154

                          [TRACE] 2016-11-14 22:54:07,522 HttpResponse::getBody: Read body as single string. m_body: {"rows":[{"isConnected":true}],"datashape":{"fieldDefinitions":{"isConnected":{"name":"isConnected","description":"","baseType":"BOOLEAN","aspects":{}}}}}

                          [DEBUG] 2016-11-14 22:54:07,522 SDK: twTlsClient_Close: Disconnecting from server

                          [INFO ] 2016-11-14 22:54:07,522 TestRemoteThing1: EMS is available: true, online: true

                          [INFO ] 2016-11-14 22:54:07,522 TestRemoteThing1: Attempting to GetPropertySubscriptions from server failed. code: 500, result:

                          [TRACE] 2016-11-14 22:54:07,522 TestRemoteThing1: Attempting to set property upToDate

                          [TRACE] 2016-11-14 22:54:07,526 TestRemoteThing1: Found handler inmemory

                          [DEBUG] 2016-11-14 22:54:07,526 TestRemoteThing1: Wrote property: upToDate Updated updateTime to 1666497176

                          [TRACE] 2016-11-14 22:54:07,526 setProperty: Code: 200 Msg nil

                          [TRACE] 2016-11-14 22:54:07,526 GetPropertySubscriptions: Code: 500 Msg Attempting to GetPropertySubscriptions from server failed. code: 500, result:

                          [TRACE] 2016-11-14 22:54:07,530 TestRemoteThing1: Executing task Compare

                          [TRACE] 2016-11-14 22:54:08, 11 TestRemoteThing1: Checking connection to EMS.

                          [DEBUG] 2016-11-14 22:54:08, 11 thingworx.server: Invoking /Thingworx/Things/LocalEms/Services/HasEdgeThing on server. content: {"name":"*TestRemoteThing1"}

                          [TRACE] 2016-11-14 22:54:08, 11 luaBindings:newRapClient: Found RAP at localhost:8000

                          [TRACE] 2016-11-14 22:54:08, 11 luaBindings: Got RAP timeout: 0

                          [DEBUG] 2016-11-14 22:54:08, 15 SDK: twTlsClient_Create: Initializing TLS Client

                          [TRACE] 2016-11-14 22:54:08, 15 HttpClient::processReq: POST /Thingworx/Things/LocalEms/Services/HasEdgeThing HTTP/1.1

                          [TRACE] 2016-11-14 22:54:08, 15 httpClient::processReq: Adding default header content-type: application/json

                           

                           

                          [TRACE] 2016-11-14 22:54:08, 18 httpClient::processReq: Adding default header host: localhost

                           

                           

                          [TRACE] 2016-11-14 22:54:08, 18 HttpResponse::on_message_begin: Response started

                          [TRACE] 2016-11-14 22:54:08, 18 HttpResponse::on_message_complete: Response complete.  Code: 200 Reason:

                          [DEBUG] 2016-11-14 22:54:08, 18 TlsStream::doclose: Disconeccting socket

                          [DEBUG] 2016-11-14 22:54:08, 18 SDK: twTlsClient_Close: Disconnecting from server

                          [TRACE] 2016-11-14 22:54:08, 22 HttpClient::processReq: Response received. Response code = 200

                          [TRACE] 2016-11-14 22:54:08, 22 HttpResponse::getBody: Attempting to read body as single string. m_contentLength: 139

                          [TRACE] 2016-11-14 22:54:08, 22 HttpResponse::getBody: Read body as single string. m_body: {"rows":[{"result":true}],"datashape":{"fieldDefinitions":{"result":{"name":"result","description":"","baseType":"BOOLEAN","aspects":{}}}}}

                          [DEBUG] 2016-11-14 22:54:08, 26 SDK: twTlsClient_Close: Disconnecting from server

                          [TRACE] 2016-11-14 22:54:08, 26 thingworx.server: Results - code: 200, resp: {"rows":[{"result":true}],"datashape":{"fieldDefinitions":{"result":{"name":"result","description":"","baseType":"BOOLEAN","aspects":{}}}}}

                          [TRACE] 2016-11-14 22:54:18, 67 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:18, 67 TestRemoteThing1: Read property: Pushed_InMemory_XML

                          [TRACE] 2016-11-14 22:54:18, 67 TestRemoteThing1: Found handler generator

                          [TRACE] 2016-11-14 22:54:18, 67 TestRemoteThing1: Read property: Pushed_Random_Number

                          [TRACE] 2016-11-14 22:54:18, 67 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:18, 67 TestRemoteThing1: Read property: Pushed_InMemory_Image

                          [TRACE] 2016-11-14 22:54:18, 67 TestRemoteThing1: Found handler script

                          [DEBUG] 2016-11-14 22:54:18, 70 TestRemoteThing1: Executing property read via script handler. script: sample, path: property/boolean

                          [TRACE] 2016-11-14 22:54:18, 70 ScriptResource::executeScriptRequest: Checking path /scripts/

                          [TRACE] 2016-11-14 22:54:18, 70 ScriptResource::executeScriptRequest: Checking path /scripts/sample/

                          [TRACE] 2016-11-14 22:54:18, 70 ScriptResource::executeScriptRequest: Checking path /scripts/sample/property/

                          [TRACE] 2016-11-14 22:54:18, 70 ScriptResource::executeScriptRequest: Checking path /scripts/sample/property/boolean/

                          [DEBUG] 2016-11-14 22:54:18, 70 ScriptResource::executeScriptRequest: Found callback property_boolean for path /scripts/sample/property/boolean/

                          [DEBUG] 2016-11-14 22:54:18, 70 luaScriptProxy::executeScriptCallback: Executed GET request on property_boolean

                          [TRACE] 2016-11-14 22:54:18, 70 TestRemoteThing1: Read property: Script_Pushed_Boolean

                          [TRACE] 2016-11-14 22:54:18, 74 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:18, 74 TestRemoteThing1: Read property: Pushed_InMemory_HTML

                          [TRACE] 2016-11-14 22:54:18, 74 TestRemoteThing1: Found handler generator

                          [TRACE] 2016-11-14 22:54:18, 74 TestRemoteThing1: Read property: Pushed_Random_Location

                          [TRACE] 2016-11-14 22:54:18, 74 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:18, 74 TestRemoteThing1: Read property: Pushed_InMemory_Query

                          [TRACE] 2016-11-14 22:54:18, 74 TestRemoteThing1: Found handler generator

                          [TRACE] 2016-11-14 22:54:18, 74 TestRemoteThing1: Read property: Pushed_Random_String

                          [TRACE] 2016-11-14 22:54:18, 78 TestRemoteThing1: Found handler generator

                          [TRACE] 2016-11-14 22:54:18, 78 TestRemoteThing1: Read property: Pushed_Random_DateTime

                          [TRACE] 2016-11-14 22:54:18, 78 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:18, 78 TestRemoteThing1: Read property: Pushed_InMemory_Location

                          [TRACE] 2016-11-14 22:54:18, 78 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:18, 82 TestRemoteThing1: Read property: Pushed_InMemory_Hyperlink

                          [TRACE] 2016-11-14 22:54:18, 82 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:18, 82 TestRemoteThing1: Read property: SAF_Client_Number

                          [TRACE] 2016-11-14 22:54:18, 82 TestRemoteThing1: Found handler generator

                          [TRACE] 2016-11-14 22:54:18, 82 TestRemoteThing1: Read property: Incrementing_Number

                          [TRACE] 2016-11-14 22:54:18, 82 TestRemoteThing1: Found handler generator

                          [TRACE] 2016-11-14 22:54:18, 82 TestRemoteThing1: Read property: Incrementing_DateTime

                          [TRACE] 2016-11-14 22:54:18, 82 TestRemoteThing1: Found handler generator

                          [TRACE] 2016-11-14 22:54:18, 82 TestRemoteThing1: Read property: Pushed_Incrementing_Location

                          [TRACE] 2016-11-14 22:54:18, 86 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:18, 87 TestRemoteThing1: Read property: Pushed_InMemory_MenuName

                          [TRACE] 2016-11-14 22:54:18, 87 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:18, 87 TestRemoteThing1: Read property: Pushed_InMemory_Text

                          [TRACE] 2016-11-14 22:54:18, 88 TestRemoteThing1: Found handler generator

                          [TRACE] 2016-11-14 22:54:18, 88 TestRemoteThing1: Read property: AutoPush

                          [TRACE] 2016-11-14 22:54:18, 88 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:18, 89 TestRemoteThing1: Read property: Pushed_InMemory_Integer

                          [TRACE] 2016-11-14 22:54:18, 89 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:18, 91 TestRemoteThing1: Read property: Pushed_InMemory_Json

                          [TRACE] 2016-11-14 22:54:18, 92 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:18, 92 TestRemoteThing1: Read property: Pushed_InMemory_GroupName

                          [TRACE] 2016-11-14 22:54:18, 93 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:18, 93 TestRemoteThing1: Read property: Pushed_InMemory_Datetime

                          [TRACE] 2016-11-14 22:54:18, 93 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:18, 94 TestRemoteThing1: Read property: Pushed_InMemory_MashupName

                          [TRACE] 2016-11-14 22:54:18, 94 TestRemoteThing1: Found handler script

                          [DEBUG] 2016-11-14 22:54:18, 94 TestRemoteThing1: Executing property read via script handler. script: sample, path: property/location

                          [TRACE] 2016-11-14 22:54:18, 95 ScriptResource::executeScriptRequest: Checking path /scripts/

                          [TRACE] 2016-11-14 22:54:18, 95 ScriptResource::executeScriptRequest: Checking path /scripts/sample/

                          [TRACE] 2016-11-14 22:54:18, 95 ScriptResource::executeScriptRequest: Checking path /scripts/sample/property/

                          [TRACE] 2016-11-14 22:54:18, 96 ScriptResource::executeScriptRequest: Checking path /scripts/sample/property/location/

                          [DEBUG] 2016-11-14 22:54:18, 96 ScriptResource::executeScriptRequest: Found callback property_location for path /scripts/sample/property/location/

                          [DEBUG] 2016-11-14 22:54:18, 96 luaScriptProxy::executeScriptCallback: Executed GET request on property_location

                          [TRACE] 2016-11-14 22:54:18, 97 TestRemoteThing1: Read property: Script_Pushed_Location

                          [TRACE] 2016-11-14 22:54:18, 97 TestRemoteThing1: Found handler script

                          [DEBUG] 2016-11-14 22:54:18, 97 TestRemoteThing1: Executing property read via script handler. script: sample, path: property/datetime

                          [TRACE] 2016-11-14 22:54:18, 98 ScriptResource::executeScriptRequest: Checking path /scripts/

                          [TRACE] 2016-11-14 22:54:18, 98 ScriptResource::executeScriptRequest: Checking path /scripts/sample/

                          [TRACE] 2016-11-14 22:54:18, 98 ScriptResource::executeScriptRequest: Checking path /scripts/sample/property/

                          [TRACE] 2016-11-14 22:54:18, 99 ScriptResource::executeScriptRequest: Checking path /scripts/sample/property/datetime/

                          [DEBUG] 2016-11-14 22:54:18, 99 ScriptResource::executeScriptRequest: Found callback property_datetime for path /scripts/sample/property/datetime/

                          [DEBUG] 2016-11-14 22:54:18, 99 luaScriptProxy::executeScriptCallback: Executed GET request on property_datetime

                          [TRACE] 2016-11-14 22:54:18,100 TestRemoteThing1: Read property: Script_Pushed_Datetime

                          [TRACE] 2016-11-14 22:54:18,100 TestRemoteThing1: Found handler script

                          [DEBUG] 2016-11-14 22:54:18,100 TestRemoteThing1: Executing property read via script handler. script: sample, path: property/string

                          [TRACE] 2016-11-14 22:54:18,100 ScriptResource::executeScriptRequest: Checking path /scripts/

                          [TRACE] 2016-11-14 22:54:18,100 ScriptResource::executeScriptRequest: Checking path /scripts/sample/

                          [TRACE] 2016-11-14 22:54:18,100 ScriptResource::executeScriptRequest: Checking path /scripts/sample/property/

                          [TRACE] 2016-11-14 22:54:18,100 ScriptResource::executeScriptRequest: Checking path /scripts/sample/property/string/

                          [DEBUG] 2016-11-14 22:54:18,100 ScriptResource::executeScriptRequest: Found callback property_string for path /scripts/sample/property/string/

                          [DEBUG] 2016-11-14 22:54:18,100 luaScriptProxy::executeScriptCallback: Executed GET request on property_string

                          [TRACE] 2016-11-14 22:54:18,100 TestRemoteThing1: Read property: Script_Pushed_String

                          [TRACE] 2016-11-14 22:54:18,104 TestRemoteThing1: Found handler script

                          [DEBUG] 2016-11-14 22:54:18,104 TestRemoteThing1: Executing property read via script handler. script: sample, path: property/number

                          [TRACE] 2016-11-14 22:54:18,104 ScriptResource::executeScriptRequest: Checking path /scripts/

                          [TRACE] 2016-11-14 22:54:18,104 ScriptResource::executeScriptRequest: Checking path /scripts/sample/

                          [TRACE] 2016-11-14 22:54:18,104 ScriptResource::executeScriptRequest: Checking path /scripts/sample/property/

                          [TRACE] 2016-11-14 22:54:18,104 ScriptResource::executeScriptRequest: Checking path /scripts/sample/property/number/

                          [DEBUG] 2016-11-14 22:54:18,104 ScriptResource::executeScriptRequest: Found callback property_number for path /scripts/sample/property/number/

                          [DEBUG] 2016-11-14 22:54:18,104 luaScriptProxy::executeScriptCallback: Executed GET request on property_number

                          [TRACE] 2016-11-14 22:54:18,104 TestRemoteThing1: Read property: Script_Pushed_Number

                          [TRACE] 2016-11-14 22:54:18,104 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:18,104 TestRemoteThing1: Read property: Pushed_InMemory_ThingName

                          [TRACE] 2016-11-14 22:54:18,108 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:18,108 TestRemoteThing1: Read property: Pushed_InMemory_Number

                          [TRACE] 2016-11-14 22:54:18,108 TestRemoteThing1: Found handler generator

                          [TRACE] 2016-11-14 22:54:18,108 TestRemoteThing1: Read property: Pushed_Incrementing_DateTime

                          [TRACE] 2016-11-14 22:54:18,108 TestRemoteThing1: Found handler generator

                          [TRACE] 2016-11-14 22:54:18,108 TestRemoteThing1: Read property: Pushed_Square_Number

                          [TRACE] 2016-11-14 22:54:18,108 TestRemoteThing1: Found handler generator

                          [TRACE] 2016-11-14 22:54:18,108 TestRemoteThing1: Read property: Pushed_Incrementing_Number

                          [TRACE] 2016-11-14 22:54:18,108 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:18,108 TestRemoteThing1: Read property: Pushed_InMemory_Boolean

                          [TRACE] 2016-11-14 22:54:18,108 TestRemoteThing1: Found handler generator

                          [TRACE] 2016-11-14 22:54:18,112 TestRemoteThing1: Read property: Pushed_Cos_Number

                          [TRACE] 2016-11-14 22:54:18,112 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:18,112 TestRemoteThing1: Read property: Pushed_InMemory_InfoTable

                          [TRACE] 2016-11-14 22:54:18,112 TestRemoteThing1: Found handler generator

                          [TRACE] 2016-11-14 22:54:18,112 TestRemoteThing1: Read property: Pushed_Sin_Number

                          [TRACE] 2016-11-14 22:54:18,116 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:18,116 TestRemoteThing1: Read property: Pushed_InMemory_String

                          [TRACE] 2016-11-14 22:54:18,116 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:18,116 TestRemoteThing1: Read property: ValidationString

                          [TRACE] 2016-11-14 22:54:18,116 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:18,116 TestRemoteThing1: Read property: Pushed_InMemory_Imagelink

                          [TRACE] 2016-11-14 22:54:18,116 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:18,116 TestRemoteThing1: Read property: Pushed_InMemory_UserName

                          [TRACE] 2016-11-14 22:54:18,116 thingworx.server: Adding property to list: Pushed_InMemory_XML

                          [TRACE] 2016-11-14 22:54:18,116 thingworx.server: Adding property to list: Pushed_Random_Number

                          [TRACE] 2016-11-14 22:54:18,116 thingworx.server: Adding property to list: Pushed_InMemory_Image

                          [TRACE] 2016-11-14 22:54:18,116 thingworx.server: Adding property to list: Script_Pushed_Boolean

                          [TRACE] 2016-11-14 22:54:18,120 thingworx.server: Adding property to list: Pushed_InMemory_HTML

                          [TRACE] 2016-11-14 22:54:18,120 thingworx.server: Adding property to list: Pushed_Random_Location

                          [TRACE] 2016-11-14 22:54:18,120 thingworx.server: Adding property to list: Pushed_InMemory_Query

                          [TRACE] 2016-11-14 22:54:18,120 thingworx.server: Adding property to list: Pushed_Random_String

                          [TRACE] 2016-11-14 22:54:18,120 thingworx.server: Adding property to list: Pushed_Random_DateTime

                          [TRACE] 2016-11-14 22:54:18,120 thingworx.server: Adding property to list: Pushed_InMemory_Location

                          [TRACE] 2016-11-14 22:54:18,120 thingworx.server: Adding property to list: Pushed_InMemory_Hyperlink

                          [TRACE] 2016-11-14 22:54:18,120 thingworx.server: Adding property to list: SAF_Client_Number

                          [TRACE] 2016-11-14 22:54:18,120 thingworx.server: Adding property to list: Incrementing_Number

                          [TRACE] 2016-11-14 22:54:18,120 thingworx.server: Adding property to list: Incrementing_DateTime

                          [TRACE] 2016-11-14 22:54:18,120 thingworx.server: Adding property to list: Pushed_Incrementing_Location

                          [TRACE] 2016-11-14 22:54:18,124 thingworx.server: Adding property to list: Pushed_InMemory_MenuName

                          [TRACE] 2016-11-14 22:54:18,124 thingworx.server: Adding property to list: Pushed_InMemory_Text

                          [TRACE] 2016-11-14 22:54:18,124 thingworx.server: Adding property to list: AutoPush

                          [TRACE] 2016-11-14 22:54:18,124 thingworx.server: Adding property to list: Pushed_InMemory_Integer

                          [TRACE] 2016-11-14 22:54:18,128 thingworx.server: Adding property to list: Pushed_InMemory_Json

                          [TRACE] 2016-11-14 22:54:18,128 thingworx.server: Adding property to list: Pushed_InMemory_GroupName

                          [TRACE] 2016-11-14 22:54:18,128 thingworx.server: Adding property to list: Pushed_InMemory_Datetime

                          [TRACE] 2016-11-14 22:54:18,128 thingworx.server: Adding property to list: Pushed_InMemory_MashupName

                          [TRACE] 2016-11-14 22:54:18,128 thingworx.server: Adding property to list: Script_Pushed_Location

                          [TRACE] 2016-11-14 22:54:18,128 thingworx.server: Adding property to list: Script_Pushed_Datetime

                          [TRACE] 2016-11-14 22:54:18,128 thingworx.server: Adding property to list: Script_Pushed_String

                          [TRACE] 2016-11-14 22:54:18,128 thingworx.server: Adding property to list: Script_Pushed_Number

                          [TRACE] 2016-11-14 22:54:18,128 thingworx.server: Adding property to list: Pushed_InMemory_ThingName

                          [TRACE] 2016-11-14 22:54:18,128 thingworx.server: Adding property to list: Pushed_InMemory_Number

                          [TRACE] 2016-11-14 22:54:18,128 thingworx.server: Adding property to list: Pushed_Incrementing_DateTime

                          [TRACE] 2016-11-14 22:54:18,128 thingworx.server: Adding property to list: Pushed_Square_Number

                          [TRACE] 2016-11-14 22:54:18,131 thingworx.server: Adding property to list: Pushed_Incrementing_Number

                          [TRACE] 2016-11-14 22:54:18,131 thingworx.server: Adding property to list: Pushed_InMemory_Boolean

                          [TRACE] 2016-11-14 22:54:18,131 thingworx.server: Adding property to list: Pushed_Cos_Number

                          [TRACE] 2016-11-14 22:54:18,131 thingworx.server: Adding property to list: Pushed_InMemory_InfoTable

                          [TRACE] 2016-11-14 22:54:18,131 thingworx.server: Adding property to list: Pushed_Sin_Number

                          [TRACE] 2016-11-14 22:54:18,131 thingworx.server: Adding property to list: Pushed_InMemory_String

                          [TRACE] 2016-11-14 22:54:18,131 thingworx.server: Adding property to list: ValidationString

                          [TRACE] 2016-11-14 22:54:18,131 thingworx.server: Adding property to list: Pushed_InMemory_Imagelink

                          [TRACE] 2016-11-14 22:54:18,131 thingworx.server: Adding property to list: Pushed_InMemory_UserName

                          [DEBUG] 2016-11-14 22:54:18,131 thingworx.server: Created batch of 40 properties to be pushed to the server (last batch of group).

                          [TRACE] 2016-11-14 22:54:18,131 thingworx.server: Setting properties on server. batch: 1, path: /Thingworx/Things/*TestRemoteThing1/Services/UpdateSubscribedPropertyValues, content:

                          {"dataShape":{"fieldDefinitions":{"values":{"aspects":[],"name":"values","baseType":"INFOTABLE"}}},"rows":[{"values":{"dataShape":{"fieldDefinitions":{"value":{"aspects":[],"name":"value","baseType":"VARIANT"},"time":{"aspects":[],"name":"time","baseType":"DATETIME"},"name":{"aspects":[],"name":"name","baseType":"STRING"},"quality":{"aspects":[],"name":"quality","baseType":"STRING"}}},"rows":[{"value":{"baseType":"XML","value":"<?xml version=\"1.0\" encoding=\"utf-8\" standalone=\"no\"?><Root><Child>Test</Child></Root>"},"name":"Pushed_InMemory_XML","time":1479135243000,"quality":"GOOD"},{"value":{"baseType":"NUMBER","value":43},"name":"Pushed_Random_Number","time":1479135258000,"quality":"GOOD"},{"value":{"baseType":"IMAGE","value":""},"name":"Pushed_InMemory_Image","time":1479135243000,"quality":"GOOD"},{"value":{"baseType":"BOOLEAN","value":true},"name":"Script_Pushed_Boolean","time":1479135258000,"quality":"GOOD"},{"value":{"baseType":"HTML","value":"<html><body><h1>Default Value</h1></body></html>"},"name":"Pushed_InMemory_HTML","time":1479135243000,"quality":"GOOD"},{"value":{"baseType":"LOCATION","value":{"longitude":64,"latitude":-6,"elevation":3968}},"name":"Pushed_Random_Location","time":1479135258000,"quality":"GOOD"},{"value":{"baseType":"QUERY","value":"{}"},"name":"Pushed_InMemory_Query","time":1479135243000,"quality":"GOOD"},{"value":{"baseType":"STRING","value":"IXL"},"name":"Pushed_Random_String","time":1479135258000,"quality":"GOOD"},{"value":{"baseType":"DATETIME","value":1352502092000},"name":"Pushed_Random_DateTime","time":1479135258000,"quality":"GOOD"},{"value":{"baseType":"LOCATION","value":{"longitude":-75.62,"latitude":40.03,"elevation":103}},"name":"Pushed_InMemory_Location","time":1479135243000,"quality":"GOOD"},{"value":{"baseType":"HYPERLINK","value":"http://www.thingworx.com"},"name":"Pushed_InMemory_Hyperlink","time":1479135243000,"quality":"GOOD"},{

                          [TRACE] 2016-11-14 22:54:18,131 luaBindings:newRapClient: Found RAP at localhost:8000

                          [TRACE] 2016-11-14 22:54:18,135 luaBindings: Got RAP timeout: 0

                          [DEBUG] 2016-11-14 22:54:18,135 SDK: twTlsClient_Create: Initializing TLS Client

                          [TRACE] 2016-11-14 22:54:18,135 HttpClient::processReq: POST /Thingworx/Things/*TestRemoteThing1/Services/UpdateSubscribedPropertyValues HTTP/1.1

                          [TRACE] 2016-11-14 22:54:18,135 httpClient::processReq: Adding default header content-type: application/json

                           

                           

                          [TRACE] 2016-11-14 22:54:18,135 httpClient::processReq: Adding default header host: localhost

                           

                           

                          [TRACE] 2016-11-14 22:54:18,174 HttpResponse::on_message_begin: Response started

                          [TRACE] 2016-11-14 22:54:18,174 HttpResponse::on_message_complete: Response complete.  Code: 500 Reason:

                          [DEBUG] 2016-11-14 22:54:18,174 TlsStream::doclose: Disconeccting socket

                          [DEBUG] 2016-11-14 22:54:18,174 SDK: twTlsClient_Close: Disconnecting from server

                          [TRACE] 2016-11-14 22:54:18,174 HttpClient::processReq: Response received. Response code = 500

                          [TRACE] 2016-11-14 22:54:18,178 HttpResponse::getBody: Attempting to read body as single string. m_contentLength: 0

                          [DEBUG] 2016-11-14 22:54:18,178 SDK: twTlsClient_Close: Disconnecting from server

                          [TRACE] 2016-11-14 22:54:18,178 thingworx.server: Results - code: 500, resp:

                          [INFO ] 2016-11-14 22:54:18,178 TestRemoteThing1: Error occured while accessing EMS. Checking isConnected.

                          [TRACE] 2016-11-14 22:54:18,178 luaBindings:newRapClient: Found RAP at localhost:8000

                          [TRACE] 2016-11-14 22:54:18,178 luaBindings: Got RAP timeout: 0

                          [DEBUG] 2016-11-14 22:54:18,178 SDK: twTlsClient_Create: Initializing TLS Client

                          [TRACE] 2016-11-14 22:54:18,178 HttpClient::processReq: GET /Thingworx/Things/LocalEms/Properties/isConnected HTTP/1.1

                          [TRACE] 2016-11-14 22:54:18,182 httpClient::processReq: Adding default header Host: localhost

                           

                           

                          [TRACE] 2016-11-14 22:54:18,182 HttpResponse::on_message_begin: Response started

                          [TRACE] 2016-11-14 22:54:18,182 HttpResponse::on_message_complete: Response complete.  Code: 200 Reason:

                          [DEBUG] 2016-11-14 22:54:18,182 TlsStream::doclose: Disconeccting socket

                          [DEBUG] 2016-11-14 22:54:18,182 SDK: twTlsClient_Close: Disconnecting from server

                          [TRACE] 2016-11-14 22:54:18,182 HttpClient::processReq: Response received. Response code = 200

                          [TRACE] 2016-11-14 22:54:18,182 HttpResponse::getBody: Attempting to read body as single string. m_contentLength: 154

                          [TRACE] 2016-11-14 22:54:18,182 HttpResponse::getBody: Read body as single string. m_body: {"rows":[{"isConnected":true}],"datashape":{"fieldDefinitions":{"isConnected":{"name":"isConnected","description":"","baseType":"BOOLEAN","aspects":{}}}}}

                          [DEBUG] 2016-11-14 22:54:18,186 SDK: twTlsClient_Close: Disconnecting from server

                          [INFO ] 2016-11-14 22:54:18,188 TestRemoteThing1: EMS is available: true, online: true

                          [WARN ] 2016-11-14 22:54:18,189 thingworx.server: Could not set properties on server. code: 500, resp:

                          [TRACE] 2016-11-14 22:54:23,202 TestRemoteThing1: Executing task RunStoreAndForwardTest

                          [TRACE] 2016-11-14 22:54:23,202 TestRemoteThing1: Executing task UpdatePropertyMap

                          [TRACE] 2016-11-14 22:54:23,204 TestRemoteThing1: Checking properties.upToDate: false

                          [TRACE] 2016-11-14 22:54:23,205 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:23,205 TestRemoteThing1: Read property: upToDate

                          [DEBUG] 2016-11-14 22:54:23,206 thingworx.server: Invoking /Thingworx/Things/*TestRemoteThing1/Services/GetPropertySubscriptions on server. content: {}

                          [TRACE] 2016-11-14 22:54:23,206 luaBindings:newRapClient: Found RAP at localhost:8000

                          [TRACE] 2016-11-14 22:54:23,206 luaBindings: Got RAP timeout: 0

                          [DEBUG] 2016-11-14 22:54:23,206 SDK: twTlsClient_Create: Initializing TLS Client

                          [TRACE] 2016-11-14 22:54:23,206 HttpClient::processReq: POST /Thingworx/Things/*TestRemoteThing1/Services/GetPropertySubscriptions HTTP/1.1

                          [TRACE] 2016-11-14 22:54:23,206 httpClient::processReq: Adding default header content-type: application/json

                           

                           

                          [TRACE] 2016-11-14 22:54:23,206 httpClient::processReq: Adding default header host: localhost

                           

                           

                          [TRACE] 2016-11-14 22:54:23,410 HttpResponse::on_message_begin: Response started

                          [TRACE] 2016-11-14 22:54:23,410 HttpResponse::on_message_complete: Response complete.  Code: 500 Reason:

                          [DEBUG] 2016-11-14 22:54:23,410 TlsStream::doclose: Disconeccting socket

                          [DEBUG] 2016-11-14 22:54:23,410 SDK: twTlsClient_Close: Disconnecting from server

                          [TRACE] 2016-11-14 22:54:23,414 HttpClient::processReq: Response received. Response code = 500

                          [TRACE] 2016-11-14 22:54:23,414 HttpResponse::getBody: Attempting to read body as single string. m_contentLength: 0

                          [DEBUG] 2016-11-14 22:54:23,414 SDK: twTlsClient_Close: Disconnecting from server

                          [TRACE] 2016-11-14 22:54:23,414 thingworx.server: Results - code: 500, resp:

                          [INFO ] 2016-11-14 22:54:23,414 TestRemoteThing1: Error occured while accessing EMS. Checking isConnected.

                          [TRACE] 2016-11-14 22:54:23,414 luaBindings:newRapClient: Found RAP at localhost:8000

                          [TRACE] 2016-11-14 22:54:23,414 luaBindings: Got RAP timeout: 0

                          [DEBUG] 2016-11-14 22:54:23,414 SDK: twTlsClient_Create: Initializing TLS Client

                          [TRACE] 2016-11-14 22:54:23,418 HttpClient::processReq: GET /Thingworx/Things/LocalEms/Properties/isConnected HTTP/1.1

                          [TRACE] 2016-11-14 22:54:23,418 httpClient::processReq: Adding default header Host: localhost

                           

                           

                          [TRACE] 2016-11-14 22:54:23,418 HttpResponse::on_message_begin: Response started

                          [TRACE] 2016-11-14 22:54:23,418 HttpResponse::on_message_complete: Response complete.  Code: 200 Reason:

                          [DEBUG] 2016-11-14 22:54:23,418 TlsStream::doclose: Disconeccting socket

                          [DEBUG] 2016-11-14 22:54:23,418 SDK: twTlsClient_Close: Disconnecting from server

                          [TRACE] 2016-11-14 22:54:23,418 HttpClient::processReq: Response received. Response code = 200

                          [TRACE] 2016-11-14 22:54:23,418 HttpResponse::getBody: Attempting to read body as single string. m_contentLength: 154

                          [TRACE] 2016-11-14 22:54:23,418 HttpResponse::getBody: Read body as single string. m_body: {"rows":[{"isConnected":true}],"datashape":{"fieldDefinitions":{"isConnected":{"name":"isConnected","description":"","baseType":"BOOLEAN","aspects":{}}}}}

                          [DEBUG] 2016-11-14 22:54:23,418 SDK: twTlsClient_Close: Disconnecting from server

                          [INFO ] 2016-11-14 22:54:23,418 TestRemoteThing1: EMS is available: true, online: true

                          [INFO ] 2016-11-14 22:54:23,421 TestRemoteThing1: Attempting to GetPropertySubscriptions from server failed. code: 500, result:

                          [TRACE] 2016-11-14 22:54:23,421 TestRemoteThing1: Attempting to set property upToDate

                          [TRACE] 2016-11-14 22:54:23,421 TestRemoteThing1: Found handler inmemory

                          [DEBUG] 2016-11-14 22:54:23,421 TestRemoteThing1: Wrote property: upToDate Updated updateTime to 1666513176

                          [TRACE] 2016-11-14 22:54:23,421 setProperty: Code: 200 Msg nil

                          [TRACE] 2016-11-14 22:54:23,421 GetPropertySubscriptions: Code: 500 Msg Attempting to GetPropertySubscriptions from server failed. code: 500, result:

                          [TRACE] 2016-11-14 22:54:23,421 TestRemoteThing1: Executing task Compare

                          [TRACE] 2016-11-14 22:54:29,444 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:29,444 TestRemoteThing1: Read property: Pushed_InMemory_XML

                          [TRACE] 2016-11-14 22:54:29,444 TestRemoteThing1: Found handler generator

                          [TRACE] 2016-11-14 22:54:29,444 TestRemoteThing1: Read property: Pushed_Random_Number

                          [TRACE] 2016-11-14 22:54:29,444 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:29,444 TestRemoteThing1: Read property: Pushed_InMemory_Image

                          [TRACE] 2016-11-14 22:54:29,444 TestRemoteThing1: Found handler script

                          [DEBUG] 2016-11-14 22:54:29,447 TestRemoteThing1: Executing property read via script handler. script: sample, path: property/boolean

                          [TRACE] 2016-11-14 22:54:29,447 ScriptResource::executeScriptRequest: Checking path /scripts/

                          [TRACE] 2016-11-14 22:54:29,447 ScriptResource::executeScriptRequest: Checking path /scripts/sample/

                          [TRACE] 2016-11-14 22:54:29,447 ScriptResource::executeScriptRequest: Checking path /scripts/sample/property/

                          [TRACE] 2016-11-14 22:54:29,447 ScriptResource::executeScriptRequest: Checking path /scripts/sample/property/boolean/

                          [DEBUG] 2016-11-14 22:54:29,447 ScriptResource::executeScriptRequest: Found callback property_boolean for path /scripts/sample/property/boolean/

                          [DEBUG] 2016-11-14 22:54:29,447 luaScriptProxy::executeScriptCallback: Executed GET request on property_boolean

                          [TRACE] 2016-11-14 22:54:29,451 TestRemoteThing1: Read property: Script_Pushed_Boolean

                          [TRACE] 2016-11-14 22:54:29,451 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:29,451 TestRemoteThing1: Read property: Pushed_InMemory_HTML

                          [TRACE] 2016-11-14 22:54:29,451 TestRemoteThing1: Found handler generator

                          [TRACE] 2016-11-14 22:54:29,451 TestRemoteThing1: Read property: Pushed_Random_Location

                          [TRACE] 2016-11-14 22:54:29,451 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:29,451 TestRemoteThing1: Read property: Pushed_InMemory_Query

                          [TRACE] 2016-11-14 22:54:29,451 TestRemoteThing1: Found handler generator

                          [TRACE] 2016-11-14 22:54:29,455 TestRemoteThing1: Read property: Pushed_Random_String

                          [TRACE] 2016-11-14 22:54:29,459 TestRemoteThing1: Found handler generator

                          [TRACE] 2016-11-14 22:54:29,459 TestRemoteThing1: Read property: Pushed_Random_DateTime

                          [TRACE] 2016-11-14 22:54:29,459 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:29,459 TestRemoteThing1: Read property: Pushed_InMemory_Location

                          [TRACE] 2016-11-14 22:54:29,459 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:29,459 TestRemoteThing1: Read property: Pushed_InMemory_Hyperlink

                          [TRACE] 2016-11-14 22:54:29,459 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:29,459 TestRemoteThing1: Read property: SAF_Client_Number

                          [TRACE] 2016-11-14 22:54:29,463 TestRemoteThing1: Found handler generator

                          [TRACE] 2016-11-14 22:54:29,463 TestRemoteThing1: Read property: Incrementing_Number

                          [TRACE] 2016-11-14 22:54:29,463 utils::evaluateChange: Property Incrementing_Number change of 1 exceeds pushThreshold of 0

                          [TRACE] 2016-11-14 22:54:29,463 TestRemoteThing1: Found handler generator

                          [TRACE] 2016-11-14 22:54:29,463 TestRemoteThing1: Read property: Incrementing_DateTime

                          [TRACE] 2016-11-14 22:54:29,463 TestRemoteThing1: Found handler generator

                          [TRACE] 2016-11-14 22:54:29,467 TestRemoteThing1: Read property: Pushed_Incrementing_Location

                          [TRACE] 2016-11-14 22:54:29,467 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:29,467 TestRemoteThing1: Read property: Pushed_InMemory_MenuName

                          [TRACE] 2016-11-14 22:54:29,467 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:29,467 TestRemoteThing1: Read property: Pushed_InMemory_Text

                          [TRACE] 2016-11-14 22:54:29,471 TestRemoteThing1: Found handler generator

                          [TRACE] 2016-11-14 22:54:29,471 TestRemoteThing1: Read property: AutoPush

                          [TRACE] 2016-11-14 22:54:29,471 utils::evaluateChange: Property AutoPush change of 1 exceeds pushThreshold of 0

                          [TRACE] 2016-11-14 22:54:29,471 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:29,471 TestRemoteThing1: Read property: Pushed_InMemory_Integer

                          [TRACE] 2016-11-14 22:54:29,471 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:29,471 TestRemoteThing1: Read property: Pushed_InMemory_Json

                          [TRACE] 2016-11-14 22:54:29,471 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:29,475 TestRemoteThing1: Read property: Pushed_InMemory_GroupName

                          [TRACE] 2016-11-14 22:54:29,475 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:29,475 TestRemoteThing1: Read property: Pushed_InMemory_Datetime

                          [TRACE] 2016-11-14 22:54:29,475 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:29,475 TestRemoteThing1: Read property: Pushed_InMemory_MashupName

                          [TRACE] 2016-11-14 22:54:29,475 TestRemoteThing1: Found handler script

                          [DEBUG] 2016-11-14 22:54:29,475 TestRemoteThing1: Executing property read via script handler. script: sample, path: property/location

                          [TRACE] 2016-11-14 22:54:29,475 ScriptResource::executeScriptRequest: Checking path /scripts/

                          [TRACE] 2016-11-14 22:54:29,475 ScriptResource::executeScriptRequest: Checking path /scripts/sample/

                          [TRACE] 2016-11-14 22:54:29,475 ScriptResource::executeScriptRequest: Checking path /scripts/sample/property/

                          [TRACE] 2016-11-14 22:54:29,479 ScriptResource::executeScriptRequest: Checking path /scripts/sample/property/location/

                          [DEBUG] 2016-11-14 22:54:29,479 ScriptResource::executeScriptRequest: Found callback property_location for path /scripts/sample/property/location/

                          [DEBUG] 2016-11-14 22:54:29,479 luaScriptProxy::executeScriptCallback: Executed GET request on property_location

                          [TRACE] 2016-11-14 22:54:29,483 TestRemoteThing1: Read property: Script_Pushed_Location

                          [TRACE] 2016-11-14 22:54:29,483 TestRemoteThing1: Found handler script

                          [DEBUG] 2016-11-14 22:54:29,483 TestRemoteThing1: Executing property read via script handler. script: sample, path: property/datetime

                          [TRACE] 2016-11-14 22:54:29,483 ScriptResource::executeScriptRequest: Checking path /scripts/

                          [TRACE] 2016-11-14 22:54:29,483 ScriptResource::executeScriptRequest: Checking path /scripts/sample/

                          [TRACE] 2016-11-14 22:54:29,483 ScriptResource::executeScriptRequest: Checking path /scripts/sample/property/

                          [TRACE] 2016-11-14 22:54:29,483 ScriptResource::executeScriptRequest: Checking path /scripts/sample/property/datetime/

                          [DEBUG] 2016-11-14 22:54:29,487 ScriptResource::executeScriptRequest: Found callback property_datetime for path /scripts/sample/property/datetime/

                          [DEBUG] 2016-11-14 22:54:29,487 luaScriptProxy::executeScriptCallback: Executed GET request on property_datetime

                          [TRACE] 2016-11-14 22:54:29,487 TestRemoteThing1: Read property: Script_Pushed_Datetime

                          [TRACE] 2016-11-14 22:54:29,487 TestRemoteThing1: Found handler script

                          [DEBUG] 2016-11-14 22:54:29,487 TestRemoteThing1: Executing property read via script handler. script: sample, path: property/string

                          [TRACE] 2016-11-14 22:54:29,487 ScriptResource::executeScriptRequest: Checking path /scripts/

                          [TRACE] 2016-11-14 22:54:29,487 ScriptResource::executeScriptRequest: Checking path /scripts/sample/

                          [TRACE] 2016-11-14 22:54:29,487 ScriptResource::executeScriptRequest: Checking path /scripts/sample/property/

                          [TRACE] 2016-11-14 22:54:29,490 ScriptResource::executeScriptRequest: Checking path /scripts/sample/property/string/

                          [DEBUG] 2016-11-14 22:54:29,490 ScriptResource::executeScriptRequest: Found callback property_string for path /scripts/sample/property/string/

                          [DEBUG] 2016-11-14 22:54:29,490 luaScriptProxy::executeScriptCallback: Executed GET request on property_string

                          [TRACE] 2016-11-14 22:54:29,494 TestRemoteThing1: Read property: Script_Pushed_String

                          [TRACE] 2016-11-14 22:54:29,494 TestRemoteThing1: Found handler script

                          [DEBUG] 2016-11-14 22:54:29,494 TestRemoteThing1: Executing property read via script handler. script: sample, path: property/number

                          [TRACE] 2016-11-14 22:54:29,494 ScriptResource::executeScriptRequest: Checking path /scripts/

                          [TRACE] 2016-11-14 22:54:29,494 ScriptResource::executeScriptRequest: Checking path /scripts/sample/

                          [TRACE] 2016-11-14 22:54:29,494 ScriptResource::executeScriptRequest: Checking path /scripts/sample/property/

                          [TRACE] 2016-11-14 22:54:29,494 ScriptResource::executeScriptRequest: Checking path /scripts/sample/property/number/

                          [DEBUG] 2016-11-14 22:54:29,498 ScriptResource::executeScriptRequest: Found callback property_number for path /scripts/sample/property/number/

                          [DEBUG] 2016-11-14 22:54:29,499 luaScriptProxy::executeScriptCallback: Executed GET request on property_number

                          [TRACE] 2016-11-14 22:54:29,499 TestRemoteThing1: Read property: Script_Pushed_Number

                          [TRACE] 2016-11-14 22:54:29,500 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:29,500 TestRemoteThing1: Read property: Pushed_InMemory_ThingName

                          [TRACE] 2016-11-14 22:54:29,500 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:29,501 TestRemoteThing1: Read property: Pushed_InMemory_Number

                          [TRACE] 2016-11-14 22:54:29,501 TestRemoteThing1: Found handler generator

                          [TRACE] 2016-11-14 22:54:29,503 TestRemoteThing1: Read property: Pushed_Incrementing_DateTime

                          [TRACE] 2016-11-14 22:54:29,504 TestRemoteThing1: Found handler generator

                          [TRACE] 2016-11-14 22:54:29,504 TestRemoteThing1: Read property: Pushed_Square_Number

                          [TRACE] 2016-11-14 22:54:29,505 TestRemoteThing1: Found handler generator

                          [TRACE] 2016-11-14 22:54:29,505 TestRemoteThing1: Read property: Pushed_Incrementing_Number

                          [TRACE] 2016-11-14 22:54:29,505 utils::evaluateChange: Property Pushed_Incrementing_Number change of 1 exceeds pushThreshold of 0

                          [TRACE] 2016-11-14 22:54:29,506 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:29,506 TestRemoteThing1: Read property: Pushed_InMemory_Boolean

                          [TRACE] 2016-11-14 22:54:29,506 TestRemoteThing1: Found handler generator

                          [TRACE] 2016-11-14 22:54:29,507 TestRemoteThing1: Read property: Pushed_Cos_Number

                          [TRACE] 2016-11-14 22:54:29,507 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:29,508 TestRemoteThing1: Read property: Pushed_InMemory_InfoTable

                          [TRACE] 2016-11-14 22:54:29,508 TestRemoteThing1: Found handler generator

                          [TRACE] 2016-11-14 22:54:29,509 TestRemoteThing1: Read property: Pushed_Sin_Number

                          [TRACE] 2016-11-14 22:54:29,510 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:29,511 TestRemoteThing1: Read property: Pushed_InMemory_String

                          [TRACE] 2016-11-14 22:54:29,511 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:29,512 TestRemoteThing1: Read property: ValidationString

                          [TRACE] 2016-11-14 22:54:29,513 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:29,513 TestRemoteThing1: Read property: Pushed_InMemory_Imagelink

                          [TRACE] 2016-11-14 22:54:29,513 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:29,513 TestRemoteThing1: Read property: Pushed_InMemory_UserName

                          [TRACE] 2016-11-14 22:54:29,513 thingworx.server: Adding property to list: Script_Pushed_Boolean

                          [TRACE] 2016-11-14 22:54:29,513 thingworx.server: Adding property to list: Pushed_Random_Location

                          [TRACE] 2016-11-14 22:54:29,513 thingworx.server: Adding property to list: Pushed_Random_String

                          [TRACE] 2016-11-14 22:54:29,517 thingworx.server: Adding property to list: Pushed_Random_DateTime

                          [TRACE] 2016-11-14 22:54:29,517 thingworx.server: Adding property to list: Incrementing_Number

                          [TRACE] 2016-11-14 22:54:29,517 thingworx.server: Adding property to list: Incrementing_DateTime

                          [TRACE] 2016-11-14 22:54:29,517 thingworx.server: Adding property to list: Pushed_Incrementing_Location

                          [TRACE] 2016-11-14 22:54:29,517 thingworx.server: Adding property to list: AutoPush

                          [TRACE] 2016-11-14 22:54:29,517 thingworx.server: Adding property to list: Script_Pushed_Location

                          [TRACE] 2016-11-14 22:54:29,517 thingworx.server: Adding property to list: Script_Pushed_Datetime

                          [TRACE] 2016-11-14 22:54:29,521 thingworx.server: Adding property to list: Script_Pushed_String

                          [TRACE] 2016-11-14 22:54:29,521 thingworx.server: Adding property to list: Script_Pushed_Number

                          [TRACE] 2016-11-14 22:54:29,521 thingworx.server: Adding property to list: Pushed_Incrementing_DateTime

                          [TRACE] 2016-11-14 22:54:29,521 thingworx.server: Adding property to list: Pushed_Square_Number

                          [TRACE] 2016-11-14 22:54:29,521 thingworx.server: Adding property to list: Pushed_Incrementing_Number

                          [TRACE] 2016-11-14 22:54:29,521 thingworx.server: Adding property to list: Pushed_Cos_Number

                          [TRACE] 2016-11-14 22:54:29,521 thingworx.server: Adding property to list: Pushed_Sin_Number

                          [DEBUG] 2016-11-14 22:54:29,521 thingworx.server: Created batch of 17 properties to be pushed to the server (last batch of group).

                          [TRACE] 2016-11-14 22:54:29,521 thingworx.server: Setting properties on server. batch: 1, path: /Thingworx/Things/*TestRemoteThing1/Services/UpdateSubscribedPropertyValues, content:

                          {"dataShape":{"fieldDefinitions":{"values":{"aspects":[],"name":"values","baseType":"INFOTABLE"}}},"rows":[{"values":{"dataShape":{"fieldDefinitions":{"value":{"aspects":[],"name":"value","baseType":"VARIANT"},"time":{"aspects":[],"name":"time","baseType":"DATETIME"},"name":{"aspects":[],"name":"name","baseType":"STRING"},"quality":{"aspects":[],"name":"quality","baseType":"STRING"}}},"rows":[{"value":{"baseType":"BOOLEAN","value":true},"name":"Script_Pushed_Boolean","time":1479135269000,"quality":"GOOD"},{"value":{"baseType":"LOCATION","value":{"longitude":-130,"latitude":8,"elevation":6781}},"name":"Pushed_Random_Location","time":1479135269000,"quality":"GOOD"},{"value":{"baseType":"STRING","value":"$XS"},"name":"Pushed_Random_String","time":1479135269000,"quality":"GOOD"},{"value":{"baseType":"DATETIME","value":1352502096000},"name":"Pushed_Random_DateTime","time":1479135269000,"quality":"GOOD"},{"value":{"baseType":"NUMBER","value":13},"name":"Incrementing_Number","time":1479135269000,"quality":"GOOD"},{"value":{"baseType":"DATETIME","value":923169600000},"name":"Incrementing_DateTime","time":1479135269000,"quality":"GOOD"},{"value":{"baseType":"LOCATION","value":{"longitude":0,"latitude":0,"elevation":3}},"name":"Pushed_Incrementing_Location","time":1479135269000,"quality":"GOOD"},{"value":{"baseType":"INTEGER","value":3},"name":"AutoPush","time":1479135269000,"quality":"GOOD"},{"value":{"baseType":"LOCATION","value":{"longitude":77.36,"latitude":43.9,"elevation":163}},"name":"Script_Pushed_Location","time":1479135269000,"quality":"GOOD"},{"value":{"baseType":"DATETIME","value":1479142469000},"name":"Script_Pushed_Datetime","time":1479135269000,"quality":"GOOD"},{"value":{"baseType":"STRING","value":"Hello World"},"name":"Script_Pushed_String","time":1479135269000,"quality":"GOOD"},{"value":{"baseType":"NUMBER","value":100},"name":"Script_Pushed_Number","time":1479135269000,"q

                          [TRACE] 2016-11-14 22:54:29,521 luaBindings:newRapClient: Found RAP at localhost:8000

                          [TRACE] 2016-11-14 22:54:29,524 luaBindings: Got RAP timeout: 0

                          [DEBUG] 2016-11-14 22:54:29,524 SDK: twTlsClient_Create: Initializing TLS Client

                          [TRACE] 2016-11-14 22:54:29,524 HttpClient::processReq: POST /Thingworx/Things/*TestRemoteThing1/Services/UpdateSubscribedPropertyValues HTTP/1.1

                          [TRACE] 2016-11-14 22:54:29,524 httpClient::processReq: Adding default header content-type: application/json

                           

                           

                          [TRACE] 2016-11-14 22:54:29,524 httpClient::processReq: Adding default header host: localhost

                           

                           

                          [TRACE] 2016-11-14 22:54:29,655 HttpResponse::on_message_begin: Response started

                          [TRACE] 2016-11-14 22:54:29,655 HttpResponse::on_message_complete: Response complete.  Code: 500 Reason:

                          [DEBUG] 2016-11-14 22:54:29,659 TlsStream::doclose: Disconeccting socket

                          [DEBUG] 2016-11-14 22:54:29,659 SDK: twTlsClient_Close: Disconnecting from server

                          [TRACE] 2016-11-14 22:54:29,659 HttpClient::processReq: Response received. Response code = 500

                          [TRACE] 2016-11-14 22:54:29,659 HttpResponse::getBody: Attempting to read body as single string. m_contentLength: 0

                          [DEBUG] 2016-11-14 22:54:29,659 SDK: twTlsClient_Close: Disconnecting from server

                          [TRACE] 2016-11-14 22:54:29,659 thingworx.server: Results - code: 500, resp:

                          [INFO ] 2016-11-14 22:54:29,663 TestRemoteThing1: Error occured while accessing EMS. Checking isConnected.

                          [TRACE] 2016-11-14 22:54:29,663 luaBindings:newRapClient: Found RAP at localhost:8000

                          [TRACE] 2016-11-14 22:54:29,663 luaBindings: Got RAP timeout: 0

                          [DEBUG] 2016-11-14 22:54:29,663 SDK: twTlsClient_Create: Initializing TLS Client

                          [TRACE] 2016-11-14 22:54:29,663 HttpClient::processReq: GET /Thingworx/Things/LocalEms/Properties/isConnected HTTP/1.1

                          [TRACE] 2016-11-14 22:54:29,663 httpClient::processReq: Adding default header Host: localhost

                           

                           

                          [TRACE] 2016-11-14 22:54:29,663 HttpResponse::on_message_begin: Response started

                          [TRACE] 2016-11-14 22:54:29,663 HttpResponse::on_message_complete: Response complete.  Code: 200 Reason:

                          [DEBUG] 2016-11-14 22:54:29,667 TlsStream::doclose: Disconeccting socket

                          [DEBUG] 2016-11-14 22:54:29,667 SDK: twTlsClient_Close: Disconnecting from server

                          [TRACE] 2016-11-14 22:54:29,667 HttpClient::processReq: Response received. Response code = 200

                          [TRACE] 2016-11-14 22:54:29,667 HttpResponse::getBody: Attempting to read body as single string. m_contentLength: 154

                          [TRACE] 2016-11-14 22:54:29,667 HttpResponse::getBody: Read body as single string. m_body: {"rows":[{"isConnected":true}],"datashape":{"fieldDefinitions":{"isConnected":{"name":"isConnected","description":"","baseType":"BOOLEAN","aspects":{}}}}}

                          [DEBUG] 2016-11-14 22:54:29,667 SDK: twTlsClient_Close: Disconnecting from server

                          [INFO ] 2016-11-14 22:54:29,667 TestRemoteThing1: EMS is available: true, online: true

                          [WARN ] 2016-11-14 22:54:29,667 thingworx.server: Could not set properties on server. code: 500, resp:

                          [TRACE] 2016-11-14 22:54:39,211 TestRemoteThing1: Executing task RunStoreAndForwardTest

                          [TRACE] 2016-11-14 22:54:39,211 TestRemoteThing1: Executing task UpdatePropertyMap

                          [TRACE] 2016-11-14 22:54:39,213 TestRemoteThing1: Checking properties.upToDate: false

                          [TRACE] 2016-11-14 22:54:39,214 TestRemoteThing1: Found handler inmemory

                          [TRACE] 2016-11-14 22:54:39,215 TestRemoteThing1: Read property: upToDate

                          [DEBUG] 2016-11-14 22:54:39,216 thingworx.server: Invoking /Thingworx/Things/*TestRemoteThing1/Services/GetPropertySubscriptions on server. content: {}

                          [TRACE] 2016-11-14 22:54:39,217 luaBindings:newRapClient: Found RAP at localhost:8000

                          [TRACE] 2016-11-14 22:54:39,218 luaBindings: Got RAP timeout: 0

                          [DEBUG] 2016-11-14 22:54:39,218 SDK: twTlsClient_Create: Initializing TLS Client

                          [TRACE] 2016-11-14 22:54:39,218 HttpClient::processReq: POST /Thingworx/Things/*TestRemoteThing1/Services/GetPropertySubscriptions HTTP/1.1

                          [TRACE] 2016-11-14 22:54:39,218 httpClient::processReq: Adding default header content-type: application/json

                           

                           

                          [TRACE] 2016-11-14 22:54:39,219 httpClient::processReq: Adding default header host: localhost

                           

                           

                          [TRACE] 2016-11-14 22:54:39,421 HttpResponse::on_message_begin: Response started

                          [TRACE] 2016-11-14 22:54:39,421 HttpResponse::on_message_complete: Response complete.  Code: 500 Reason:

                          [DEBUG] 2016-11-14 22:54:39,421 TlsStream::doclose: Disconeccting socket

                          [DEBUG] 2016-11-14 22:54:39,421 SDK: twTlsClient_Close: Disconnecting from server

                          [TRACE] 2016-11-14 22:54:39,425 HttpClient::processReq: Response received. Response code = 500

                          [TRACE] 2016-11-14 22:54:39,425 HttpResponse::getBody: Attempting to read body as single string. m_contentLength: 0

                          [DEBUG] 2016-11-14 22:54:39,425 SDK: twTlsClient_Close: Disconnecting from server

                          [TRACE] 2016-11-14 22:54:39,425 thingworx.server: Results - code: 500, resp:

                          [INFO ] 2016-11-14 22:54:39,429 TestRemoteThing1: Error occured while accessing EMS. Checking isConnected.

                          [TRACE] 2016-11-14 22:54:39,429 luaBindings:newRapClient: Found RAP at localhost:8000

                          [TRACE] 2016-11-14 22:54:39,429 luaBindings: Got RAP timeout: 0

                          [DEBUG] 2016-11-14 22:54:39,429 SDK: twTlsClient_Create: Initializing TLS Client

                          [TRACE] 2016-11-14 22:54:39,429 HttpClient::processReq: GET /Thingworx/Things/LocalEms/Properties/isConnected HTTP/1.1

                          [TRACE] 2016-11-14 22:54:39,429 httpClient::processReq: Adding default header Host: localhost

                           

                           

                          [TRACE] 2016-11-14 22:54:39,433 HttpResponse::on_message_begin: Response started

                          [TRACE] 2016-11-14 22:54:39,433 HttpResponse::on_message_complete: Response complete.  Code: 200 Reason:

                          [DEBUG] 2016-11-14 22:54:39,433 TlsStream::doclose: Disconeccting socket

                          [DEBUG] 2016-11-14 22:54:39,437 SDK: twTlsClient_Close: Disconnecting from server

                          [TRACE] 2016-11-14 22:54:39,437 HttpClient::processReq: Response received. Response code = 200

                          [TRACE] 2016-11-14 22:54:39,437 HttpResponse::getBody: Attempting to read body as single string. m_contentLength: 154

                          [TRACE] 2016-11-14 22:54:39,437 HttpResponse::getBody: Read body as single string. m_body: {"rows":[{"isConnected":true}],"datashape":{"fieldDefinitions":{"isConnected":{"name":"isConnected","description":"","baseType":"BOOLEAN","aspects":{}}}}}

                          [DEBUG] 2016-11-14 22:54:39,437 SDK: twTlsClient_Close: Disconnecting from server

                          [INFO ] 2016-11-14 22:54:39,437 TestRemoteThing1: EMS is available: true, online: true

                          [INFO ] 2016-11-14 22:54:39,441 TestRemoteThing1: Attempting to GetPropertySubscriptions from server failed. code: 500, result:

                          [TRACE] 2016-11-14 22:54:39,441 TestRemoteThing1: Attempting to set property upToDate

                          [TRACE] 2016-11-14 22:54:39,441 TestRemoteThing1: Found handler inmemory

                          [DEBUG] 2016-11-14 22:54:39,441 TestRemoteThing1: Wrote property: upToDate Updated updateTime to 1666529176

                          [TRACE] 2016-11-14 22:54:39,445 setProperty: Code: 200 Msg nil

                          [TRACE] 2016-11-14 22:54:39,445 GetPropertySubscriptions: Code: 500 Msg Attempting to GetPropertySubscriptions from server failed. code: 500, result: