tsathishkumar / MySController-rs

Controller for MySensors, exposes WoT APIs for the sensors. It supports OTA firmware updates, and also acts as proxy for all requests.
GNU Affero General Public License v3.0
20 stars 9 forks source link

Latest build results #29

Closed flatsiedatsie closed 5 years ago

flatsiedatsie commented 5 years ago

// scroll down to the end. The problem was fixed. But there are still two error messages.

Some results from the latest version:

Nov 28 22:51:58 DEBUG Ethernet client disconnected. Nov 28 22:52:33 DEBUG Ethernet client disconnected. Nov 28 22:52:33 DEBUG New connection from 127.0.0.1 Nov 28 22:52:33 DEBUG GWT:TSA:C=0,CONNECTED Nov 28 22:52:33 DEBUG GWT:TSA:C=1,DISCONNECTED Nov 28 22:53:01 DEBUG TSF:MSG:READ,14-14-0,s=255,c=3,t=24,pt=1,l=1,sg=0:1 Nov 28 22:53:01 DEBUG TSF:MSG:PINGED,ID=14,HP=1 Nov 28 22:53:01 DEBUG TSF:MSG:SEND,0-0-14-14,s=255,c=3,t=25,pt=1,l=1,sg=0,ft=0,st=OK:1 Nov 28 22:53:01 DEBUG TSF:MSG:READ,14-14-0,s=255,c=3,t=24,pt=1,l=5,sg=0:1 Nov 28 22:53:01 DEBUG !TSF:MSG:LEN,8!=12 Nov 28 22:53:03 DEBUG TSF:MSG:READ,9-14-0,s=255,c=3,t=24,pt=1,l=1,sg=0:2 Nov 28 22:53:03 DEBUG TSF:MSG:PINGED,ID=9,HP=2 Nov 28 22:53:03 DEBUG !TSF:MSG:SEND,0-0-14-9,s=255,c=3,t=25,pt=1,l=1,sg=0,ft=0,st=NACK:1 Nov 28 22:53:05 DEBUG TSF:MSG:READ,9-14-0,s=255,c=0,t=17,pt=0,l=10,sg=0:2.2.0-beta Nov 28 22:53:05 DEBUG TSF:MSG:READ,9-14-0,s=255,c=3,t=6,pt=1,l=1,sg=0:14 Nov 28 22:53:05 DEBUG TSF:MSG:READ,9-14-0,s=255,c=3,t=6,pt=1,l=1,sg=0:14 Nov 28 22:53:07 DEBUG TSF:MSG:READ,9-14-0,s=255,c=3,t=11,pt=0,l=25,sg=0:AIQ Sensor CO2 MH-Z19 and Nov 28 22:53:07 DEBUG TSF:MSG:READ,9-14-0,s=0,c=0,t=22,pt=0,l=0,sg=0: Nov 28 22:53:07 DEBUG TSF:MSG:READ,9-14-0,s=0,c=0,t=150,pt=0,l=0,sg=0: Nov 28 22:53:07 DEBUG TSF:MSG:READ,9-14-0,s=1,c=0,t=22,pt=0,l=0,sg=0: Nov 28 22:53:07 DEBUG TSF:MSG:READ,9-14-0,s=0,c=0,t=22,pt=0,l=0,sg=0: Nov 28 22:53:07 DEBUG TSF:MSG:READ,9-14-0,s=18,c=0,t=24,pt=0,l=0,sg=0: Nov 28 22:53:07 DEBUG TSF:MSG:READ,9-14-0,s=2,c=0,t=24,pt=0,l=0,sg=0: Nov 28 22:53:07 DEBUG TSF:MSG:READ,9-14-0,s=2,c=0,t=24,pt=0,l=0,sg=0: Nov 28 22:53:07 DEBUG TSF:MSG:READ,9-14-0,s=2,c=0,t=24,pt=0,l=0,sg=0: Nov 28 22:53:07 DEBUG TSF:MSG:READ,9-14-0,s=3,c=0,t=24,pt=0,l=0,sg=0: Nov 28 22:53:07 DEBUG TSF:MSG:READ,9-14-0,s=3,c=0,t=24,pt=0,l=0,sg=0: Nov 28 22:53:07 DEBUG TSF:MSG:READ,9-14-0,s=3,c=0,t=24,pt=0,l=0,sg=0: Nov 28 22:53:07 DEBUG TSF:MSG:READ,9-14-0,s=5,c=0,t=24,pt=1,l=0,sg=0:0 Nov 28 22:53:07 DEBUG TSF:MSG:ACK Nov 28 22:53:07 DEBUG TSF:MSG:READ,9-14-0,s=5,c=0,t=24,pt=0,l=0,sg=0: Nov 28 22:53:07 DEBUG TSF:MSG:READ,9-14-0,s=5,c=0,t=24,pt=0,l=0,sg=0: Nov 28 22:53:07 DEBUG TSF:MSG:READ,9-14-0,s=5,c=0,t=24,pt=0,l=0,sg=0: Nov 28 22:53:07 DEBUG TSF:MSG:READ,9-30-0,s=5,c=0,t=24,pt=0,l=0,sg=0: Nov 28 22:53:07 DEBUG TSF:MSG:READ,9-14-0,s=255,c=3,t=26,pt=1,l=1,sg=0:2 Nov 28 22:53:07 DEBUG TSF:MSG:SEND,0-0-14-9,s=255,c=3,t=27,pt=1,l=1,sg=0,ft=0,st=OK:1 Nov 28 22:53:08 DEBUG New connection from 127.0.0.1 Nov 28 22:53:08 DEBUG GWT:TSA:C=1,CONNECTED Nov 28 22:53:13 DEBUG GWT:TSA:C=0,DISCONNECTED Nov 28 22:53:13 DEBUG Ethernet client disconnected. Nov 28 22:53:19 DEBUG TSF:MSG:READ,14-14-0,s=0,c=1,t=37,pt=2,l=2,sg=0:4744 Nov 28 22:53:19 DEBUG TSF:MSG:ACK REQ Nov 28 22:53:19 DEBUG TSF:MSG:SEND,0-0-14-14,s=0,c=1,t=37,pt=2,l=2,sg=0,ft=0,st=OK:4744 Nov 28 22:53:28 DEBUG TSF:MSG:READ,9-14-0,s=2,c=1,t=37,pt=7,l=5,sg=0:5.0 Nov 28 22:53:28 DEBUG TSF:MSG:READ,9-14-0,s=5,c=1,t=37,pt=7,l=5,sg=0:9.0 Nov 28 22:53:29 DEBUG TSF:MSG:READ,9-14-0,s=4,c=1,t=37,pt=7,l=5,sg=0:2.0 Nov 28 22:53:30 DEBUG TSF:MSG:READ,9-14-0,s=0,c=1,t=37,pt=4,l=4,sg=0:-1 Nov 28 22:53:31 DEBUG TSF:MSG:READ,15-15-0,s=255,c=3,t=24,pt=1,l=1,sg=0:1 Nov 28 22:53:31 DEBUG TSF:MSG:PINGED,ID=15,HP=1 Nov 28 22:53:31 DEBUG TSF:MSG:SEND,0-0-15-15,s=255,c=3,t=25,pt=1,l=1,sg=0,ft=0,st=OK:1 Nov 28 22:54:03 DEBUG New connection from 127.0.0.1 Nov 28 22:54:03 DEBUG GWT:TSA:C=0,CONNECTED Nov 28 22:54:28 DEBUG GWT:TSA:C=1,DISCONNECTED Nov 28 22:54:28 DEBUG Ethernet client disconnected. Nov 28 22:54:38 DEBUG New connection from 127.0.0.1 Nov 28 22:54:38 DEBUG GWT:TSA:C=1,CONNECTED Nov 28 22:54:43 DEBUG GWT:TSA:C=0,DISCONNECTED Nov 28 22:54:43 DEBUG Ethernet client disconnected. Nov 28 22:55:00 DEBUG TSF:MSG:READ,15-15-0,s=255,c=3,t=24,pt=1,l=1,sg=0:1 Nov 28 22:55:00 DEBUG !TSF:MSG:LEN,0!=8 Nov 28 22:55:02 DEBUG TSF:MSG:READ,9-46-16,s=1,c=3,t=165,pt=7,l=5,sg=0:1107.0 Nov 28 22:55:02 DEBUG TSF:MSG:REL MSG Nov 28 22:55:02 DEBUG !TSF:RTE:16 UNKNOWN Nov 28 22:55:02 DEBUG !TSF:MSG:SEND,9-0-16-16,s=1,c=3,t=165,pt=7,l=5,sg=0,ft=0,st=NACK:1107.0 Nov 28 22:55:13 DEBUG New connection from 127.0.0.1 Nov 28 22:55:13 DEBUG GWT:TSA:C=0,CONNECTED Nov 28 22:55:18 DEBUG GWT:TSA:C=1,DISCONNECTED Nov 28 22:55:18 DEBUG Ethernet client disconnected.

