MySensors - Nothing works?

hdrider465 · March 16, 2016, 6:05pm

I must be really dense - I have been working for weeks trying to get a simple MySensors network up.
I have one WiFI Gateway built - I can telnet to it on port 5003 and see that it is running fine. I Have joined one simple relay sensor to it again no problem.
I have the plugin created and taking to the gateway - As I am telneted into the gateway I can see openluup client connect.
I put the plugin into include mode and got the relay device and a repeater device created.
Now this is where it all stops working
I can never turn on the relay - I click on the On/Off slider and nothing happens. Monitoring the telnet session on the gateway I get no communications. I have reloaded Luup several times - Let it sit for hours - power cycled the relay device - power cycled the gateway…
Seams like everyone else gets this all working and it is very stable - What the heck am I doing wrong?

All versions of AutUI and OpenLuup are the latest releases.

Thanks

akbooer · March 16, 2016, 6:46pm

Sorry to hear of your difficulties… sounds like you should have posted sooner!

I confess, I have not tried either a repeater or a relay, but since the plugin runs (for me) with no modifications, I assume that this is probably not the problem. Which version of the Arduino plugin are you, in fact, running? I haven’t tried to update recently, so on the control panel it shows me:
[tt]
Plugin Version: 1.4
Lib Version: 1.5
[/tt]
The fact that you have successfully included your devices must mean that the basic hardware and software are working.

On my development machine, I’m running a small MySensors network with two nodes:

[ol][li]Sensebender with standard T and H sensors[/li]
[li]my own multi-sensor code running on a nano[/li][/ol]

It would perhaps be useful to compare logs at startup. Following a reload, the relevant log entries I see are:

2016-03-16 18:35:14.876   openLuup.scheduler:: [7] device startup
2016-03-16 18:35:14.879   luup_log:7: Arduino plugin: loading library L_Arduino ...
2016-03-16 18:35:14.952   luup_log:7: Arduino plugin: library L_Arduino loaded
2016-03-16 18:35:14.956   luup.set_failure:7: status = false
2016-03-16 18:35:14.959   luup_log:7: Arduino: urn:upnp-arduino-cc:serviceId:arduino1,PluginVersion, 1.4, 7
2016-03-16 18:35:14.963   luup_log:7: Arduino: urn:upnp-arduino-cc:serviceId:arduino1,GWAddress, -, 7
2016-03-16 18:35:14.969   luup.variable_set:7: 7.urn:upnp-arduino-cc:serviceId:arduino1.GWAddress was: 127.0.0.1:5003 now: - #hooks:0
2016-03-16 18:35:14.983   luup_log:7: Arduino: Using network connection: IP address is 127.0.0.1:5003
2016-03-16 18:35:14.988   luup.io.open:7: connecting to 127.0.0.1:5003, using crlf protocol tcp{client}: 0x969348
2016-03-16 18:35:14.991   openLuup.io:7: connect OK
2016-03-16 18:35:15.002   luup_log:7: Arduino: urn:upnp-arduino-cc:serviceId:arduino1,GWAddress, 127.0.0.1:5003, 7
2016-03-16 18:35:15.006   luup.variable_set:7: 7.urn:upnp-arduino-cc:serviceId:arduino1.GWAddress was: - now: 127.0.0.1:5003 #hooks:0
2016-03-16 18:35:15.010   luup_log:7: Arduino: urn:upnp-org:serviceId:altui1,DisplayLine1, gateway: 127.0.0.1:5003, 7
2016-03-16 18:35:15.017   luup_log:7: Arduino: Sending: 0;0;3;0;2;Get Version
2016-03-16 18:35:15.023   luup.io.write:7: message length: 23, bytes sent: 23, status: OK tcp{client}: 0x969348
2016-03-16 18:35:15.027   openLuup.scheduler:: [7] device startup completed: status=nil, msg=nil, name=nil

...

2016-03-16 18:35:26.160   luup.io.incoming:7: bytes received: 36, status: OK tcp{client}: 0x969348
2016-03-16 18:35:26.165   luup_log:7: Arduino: Log: Gateway startup complete.

...

2016-03-16 18:35:29.905   luup.io.incoming:7: bytes received: 13, status: OK tcp{client}: 0x969348
2016-03-16 18:35:29.909   luup_log:7: Arduino: urn:upnp-arduino-cc:serviceId:arduino1,ArduinoLibVersion, 1.5, 7

...

