Skip to main content
1-Visitor
February 28, 2018
Question

./luaScriptResource hangs on thingworx.handler: Creating a new handler.

  • February 28, 2018
  • 4 replies
  • 13565 views

I have spent a a couple days trying to get a raspberry to talk to Thingworx using the tutorial. I am able to get connected to the websocket and everything, and I can see that the value for isConnected on the PiThing Properties tab change to true. My issue is that I can't get the luaScriptResources to finish the connection process and send any of the variables over to Thingworx to bind them. Here is the output from both ./wsems and ./luaScriptResources. If any of you see anything that sticks out or know of something else I can try please let me know.
$: sudo ./wsems
[FORCE] 2018-02-28 21:49:34,205 ./wsems: Initializing EMS ....
[FORCE] 2018-02-28 21:49:34,205 main: Using config file /home/pi/microserver/etc/config.json
[INFO ] 2018-02-28 21:49:34,205 ./wsems: Creating the WsEms proxy.
[INFO ] 2018-02-28 21:49:34,205 ./wsems: Starting HTTP Server.
[INFO ] 2018-02-28 21:49:34,206 Main: Using custom certificate and private key for HTTP Server
[WARN ] 2018-02-28 21:49:34,206 Main: Encryption is disabled on HTTP Server.
[WARN ] 2018-02-28 21:49:34,206 Main: Authentication is disabled on the HTTP Server.
[INFO ] 2018-02-28 21:49:34,206 ./wsems: Initializing the ThingWorx REST interface.
[FORCE] 2018-02-28 21:49:34,206 httpServer: starting http server port=8080
[INFO ] 2018-02-28 21:49:34,207 wsEmsProxy::initialize: FIPS is disabled.
[INFO ] 2018-02-28 21:49:34,207 wsEmsProxy::initialize: Encryption is disabled on Web Socket connection.
[DEBUG] 2018-02-28 21:49:34,207 httpServer: http server bound to port=8080.
[WARN ] 2018-02-28 21:49:34,208 SDK: SDK Version: 2.0.4
[WARN ] 2018-02-28 21:49:34,208 SDK: TLS Library: OpenSSL
[WARN ] 2018-02-28 21:49:34,208 SDK: TLS Library Version: 1.0.2l
[WARN ] 2018-02-28 21:49:34,208 SDK: FIPS Capable
[DEBUG] 2018-02-28 21:49:34,208 SDK: twWs_Create: Initializing Websocket Client for 192.168.93.24:80//Thingworx/WS
[DEBUG] 2018-02-28 21:49:34,208 SDK: twTlsClient_Create: Initializing TLS Client
[DEBUG] 2018-02-28 21:49:34,217 SDK: twApi_Initialize: Websocket Established after 0 tries
[DEBUG] 2018-02-28 21:49:34,217 SDK: subscribedPropsMgr_Initialize: Initializing subscribed properties manager
[INFO ] 2018-02-28 21:49:34,217 WsProxy::initialize: EMS Version 5.4.0.114
[INFO ] 2018-02-28 21:49:34,217 WsProxy::initialize: twApi singleton initialized
[WARN ] 2018-02-28 21:49:34,217 WsProxy::initialize: Certificate validation is disabled.
[WARN ] 2018-02-28 21:49:34,217 WsProxy::initialize: Self signed certificates are enabled.
[DEBUG] 2018-02-28 21:49:34,217 jsonConfigurator::getJsonEntity: Key validation_criteria not found
[DEBUG] 2018-02-28 21:49:34,217 jsonConfigurator::getJsonEntity: Parent file not found
[DEBUG] 2018-02-28 21:49:34,218 SDK: twTunnelManager_Create: Tunnel Manager singleton already exists
[ERROR] 2018-02-28 21:49:34,218 SDK: twMap_Add: parse function returned null.
[DEBUG] 2018-02-28 21:49:34,217 WsEmsProxy::bindThing: Host specified as 'localhost'. Testing IPV6/IPV4 connectivity
[WARN ] 2018-02-28 21:49:34,219 WsEmsProxy::bindThing: Exception connecting to localhost:8001. Err: Connection refused [localhost:8001]
[WARN ] 2018-02-28 21:49:34,219 WsEmsProxy::bindThing: Changing host from 'localhost' to '127.0.0.1'
[DEBUG] 2018-02-28 21:49:34,220 SDK: added PiThing to boundList
[DEBUG] 2018-02-28 21:49:34,220 SDK: twApi_BindThings: not currently connected, only binding things to api
[DEBUG] 2018-02-28 21:49:34,220 SDK: twMessage_Delete: Deleting BIND Message: 1
[DEBUG] 2018-02-28 21:49:34,219 jsonConfigurator::getJsonEntity: Parent file not found
[INFO ] 2018-02-28 21:49:34,219 wsEmsProxy::initialize: Initialization complete!
[INFO ] 2018-02-28 21:49:34,220 ./wsems: Starting the connection.