The server itself says this:

INFO 2018-11-28T21:53:48Z: myscontroller_rs::core::connection: 0.0.0.0:5003 << 0;255;3;0;2; ERROR 2018-11-28T21:54:01Z: myscontroller_rs::core::connection: Error while reading -- Os { code: 11, kind: WouldBlock, message: "Resource temporarily unavailable" } INFO 2018-11-28T21:54:03Z: myscontroller_rs::core::connection: Waiting for server connection -- 0.0.0.0:5003 ... INFO 2018-11-28T21:54:03Z: myscontroller_rs::core::connection: Connected to -- 0.0.0.0:5003 INFO 2018-11-28T21:54:03Z: myscontroller_rs::core::connection: 0.0.0.0:5003 << 0;255;3;0;2; INFO 2018-11-28T21:54:03Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "0;255;3;0;14;Gateway startup complete.\n" INFO 2018-11-28T21:54:03Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "0;255;0;0;18;2.3.0\n" INFO 2018-11-28T21:54:28Z: myscontroller_rs::core::connection: 0.0.0.0:5003 << 0;255;3;0;2; ERROR 2018-11-28T21:54:33Z: myscontroller_rs::core::connection: Error while reading -- Os { code: 11, kind: WouldBlock, message: "Resource temporarily unavailable" } INFO 2018-11-28T21:54:38Z: myscontroller_rs::core::connection: Waiting for server connection -- 0.0.0.0:5003 ... INFO 2018-11-28T21:54:38Z: myscontroller_rs::core::connection: Connected to -- 0.0.0.0:5003 INFO 2018-11-28T21:54:38Z: myscontroller_rs::core::connection: 0.0.0.0:5003 << 0;255;3;0;2; INFO 2018-11-28T21:54:38Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "0;255;3;0;14;Gateway startup complete.\n" INFO 2018-11-28T21:54:38Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "0;255;0;0;18;2.3.0\n" INFO 2018-11-28T21:54:43Z: myscontroller_rs::core::connection: 0.0.0.0:5003 << 0;255;3;0;2; ERROR 2018-11-28T21:55:08Z: myscontroller_rs::core::connection: Error while reading -- Os { code: 11, kind: WouldBlock, message: "Resource temporarily unavailable" } INFO 2018-11-28T21:55:13Z: myscontroller_rs::core::connection: Waiting for server connection -- 0.0.0.0:5003 ... INFO 2018-11-28T21:55:13Z: myscontroller_rs::core::connection: Connected to -- 0.0.0.0:5003 INFO 2018-11-28T21:55:13Z: myscontroller_rs::core::connection: 0.0.0.0:5003 << 0;255;3;0;2; INFO 2018-11-28T21:55:13Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "0;255;3;0;14;Gateway startup complete.\n" INFO 2018-11-28T21:55:13Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "0;255;0;0;18;2.3.0\n" INFO 2018-11-28T21:55:18Z: myscontroller_rs::core::connection: 0.0.0.0:5003 << 0;255;3;0;2; INFO 2018-11-28T21:55:19Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "14;0;1;0;37;643\n" INFO 2018-11-28T21:55:19Z: myscontroller_rs::wot: Received SetMessage { node_id: 14, child_sensor_id: 0, ack: 0, value: Value { set_type: Level, value: "643" } } INFO 2018-11-28T21:55:19Z: myscontroller_rs::wot: Notifying property "level" with value Number(643.0)

flatsiedatsie commented 5 years ago

Also saw this:

WARN 2018-11-28T22:00:00Z: myscontroller_rs::wot: No thing found matching SetMessage { node_id: 9, child_sensor_id: 0, ack: 0, value: Value { set_type: Level, value: "-1" } } INFO 2018-11-28T22:00:09Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "9;2;3;0;37;6.0\n" ERROR 2018-11-28T22:00:09Z: myscontroller_rs::core::interceptor: Error while parsing command message InvalidSubType, simply forwarding to controller

flatsiedatsie commented 5 years ago

I see the server rebooting. I suspect that's the rebooting when a new device is found? However, when I click 'add devices' in the Mozilla Gateway I don't see any new devices.

WARN 2018-11-28T22:09:26Z: myscontroller_rs::wot::adapter: PresentationType Dust is not handled yet! WARN 2018-11-28T22:09:26Z: myscontroller_rs::wot::adapter: PresentationType ArduinoRepeaterNode is not handled yet! INFO 2018-11-28T22:09:26Z: myscontroller_rs::wot: Starting WoT server ERROR 2018-11-28T22:09:56Z: myscontroller_rs::core::connection: Error while reading -- Os { code: 11, kind: WouldBlock, message: "Resource temporarily unavailable" } INFO 2018-11-28T22:09:57Z: myscontroller_rs::core::connection: Waiting for server connection -- 0.0.0.0:5003 ... INFO 2018-11-28T22:09:57Z: myscontroller_rs::core::connection: Connected to -- 0.0.0.0:5003 INFO 2018-11-28T22:09:57Z: myscontroller_rs::core::connection: 0.0.0.0:5003 << 0;255;3;0;2; INFO 2018-11-28T22:09:57Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "0;255;3;0;14;Gateway startup complete.\n" INFO 2018-11-28T22:09:57Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "0;255;0;0;18;2.3.0\n" INFO 2018-11-28T22:09:59Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "9;255;3;0;11;AIQ Sensor CO2 MH-Z19 and\n" INFO 2018-11-28T22:09:59Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "9;0;0;0;22;\n" INFO 2018-11-28T22:09:59Z: myscontroller_rs::core::message_handler::presentation: Node doesn't exist for Sensor { node_id: 9, child_sensor_id: 0, sensor_type: AirQuality, description: "" }, Creating new node INFO 2018-11-28T22:09:59Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "9;128;0;0;22;\n" INFO 2018-11-28T22:09:59Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "9;0;0;0;22;\n" INFO 2018-11-28T22:09:59Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "9;0;0;0;54;\n" ERROR 2018-11-28T22:09:59Z: myscontroller_rs::core::interceptor: Error while parsing command message InvalidSubType, simply forwarding to controller INFO 2018-11-28T22:09:59Z: myscontroller_rs::core::message_handler::presentation: Created Sensor { node_id: 9, child_sensor_id: 0, sensor_type: AirQuality, description: "" } INFO 2018-11-28T22:09:59Z: myscontroller_rs::wot: Added new thing to things INFO 2018-11-28T22:09:59Z: myscontroller_rs::core::message_handler::presentation: Created Sensor { node_id: 9, child_sensor_id: 128, sensor_type: AirQuality, description: "" } INFO 2018-11-28T22:09:59Z: myscontroller_rs::wot: Added new thing to things INFO 2018-11-28T22:09:59Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "9;2;0;0;24;\n" INFO 2018-11-28T22:09:59Z: myscontroller_rs::core::message_handler::presentation: Created Sensor { node_id: 9, child_sensor_id: 2, sensor_type: Dust, description: "" } WARN 2018-11-28T22:09:59Z: myscontroller_rs::wot::adapter: PresentationType Dust is not handled yet! INFO 2018-11-28T22:09:59Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "9;5;0;0;24;\n" INFO 2018-11-28T22:09:59Z: myscontroller_rs::core::message_handler::presentation: Created Sensor { node_id: 9, child_sensor_id: 5, sensor_type: Dust, description: "" } WARN 2018-11-28T22:09:59Z: myscontroller_rs::wot::adapter: PresentationType Dust is not handled yet! INFO 2018-11-28T22:09:59Z: myscontroller_rs::wot: WoT Server stopped WARN 2018-11-28T22:09:59Z: myscontroller_rs::wot::adapter: PresentationType ArduinoRepeaterNode is not handled yet! WARN 2018-11-28T22:09:59Z: myscontroller_rs::wot::adapter: PresentationType ArduinoRepeaterNode is not handled yet! WARN 2018-11-28T22:09:59Z: myscontroller_rs::wot::adapter: PresentationType Info is not handled yet! WARN 2018-11-28T22:09:59Z: myscontroller_rs::wot::adapter: PresentationType Info is not handled yet! WARN 2018-11-28T22:09:59Z: myscontroller_rs::wot::adapter: PresentationType Info is not handled yet! WARN 2018-11-28T22:09:59Z: myscontroller_rs::wot::adapter: PresentationType Info is not handled yet! WARN 2018-11-28T22:09:59Z: myscontroller_rs::wot::adapter: PresentationType Info is not handled yet! WARN 2018-11-28T22:09:59Z: myscontroller_rs::wot::adapter: PresentationType Info is not handled yet! WARN 2018-11-28T22:09:59Z: myscontroller_rs::wot::adapter: PresentationType Info is not handled yet! WARN 2018-11-28T22:09:59Z: myscontroller_rs::wot::adapter: PresentationType ArduinoNode is not handled yet! WARN 2018-11-28T22:09:59Z: myscontroller_rs::wot::adapter: PresentationType Dust is not handled yet! WARN 2018-11-28T22:09:59Z: myscontroller_rs::wot::adapter: PresentationType Dust is not handled yet! WARN 2018-11-28T22:09:59Z: myscontroller_rs::wot::adapter: PresentationType ArduinoRepeaterNode is not handled yet! WARN 2018-11-28T22:09:59Z: myscontroller_rs::wot::adapter: PresentationType Dust is not handled yet! WARN 2018-11-28T22:09:59Z: myscontroller_rs::wot::adapter: PresentationType Dust is not handled yet! INFO 2018-11-28T22:10:00Z: myscontroller_rs::wot: Starting WoT server INFO 2018-11-28T22:10:02Z: myscontroller_rs::core::connection: 0.0.0.0:5003 << 0;255;3;0;2;

