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

Data is not getting through - missing newline? #36

Closed flatsiedatsie closed 5 years ago

flatsiedatsie commented 5 years ago

There are still a few small bugs in the system that usually disappear after a few reboots. But those bugs can still be very confusing.

For example, I have added some moisture sensors and dimmers from my Plant Health sensor.

I then change the value in Mozilla Gateway, hoping to see the value reflected in the node.

The MyController-RS seems to send this:

INFO 2018-12-10T21:31:27Z: myscontroller_rs::wot::adapter: **Property forwarded 67 for sensor Sensor { node_id: 1, child_sensor_id: 5, sensor_type: Dimmer, description: "3" }**
 INFO 2018-12-10T21:31:27Z: myscontroller_rs::core::connection: 0.0.0.0:5003 << "1;5;1;0;3;67\n"
 INFO 2018-12-10T21:31:27Z: actix_web::middleware::logger: 127.0.0.1:58796 "PUT /8/properties/level HTTP/1.1" 200 12 "-" "node-fetch/1.0 (+https://github.com/bitinn/node-fetch)" 0.005710
 INFO 2018-12-10T21:31:27Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "0;255;3;0;2;2.3.0\n"
 INFO 2018-12-10T21:31:27Z: myscontroller_rs::core::connection: 0.0.0.0:8088 << "0;255;3;0;2;2.3.0\n"

And then there is this message in the MySensors gateway has 67 as its payload:

Dec 10 22:31:20 DEBUG GWT:RFC:C=0,MSG=0;0;3;0;18;PING
Dec 10 22:31:27 DEBUG GWT:RFC:C=0,MSG=**0;255;3;0;2;1;5;1;0;3;67**
Dec 10 22:31:30 DEBUG GWT:RFC:C=0,MSG=0;0;3;0;18;PING
Dec 10 22:31:36 DEBUG TSF:SAN:OK

I don't receive the data in my node.

The MySensors gateway debug lines seem a bit odd? The line seems to be a concatenation of two messages. The first part is 0;255;3;0;2 and the second part is 1;5;1;0;3;67

Could it be that there are two message concatenated here, causing the second message to not be sent? Perhaps a newline is missing?

In general there are A LOT of 0;255;3;0;2; messages in the log: 0; (gateway node) 255; (repeater child? System child?) 3; (system message) 0; (no ACK) 2 (I_VERSION, Used to request gateway version from controller)

 INFO 2018-12-10T21:40:20Z: myscontroller_rs::core::connection: 0.0.0.0:8088 >> "0;0;3;0;18;PING\n"
 INFO 2018-12-10T21:40:20Z: myscontroller_rs::core::connection: 0.0.0.0:5003 << "0;0;3;0;18;PING\n"
 INFO 2018-12-10T21:40:20Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "0;255;3;0;22;1423834\n"
 INFO 2018-12-10T21:40:20Z: myscontroller_rs::core::connection: 0.0.0.0:8088 << "0;255;3;0;22;1423834\n"
 INFO 2018-12-10T21:40:30Z: myscontroller_rs::core::connection: 0.0.0.0:8088 >> "0;0;3;0;18;PING\n"
 INFO 2018-12-10T21:40:30Z: myscontroller_rs::core::connection: 0.0.0.0:5003 << "0;0;3;0;18;PING\n"
 INFO 2018-12-10T21:40:30Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "0;255;3;0;22;1433838\n"
 INFO 2018-12-10T21:40:30Z: myscontroller_rs::core::connection: 0.0.0.0:8088 << "0;255;3;0;22;1433838\n"
 INFO 2018-12-10T21:40:40Z: myscontroller_rs::core::connection: 0.0.0.0:8088 >> "0;0;3;0;18;PING\n"
 INFO 2018-12-10T21:40:40Z: myscontroller_rs::core::connection: 0.0.0.0:5003 << "0;0;3;0;18;PING\n"
 INFO 2018-12-10T21:40:40Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "0;255;3;0;22;1443831\n"
 INFO 2018-12-10T21:40:40Z: myscontroller_rs::core::connection: 0.0.0.0:8088 << "0;255;3;0;22;1443831\n"
 INFO 2018-12-10T21:40:40Z: myscontroller_rs::core::connection: 0.0.0.0:8088 << 0;255;3;0;2;
 INFO 2018-12-10T21:40:45Z: myscontroller_rs::core::connection: 0.0.0.0:5003 << 0;255;3;0;2;
 INFO 2018-12-10T21:40:50Z: myscontroller_rs::core::connection: 0.0.0.0:8088 >> "0;0;3;0;18;PING\n"
 INFO 2018-12-10T21:40:50Z: myscontroller_rs::core::connection: 0.0.0.0:5003 << "0;0;3;0;18;PING\n"
 INFO 2018-12-10T21:40:50Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "0;255;3;0;2;2.3.0\n"
 INFO 2018-12-10T21:40:50Z: myscontroller_rs::core::connection: 0.0.0.0:8088 << "0;255;3;0;2;2.3.0\n"
 INFO 2018-12-10T21:41:00Z: myscontroller_rs::core::connection: 0.0.0.0:8088 >> "0;0;3;0;18;PING\n"
 INFO 2018-12-10T21:41:00Z: myscontroller_rs::core::connection: 0.0.0.0:5003 << "0;0;3;0;18;PING\n"
 INFO 2018-12-10T21:41:00Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "0;255;3;0;22;1463834\n"
 INFO 2018-12-10T21:41:00Z: myscontroller_rs::core::connection: 0.0.0.0:8088 << "0;255;3;0;22;1463834\n"
 INFO 2018-12-10T21:41:10Z: myscontroller_rs::core::connection: 0.0.0.0:8088 >> "0;0;3;0;18;PING\n"
 INFO 2018-12-10T21:41:10Z: myscontroller_rs::core::connection: 0.0.0.0:5003 << "0;0;3;0;18;PING\n"
 INFO 2018-12-10T21:41:10Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "0;255;3;0;22;1473840\n"
 INFO 2018-12-10T21:41:10Z: myscontroller_rs::core::connection: 0.0.0.0:8088 << "0;255;3;0;22;1473840\n"
 INFO 2018-12-10T21:41:20Z: myscontroller_rs::core::connection: 0.0.0.0:8088 >> "0;0;3;0;18;PING\n"
 INFO 2018-12-10T21:41:20Z: myscontroller_rs::core::connection: 0.0.0.0:5003 << "0;0;3;0;18;PING\n"
 INFO 2018-12-10T21:41:20Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "0;255;3;0;22;1483835\n"
 INFO 2018-12-10T21:41:20Z: myscontroller_rs::core::connection: 0.0.0.0:8088 << "0;255;3;0;22;1483835\n"