192.168.93.24:80-->[DEBUG] 2018-02-28 21:49:34,221 SDK: twTlsClient_Reconnect: Re-establishing SSL context
[DEBUG] 2018-02-28 21:49:34,221 SDK: twTlsClient_Connect: Connecting to server
[DEBUG] 2018-02-28 21:49:34,224 SDK: ws_on_headers_complete: Websocket connected!
[INFO ] 2018-02-28 21:49:34,224 SDK: twWs_Connect: Websocket connected!
[DEBUG] 2018-02-28 21:49:34,224 SDK: twWs_SendMessage: Sent 60 bytes using 1 frames.
[DEBUG] 2018-02-28 21:49:34,266 SDK: twMessage_Delete: Deleting RESPONSE Message: 2
[DEBUG] 2018-02-28 21:49:34,266 SDK: twMessage_Delete: Deleting AUTH Message: 2
[WARN ] 2018-02-28 21:49:34,267 SDK: twBindBody_Delete: NULL body or stream pointer
[DEBUG] 2018-02-28 21:49:34,267 SDK: twMessage_Delete: Deleting BIND Message: 3
[DEBUG] 2018-02-28 21:49:34,267 SDK: twWs_SendMessage: Sent 26 bytes using 1 frames.
[DEBUG] 2018-02-28 21:49:34,269 SDK: sendCtlFrame: >>>>> Sending Ping. Msg: 21:49:34
[INFO ] 2018-02-28 21:49:34,271 Main: Succesfully connected. Saving .booted config file
[DEBUG] 2018-02-28 21:49:34,309 SDK: twMessage_Delete: Deleting RESPONSE Message: 3
[DEBUG] 2018-02-28 21:49:34,309 SDK: twMessage_Delete: Deleting BIND Message: 3
[DEBUG] 2018-02-28 21:49:35,315 SDK: twTlsClient_Create: Initializing TLS Client

$: sudo ./luaScriptResources
[INFO ] 2018-02-28 21:59:38,413 ./luaScriptResource: Using config file: /home/pi/microserver/etc/config.lua
[FORCE] 2018-02-28 21:59:38,413 ./luaScriptResource: Starting up ....