flatsiedatsie commented 5 years ago

And here there's a repeating issue where no connection to the MySensors ethernet gateway can be made. It seems to continuously reboot. But the log from the MySensors gateway itself shows that it isn't actually rebooting.

INFO 2018-11-28T22:09:59Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "9;128;0;0;22;\n" INFO 2018-11-28T22:09:59Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "9;0;0;0;22;\n" INFO 2018-11-28T22:09:59Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "9;0;0;0;54;\n" ERROR 2018-11-28T22:09:59Z: myscontroller_rs::core::interceptor: Error while parsing command message InvalidSubType, simply forwarding to controller INFO 2018-11-28T22:09:59Z: myscontroller_rs::core::message_handler::presentation: Created Sensor { node_id: 9, child_sensor_id: 0, sensor_type: AirQuality, description: "" } INFO 2018-11-28T22:09:59Z: myscontroller_rs::wot: Added new thing to things INFO 2018-11-28T22:09:59Z: myscontroller_rs::core::message_handler::presentation: Created Sensor { node_id: 9, child_sensor_id: 128, sensor_type: AirQuality, description: "" } INFO 2018-11-28T22:09:59Z: myscontroller_rs::wot: Added new thing to things INFO 2018-11-28T22:09:59Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "9;2;0;0;24;\n" INFO 2018-11-28T22:09:59Z: myscontroller_rs::core::message_handler::presentation: Created Sensor { node_id: 9, child_sensor_id: 2, sensor_type: Dust, description: "" } WARN 2018-11-28T22:09:59Z: myscontroller_rs::wot::adapter: PresentationType Dust is not handled yet! INFO 2018-11-28T22:09:59Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "9;5;0;0;24;\n" INFO 2018-11-28T22:09:59Z: myscontroller_rs::core::message_handler::presentation: Created Sensor { node_id: 9, child_sensor_id: 5, sensor_type: Dust, description: "" } WARN 2018-11-28T22:09:59Z: myscontroller_rs::wot::adapter: PresentationType Dust is not handled yet! INFO 2018-11-28T22:09:59Z: myscontroller_rs::wot: WoT Server stopped WARN 2018-11-28T22:09:59Z: myscontroller_rs::wot::adapter: PresentationType ArduinoRepeaterNode is not handled yet! WARN 2018-11-28T22:09:59Z: myscontroller_rs::wot::adapter: PresentationType ArduinoRepeaterNode is not handled yet! WARN 2018-11-28T22:09:59Z: myscontroller_rs::wot::adapter: PresentationType Info is not handled yet! WARN 2018-11-28T22:09:59Z: myscontroller_rs::wot::adapter: PresentationType Info is not handled yet! WARN 2018-11-28T22:09:59Z: myscontroller_rs::wot::adapter: PresentationType Info is not handled yet! WARN 2018-11-28T22:09:59Z: myscontroller_rs::wot::adapter: PresentationType Info is not handled yet! WARN 2018-11-28T22:09:59Z: myscontroller_rs::wot::adapter: PresentationType Info is not handled yet! WARN 2018-11-28T22:09:59Z: myscontroller_rs::wot::adapter: PresentationType Info is not handled yet! WARN 2018-11-28T22:09:59Z: myscontroller_rs::wot::adapter: PresentationType Info is not handled yet! WARN 2018-11-28T22:09:59Z: myscontroller_rs::wot::adapter: PresentationType ArduinoNode is not handled yet! WARN 2018-11-28T22:09:59Z: myscontroller_rs::wot::adapter: PresentationType Dust is not handled yet! WARN 2018-11-28T22:09:59Z: myscontroller_rs::wot::adapter: PresentationType Dust is not handled yet! WARN 2018-11-28T22:09:59Z: myscontroller_rs::wot::adapter: PresentationType ArduinoRepeaterNode is not handled yet! WARN 2018-11-28T22:09:59Z: myscontroller_rs::wot::adapter: PresentationType Dust is not handled yet! WARN 2018-11-28T22:09:59Z: myscontroller_rs::wot::adapter: PresentationType Dust is not handled yet! INFO 2018-11-28T22:10:00Z: myscontroller_rs::wot: Starting WoT server INFO 2018-11-28T22:10:02Z: myscontroller_rs::core::connection: 0.0.0.0:5003 << 0;255;3;0;2; INFO 2018-11-28T22:10:04Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "9;0;1;0;37;-1\n" INFO 2018-11-28T22:10:04Z: myscontroller_rs::wot: Received SetMessage { node_id: 9, child_sensor_id: 0, ack: 0, value: Value { set_type: Level, value: "-1" } } INFO 2018-11-28T22:10:04Z: myscontroller_rs::wot: Notifying property "level" with value Number(-1.0) INFO 2018-11-28T22:10:07Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "14;0;1;0;37;-1\n" INFO 2018-11-28T22:10:07Z: myscontroller_rs::wot: Received SetMessage { node_id: 14, child_sensor_id: 0, ack: 0, value: Value { set_type: Level, value: "-1" } } INFO 2018-11-28T22:10:07Z: myscontroller_rs::wot: Notifying property "level" with value Number(-1.0) ERROR 2018-11-28T22:10:37Z: myscontroller_rs::core::connection: Error while reading -- Os { code: 11, kind: WouldBlock, message: "Resource temporarily unavailable" } INFO 2018-11-28T22:10:37Z: myscontroller_rs::core::connection: 0.0.0.0:5003 << 0;255;3;0;2; INFO 2018-11-28T22:10:37Z: myscontroller_rs::core::connection: Waiting for server connection -- 0.0.0.0:5003 ... INFO 2018-11-28T22:10:37Z: myscontroller_rs::core::connection: Connected to -- 0.0.0.0:5003 INFO 2018-11-28T22:10:37Z: myscontroller_rs::core::connection: 0.0.0.0:5003 << 0;255;3;0;2; INFO 2018-11-28T22:10:37Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "0;255;3;0;14;Gateway startup complete.\n" INFO 2018-11-28T22:10:37Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "0;255;0;0;18;2.3.0\n" INFO 2018-11-28T22:10:59Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "25;2;1;0;101;4.0\n" ERROR 2018-11-28T22:10:59Z: myscontroller_rs::core::interceptor: Error while parsing command message InvalidSubType, simply forwarding to controller INFO 2018-11-28T22:11:17Z: myscontroller_rs::core::connection: 0.0.0.0:5003 << 0;255;3;0;2; ERROR 2018-11-28T22:11:30Z: myscontroller_rs::core::connection: Error while reading -- Os { code: 11, kind: WouldBlock, message: "Resource temporarily unavailable" } INFO 2018-11-28T22:11:33Z: myscontroller_rs::core::connection: Waiting for server connection -- 0.0.0.0:5003 ... INFO 2018-11-28T22:11:33Z: myscontroller_rs::core::connection: Connected to -- 0.0.0.0:5003 INFO 2018-11-28T22:11:33Z: myscontroller_rs::core::connection: 0.0.0.0:5003 << 0;255;3;0;2; INFO 2018-11-28T22:11:33Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "0;255;3;0;14;Gateway startup complete.\n" INFO 2018-11-28T22:11:33Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "0;255;0;0;18;2.3.0\n" INFO 2018-11-28T22:11:57Z: myscontroller_rs::core::connection: 0.0.0.0:5003 << 0;255;3;0;2; ERROR 2018-11-28T22:12:03Z: myscontroller_rs::core::connection: Error while reading -- Os { code: 11, kind: WouldBlock, message: "Resource temporarily unavailable" } INFO 2018-11-28T22:12:08Z: myscontroller_rs::core::connection: Waiting for server connection -- 0.0.0.0:5003 ... INFO 2018-11-28T22:12:08Z: myscontroller_rs::core::connection: Connected to -- 0.0.0.0:5003 INFO 2018-11-28T22:12:08Z: myscontroller_rs::core::connection: 0.0.0.0:5003 << 0;255;3;0;2; INFO 2018-11-28T22:12:08Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "0;255;3;0;14;Gateway startup complete.\n" INFO 2018-11-28T22:12:08Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "0;255;0;0;18;2.3.0\n" INFO 2018-11-28T22:12:13Z: myscontroller_rs::core::connection: 0.0.0.0:5003 << 0;255;3;0;2; ERROR 2018-11-28T22:12:38Z: myscontroller_rs::core::connection: Error while reading -- Os { code: 11, kind: WouldBlock, message: "Resource temporarily unavailable" } INFO 2018-11-28T22:12:43Z: myscontroller_rs::core::connection: Waiting for server connection -- 0.0.0.0:5003 ... INFO 2018-11-28T22:12:43Z: myscontroller_rs::core::connection: Connected to -- 0.0.0.0:5003 INFO 2018-11-28T22:12:43Z: myscontroller_rs::core::connection: 0.0.0.0:5003 << 0;255;3;0;2; INFO 2018-11-28T22:12:43Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "0;255;3;0;14;Gateway startup complete.\n" INFO 2018-11-28T22:12:43Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "0;255;0;0;18;2.3.0\n" INFO 2018-11-28T22:12:48Z: myscontroller_rs::core::connection: 0.0.0.0:5003 << 0;255;3;0;2; ERROR 2018-11-28T22:13:13Z: myscontroller_rs::core::connection: Error while reading -- Os { code: 11, kind: WouldBlock, message: "Resource temporarily unavailable" } INFO 2018-11-28T22:13:18Z: myscontroller_rs::core::connection: Waiting for server connection -- 0.0.0.0:5003 ... INFO 2018-11-28T22:13:18Z: myscontroller_rs::core::connection: Connected to -- 0.0.0.0:5003 INFO 2018-11-28T22:13:18Z: myscontroller_rs::core::connection: 0.0.0.0:5003 << 0;255;3;0;2; INFO 2018-11-28T22:13:18Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "0;255;3;0;14;Gateway startup complete.\n" INFO 2018-11-28T22:13:18Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "0;255;0;0;18;2.3.0\n" INFO 2018-11-28T22:13:23Z: myscontroller_rs::core::connection: 0.0.0.0:5003 << 0;255;3;0;2; ERROR 2018-11-28T22:13:48Z: myscontroller_rs::core::connection: Error while reading -- Os { code: 11, kind: WouldBlock, message: "Resource temporarily unavailable" } INFO 2018-11-28T22:13:53Z: myscontroller_rs::core::connection: Waiting for server connection -- 0.0.0.0:5003 ... INFO 2018-11-28T22:13:53Z: myscontroller_rs::core::connection: Connected to -- 0.0.0.0:5003 INFO 2018-11-28T22:13:53Z: myscontroller_rs::core::connection: 0.0.0.0:5003 << 0;255;3;0;2; INFO 2018-11-28T22:13:53Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "0;255;3;0;14;Gateway startup complete.\n" INFO 2018-11-28T22:13:53Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "0;255;0;0;18;2.3.0\n" INFO 2018-11-28T22:13:58Z: myscontroller_rs::core::connection: 0.0.0.0:5003 << 0;255;3;0;2; ERROR 2018-11-28T22:14:23Z: myscontroller_rs::core::connection: Error while reading -- Os { code: 11, kind: WouldBlock, message: "Resource temporarily unavailable" } INFO 2018-11-28T22:14:28Z: myscontroller_rs::core::connection: Waiting for server connection -- 0.0.0.0:5003 ... INFO 2018-11-28T22:14:28Z: myscontroller_rs::core::connection: Connected to -- 0.0.0.0:5003 INFO 2018-11-28T22:14:28Z: myscontroller_rs::core::connection: 0.0.0.0:5003 << 0;255;3;0;2; INFO 2018-11-28T22:14:28Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "0;255;3;0;14;Gateway startup complete.\n" INFO 2018-11-28T22:14:28Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "0;255;0;0;18;2.3.0\n" INFO 2018-11-28T22:14:33Z: myscontroller_rs::core::connection: 0.0.0.0:5003 << 0;255;3;0;2; ERROR 2018-11-28T22:14:58Z: myscontroller_rs::core::connection: Error while reading -- Os { code: 11, kind: WouldBlock, message: "Resource temporarily unavailable" } INFO 2018-11-28T22:15:03Z: myscontroller_rs::core::connection: Waiting for server connection -- 0.0.0.0:5003 ... INFO 2018-11-28T22:15:03Z: myscontroller_rs::core::connection: Connected to -- 0.0.0.0:5003 INFO 2018-11-28T22:15:03Z: myscontroller_rs::core::connection: 0.0.0.0:5003 << 0;255;3;0;2; INFO 2018-11-28T22:15:03Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "0;255;3;0;14;Gateway startup complete.\n" INFO 2018-11-28T22:15:03Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "0;255;0;0;18;2.3.0\n"