2016-03-16 18:35:29.981   luup.io.incoming:7: bytes received: 14, status: OK tcp{client}: 0x969348
2016-03-16 18:35:29.985   luup_log:7: Arduino: urn:micasaverde-com:serviceId:HaDevice1,BatteryLevel, 63, 45
2016-03-16 18:35:29.990   luup_log:7: Arduino: urn:micasaverde-com:serviceId:HaDevice1,BatteryDate, 1458153329, 45
2016-03-16 18:35:29.996   luup.variable_set:7: 45.urn:micasaverde-com:serviceId:HaDevice1.BatteryDate was: 1458153138 now: 1458153329 #hooks:0
2016-03-16 18:35:30.013   luup.io.incoming:7: bytes received: 14, status: OK tcp{client}: 0x969348
2016-03-16 18:35:30.032   luup_log:7: Arduino: Set variable: 2;1;1;0;0;10.7
2016-03-16 18:35:30.038   luup_log:7: Arduino: Setting variable 'CurrentTemperature' to value '10.7'
2016-03-16 18:35:30.041   luup_log:7: Arduino: urn:upnp-org:serviceId:TemperatureSensor1,CurrentTemperature, 10.7, 43
2016-03-16 18:35:30.055   luup.variable_set:7: 43.urn:upnp-org:serviceId:TemperatureSensor1.CurrentTemperature was: 10.8 now: 10.7 #hooks:1
2016-03-16 18:35:30.128   luup_log:7: Arduino: urn:micasaverde-com:serviceId:HaDevice1,LastUpdate, 1458153330, 43
2016-03-16 18:35:30.134   luup.variable_set:7: 43.urn:micasaverde-com:serviceId:HaDevice1.LastUpdate was: 1458153200 now: 1458153330 #hooks:0
2016-03-16 18:35:30.138   luup_log:7: Arduino: urn:micasaverde-com:serviceId:HaDevice1,LastUpdate, 1458153330, 45
2016-03-16 18:35:30.142   luup.variable_set:7: 45.urn:micasaverde-com:serviceId:HaDevice1.LastUpdate was: 1458153200 now: 1458153330 #hooks:0
2016-03-16 18:35:30.157   luup_log:7: Arduino: urn:upnp-org:serviceId:altui1,DisplayLine2, ... at 18:35, 45
2016-03-16 18:35:30.160   luup.variable_set:7: 45.urn:upnp-org:serviceId:altui1.DisplayLine2 was: ... at 18:33 now: ... at 18:35 #hooks:0
2016-03-16 18:35:30.164   luup_log:7: Arduino: urn:micasaverde-com:serviceId:HaDevice1,LastUpdateHR, 18:35, 45
2016-03-16 18:35:30.168   luup.variable_set:7: 45.urn:micasaverde-com:serviceId:HaDevice1.LastUpdateHR was: 18:33 now: 18:35 #hooks:0

...

2016-03-16 18:35:30.194   luup_log:7: Arduino: Set variable: 2;2;1;0;1;69
2016-03-16 18:35:30.197   luup_log:7: Arduino: Setting variable 'CurrentLevel' to value '69'
2016-03-16 18:35:30.201   luup_log:7: Arduino: urn:micasaverde-com:serviceId:HumiditySensor1,CurrentLevel, 69, 44
2016-03-16 18:35:30.212   luup_log:7: Arduino: urn:micasaverde-com:serviceId:HaDevice1,LastUpdate, 1458153330, 44
2016-03-16 18:35:30.216   luup.variable_set:7: 44.urn:micasaverde-com:serviceId:HaDevice1.LastUpdate was: 1458153200 now: 1458153330 #hooks:0
2016-03-16 18:35:30.221   luup_log:7: Arduino: urn:micasaverde-com:serviceId:HaDevice1,LastUpdate, 1458153330, 45
2016-03-16 18:35:30.224   luup.variable_set:7: 45.urn:micasaverde-com:serviceId:HaDevice1.LastUpdate was: 1458153330 now: 1458153330 #hooks:0
2016-03-16 18:35:30.231   luup_log:7: Arduino: urn:upnp-org:serviceId:altui1,DisplayLine2, ... at 18:35, 45
2016-03-16 18:35:30.244   luup_log:7: Arduino: urn:micasaverde-com:serviceId:HaDevice1,LastUpdateHR, 18:35, 45

…showing the device startup and a few early incoming meaurements from the sensors.

Do you have anything which just sends data, rather than a device which requires control?

hdrider465 · March 24, 2016, 6:44pm

Thanks for replying

The plugin is version 1.5
Ther Lib Version is blank

The logs look like this