[INFO ] 2018-02-28 21:59:38,419 luaScriptResource:main: Encryption is disabled on the RAP connection.
[INFO ] 2018-02-28 21:59:38,420 luaScriptResource:main: FIPS is disabled.
[INFO ] 2018-02-28 21:59:38,424 ./luaScriptResource: New path is /home/pi/microserver/etc/thingworx/clibs:/home/pi/microserver/etc/custom/clibs:/home/pi/microserver/etc/community/clibs:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
[WARN ] 2018-02-28 21:59:38,427 ScriptResource::initialize: Encryption is disabled on HTTP Server.
[WARN ] 2018-02-28 21:59:38,427 ScriptResource::initialize: Authentication is disabled on the HTTP Server.
[INFO ] 2018-02-28 21:59:38,481 thingworx.shape: Creating a new shape.
[INFO ] 2018-02-28 21:59:38,482 PiThing: -- Configuration -------------------------------
[INFO ] 2018-02-28 21:59:38,482 PiThing: scanRate: 1000
[INFO ] 2018-02-28 21:59:38,482 PiThing: scanRateResolution: 500
[INFO ] 2018-02-28 21:59:38,483 PiThing: taskRate: 30000
[INFO ] 2018-02-28 21:59:38,484 PiThing: keepAliveRate: 60000
[INFO ] 2018-02-28 21:59:38,484 PiThing: requestTimeout: 15000
[INFO ] 2018-02-28 21:59:38,484 PiThing: registerRate: 43200000
[INFO ] 2018-02-28 21:59:38,484 PiThing: register: true
[INFO ] 2018-02-28 21:59:38,484 PiThing: getPropertySubscriptionOnReconnect: false
[INFO ] 2018-02-28 21:59:38,484 PiThing: maxConcurrentPropertyUpdates: 100
[INFO ] 2018-02-28 21:59:38,485 PiThing: defaultPushType: VALUE
[INFO ] 2018-02-28 21:59:38,488 PiThing: useShapes: true
[INFO ] 2018-02-28 21:59:38,488 PiThing: identifier: Not Specififed
[INFO ] 2018-02-28 21:59:38,488 PiThing: ------------------------------------------------
[FORCE] 2018-02-28 21:59:38,489 httpServer: starting http server port=8001
[INFO ] 2018-02-28 21:59:38,490 thingworx.template: Adding shape 'shapes.metadata' to template 'thingworx.template'
[INFO ] 2018-02-28 21:59:38,492 thingworx.template: Adding shape 'shapes.propsubscribe' to template 'thingworx.template'
[INFO ] 2018-02-28 21:59:38,493 thingworx.template: Creating new templates.PiTemplate named 'PiThing'
[INFO ] 2018-02-28 21:59:38,493 PiThing: -- Initializing properties ---------------------
[INFO ] 2018-02-28 21:59:38,493 PiThing: Initialized property upToDate [baseType: BOOLEAN, pushType: NEVER, handler: nil, value: true]
[INFO ] 2018-02-28 21:59:38,494 PiThing: Initialized property cpu_volt [baseType: NUMBER, pushType: ALWAYS, handler: nil, value: 0]
[INFO ] 2018-02-28 21:59:38,494 PiThing: Initialized property cpu_temperature [baseType: NUMBER, pushType: ALWAYS, handler: nil, value: 0]
[INFO ] 2018-02-28 21:59:38,494 PiThing: Initialized property cpu_freq [baseType: NUMBER, pushType: ALWAYS, handler: nil, value: 0]
[INFO ] 2018-02-28 21:59:38,494 PiThing: ------------------------------------------------
[ERROR] 2018-02-28 21:59:38,495 httpserver: Server socket error: Address already in use [127.0.0.1:8001]
[ERROR] 2018-02-28 21:59:38,495 httpServer: unable to bind http server to port=8001, trying next port.
[ERROR] 2018-02-28 21:59:38,495 httpServer: unable to bind http server to any port from 8001 to 8001.
[INFO ] 2018-02-28 21:59:40,464 PiThing: -- Starting script --------------------------
[INFO ] 2018-02-28 21:59:40,465 PiThing: Registering core callback handler
[INFO ] 2018-02-28 21:59:40,465 PiThing: Starting main loop
[INFO ] 2018-02-28 21:59:40,465 PiThing: Calling lifecycle start listeners.
[INFO ] 2018-02-28 21:59:40,465 shapes.propsubscribe: Initialized
[INFO ] 2018-02-28 21:59:40,466 thingworx.handler: Creating a new handler.

It just hangs at this point and doesn't go on. If I change setting to some other ports i.e. 80 I will get this from ./luaScriptResources, which I feel is due to incorrect port choice so I think what is above is the correct configuration but I thought I would include this for completeness.
$: sudo ./luaScriptResources
[INFO ] 2018-02-28 22:02:20,802 ./luaScriptResource: Using config file: /home/pi/microserver/etc/config.lua
[FORCE] 2018-02-28 22:02:20,802 ./luaScriptResource: Starting up ....