flatsiedatsie commented 5 years ago

I deleted all the devices in the Mozilla Gateway interface, and I deleted the SQLite database. Then I tried again. This creates some "running migration" messages.

Still, no devices are showing up when I click the "add devices" button.

And then a little later the repeated disconnecting-from-Mysensors-gateway starts happening again.

pi@gateway:~/MySController-rs/target/debug $ sudo ./myscontroller-rs Running migration 20180416170858 Running migration 20180425200801 Running migration 20180515193701 Running migration 20180530120000 Running migration 20181012103949 INFO 2018-11-28T22:24:26Z: myscontroller_rs: Starting proxy server INFO 2018-11-28T22:24:26Z: myscontroller_rs: Started proxy server INFO 2018-11-28T22:24:26Z: myscontroller_rs: Started WoT server INFO 2018-11-28T22:24:26Z: myscontroller_rs::core::connection: Waiting for server connection -- 0.0.0.0:5003 ... INFO 2018-11-28T22:24:26Z: myscontroller_rs::core::connection: Server listening on -- 0.0.0.0:9095 INFO 2018-11-28T22:24:26Z: myscontroller_rs::wot: Starting WoT server INFO 2018-11-28T22:24:46Z: myscontroller_rs::core::connection: Connected to -- 0.0.0.0:5003 INFO 2018-11-28T22:24:46Z: myscontroller_rs::core::connection: 0.0.0.0:5003 << 0;255;3;0;2; INFO 2018-11-28T22:24:46Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "0;255;3;0;14;Gateway startup complete.\n" INFO 2018-11-28T22:24:46Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "0;255;0;0;18;2.3.0\n" INFO 2018-11-28T22:24:46Z: myscontroller_rs::core::message_handler::presentation: Node doesn't exist for Sensor { node_id: 0, child_sensor_id: 255, sensor_type: ArduinoRepeaterNode, description: "2.3.0" }, Creating new node INFO 2018-11-28T22:24:46Z: myscontroller_rs::core::message_handler::presentation: Created Sensor { node_id: 0, child_sensor_id: 255, sensor_type: ArduinoRepeaterNode, description: "2.3.0" } WARN 2018-11-28T22:24:46Z: myscontroller_rs::wot::adapter: PresentationType ArduinoRepeaterNode is not handled yet! INFO 2018-11-28T22:24:51Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "67;1;1;0;1;42\n" WARN 2018-11-28T22:24:51Z: myscontroller_rs::wot: No thing found matching SetMessage { node_id: 67, child_sensor_id: 1, ack: 0, value: Value { set_type: Hum, value: "42" } } INFO 2018-11-28T22:24:51Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "15;1;1;0;1;42\n" INFO 2018-11-28T22:24:51Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "19;1;1;0;1;42\n" WARN 2018-11-28T22:24:51Z: myscontroller_rs::wot: No thing found matching SetMessage { node_id: 15, child_sensor_id: 1, ack: 0, value: Value { set_type: Hum, value: "42" } } WARN 2018-11-28T22:24:51Z: myscontroller_rs::wot: No thing found matching SetMessage { node_id: 19, child_sensor_id: 1, ack: 0, value: Value { set_type: Hum, value: "42" } } INFO 2018-11-28T22:24:53Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "9;6;1;0;37;4.0\n" WARN 2018-11-28T22:24:53Z: myscontroller_rs::wot: No thing found matching SetMessage { node_id: 9, child_sensor_id: 6, ack: 0, value: Value { set_type: Level, value: "4.0" } } INFO 2018-11-28T22:24:53Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "9;66;1;0;45;4.00000000\n" WARN 2018-11-28T22:24:53Z: myscontroller_rs::wot: No thing found matching SetMessage { node_id: 9, child_sensor_id: 66, ack: 0, value: Value { set_type: HvacSetpointHeat, value: "4.00000000" } } INFO 2018-11-28T22:24:53Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "9;2;1;0;37;16.0\n" WARN 2018-11-28T22:24:53Z: myscontroller_rs::wot: No thing found matching SetMessage { node_id: 9, child_sensor_id: 2, ack: 0, value: Value { set_type: Level, value: "16.0" } } INFO 2018-11-28T22:24:57Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "14;16;1;0;37;644\n" WARN 2018-11-28T22:24:57Z: myscontroller_rs::wot: No thing found matching SetMessage { node_id: 14, child_sensor_id: 16, ack: 0, value: Value { set_type: Level, value: "644" } } INFO 2018-11-28T22:25:26Z: myscontroller_rs::core::connection: 0.0.0.0:5003 << 0;255;3;0;2; ERROR 2018-11-28T22:25:27Z: myscontroller_rs::core::connection: Error while reading -- Os { code: 11, kind: WouldBlock, message: "Resource temporarily unavailable" } INFO 2018-11-28T22:25:31Z: myscontroller_rs::core::connection: Waiting for server connection -- 0.0.0.0:5003 ... INFO 2018-11-28T22:25:31Z: myscontroller_rs::core::connection: Connected to -- 0.0.0.0:5003 INFO 2018-11-28T22:25:31Z: myscontroller_rs::core::connection: 0.0.0.0:5003 << 0;255;3;0;2; INFO 2018-11-28T22:25:31Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "0;255;3;0;14;Gateway startup complete.\n" INFO 2018-11-28T22:25:31Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "0;255;0;0;18;2.3.0\n" ERROR 2018-11-28T22:26:02Z: myscontroller_rs::core::connection: Error while reading -- Os { code: 11, kind: WouldBlock, message: "Resource temporarily unavailable" } INFO 2018-11-28T22:26:06Z: myscontroller_rs::core::connection: Waiting for server connection -- 0.0.0.0:5003 ... INFO 2018-11-28T22:26:06Z: myscontroller_rs::core::connection: Connected to -- 0.0.0.0:5003 INFO 2018-11-28T22:26:06Z: myscontroller_rs::core::connection: 0.0.0.0:5003 << 0;255;3;0;2; INFO 2018-11-28T22:26:06Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "0;255;3;0;14;Gateway startup complete.\n" INFO 2018-11-28T22:26:06Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "0;255;0;0;18;2.3.0\n" INFO 2018-11-28T22:26:11Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "15;9;2;0;47;\n" INFO 2018-11-28T22:26:11Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "15;10;2;0;47;\n" INFO 2018-11-28T22:26:11Z: myscontroller_rs::core::connection: 0.0.0.0:5003 << 0;255;3;0;2; INFO 2018-11-28T22:26:15Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "15;3;2;0;47;\n" INFO 2018-11-28T22:26:15Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "15;4;2;0;47;\n" INFO 2018-11-28T22:26:38Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "9;0;1;0;37;-1\n" WARN 2018-11-28T22:26:38Z: myscontroller_rs::wot: No thing found matching SetMessage { node_id: 9, child_sensor_id: 0, ack: 0, value: Value { set_type: Level, value: "-1" } } INFO 2018-11-28T22:26:46Z: myscontroller_rs::core::connection: 0.0.0.0:5003 << 0;255;3;0;2; INFO 2018-11-28T22:26:53Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "3;1;1;0;1;42\n" WARN 2018-11-28T22:26:53Z: myscontroller_rs::wot: No thing found matching SetMessage { node_id: 3, child_sensor_id: 1, ack: 0, value: Value { set_type: Hum, value: "42" } } INFO 2018-11-28T22:26:57Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "14;0;1;0;37;891\n" WARN 2018-11-28T22:26:57Z: myscontroller_rs::wot: No thing found matching SetMessage { node_id: 14, child_sensor_id: 0, ack: 0, value: Value { set_type: Level, value: "891" } }