luup.create_device:: [31] D_Arduino1.xml / I_Arduino1.xml / D_Arduino1.json
2016-03-24 11:29:38.579 luup.create_device:: [36] D_ArduinoRelay1.xml / / D_ArduinoRelay1.json
2016-03-24 11:29:38.643 luup.create_device:: [34] D_ArduinoRelay1.xml / / D_ArduinoRelay1.json
2016-03-24 11:29:38.681 luup_log:31: Arduino plugin: loading library L_Arduino …
2016-03-24 11:29:38.689 luup_log:31: Arduino plugin: library L_Arduino loaded
2016-03-24 11:29:38.689 luup_log:31: Arduino: urn:upnp-arduino-cc:serviceId:arduino1,PluginVersion, 1.5, 31
2016-03-24 11:29:38.689 luup_log:31: Arduino: urn:upnp-arduino-cc:serviceId:arduino1,GWAddress, -, 31
2016-03-24 11:29:38.689 luup_log:31: Arduino: Using network connection: IP address is 192.168.253.246:5003
2016-03-24 11:29:38.689 luup_log:31: Arduino: urn:upnp-arduino-cc:serviceId:arduino1,GWAddress, 192.168.253.246:5003, 31
2016-03-24 11:29:38.689 luup_log:31: Arduino: Sending: 0;0;3;0;2;Get Version
2016-03-24 11:29:38.689 luup.variable_set:31: 31.urn:upnp-arduino-cc:serviceId:arduino1.GWAddress was: 192.168.253.246:5003 now: - #hooks:0
2016-03-24 11:29:38.689 luup_log:31: Arduino: Using network connection: IP address is 192.168.253.246:5003
2016-03-24 11:29:38.689 luup.io.open:31: connecting to 192.168.253.246:5003, using crlf protocol tcp{client}: 0x15850b8
2016-03-24 11:29:38.689 luup_log:31: Arduino: urn:upnp-arduino-cc:serviceId:arduino1,GWAddress, 192.168.253.246:5003, 31
2016-03-24 11:29:38.689 luup.variable_set:31: 31.urn:upnp-arduino-cc:serviceId:arduino1.GWAddress was: - now: 192.168.253.246:5003 #hooks:0
2016-03-24 11:29:38.690 luup_log:31: Arduino: Using network connection: IP address is 192.168.253.246:5003
2016-03-24 11:29:38.690 luup.io.open:31: connecting to 192.168.253.246:5003, using crlf protocol tcp{client}: 0x158a6d8
2016-03-24 11:29:38.690 luup_log:31: Arduino: Cannot send command - communications error

From the OpenLuup Server I can telnet into the GW with no problems
sudo telnet 192.168.253.246 5003
Trying 192.168.253.246…
Connected to 192.168.253.246.
Escape character is ‘^]’.
0;0;3;0;14;Gateway startup complete.

akbooer · March 24, 2016, 7:04pm

The lib version is blank because the communication with the gateway has not been established. The plugin version is different from what I am using. Here’s the Lua file for what works for me - can you try this one instead?

hdrider465 · March 24, 2016, 9:05pm

Well it is looking better

Plugin Version:1.4
Lib Version: 1.5.4

I will build up a T & H Sensor tonight and see if it will talk.

Thanks for the help.

akbooer · March 24, 2016, 9:38pm

OK, good news for you, I think. However, bad news for me since I need to see what’s broken in v.1.5!

hdrider465 · March 28, 2016, 7:39pm

OK - Did alot of experimenting over the weekend.
Looks like as longs as I have a sensor that reports status regularly (Like a temp / humidity sensor) active on the network everything works. But if I just have an action sensor ( like a relay switch ) then after about an hour it stops responding - If I turn the temperature sensor back on then everything starts to work again.

akbooer · March 28, 2016, 9:10pm

Interesting. Is this still with the 1.4 plugin version? or are you now talking of 1.5 (or both) ?

So, some sort of timeout, perhaps, if no reporting within an hour. Anything in the log to diagnose this?

hdrider465 · March 30, 2016, 6:42pm

using the 1.4 that you provided.
Looks like even with a reporting device - I loose connection after a period of time. Everything is working - then I go back into AltUI the next day and the temp / hum device will show show a last communication time of hours ago. Reload the luup engine and everything starts talking again. I will dig through the logs to see if I can find when it stops.

akbooer · April 1, 2016, 3:32pm

This would happen if the MySensors gateway lost power and/or rebooted. It would be the same if you were on openLuup or Vera. The IP connection to the gateway is established by the Arduino plugin at startup. Since it uses the luup.io module, there’s no way of catching a closed connection and reopening it, without a Luup reload.

hdrider465 · April 7, 2016, 8:54pm

Here are my logs - I will look into see if the gateway is resetting for some reason.
There is no way to have the connection restart if no data received in 5 minutes? Every-time that I check on the gateway it is up - but not sure if it glitched for a second at some time.