[INFO ] 2018-02-28 22:02:20,805 luaScriptResource:main: Encryption is disabled on the RAP connection.
[INFO ] 2018-02-28 22:02:20,805 luaScriptResource:main: FIPS is disabled.
[INFO ] 2018-02-28 22:02:20,807 ./luaScriptResource: New path is /home/pi/microserver/etc/thingworx/clibs:/home/pi/microserver/etc/custom/clibs:/home/pi/microserver/etc/community/clibs:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
[WARN ] 2018-02-28 22:02:20,808 ScriptResource::initialize: Encryption is disabled on HTTP Server.
[WARN ] 2018-02-28 22:02:20,808 ScriptResource::initialize: Authentication is disabled on the HTTP Server.
[FORCE] 2018-02-28 22:02:20,831 httpServer: starting http server port=8001
[ERROR] 2018-02-28 22:02:20,834 httpserver: Server socket error: Address already in use [127.0.0.1:8001]
[ERROR] 2018-02-28 22:02:20,834 httpServer: unable to bind http server to port=8001, trying next port.
[ERROR] 2018-02-28 22:02:20,836 httpServer: unable to bind http server to any port from 8001 to 8001.
[INFO ] 2018-02-28 22:02:20,858 thingworx.shape: Creating a new shape.
[INFO ] 2018-02-28 22:02:20,859 PiThing: -- Configuration -------------------------------
[INFO ] 2018-02-28 22:02:20,859 PiThing: scanRate: 1000
[INFO ] 2018-02-28 22:02:20,859 PiThing: scanRateResolution: 500
[INFO ] 2018-02-28 22:02:20,859 PiThing: taskRate: 30000
[INFO ] 2018-02-28 22:02:20,859 PiThing: keepAliveRate: 60000
[INFO ] 2018-02-28 22:02:20,860 PiThing: requestTimeout: 15000
[INFO ] 2018-02-28 22:02:20,860 PiThing: registerRate: 43200000
[INFO ] 2018-02-28 22:02:20,860 PiThing: register: true
[INFO ] 2018-02-28 22:02:20,860 PiThing: getPropertySubscriptionOnReconnect: false
[INFO ] 2018-02-28 22:02:20,860 PiThing: maxConcurrentPropertyUpdates: 100
[INFO ] 2018-02-28 22:02:20,860 PiThing: defaultPushType: VALUE
[INFO ] 2018-02-28 22:02:20,860 PiThing: useShapes: true
[INFO ] 2018-02-28 22:02:20,861 PiThing: identifier: Not Specififed
[INFO ] 2018-02-28 22:02:20,861 PiThing: ------------------------------------------------
[INFO ] 2018-02-28 22:02:20,862 thingworx.template: Adding shape 'shapes.metadata' to template 'thingworx.template'
[INFO ] 2018-02-28 22:02:20,862 thingworx.template: Adding shape 'shapes.propsubscribe' to template 'thingworx.template'
[INFO ] 2018-02-28 22:02:20,862 thingworx.template: Creating new templates.PiTemplate named 'PiThing'
[INFO ] 2018-02-28 22:02:20,862 PiThing: -- Initializing properties ---------------------
[INFO ] 2018-02-28 22:02:20,863 PiThing: Initialized property upToDate [baseType: BOOLEAN, pushType: NEVER, handler: nil, value: true]
[INFO ] 2018-02-28 22:02:20,863 PiThing: Initialized property cpu_volt [baseType: NUMBER, pushType: ALWAYS, handler: nil, value: 0]
[INFO ] 2018-02-28 22:02:20,863 PiThing: Initialized property cpu_temperature [baseType: NUMBER, pushType: ALWAYS, handler: nil, value: 0]
[INFO ] 2018-02-28 22:02:20,863 PiThing: Initialized property cpu_freq [baseType: NUMBER, pushType: ALWAYS, handler: nil, value: 0]
[INFO ] 2018-02-28 22:02:20,863 PiThing: ------------------------------------------------
[INFO ] 2018-02-28 22:02:22,833 PiThing: -- Starting script --------------------------
[INFO ] 2018-02-28 22:02:22,833 PiThing: Registering core callback handler
[INFO ] 2018-02-28 22:02:22,833 PiThing: Starting main loop
[INFO ] 2018-02-28 22:02:22,833 PiThing: Calling lifecycle start listeners.
[INFO ] 2018-02-28 22:02:22,834 shapes.propsubscribe: Initialized
[INFO ] 2018-02-28 22:02:22,834 thingworx.handler: Creating a new handler.
[ERROR] 2018-02-28 22:02:22,846 UnencryptedClientStream::doopen: Error opening socket. Error: 111
[ERROR] 2018-02-28 22:02:22,847 HttpClient::initialize: Exception while opening connection request to 127.0.0.1. Error: Error opening non-TLS socket [127.0.0.1:80]
[ERROR] 2018-02-28 22:02:22,847 luaBindings::httpPost: Error POSTing to HTTP Server at 127.0.0.1/Thingworx/Things/LocalEms/Services/AddEdgeThing
[INFO ] 2018-02-28 22:02:22,848 PiThing: Error occured while accessing EMS. Checking isConnected.
[ERROR] 2018-02-28 22:02:22,849 UnencryptedClientStream::doopen: Error opening socket. Error: 111
[ERROR] 2018-02-28 22:02:22,849 HttpClient::initialize: Exception while opening connection request to 127.0.0.1. Error: Error opening non-TLS socket [127.0.0.1:80]
[ERROR] 2018-02-28 22:02:22,850 luaBindings::httpGet: Error GETing from HTTP server at 127.0.0.1/Thingworx/Things/LocalEms/Properties/isConnected
[INFO ] 2018-02-28 22:02:22,850 PiThing: EMS is available: false, online: false