flatsiedatsie commented 5 years ago

When I visit :8000/nodes I see:

[{"node_id":0,"node_name":"New Node","firmware_type":0,"firmware_version":0,"desired_firmware_type":0,"desired_firmware_version":0,"auto_update":false,"scheduled":false,"parent_node_id":0},{"node_id":3,"node_name":"New Node","firmware_type":0,"firmware_version":0,"desired_firmware_type":0,"desired_firmware_version":0,"auto_update":false,"scheduled":false,"parent_node_id":0},{"node_id":14,"node_name":"New Node","firmware_type":0,"firmware_version":0,"desired_firmware_type":0,"desired_firmware_version":0,"auto_update":false,"scheduled":false,"parent_node_id":0}]

So that indicates that it does add some new devices by itself. Very nice!

When I visit :8888 I see:

[]

flatsiedatsie commented 5 years ago

Even though it is run using sudo, the controller gives some errors about the database not being writeable. This is when a device with 12 children is added. Perhaps it's trying to open the database too quickly concurrently?

INFO 2018-11-28T22:35:44Z: myscontroller_rs::wot: Added new thing to things INFO 2018-11-28T22:35:44Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "1;3;0;0;4;2\n" INFO 2018-11-28T22:35:44Z: myscontroller_rs::core::message_handler::presentation: Created Sensor { node_id: 1, child_sensor_id: 3, sensor_type: Dimmer, description: "2" } INFO 2018-11-28T22:35:44Z: myscontroller_rs::wot: Added new thing to things INFO 2018-11-28T22:35:45Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "1;4;0;0;35;3\n" INFO 2018-11-28T22:35:45Z: myscontroller_rs::wot: WoT Server stopped ERROR 2018-11-28T22:35:45Z: myscontroller_rs::wot: Error while trying to get nodes DatabaseError(__Unknown, "database is locked") ERROR 2018-11-28T22:35:45Z: myscontroller_rs::wot: Error while trying to get sensors DatabaseError(__Unknown, "database is locked") INFO 2018-11-28T22:35:45Z: myscontroller_rs::core::message_handler::presentation: Created Sensor { node_id: 1, child_sensor_id: 4, sensor_type: Moisture, description: "3" } INFO 2018-11-28T22:35:45Z: myscontroller_rs::wot: Added new thing to things INFO 2018-11-28T22:35:45Z: myscontroller_rs::wot: Starting WoT server INFO 2018-11-28T22:35:45Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "1;5;0;0;4;3\n" INFO 2018-11-28T22:35:45Z: myscontroller_rs::core::message_handler::presentation: Created Sensor { node_id: 1, child_sensor_id: 5, sensor_type: Dimmer, description: "3" } INFO 2018-11-28T22:35:45Z: myscontroller_rs::wot: Added new thing to things INFO 2018-11-28T22:35:45Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "1;6;0;0;35;4\n" INFO 2018-11-28T22:35:45Z: myscontroller_rs::core::message_handler::presentation: Created Sensor { node_id: 1, child_sensor_id: 6, sensor_type: Moisture, description: "4" } INFO 2018-11-28T22:35:45Z: myscontroller_rs::wot: Added new thing to things INFO 2018-11-28T22:35:45Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "1;6;0;0;35;4\n" INFO 2018-11-28T22:35:45Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "1;7;0;0;4;4\n" INFO 2018-11-28T22:35:45Z: myscontroller_rs::core::message_handler::presentation: Created Sensor { node_id: 1, child_sensor_id: 7, sensor_type: Dimmer, description: "4" } INFO 2018-11-28T22:35:45Z: myscontroller_rs::wot: Added new thing to things INFO 2018-11-28T22:35:45Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "1;8;0;0;35;5\n" INFO 2018-11-28T22:35:45Z: myscontroller_rs::core::message_handler::presentation: Created Sensor { node_id: 1, child_sensor_id: 8, sensor_type: Moisture, description: "5" } INFO 2018-11-28T22:35:45Z: myscontroller_rs::wot: Added new thing to things INFO 2018-11-28T22:35:45Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "1;9;0;0;4;5\n" INFO 2018-11-28T22:35:45Z: myscontroller_rs::core::message_handler::presentation: Created Sensor { node_id: 1, child_sensor_id: 9, sensor_type: Dimmer, description: "5" } INFO 2018-11-28T22:35:45Z: myscontroller_rs::wot: Added new thing to things INFO 2018-11-28T22:35:45Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "1;10;0;0;35;6\n" INFO 2018-11-28T22:35:45Z: myscontroller_rs::core::message_handler::presentation: Created Sensor { node_id: 1, child_sensor_id: 10, sensor_type: Moisture, description: "6" } INFO 2018-11-28T22:35:45Z: myscontroller_rs::wot: Added new thing to things INFO 2018-11-28T22:35:45Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "1;11;0;0;4;6\n" INFO 2018-11-28T22:35:45Z: myscontroller_rs::wot: WoT Server stopped ERROR 2018-11-28T22:35:45Z: myscontroller_rs::wot: Error while trying to get nodes DatabaseError(__Unknown, "database is locked") ERROR 2018-11-28T22:35:45Z: myscontroller_rs::wot: Error while trying to get sensors DatabaseError(__Unknown, "database is locked") INFO 2018-11-28T22:35:45Z: myscontroller_rs::core::message_handler::presentation: Created Sensor { node_id: 1, child_sensor_id: 11, sensor_type: Dimmer, description: "6" }