Which looks like this in the MySensors Gateway log:

 INFO 2018-12-10T21:43:10Z: myscontroller_rs::core::connection: 0.0.0.0:8088 >> "0;0;3;0;18;PING\n"
 INFO 2018-12-10T21:43:10Z: myscontroller_rs::core::connection: 0.0.0.0:5003 << "0;0;3;0;18;PING\n"
 INFO 2018-12-10T21:43:10Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "0;255;3;0;22;1593842\n"
 INFO 2018-12-10T21:43:10Z: myscontroller_rs::core::connection: 0.0.0.0:8088 << "0;255;3;0;22;1593842\n"
 INFO 2018-12-10T21:43:20Z: myscontroller_rs::core::connection: 0.0.0.0:8088 >> "0;0;3;0;18;PING\n"
 INFO 2018-12-10T21:43:20Z: myscontroller_rs::core::connection: 0.0.0.0:5003 << "0;0;3;0;18;PING\n"
 INFO 2018-12-10T21:43:20Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "0;255;3;0;22;1603843\n"
 INFO 2018-12-10T21:43:20Z: myscontroller_rs::core::connection: 0.0.0.0:8088 << "0;255;3;0;22;1603843\n"
 INFO 2018-12-10T21:43:20Z: myscontroller_rs::core::connection: 0.0.0.0:8088 << 0;255;3;0;2;
 INFO 2018-12-10T21:43:25Z: myscontroller_rs::core::connection: 0.0.0.0:5003 << 0;255;3;0;2;
 INFO 2018-12-10T21:43:30Z: myscontroller_rs::core::connection: 0.0.0.0:8088 >> "0;0;3;0;18;PING\n"
 INFO 2018-12-10T21:43:30Z: myscontroller_rs::core::connection: 0.0.0.0:5003 << "0;0;3;0;18;PING\n"
 INFO 2018-12-10T21:43:30Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "0;255;3;0;2;2.3.0\n"
 INFO 2018-12-10T21:43:30Z: myscontroller_rs::core::connection: 0.0.0.0:8088 << "0;255;3;0;2;2.3.0\n"
 INFO 2018-12-10T21:43:40Z: myscontroller_rs::core::connection: 0.0.0.0:8088 >> "0;0;3;0;18;PING\n"
 INFO 2018-12-10T21:43:40Z: myscontroller_rs::core::connection: 0.0.0.0:5003 << "0;0;3;0;18;PING\n"
 INFO 2018-12-10T21:43:40Z: myscontroller_rs::core::connection: 0.0.0.0:5003 >> "0;255;3;0;22;1623848\n"
 INFO 2018-12-10T21:43:40Z: myscontroller_rs::core::connection: 0.0.0.0:8088 << "0;255;3;0;22;1623848\n"
flatsiedatsie commented 5 years ago

Ah, no, now it's working :-D

I think I have an issue with my Plant Health device. The old values of the device keep becoming non-valid somehow, and then when I click the (+) button in the Mozilla Gateway MySController-rs will offer the device as if its a completely new device. The old buttons then no longer work, and I have to delete those. As if it got a new node ID or something. Since only the plant health device shows this behaviour it must be in my code somehow.

flatsiedatsie commented 5 years ago

This can be closed