Thanks in advance for any help you can give!

4 replies

sservices1-VisitorAuthor
1-Visitor
February 28, 2018
I noticed an issue with my original post in the first execution of ./luaScriptResources. I have uploaded one which has no error being reported, which is the behavior I normally get
$: sudo ./luaScriptResources
[INFO ] 2018-02-28 22:14:21,623 ./luaScriptResource: Using config file: /home/pi/microserver/etc/config.lua
[FORCE] 2018-02-28 22:14:21,623 ./luaScriptResource: Starting up ....

[INFO ] 2018-02-28 22:14:21,630 luaScriptResource:main: Encryption is disabled on the RAP connection.
[INFO ] 2018-02-28 22:14:21,630 luaScriptResource:main: FIPS is disabled.
[INFO ] 2018-02-28 22:14:21,634 ./luaScriptResource: New path is /home/pi/microserver/etc/thingworx/clibs:/home/pi/microserver/etc/custom/clibs:/home/pi/microserver/etc/community/clibs:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
[WARN ] 2018-02-28 22:14:21,636 ScriptResource::initialize: Encryption is disabled on HTTP Server.
[WARN ] 2018-02-28 22:14:21,636 ScriptResource::initialize: Authentication is disabled on the HTTP Server.
[FORCE] 2018-02-28 22:14:21,677 httpServer: starting http server port=8001
[INFO ] 2018-02-28 22:14:21,697 thingworx.shape: Creating a new shape.
[INFO ] 2018-02-28 22:14:21,697 PiThing: -- Configuration -------------------------------
[INFO ] 2018-02-28 22:14:21,698 PiThing: scanRate: 1000
[INFO ] 2018-02-28 22:14:21,698 PiThing: scanRateResolution: 500
[INFO ] 2018-02-28 22:14:21,698 PiThing: taskRate: 30000
[INFO ] 2018-02-28 22:14:21,698 PiThing: keepAliveRate: 60000
[INFO ] 2018-02-28 22:14:21,699 PiThing: requestTimeout: 15000
[INFO ] 2018-02-28 22:14:21,699 PiThing: registerRate: 43200000
[INFO ] 2018-02-28 22:14:21,699 PiThing: register: true
[INFO ] 2018-02-28 22:14:21,699 PiThing: getPropertySubscriptionOnReconnect: false
[INFO ] 2018-02-28 22:14:21,699 PiThing: maxConcurrentPropertyUpdates: 100
[INFO ] 2018-02-28 22:14:21,699 PiThing: defaultPushType: VALUE
[INFO ] 2018-02-28 22:14:21,699 PiThing: useShapes: true
[INFO ] 2018-02-28 22:14:21,699 PiThing: identifier: Not Specififed
[INFO ] 2018-02-28 22:14:21,699 PiThing: ------------------------------------------------
[INFO ] 2018-02-28 22:14:21,700 thingworx.template: Adding shape 'shapes.metadata' to template 'thingworx.template'
[INFO ] 2018-02-28 22:14:21,701 thingworx.template: Adding shape 'shapes.propsubscribe' to template 'thingworx.template'
[INFO ] 2018-02-28 22:14:21,701 thingworx.template: Creating new templates.PiTemplate named 'PiThing'
[INFO ] 2018-02-28 22:14:21,701 PiThing: -- Initializing properties ---------------------
[INFO ] 2018-02-28 22:14:21,701 PiThing: Initialized property upToDate [baseType: BOOLEAN, pushType: NEVER, handler: nil, value: true]
[INFO ] 2018-02-28 22:14:21,702 PiThing: Initialized property cpu_volt [baseType: NUMBER, pushType: ALWAYS, handler: nil, value: 0]
[INFO ] 2018-02-28 22:14:21,702 PiThing: Initialized property cpu_temperature [baseType: NUMBER, pushType: ALWAYS, handler: nil, value: 0]
[INFO ] 2018-02-28 22:14:21,702 PiThing: Initialized property cpu_freq [baseType: NUMBER, pushType: ALWAYS, handler: nil, value: 0]
[INFO ] 2018-02-28 22:14:21,702 PiThing: ------------------------------------------------
[INFO ] 2018-02-28 22:14:23,672 PiThing: -- Starting script --------------------------
[INFO ] 2018-02-28 22:14:23,672 PiThing: Registering core callback handler
[INFO ] 2018-02-28 22:14:23,672 PiThing: Starting main loop
[INFO ] 2018-02-28 22:14:23,673 PiThing: Calling lifecycle start listeners.
[INFO ] 2018-02-28 22:14:23,673 shapes.propsubscribe: Initialized
[INFO ] 2018-02-28 22:14:23,674 thingworx.handler: Creating a new handler.
1-Visitor
March 1, 2018