flatsiedatsie commented 5 years ago

After presenting some more devices:

For :8000/nodes I have [{"node_id":0,"node_name":"New Node","firmware_type":0,"firmware_version":0,"desired_firmware_type":0,"desired_firmware_version":0,"auto_update":false,"scheduled":false,"parent_node_id":0},{"node_id":1,"node_name":"New Node","firmware_type":0,"firmware_version":0,"desired_firmware_type":0,"desired_firmware_version":0,"auto_update":false,"scheduled":false,"parent_node_id":0},{"node_id":3,"node_name":"New Node","firmware_type":0,"firmware_version":0,"desired_firmware_type":0,"desired_firmware_version":0,"auto_update":false,"scheduled":false,"parent_node_id":0},{"node_id":9,"node_name":"New Node","firmware_type":0,"firmware_version":0,"desired_firmware_type":0,"desired_firmware_version":0,"auto_update":false,"scheduled":false,"parent_node_id":0},{"node_id":14,"node_name":"New Node","firmware_type":0,"firmware_version":0,"desired_firmware_type":0,"desired_firmware_version":0,"auto_update":false,"scheduled":false,"parent_node_id":0}]

For :8000/sensors I have [{"node_id":0,"child_sensor_id":255,"sensor_type":"ArduinoRepeaterNode","description":"2.3.0"},{"node_id":14,"child_sensor_id":255,"sensor_type":"ArduinoRepeaterNode","description":"2.3.0"},{"node_id":3,"child_sensor_id":255,"sensor_type":"ArduinoNode","description":"2.3.0"},{"node_id":3,"child_sensor_id":0,"sensor_type":"Temp","description":""},{"node_id":3,"child_sensor_id":2,"sensor_type":"Baro","description":""},{"node_id":9,"child_sensor_id":255,"sensor_type":"ArduinoNode","description":"2.2.0-beta"},{"node_id":9,"child_sensor_id":0,"sensor_type":"AirQuality","description":""},{"node_id":9,"child_sensor_id":1,"sensor_type":"Dust","description":""},{"node_id":9,"child_sensor_id":2,"sensor_type":"Dust","description":""},{"node_id":9,"child_sensor_id":3,"sensor_type":"Dust","description":""},{"node_id":9,"child_sensor_id":5,"sensor_type":"Dust","description":""},{"node_id":9,"child_sensor_id":4,"sensor_type":"Dust","description":""},{"node_id":1,"child_sensor_id":255,"sensor_type":"ArduinoRepeaterNode","description":"2.2.0"},{"node_id":1,"child_sensor_id":0,"sensor_type":"Moisture","description":"1"},{"node_id":1,"child_sensor_id":1,"sensor_type":"Dimmer","description":"1"},{"node_id":1,"child_sensor_id":2,"sensor_type":"Moisture","description":"2"},{"node_id":1,"child_sensor_id":3,"sensor_type":"Dimmer","description":"2"},{"node_id":1,"child_sensor_id":4,"sensor_type":"Moisture","description":"3"},{"node_id":1,"child_sensor_id":5,"sensor_type":"Dimmer","description":"3"},{"node_id":1,"child_sensor_id":6,"sensor_type":"Moisture","description":"4"},{"node_id":1,"child_sensor_id":7,"sensor_type":"Dimmer","description":"4"},{"node_id":1,"child_sensor_id":8,"sensor_type":"Moisture","description":"5"},{"node_id":1,"child_sensor_id":9,"sensor_type":"Dimmer","description":"5"},{"node_id":1,"child_sensor_id":10,"sensor_type":"Moisture","description":"6"},{"node_id":1,"child_sensor_id":11,"sensor_type":"Dimmer","description":"6"}]

For :8888 I have

[]

Ah, but when I restart MySController-rs I now get this at :8888