2016-04-05 11:36:52.203 luup_log:31: Arduino plugin: loading library L_Arduino ... 2016-04-05 11:36:52.204 luup_log:31: Arduino plugin: library L_Arduino loaded 2016-04-05 11:36:52.204 luup.set_failure:31: status = false 2016-04-05 11:36:52.204 luup_log:31: Arduino: urn:upnp-arduino-cc:serviceId:arduino1,PluginVersion, 1.4, 31 2016-04-05 11:36:52.204 luup_log:31: Arduino: urn:upnp-arduino-cc:serviceId:arduino1,GWAddress, -, 31 2016-04-05 11:36:52.204 luup.variable_set:31: 31.urn:upnp-arduino-cc:serviceId:arduino1.GWAddress was: 192.168.253.246:5003 now: - #hooks:0 2016-04-05 11:36:52.204 luup_log:31: Arduino: Using network connection: IP address is 192.168.253.246:5003 2016-04-05 11:36:52.241 luup.io.open:31: connecting to 192.168.253.246:5003, using crlf protocol tcp{client}: 0x3085ab8 2016-04-05 11:36:52.242 openLuup.io:31: connect OK 2016-04-05 11:36:52.242 luup_log:31: Arduino: urn:upnp-arduino-cc:serviceId:arduino1,GWAddress, 192.168.253.246:5003, 31 2016-04-05 11:36:52.242 luup.variable_set:31: 31.urn:upnp-arduino-cc:serviceId:arduino1.GWAddress was: - now: 192.168.253.246:5003 #hooks:0 2016-04-05 11:36:52.242 luup_log:31: Arduino: urn:upnp-org:serviceId:altui1,DisplayLine1, gateway: 192.168.253.246:5003, 31 2016-04-05 11:36:52.242 luup_log:31: Arduino: Sending: 0;0;3;0;2;Get Version 2016-04-05 11:36:52.242 luup.io.write:31: message length: 23, bytes sent: 23, status: OK tcp{client}: 0x3085ab8 2016-04-05 11:36:52.242 openLuup.scheduler:: [31] device startup completed: status=nil, msg=nil, name=nil 2016-04-05 11:36:52.304 luup_log:31: Arduino: Log: Gateway startup complete. 2016-04-05 11:36:52.465 luup.io.incoming:31: bytes received: 15, status: OK tcp{client}: 0x3085ab8 2016-04-05 11:36:52.465 luup_log:31: Arduino: urn:upnp-arduino-cc:serviceId:arduino1,ArduinoLibVersion, 1.5.4, 31 2016-04-05 11:37:16.142 luup.io.incoming:31: bytes received: 14, status: OK tcp{client}: 0x3085ab8 2016-04-05 11:37:16.143 luup_log:31: Arduino: Set variable: 1;1;1;0;0;76.8 2016-04-05 11:37:16.143 luup_log:31: Arduino: Setting variable 'CurrentTemperature' to value '76.8' 2016-04-05 11:37:16.143 luup_log:31: Arduino: urn:upnp-org:serviceId:TemperatureSensor1,CurrentTemperature, 76.8, 38 2016-04-05 11:37:16.143 luup.variable_set:31: 38.urn:upnp-org:serviceId:TemperatureSensor1.CurrentTemperature was: 78.4 now: 76.8 #hooks:0 2016-04-05 11:37:16.143 luup_log:31: Arduino: urn:micasaverde-com:serviceId:HaDevice1,LastUpdate, 1459881436, 38 2016-04-05 11:37:16.143 luup.variable_set:31: 38.urn:micasaverde-com:serviceId:HaDevice1.LastUpdate was: 1459565866 now: 1459881436 #hooks:0 2016-04-05 11:37:16.143 luup_log:31: Arduino: urn:micasaverde-com:serviceId:HaDevice1,LastUpdate, 1459881436, 37 2016-04-05 11:37:16.143 luup.variable_set:31: 37.urn:micasaverde-com:serviceId:HaDevice1.LastUpdate was: 1459565866 now: 1459881436 #hooks:0 2016-04-05 11:37:16.143 luup_log:31: Arduino: urn:upnp-org:serviceId:altui1,DisplayLine2, ... at 11:37 AM, 37 2016-04-05 11:37:16.143 luup.variable_set:31: 37.urn:upnp-org:serviceId:altui1.DisplayLine2 was: ... at 07:57 PM now: ... at 11:37 AM #hooks:0 2016-04-05 11:37:16.144 luup_log:31: Arduino: urn:micasaverde-com:serviceId:HaDevice1,LastUpdateHR, 11:37 AM, 37 2016-04-05 11:37:16.144 luup.variable_set:31: 37.urn:micasaverde-com:serviceId:HaDevice1.LastUpdateHR was: 07:57 PM now: 11:37 AM #hooks:0 2016-04-05 11:37:16.238 luup.io.incoming:31: bytes received: 14, status: OK tcp{client}: 0x3085ab8 2016-04-05 11:37:16.238 luup_log:31: Arduino: Set variable: 1;2;1;0;1;23.0 2016-04-05 11:37:16.238 luup_log:31: Arduino: Setting variable 'CurrentLevel' to value '23.0' 2016-04-05 11:37:16.238 luup_log:31: Arduino: urn:micasaverde-com:serviceId:HumiditySensor1,CurrentLevel, 23.0, 39 2016-04-05 11:37:16.238 luup.variable_set:31: 39.urn:micasaverde-com:serviceId:HumiditySensor1.CurrentLevel was: 27.0 now: 23.0 #hooks:0 2016-04-05 11:37:16.238 luup_log:31: Arduino: urn:micasaverde-com:serviceId:HaDevice1,LastUpdate, 1459881436, 39 2016-04-05 11:37:16.238 luup.variable_set:31: 39.urn:micasaverde-com:serviceId:HaDevice1.LastUpdate was: 1459565866 now: 1459881436 #hooks:0 2016-04-05 11:37:16.238 luup_log:31: Arduino: urn:micasaverde-com:serviceId:HaDevice1,LastUpdate, 1459881436, 37 2016-04-05 11:37:16.238 luup.variable_set:31: 37.urn:micasaverde-com:serviceId:HaDevice1.LastUpdate was: 1459881436 now: 1459881436 #hooks:0 2016-04-05 11:37:16.238 luup_log:31: Arduino: urn:upnp-org:serviceId:altui1,DisplayLine2, ... at 11:37 AM, 37 2016-04-05 11:37:16.238 luup_log:31: Arduino: urn:micasaverde-com:serviceId:HaDevice1,LastUpdateHR, 11:37 AM, 37 2016-04-05 11:37:17.952 luup_log:31: Arduino: Sending: 2;2;1;1;2;1 2016-04-05 11:37:17.952 luup.io.write:31: message length: 13, bytes sent: 13, status: OK tcp{client}: 0x3085ab8 2016-04-05 11:37:18.002 luup.io.incoming:31: bytes received: 11, status: OK tcp{client}: 0x3085ab8 2016-04-05 11:37:18.002 luup_log:31: Arduino: Set variable: 2;2;1;1;2;1 2016-04-05 11:37:18.002 luup_log:31: Arduino: Setting variable 'Status' to value '1' 2016-04-05 11:37:18.002 luup_log:31: Arduino: urn:upnp-org:serviceId:SwitchPower1,Status, 1, 40 2016-04-05 11:37:18.002 luup.variable_set:31: 40.urn:upnp-org:serviceId:SwitchPower1.Status was: 0 now: 1 #hooks:0 2016-04-05 11:37:18.002 luup_log:31: Arduino: urn:micasaverde-com:serviceId:HaDevice1,LastUpdate, 1459881437, 40 2016-04-05 11:37:18.002 luup.variable_set:31: 40.urn:micasaverde-com:serviceId:HaDevice1.LastUpdate was: 1459488396 now: 1459881437 #hooks:0 2016-04-05 11:37:18.003 luup_log:31: Arduino: urn:micasaverde-com:serviceId:HaDevice1,LastUpdate, 1459881437, 41 2016-04-05 11:37:18.003 luup.variable_set:31: 41.urn:micasaverde-com:serviceId:HaDevice1.LastUpdate was: 1459488396 now: 1459881437 #hooks:0 2016-04-05 11:37:18.003 luup_log:31: Arduino: urn:upnp-org:serviceId:altui1,DisplayLine2, ... at 11:37 AM, 41 2016-04-05 11:37:18.003 luup.variable_set:31: 41.urn:upnp-org:serviceId:altui1.DisplayLine2 was: ... at 10:26 PM now: ... at 11:37 AM #hooks:0 2016-04-05 11:37:18.003 luup_log:31: Arduino: urn:micasaverde-com:serviceId:HaDevice1,LastUpdateHR, 11:37 AM, 41 2016-04-05 11:37:18.003 luup.variable_set:31: 41.urn:micasaverde-com:serviceId:HaDevice1.LastUpdateHR was: 10:26 PM now: 11:37 AM #hooks:0 2016-04-05 11:38:21.315 luup_log:31: Arduino: Set variable: 1;1;1;0;0;76.8 2016-04-05 11:38:21.315 luup_log:31: Arduino: Setting variable 'CurrentTemperature' to value '76.8' 2016-04-05 11:38:21.315 luup_log:31: Arduino: urn:upnp-org:serviceId:TemperatureSensor1,CurrentTemperature, 76.8, 38 2016-04-05 11:38:21.315 luup_log:31: Arduino: urn:micasaverde-com:serviceId:HaDevice1,LastUpdate, 1459881501, 38 2016-04-05 11:38:21.315 luup.variable_set:31: 38.urn:micasaverde-com:serviceId:HaDevice1.LastUpdate was: 1459881436 now: 1459881501 #hooks:0 2016-04-05 11:38:21.315 luup_log:31: Arduino: urn:micasaverde-com:serviceId:HaDevice1,LastUpdate, 1459881501, 37 2016-04-05 11:38:21.315 luup.variable_set:31: 37.urn:micasaverde-com:serviceId:HaDevice1.LastUpdate was: 1459881436 now: 1459881501 #hooks:0 2016-04-05 11:38:21.315 luup_log:31: Arduino: urn:upnp-org:serviceId:altui1,DisplayLine2, ... at 11:38 AM, 37 2016-04-05 11:38:21.315 luup.variable_set:31: 37.urn:upnp-org:serviceId:altui1.DisplayLine2 was: ... at 11:37 AM now: ... at 11:38 AM #hooks:0 2016-04-05 11:38:21.315 luup_log:31: Arduino: urn:micasaverde-com:serviceId:HaDevice1,LastUpdateHR, 11:38 AM, 37 2016-04-05 11:38:21.315 luup.variable_set:31: 37.urn:micasaverde-com:serviceId:HaDevice1.LastUpdateHR was: 11:37 AM now: 11:38 AM #hooks:0 2016-04-05 11:38:21.410 luup.io.incoming:31: bytes received: 14, status: OK tcp{client}: 0x3085ab8 2016-04-05 11:38:21.410 luup_log:31: Arduino: Set variable: 1;2;1;0;1;23.0 2016-04-05 11:38:21.411 luup_log:31: Arduino: Setting variable 'CurrentLevel' to value '23.0' 2016-04-05 11:38:21.411 luup_log:31: Arduino: urn:micasaverde-com:serviceId:HumiditySensor1,CurrentLevel, 23.0, 39 2016-04-05 11:38:21.411 luup_log:31: Arduino: urn:micasaverde-com:serviceId:HaDevice1,LastUpdate, 1459881501, 39 2016-04-05 11:38:21.411 luup.variable_set:31: 39.urn:micasaverde-com:serviceId:HaDevice1.LastUpdate was: 1459881436 now: 1459881501 #hooks:0 2016-04-05 11:38:21.411 luup_log:31: Arduino: urn:micasaverde-com:serviceId:HaDevice1,LastUpdate, 1459881501, 37 2016-04-05 11:38:21.411 luup.variable_set:31: 37.urn:micasaverde-com:serviceId:HaDevice1.LastUpdate was: 1459881501 now: 1459881501 #hooks:0 2016-04-05 11:38:21.411 luup_log:31: Arduino: urn:upnp-org:serviceId:altui1,DisplayLine2, ... at 11:38 AM, 37 2016-04-05 11:38:21.411 luup_log:31: Arduino: urn:micasaverde-com:serviceId:HaDevice1,LastUpdateHR, 11:38 AM, 37 Repeats every minute 2016-04-05 11:54:38.971 luup.io.incoming:31: bytes received: 14, status: OK tcp{client}: 0x3085ab8 2016-04-05 11:54:38.971 luup_log:31: Arduino: Set variable: 1;1;1;0;0;77.0 2016-04-05 11:54:38.971 luup_log:31: Arduino: Setting variable 'CurrentTemperature' to value '77.0' 2016-04-05 11:54:38.971 luup_log:31: Arduino: urn:upnp-org:serviceId:TemperatureSensor1,CurrentTemperature, 77.0, 38 2016-04-05 11:54:38.971 luup_log:31: Arduino: urn:micasaverde-com:serviceId:HaDevice1,LastUpdate, 1459882478, 38 2016-04-05 11:54:38.972 luup.variable_set:31: 38.urn:micasaverde-com:serviceId:HaDevice1.LastUpdate was: 1459882413 now: 1459882478 #hooks:0 2016-04-05 11:54:38.972 luup_log:31: Arduino: urn:micasaverde-com:serviceId:HaDevice1,LastUpdate, 1459882478, 37 2016-04-05 11:54:38.972 luup.variable_set:31: 37.urn:micasaverde-com:serviceId:HaDevice1.LastUpdate was: 1459882413 now: 1459882478 #hooks:0 2016-04-05 11:54:38.972 luup_log:31: Arduino: urn:upnp-org:serviceId:altui1,DisplayLine2, ... at 11:54 AM, 37 2016-04-05 11:54:38.972 luup.variable_set:31: 37.urn:upnp-org:serviceId:altui1.DisplayLine2 was: ... at 11:53 AM now: ... at 11:54 AM #hooks:0 2016-04-05 11:54:38.972 luup_log:31: Arduino: urn:micasaverde-com:serviceId:HaDevice1,LastUpdateHR, 11:54 AM, 37 2016-04-05 11:54:38.972 luup.variable_set:31: 37.urn:micasaverde-com:serviceId:HaDevice1.LastUpdateHR was: 11:53 AM now: 11:54 AM #hooks:0 2016-04-05 11:54:39.065 luup.io.incoming:31: bytes received: 14, status: OK tcp{client}: 0x3085ab8 2016-04-05 11:54:39.065 luup_log:31: Arduino: Set variable: 1;2;1;0;1;22.0 2016-04-05 11:54:39.065 luup_log:31: Arduino: Setting variable 'CurrentLevel' to value '22.0' 2016-04-05 11:54:39.065 luup_log:31: Arduino: urn:micasaverde-com:serviceId:HumiditySensor1,CurrentLevel, 22.0, 39 2016-04-05 11:54:39.066 luup_log:31: Arduino: urn:micasaverde-com:serviceId:HaDevice1,LastUpdate, 1459882479, 39 2016-04-05 11:54:39.066 luup.variable_set:31: 39.urn:micasaverde-com:serviceId:HaDevice1.LastUpdate was: 1459882413 now: 1459882479 #hooks:0 2016-04-05 11:54:39.066 luup_log:31: Arduino: urn:micasaverde-com:serviceId:HaDevice1,LastUpdate, 1459882479, 37 2016-04-05 11:54:39.066 luup.variable_set:31: 37.urn:micasaverde-com:serviceId:HaDevice1.LastUpdate was: 1459882478 now: 1459882479 #hooks:0 2016-04-05 11:54:39.066 luup_log:31: Arduino: urn:upnp-org:serviceId:altui1,DisplayLine2, ... at 11:54 AM, 37 2016-04-05 11:54:39.066 luup_log:31: Arduino: urn:micasaverde-com:serviceId:HaDevice1,LastUpdateHR, 11:54 AM, 37 34 Min gap in time no data 2016-04-05 12:28:11.613 luup.io.incoming:31: bytes received: 14, status: OK tcp{client}: 0x3085ab8 2016-04-05 12:28:11.614 luup_log:31: Arduino: Set variable: 1;1;1;0;0;77.5 2016-04-05 12:28:11.614 luup_log:31: Arduino: Setting variable 'CurrentTemperature' to value '77.5' 2016-04-05 12:28:11.614 luup_log:31: Arduino: urn:upnp-org:serviceId:TemperatureSensor1,CurrentTemperature, 77.5, 38 2016-04-05 12:28:11.614 luup.variable_set:31: 38.urn:upnp-org:serviceId:TemperatureSensor1.CurrentTemperature was: 77.0 now: 77.5 #hooks:0 2016-04-05 12:28:11.614 luup_log:31: Arduino: urn:micasaverde-com:serviceId:HaDevice1,LastUpdate, 1459884491, 38 2016-04-05 12:28:11.614 luup.variable_set:31: 38.urn:micasaverde-com:serviceId:HaDevice1.LastUpdate was: 1459882478 now: 1459884491 #hooks:0 2016-04-05 12:28:11.614 luup_log:31: Arduino: urn:micasaverde-com:serviceId:HaDevice1,LastUpdate, 1459884491, 37 2016-04-05 12:28:11.614 luup.variable_set:31: 37.urn:micasaverde-com:serviceId:HaDevice1.LastUpdate was: 1459882479 now: 1459884491 #hooks:0 2016-04-05 12:28:11.614 luup_log:31: Arduino: urn:upnp-org:serviceId:altui1,DisplayLine2, ... at 12:28 PM, 37 2016-04-05 12:28:11.614 luup.variable_set:31: 37.urn:upnp-org:serviceId:altui1.DisplayLine2 was: ... at 11:54 AM now: ... at 12:28 PM #hooks:0 2016-04-05 12:28:11.614 luup_log:31: Arduino: urn:micasaverde-com:serviceId:HaDevice1,LastUpdateHR, 12:28 PM, 37 2016-04-05 12:28:11.614 luup.variable_set:31: 37.urn:micasaverde-com:serviceId:HaDevice1.LastUpdateHR was: 11:54 AM now: 12:28 PM #hooks:0 2016-04-05 12:28:16.640 luup.io.incoming:31: bytes received: 14, status: OK tcp{client}: 0x3085ab8 2016-04-05 12:28:16.640 luup_log:31: Arduino: Set variable: 1;2;1;0;1;22.0 2016-04-05 12:28:16.640 luup_log:31: Arduino: Setting variable 'CurrentLevel' to value '22.0' 2016-04-05 12:28:16.641 luup_log:31: Arduino: urn:micasaverde-com:serviceId:HumiditySensor1,CurrentLevel, 22.0, 39 2016-04-05 12:28:16.641 luup_log:31: Arduino: urn:micasaverde-com:serviceId:HaDevice1,LastUpdate, 1459884496, 39 2016-04-05 12:28:16.641 luup.variable_set:31: 39.urn:micasaverde-com:serviceId:HaDevice1.LastUpdate was: 1459882479 now: 1459884496 #hooks:0 2016-04-05 12:28:16.641 luup_log:31: Arduino: urn:micasaverde-com:serviceId:HaDevice1,LastUpdate, 1459884496, 37 2016-04-05 12:28:16.641 luup.variable_set:31: 37.urn:micasaverde-com:serviceId:HaDevice1.LastUpdate was: 1459884491 now: 1459884496 #hooks:0 2016-04-05 12:28:16.641 luup_log:31: Arduino: urn:upnp-org:serviceId:altui1,DisplayLine2, ... at 12:28 PM, 37 2016-04-05 12:28:16.641 luup_log:31: Arduino: urn:micasaverde-com:serviceId:HaDevice1,LastUpdateHR, 12:28 PM, 37 Just Battery Update 2016-04-05 12:30:21.740 luup.io.incoming:31: bytes received: 17, status: OK tcp{client}: 0x3085ab8 2016-04-05 12:30:21.740 luup_log:31: Arduino: Set variable: 1;199;1;0;38;2334 25 Min Gap No Data 2016-04-05 12:55:15.147 luup.io.incoming:31: bytes received: 14, status: OK tcp{client}: 0x3085ab8 2016-04-05 12:55:15.147 luup_log:31: Arduino: Set variable: 1;1;1;0;0;78.0 2016-04-05 12:55:15.147 luup_log:31: Arduino: Setting variable 'CurrentTemperature' to value '78.0' 2016-04-05 12:55:15.147 luup_log:31: Arduino: urn:upnp-org:serviceId:TemperatureSensor1,CurrentTemperature, 78.0, 38 2016-04-05 12:55:15.147 luup.variable_set:31: 38.urn:upnp-org:serviceId:TemperatureSensor1.CurrentTemperature was: 77.5 now: 78.0 #hooks:0 2016-04-05 12:55:15.147 luup_log:31: Arduino: urn:micasaverde-com:serviceId:HaDevice1,LastUpdate, 1459886115, 38 2016-04-05 12:55:15.147 luup.variable_set:31: 38.urn:micasaverde-com:serviceId:HaDevice1.LastUpdate was: 1459884491 now: 1459886115 #hooks:0 2016-04-05 12:55:15.147 luup_log:31: Arduino: urn:micasaverde-com:serviceId:HaDevice1,LastUpdate, 1459886115, 37 2016-04-05 12:55:15.148 luup.variable_set:31: 37.urn:micasaverde-com:serviceId:HaDevice1.LastUpdate was: 1459884496 now: 1459886115 #hooks:0 2016-04-05 12:55:15.148 luup_log:31: Arduino: urn:upnp-org:serviceId:altui1,DisplayLine2, ... at 12:55 PM, 37 2016-04-05 12:55:15.148 luup.variable_set:31: 37.urn:upnp-org:serviceId:altui1.DisplayLine2 was: ... at 12:28 PM now: ... at 12:55 PM #hooks:0 2016-04-05 12:55:15.148 luup_log:31: Arduino: urn:micasaverde-com:serviceId:HaDevice1,LastUpdateHR, 12:55 PM, 37 2016-04-05 12:55:15.148 luup.variable_set:31: 37.urn:micasaverde-com:serviceId:HaDevice1.LastUpdateHR was: 12:28 PM now: 12:55 PM #hooks:0 2016-04-05 12:55:15.242 luup.io.incoming:31: bytes received: 14, status: OK tcp{client}: 0x3085ab8 2016-04-05 12:55:15.242 luup_log:31: Arduino: Set variable: 1;2;1;0;1;22.0 2016-04-05 12:55:15.242 luup_log:31: Arduino: Setting variable 'CurrentLevel' to value '22.0' 2016-04-05 12:55:15.242 luup_log:31: Arduino: urn:micasaverde-com:serviceId:HumiditySensor1,CurrentLevel, 22.0, 39 2016-04-05 12:55:15.242 luup_log:31: Arduino: urn:micasaverde-com:serviceId:HaDevice1,LastUpdate, 1459886115, 39 2016-04-05 12:55:15.242 luup.variable_set:31: 39.urn:micasaverde-com:serviceId:HaDevice1.LastUpdate was: 1459884496 now: 1459886115 #hooks:0 2016-04-05 12:55:15.242 luup_log:31: Arduino: urn:micasaverde-com:serviceId:HaDevice1,LastUpdate, 1459886115, 37 2016-04-05 12:55:15.242 luup.variable_set:31: 37.urn:micasaverde-com:serviceId:HaDevice1.LastUpdate was: 1459886115 now: 1459886115 #hooks:0 2016-04-05 12:55:15.242 luup_log:31: Arduino: urn:upnp-org:serviceId:altui1,DisplayLine2, ... at 12:55 PM, 37 2016-04-05 12:55:15.242 luup_log:31: Arduino: urn:micasaverde-com:serviceId:HaDevice1,LastUpdateHR, 12:55 PM, 37

Nothing more until I restart Luup Engine

[hr]

[size=8pt]Edited by moderator: put log data into code block[/size]

akbooer · April 7, 2016, 9:20pm

The resumption of data after some very long gaps shows that the connection is still maintained, at least over those periods. And it’s somewhat surprising. This is not a typical socket timeout (indeed, the luup.io module code in openLuup using the LuaSocket library has features enabled to guard against this.) There is no error message, just no messages!? If the connection was closed on the openLuup side there would be a message.

Do you have any other way to monitor the MySensors network traffic? So far as I can see, the Arduino plugin is still running.

Of course, the answer may lie in the v1.5 library and whatever was stopping that from working.

hdrider465 · April 14, 2016, 12:37am

For now I have put a cron job in place to reload the Luup Engine every 30 minutes.

akbooer · April 14, 2016, 6:48am

Disappointing. That’s a very Vera-like fix. But I simply cannot duplicate your problem.

Edit: you could also achieve this with a scheduled scene which simply calls luup.reload().