i face the same issue... i believe there is a bug in the system.

Can you please post your wsems log?

 

My system shows there is an error in running the twTlsClient ( Both LuascriptResource and my TW Foundation Server  opens and closes the client connection) i get a DEBUG Msg like this..

 

[DEBUG] 01/Mar/2018:02:54:39 [+0000] HTTP Server: 154.29.168.192 - SeqId 4 - "" 400 375 "-"

 

if you see, it has inverted IP address... what can be reason for this?

12-Amethyst
March 21, 2018

From reading the original log, it sounds like a port conflict.  Try customizing your Lua Script Resource's config.lua to use a different port.  If you don't customize a port, it will try to use 8001 by default.  I've included a snippet from the docs that describes what values you can set in config.lua for the LSR and EMS's HTTP Server settings.  You need to make sure the `rap` settings match how your EMS is configured.

 

--
-- Connection parameters that reflect EMS configuration settings
--
scripts.rap_host = "127.0.0.1" 
scripts.rap_port = "8000"
scripts.rap_ssl = true
scripts.rap_server_authenticate = true
scripts.rap_cert_file = "pki/ca.pem"
scripts.rap_deny_selfsigned = true
scripts.rap_validate = true

--
-- Lua Script Resource HTTP Server Configuration Parameters
--
scripts.script_resource_host = "127.0.0.1"
scripts.script_resource_port = "8001"
scripts.script_resource_ssl = "true"
scripts.script_resource_certificate_chain = "pki/LSR_HTTP_Server.crt"
scripts.script_resource_private_key = "pki/LSR_HTTP_Server.pem"
scripts.script_resource_passphrase = "password"
scripts.script_resource_authenticate = false
scripts.script_resource_use_default_certificate = false

 

 

5-Regular Member
March 1, 2018