[{"@context":"https://iot.mozilla.org/schemas","@type":["multiLevelSensor"],"actions":{},"description":"Temperature sensor","events":{},"href":"/0","links":[{"href":"/0/properties","rel":"properties"},{"href":"/0/actions","rel":"actions"},{"href":"/0/events","rel":"events"},{"href":"ws://192.168.2.110:8888/0","rel":"alternate"}],"name":"New Node - Temperature sensor","properties":{"level":{"description":"Temperature","href":"/0/properties/level","type":"number","unit":"celsius"},"on":{"description":"Whether the thing is on","href":"/0/properties/on","type":"boolean","unit":""}}},{"@context":"https://iot.mozilla.org/schemas","@type":["multiLevelSensor"],"actions":{},"description":"Barometer sensor","events":{},"href":"/1","links":[{"href":"/1/properties","rel":"properties"},{"href":"/1/actions","rel":"actions"},{"href":"/1/events","rel":"events"},{"href":"ws://192.168.2.110:8888/1","rel":"alternate"}],"name":"New Node - Barometer sensor","properties":{"forecast":{"description":"Forecast predicted by sensor","href":"/1/properties/forecast","type":"string","unit":""},"level":{"description":"Pressure measured by sensor","href":"/1/properties/level","type":"number","unit":""}}},{"@context":"https://iot.mozilla.org/schemas","@type":["multiLevelSensor"],"actions":{},"description":"Air Quality sensor","events":{},"href":"/2","links":[{"href":"/2/properties","rel":"properties"},{"href":"/2/actions","rel":"actions"},{"href":"/2/events","rel":"events"},{"href":"ws://192.168.2.110:8888/2","rel":"alternate"}],"name":"New Node - Air Quality sensor","properties":{"level":{"description":"Level output of the sensor","href":"/2/properties/level","type":"number","unit":""},"unit":{"description":"Unit of the sensor output","href":"/2/properties/unit","type":"string","unit":""}}},{"@context":"https://iot.mozilla.org/schemas","@type":["multiLevelSensor"],"actions":{},"description":"Moisture sensor","events":{},"href":"/3","links":[{"href":"/3/properties","rel":"properties"},{"href":"/3/actions","rel":"actions"},{"href":"/3/events","rel":"events"},{"href":"ws://192.168.2.110:8888/3","rel":"alternate"}],"name":"New Node - Moisture sensor","properties":{"level":{"description":"Level output of the sensor","href":"/3/properties/level","type":"number","unit":""}}},{"@context":"https://iot.mozilla.org/schemas","@type":["dimmableLight"],"actions":{},"description":"Dimmable lamp","events":{},"href":"/4","links":[{"href":"/4/properties","rel":"properties"},{"href":"/4/actions","rel":"actions"},{"href":"/4/events","rel":"events"},{"href":"ws://192.168.2.110:8888/4","rel":"alternate"}],"name":"New Node - Dimmable lamp","properties":{"level":{"description":"The level of the thing from 0-100","href":"/4/properties/level","type":"number","unit":"%"},"on":{"description":"Whether the thing is on","href":"/4/properties/on","type":"boolean","unit":""}}},{"@context":"https://iot.mozilla.org/schemas","@type":["multiLevelSensor"],"actions":{},"description":"Moisture sensor","events":{},"href":"/5","links":[{"href":"/5/properties","rel":"properties"},{"href":"/5/actions","rel":"actions"},{"href":"/5/events","rel":"events"},{"href":"ws://192.168.2.110:8888/5","rel":"alternate"}],"name":"New Node - Moisture sensor","properties":{"level":{"description":"Level output of the sensor","href":"/5/properties/level","type":"number","unit":""}}},{"@context":"https://iot.mozilla.org/schemas","@type":["dimmableLight"],"actions":{},"description":"Dimmable lamp","events":{},"href":"/6","links":[{"href":"/6/properties","rel":"properties"},{"href":"/6/actions","rel":"actions"},{"href":"/6/events","rel":"events"},{"href":"ws://192.168.2.110:8888/6","rel":"alternate"}],"name":"New Node - Dimmable lamp","properties":{"level":{"description":"The level of the thing from 0-100","href":"/6/properties/level","type":"number","unit":"%"},"on":{"description":"Whether the thing is on","href":"/6/properties/on","type":"boolean","unit":""}}},{"@context":"https://iot.mozilla.org/schemas","@type":["multiLevelSensor"],"actions":{},"description":"Moisture sensor","events":{},"href":"/7","links":[{"href":"/7/properties","rel":"properties"},{"href":"/7/actions","rel":"actions"},{"href":"/7/events","rel":"events"},{"href":"ws://192.168.2.110:8888/7","rel":"alternate"}],"name":"New Node - Moisture sensor","properties":{"level":{"description":"Level output of the sensor","href":"/7/properties/level","type":"number","unit":""}}},{"@context":"https://iot.mozilla.org/schemas","@type":["dimmableLight"],"actions":{},"description":"Dimmable lamp","events":{},"href":"/8","links":[{"href":"/8/properties","rel":"properties"},{"href":"/8/actions","rel":"actions"},{"href":"/8/events","rel":"events"},{"href":"ws://192.168.2.110:8888/8","rel":"alternate"}],"name":"New Node - Dimmable lamp","properties":{"level":{"description":"The level of the thing from 0-100","href":"/8/properties/level","type":"number","unit":"%"},"on":{"description":"Whether the thing is on","href":"/8/properties/on","type":"boolean","unit":""}}},{"@context":"https://iot.mozilla.org/schemas","@type":["multiLevelSensor"],"actions":{},"description":"Moisture sensor","events":{},"href":"/9","links":[{"href":"/9/properties","rel":"properties"},{"href":"/9/actions","rel":"actions"},{"href":"/9/events","rel":"events"},{"href":"ws://192.168.2.110:8888/9","rel":"alternate"}],"name":"New Node - Moisture sensor","properties":{"level":{"description":"Level output of the sensor","href":"/9/properties/level","type":"number","unit":""}}},{"@context":"https://iot.mozilla.org/schemas","@type":["dimmableLight"],"actions":{},"description":"Dimmable lamp","events":{},"href":"/10","links":[{"href":"/10/properties","rel":"properties"},{"href":"/10/actions","rel":"actions"},{"href":"/10/events","rel":"events"},{"href":"ws://192.168.2.110:8888/10","rel":"alternate"}],"name":"New Node - Dimmable lamp","properties":{"level":{"description":"The level of the thing from 0-100","href":"/10/properties/level","type":"number","unit":"%"},"on":{"description":"Whether the thing is on","href":"/10/properties/on","type":"boolean","unit":""}}},{"@context":"https://iot.mozilla.org/schemas","@type":["multiLevelSensor"],"actions":{},"description":"Moisture sensor","events":{},"href":"/11","links":[{"href":"/11/properties","rel":"properties"},{"href":"/11/actions","rel":"actions"},{"href":"/11/events","rel":"events"},{"href":"ws://192.168.2.110:8888/11","rel":"alternate"}],"name":"New Node - Moisture sensor","properties":{"level":{"description":"Level output of the sensor","href":"/11/properties/level","type":"number","unit":""}}},{"@context":"https://iot.mozilla.org/schemas","@type":["dimmableLight"],"actions":{},"description":"Dimmable lamp","events":{},"href":"/12","links":[{"href":"/12/properties","rel":"properties"},{"href":"/12/actions","rel":"actions"},{"href":"/12/events","rel":"events"},{"href":"ws://192.168.2.110:8888/12","rel":"alternate"}],"name":"New Node - Dimmable lamp","properties":{"level":{"description":"The level of the thing from 0-100","href":"/12/properties/level","type":"number","unit":"%"},"on":{"description":"Whether the thing is on","href":"/12/properties/on","type":"boolean","unit":""}}},{"@context":"https://iot.mozilla.org/schemas","@type":["multiLevelSensor"],"actions":{},"description":"Moisture sensor","events":{},"href":"/13","links":[{"href":"/13/properties","rel":"properties"},{"href":"/13/actions","rel":"actions"},{"href":"/13/events","rel":"events"},{"href":"ws://192.168.2.110:8888/13","rel":"alternate"}],"name":"New Node - Moisture sensor","properties":{"level":{"description":"Level output of the sensor","href":"/13/properties/level","type":"number","unit":""}}},{"@context":"https://iot.mozilla.org/schemas","@type":["dimmableLight"],"actions":{},"description":"Dimmable lamp","events":{},"href":"/14","links":[{"href":"/14/properties","rel":"properties"},{"href":"/14/actions","rel":"actions"},{"href":"/14/events","rel":"events"},{"href":"ws://192.168.2.110:8888/14","rel":"alternate"}],"name":"New Node - Dimmable lamp","properties":{"level":{"description":"The level of the thing from 0-100","href":"/14/properties/level","type":"number","unit":"%"},"on":{"description":"Whether the thing is on","href":"/14/properties/on","type":"boolean","unit":""}}}]