Hi,

 

Can you post the contents of your config.json file from the EMS? Did you create an application key on the Platform?

 

 

Thanks!

 

-- Craig A.

1-Visitor
March 1, 2018

yes... everything is working fine on the communication side... 

TW server is talking to EMS and EMS and invoking the local host on 8001 port to ask for the remote thing..

 

Only issue is my remote thing from Config.lua is NOT getting registered.

 

lets take this scenario:

 

TW server is working and connected with EMS

EMS is working and connected to LuaResource. 

I tested this when i try to query remote properties, request flows from TW Server to LuaResource.

 

Here is the log i get on Luaresource

[DEBUG] 2018-03-01 15:13:19,864 thingworx.server: Invoking /Thingworx/Things/LocalEms/Services/AddEdgeThing on server. content: {"keepalive":60000,"port":"8001","timeout":15000,"host":"127.0.0.1","proto":"http","name":"*ExampleThing","path":"/scripts/Thingworx"}
[TRACE] 2018-03-01 15:13:19,865 luaBindings:newRapClient: Found RAP at 127.0.0.1:8080
[TRACE] 2018-03-01 15:13:19,865 luaBindings: Got RAP timeout: 0
[TRACE] 2018-03-01 15:13:19,865 luaRapBindings: Self Signed certificates are enabled for the RAP conneciton.
[TRACE] 2018-03-01 15:13:19,865 luaRapBindings: Certificate validation is disabled for the RAP conneciton.
[DEBUG] 2018-03-01 15:13:19,866 SDK: twTlsClient_Create: Initializing TLS Client

 

 

 

It stops here and tries registering on EMS and They get timed out in 30 sec..

and TwTlsClient exists...

 

What am i doing wrong ?

1-Visitor
March 1, 2018

Here is my Config Json and Config Lua files

12-Amethyst
March 21, 2018

I think what's happening here is the Lua Script Resource is unable to bind on it's default HTTP server port, which is 8001, because there is something else already bound on that address.  You can see that error in the logs here:

 

[ERROR] 2018-02-28 21:59:38,495 httpserver: Server socket error: Address already in use [127.0.0.1:8001]
[ERROR] 2018-02-28 21:59:38,495 httpServer: unable to bind http server to port=8001, trying next port.
[ERROR] 2018-02-28 21:59:38,495 httpServer: unable to bind http server to any port from 8001 to 8001.