oddly enough, scanning for new devices in Mozilla Gateway still yields no results. Strange.

flatsiedatsie commented 5 years ago

Whoa, ok. I found the problem. The web thing add-on had become uninstalled. Very strange. When I enabled it, everything appeared.

flatsiedatsie commented 5 years ago

I still see these errors:

INFO 2018-11-28T22:46:24Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "9;1;1;0;37;1128.0\n" WARN 2018-11-28T22:46:24Z: myscontroller_rs::wot: No thing found matching SetMessage { node_id: 9, child_sensor_id: 3, ack: 0, value: Value { set_type: Level, value: "8.0" } } WARN 2018-11-28T22:46:24Z: myscontroller_rs::wot: No thing found matching SetMessage { node_id: 9, child_sensor_id: 1, ack: 0, value: Value { set_type: Level, value: "1128.0" } } INFO 2018-11-28T22:46:38Z: actix_web::middleware::logger: 127.0.0.1:45880 "GET / HTTP/1.1" 200 1525 "-" "node-fetch/1.0 (+https://github.com/bitinn/node-fetch)" 0.031177 ERROR 2018-11-28T22:46:54Z: myscontroller_rs::core::connection: Error while reading -- Os { code: 11, kind: WouldBlock, message: "Resource temporarily unavailable" } INFO 2018-11-28T22:46:57Z: myscontroller_rs::core::connection: 0.0.0.0:5003 << 0;255;3;0;2;

and

INFO 2018-11-28T22:45:30Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "9;2;1;0;101;4.0\n" ERROR 2018-11-28T22:45:30Z: myscontroller_rs::core::interceptor: Error while parsing command message InvalidSubType, simply forwarding to controller

tsathishkumar commented 5 years ago

Added a new feature to reconnect to gateway when there is no response from Gateway. Currently the controller sends version request every 30 seconds, and the restart happens after 40 seconds when there is no reply. The problem seems to be related to that. Ill make the feature configurable so that you can disable it and test other features in isolation.

On Thu, Nov 29, 2018, 4:19 AM flatsiedatsie <notifications@github.com wrote:

I still see these errors:

INFO 2018-11-28T22:46:24Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "9;1;1;0;37;1128.0\n" WARN 2018-11-28T22:46:24Z: myscontroller_rs::wot: No thing found matching SetMessage { node_id: 9, child_sensor_id: 3, ack: 0, value: Value { set_type: Level, value: "8.0" } } WARN 2018-11-28T22:46:24Z: myscontroller_rs::wot: No thing found matching SetMessage { node_id: 9, child_sensor_id: 1, ack: 0, value: Value { set_type: Level, value: "1128.0" } } INFO 2018-11-28T22:46:38Z: actix_web::middleware::logger: 127.0.0.1:45880 "GET / HTTP/1.1" 200 1525 "-" "node-fetch/1.0 (+ https://github.com/bitinn/node-fetch)" 0.031177 ERROR 2018-11-28T22:46:54Z: myscontroller_rs::core::connection: Error while reading -- Os { code: 11, kind: WouldBlock, message: "Resource temporarily unavailable" } INFO 2018-11-28T22:46:57Z: myscontroller_rs::core::connection: 0.0.0.0:5003 << 0;255;3;0;2;

and

INFO 2018-11-28T22:45:30Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "9;2;1;0;101;4.0\n" ERROR 2018-11-28T22:45:30Z: myscontroller_rs::core::interceptor: Error while parsing command message InvalidSubType, simply forwarding to controller

— You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub https://github.com/tsathishkumar/MySController-rs/issues/29#issuecomment-442635307, or mute the thread https://github.com/notifications/unsubscribe-auth/ABaM5EvKugo0hdKfltDFdoytyx7su3sDks5uzxLjgaJpZM4Y4hNK .

flatsiedatsie commented 5 years ago

Sounds good. But the strange thing is that the MySensors software wasn't actually down. MySController-rs started disconnecting and reconnecting on its own. Or are you talking about the Mozilla Gateway? That was also running as far as I can tell.

flatsiedatsie commented 5 years ago

I noticed he output :8000/sensors is a bit random. Could that matter?

For example, data about node_id 3 can be found at position 2,3,4.. and 25.

0   
node_id 0
child_sensor_id 255
sensor_type "ArduinoRepeaterNode"
description "2.3.0"
1   
node_id 14
child_sensor_id 255
sensor_type "ArduinoRepeaterNode"
description "2.3.0"
2   
node_id 3
child_sensor_id 255
sensor_type "ArduinoNode"
description "2.3.0"
3   
node_id 3
child_sensor_id 0
sensor_type "Temp"
description ""
4   
node_id 3
child_sensor_id 2
sensor_type "Baro"
description ""
5   
node_id 9
child_sensor_id 255
sensor_type "ArduinoNode"
description "2.2.0-beta"
6   
node_id 9
child_sensor_id 0
sensor_type "AirQuality"
description ""
7   
node_id 9
child_sensor_id 1
sensor_type "Dust"
description ""
8   
node_id 9
child_sensor_id 2
sensor_type "Dust"
description ""
9   
node_id 9
child_sensor_id 3
sensor_type "Dust"
description ""
10  
node_id 9
child_sensor_id 5
sensor_type "Dust"
description ""
11  
node_id 9
child_sensor_id 4
sensor_type "Dust"
description ""
12  
node_id 1
child_sensor_id 255
sensor_type "ArduinoRepeaterNode"
description "2.2.0"
13  
node_id 1
child_sensor_id 0
sensor_type "Moisture"
description "1"
14  
node_id 1
child_sensor_id 1
sensor_type "Dimmer"
description "1"
15  
node_id 1
child_sensor_id 2
sensor_type "Moisture"
description "2"
16  
node_id 1
child_sensor_id 3
sensor_type "Dimmer"
description "2"
17  
node_id 1
child_sensor_id 4
sensor_type "Moisture"
description "3"
18  
node_id 1
child_sensor_id 5
sensor_type "Dimmer"
description "3"
19  
node_id 1
child_sensor_id 6
sensor_type "Moisture"
description "4"
20  
node_id 1
child_sensor_id 7
sensor_type "Dimmer"
description "4"
21  
node_id 1
child_sensor_id 8
sensor_type "Moisture"
description "5"
22  
node_id 1
child_sensor_id 9
sensor_type "Dimmer"
description "5"
23  
node_id 1
child_sensor_id 10
sensor_type "Moisture"
description "6"
24  
node_id 1
child_sensor_id 11
sensor_type "Dimmer"
description "6"
25  
node_id 3
child_sensor_id 1
sensor_type "Hum"
description ""
26  
node_id 15
child_sensor_id 255
sensor_type "ArduinoRepeaterNode"
description "2.2.0"
27  
node_id 15
child_sensor_id 1
sensor_type "Info"
description ""
28  
node_id 15
child_sensor_id 2
sensor_type "Info"
description ""
29  
node_id 15
child_sensor_id 3
sensor_type "Info"
description ""
30  
node_id 15
child_sensor_id 4
sensor_type "Info"
description ""
31  
node_id 15
child_sensor_id 5
sensor_type "Lock"
description ""
32  
node_id 15
child_sensor_id 6
sensor_type "Lock"
description ""
33  
node_id 15
child_sensor_id 7
sensor_type "Lock"
description ""
34  
node_id 15
child_sensor_id 8
sensor_type "Info"
description ""
35  
node_id 15
child_sensor_id 9
sensor_type "Info"
description ""
36  
node_id 15
child_sensor_id 10
sensor_type "Info"
description ""
tsathishkumar commented 5 years ago

MySController-rs started disconnecting and reconnecting on its own.

I was talking about exactly this behaviour. MySController-rs was thinking that the MySensors gateway was down and kept reconnecting.

tsathishkumar commented 5 years ago

Output of the sensors API is not ordered in any way. So it is normal that you see the sensor data in different positions.