If the LSR can't start it's http server, it will never be able to respond to requests from the EMS and would make sense that it would seem stuck (although I haven't confirmed this myself).  Have you tried customizing the 'script_resource_port` value in config.lua?

1-Visitor
March 21, 2018
Alex - I request you to set up a quick 30 min with me tomorrow so that I can show you what is happening. I have done all combinations of IP and ports and the problem lies somewhere else. I have compared the log with a working one as well. I have the system running and I can show you over WebEx. Pls suggest
12-Amethyst
March 21, 2018

Hi pbatwal,

 

I'm sorry you're encountering this issue.  Can you please open a case with support and provide them with the details you shared here, including logs, config files and environment details.  I'm not able to hop on a call but if you open a case I can make sure someone on my team takes a look into your issue.

 

Thanks,

-- Alex

1-Visitor
April 6, 2018

Hello,

I struggled a lot with this issue and realised that a problem in the Microserver 5.4 or in the LRS inside the package can cause these recurring disconnections. I fixed by installing the Microserver 5.3.4. There are still some network glitches but now I can always see the Thing connected. Let me know if you are successful as well.

Replaced 

MED-61060-CD-054_F000_Microserver-Linux-arm-hwfpu-openssl-5-4-0-114.zip

With

MED-61060-CD-053_SP5_Microserver-5-3-4-2383-Linux-ARM-HWFPU.zip

 

13-Aquamarine
April 9, 2018

If

-EMS and LSR are executed on a Linux env

-TLS is disabled

-a connection has established to ThingWorx platform using WSEMS

-there are no Errors logged in WSEMS and LSR logs,

-but the LSR hangs and the last fewlines of LSR look like this -

[TRACE] 2018-04-05 19:38:11,615 luaBindings:newRapClient: Found RAP at 10.0.2.15:8000
[TRACE] 2018-04-05 19:38:11,615 luaBindings: Got RAP timeout: 0
[TRACE] 2018-04-05 19:38:11,615 luaRapBindings: Self Signed certificates are enabled for the RAP conneciton.
[TRACE] 2018-04-05 19:38:11,615 luaRapBindings: Certificate validation is enabled for the RAP conneciton
[DEBUG] 2018-04-05 15:38:11,616 SDK: twTlsClient_Create: Initializing TLS Client

 

then it could be the bug reported with EMS 5.4.0. when run on Debian 9(stretch)/Ubuntu.

 

Workaround is to configure EMS and LSR to use TLS or to use a EMS version 5.3.4.

 

 

16-Pearl
May 15, 2018

I installed EMS 5.4.0 on Linux Centos7 and met the same problem, ssl is false in <http_server> segment.

- wsems started successfully

- lua started and hanged with below as last output, apparently it hanged...

-------------------------<Lua log>-----------------------

[INFO ] 2018-05-15 02:15:06,465 Edge540Thing: ------------------------------------------------
[INFO ] 2018-05-15 02:15:08,435 Edge540Thing: -- Starting script --------------------------
[INFO ] 2018-05-15 02:15:08,435 Edge540Thing: Registering core callback handler
[INFO ] 2018-05-15 02:15:08,435 Edge540Thing: Starting main loop
[INFO ] 2018-05-15 02:15:08,435 Edge540Thing: Calling lifecycle start listeners.
[INFO ] 2018-05-15 02:15:08,435 handlers.http: Opened
[INFO ] 2018-05-15 02:15:08,435 handlers.script: Opened
[INFO ] 2018-05-15 02:15:08,435 handlers.generator: Opened
[INFO ] 2018-05-15 02:15:08,435 shapes.propsubscribe: Initialized
[INFO ] 2018-05-15 02:15:08,436 thingworx.handler: Creating a new handler.

 

Then I  changed ssl to true in <http_server> segmen as below.Good news is that lua started successfully.

Bad news is that lua failed to connect with ems server thus no property update could be seen on Thingworx side.

And in lua log, I noticed there is a Http code 503 error.

-------------------------config.json-----------------------

"http_server" : {
        "host": "localhost",
        "port": 8000,
        "ssl" : true,
        "authenticate" : true,
        "user": "cui",
        "password": "ptc",
        "use_default_certificate" : true
    },

-------------------------config.lua-----------------------

scripts.rap_host = "localhost"
scripts.rap_port = "8000"
scripts.rap_ssl = true
scripts.rap_server_authenticate = true
scripts.rap_validate = false
scripts.rap_deny_selfsigned = false
scripts.rap_userid = "cui"
scripts.rap_password = "ptc"

-------------------------partial lua log-----------------------

[ERROR] 2018-05-15 01:59:44,144 HttpClient::processReq: Timeout while waiting for response from localhost.
[ERROR] 2018-05-15 01:59:44,144 luaBindings::httpPost★: Error POSTing to HTTP Server at localhost/Thingworx/Things/LocalEms/Services/AddEdgeThing
[INFO ] 2018-05-15 01:59:44,145 Edge540Thing: Error occured while accessing EMS. Checking isConnected.

[ERROR] 2018-05-15 02:00:14,153 HttpClient::processReq: Timeout while waiting for response from localhost.
[ERROR] 2018-05-15 02:00:14,153 luaBindings::httpGet★: Error GETing from HTTP server at localhost/Thingworx/Things/LocalEms/Properties/isConnected
[INFO ] 2018-05-15 02:00:14,153 Edge540Thing: EMS is available: false, online: false
[WARN ] 2018-05-15 02:00:14,153 Edge540Thing: Could not register with the MicroServer. ★code: 503, msg: Error attempting HTTP POST

 

Still not clear on below issues. Anyone has any clue??

1. why lua fails to start when not using SSL connection with ems server.

2. why lua fails to connect with ems server when using SSL connection.