tbowmo / node-red-contrib-mysensors

Mysensor nodes for node-red
23 stars 9 forks source link

Automatic Node-ID assignment fails #15

Closed Mirodin closed 6 years ago

Mirodin commented 6 years ago

I might do it wrong but for me the automatic node ID assignment vial myscontroller does not work.

Setup:

However my node gets assigned ID 255 and keeps polling ID requests every few seconds. When I set an ID manually via #define MY_NODE_ID 5 everything works out quite nice so the problem seems to be the ID assignment done by myscontroller.

Logs from my node with static ID:

17 MCO:BGN:INIT NODE,CP=RNNNA---,VER=2.3.0-alpha
26 TSM:INIT
27 TSF:WUR:MS=0
34 TSM:INIT:TSP OK
36 TSF:SID:OK,ID=5
38 TSM:FPAR
74 TSF:MSG:SEND,5-5-255-255,s=255,c=3,t=7,pt=0,l=0,sg=0,ft=0,st=OK:
2081 !TSM:FPAR:NO REPLY
2083 TSM:FPAR
2119 TSF:MSG:SEND,5-5-255-255,s=255,c=3,t=7,pt=0,l=0,sg=0,ft=0,st=OK:
2428 TSF:MSG:READ,0-0-5,s=255,c=3,t=8,pt=1,l=1,sg=0:0
2434 TSF:MSG:FPAR OK,ID=0,D=1
4126 TSM:FPAR:OK
4127 TSM:ID
4128 TSM:ID:OK
4130 TSM:UPL
4133 TSF:MSG:SEND,5-5-0-0,s=255,c=3,t=24,pt=1,l=1,sg=0,ft=0,st=OK:1
4143 TSF:MSG:READ,0-0-5,s=255,c=3,t=25,pt=1,l=1,sg=0:1
4148 TSF:MSG:PONG RECV,HP=1
4150 TSM:UPL:OK
4152 TSM:READY:ID=5,PAR=0,DIS=1
4156 TSF:MSG:SEND,5-5-0-0,s=255,c=3,t=15,pt=6,l=2,sg=0,ft=0,st=OK:0100
4163 TSF:MSG:READ,0-0-5,s=255,c=3,t=15,pt=6,l=2,sg=0:0100
4170 TSF:MSG:SEND,5-5-0-0,s=255,c=0,t=17,pt=0,l=11,sg=0,ft=0,st=OK:2.3.0-alpha
4179 TSF:MSG:SEND,5-5-0-0,s=255,c=3,t=6,pt=1,l=1,sg=0,ft=0,st=OK:0
6188 TSF:MSG:SEND,5-5-0-0,s=1,c=0,t=0,pt=0,l=0,sg=0,ft=0,st=OK:
6196 TSF:MSG:SEND,5-5-0-0,s=255,c=3,t=11,pt=0,l=10,sg=0,ft=0,st=OK:Doorswitch
6205 TSF:MSG:SEND,5-5-0-0,s=255,c=3,t=12,pt=0,l=5,sg=0,ft=0,st=OK:0.0.1
6211 MCO:REG:REQ
6214 TSF:MSG:SEND,5-5-0-0,s=255,c=3,t=26,pt=1,l=1,sg=0,ft=0,st=OK:2
6225 TSF:MSG:READ,0-0-5,s=255,c=3,t=27,pt=1,l=1,sg=0:1
6231 MCO:PIM:NODE REG=1
6233 MCO:BGN:STP
6235 MCO:BGN:INIT OK,TSP=1
6239 TSF:MSG:SEND,5-5-0-0,s=1,c=1,t=16,pt=2,l=2,sg=0,ft=0,st=OK:0

After clearing EEPROM and switching to static node ID:

17 MCO:BGN:INIT NODE,CP=RNNNA---,VER=2.3.0-alpha
26 TSM:INIT
27 TSF:WUR:MS=0
34 TSM:INIT:TSP OK
36 TSM:FPAR
38 TSF:MSG:SEND,255-255-255-255,s=255,c=3,t=7,pt=0,l=0,sg=0,ft=0,st=OK:
721 TSF:MSG:READ,0-0-255,s=255,c=3,t=8,pt=1,l=1,sg=0:0
727 TSF:MSG:FPAR OK,ID=0,D=1
2048 TSM:FPAR:OK
2049 TSM:ID
2050 TSM:ID:REQ
2053 TSF:MSG:SEND,255-255-0-0,s=2,c=3,t=3,pt=0,l=0,sg=0,ft=0,st=OK:
4060 TSM:ID
4061 TSM:ID:REQ
4063 TSF:MSG:SEND,255-255-0-0,s=221,c=3,t=3,pt=0,l=0,sg=0,ft=0,st=OK:
6071 TSM:ID
6072 TSM:ID:REQ
6074 TSF:MSG:SEND,255-255-0-0,s=184,c=3,t=3,pt=0,l=0,sg=0,ft=0,st=OK:
8082 TSM:ID
8083 TSM:ID:REQ
8085 TSF:MSG:SEND,255-255-0-0,s=147,c=3,t=3,pt=0,l=0,sg=0,ft=0,st=OK:
10093 !TSM:ID:FAIL
10094 TSM:FAIL:CNT=1
10096 TSM:FAIL:DIS
10098 TSF:TDI:TSL

Hope my informations help to debug this, I just started with MySensors so even with the help of MySensors log parser I only understand half of the things going on.

tbowmo commented 6 years ago

Could you please paste a copy of your node-red flow here? Otherwise it's a bit hard to see what is happening.

Mirodin commented 6 years ago

Sure, here you go:

[{"id":"94e95127.2c31a","type":"serial in","z":"c7df57b9.1814a8","name":"","serial":"bbc6e20b.5e3598","x":120,"y":80,"wires":[["8ac0893e.f4823","c4a9aa4b.6dbd3","598a5f34.e278f8"]]},{"id":"8ac0893e.f4823","type":"myscontroller","z":"c7df57b9.1814a8","database":"89ca3250.f1665","name":"","handleid":true,"timeresponse":true,"timezone":"UTC","measurementsystem":"M","x":530,"y":40,"wires":[["81d8b529.d3fef","33ddbcc1.18ed84"]]},{"id":"33ddbcc1.18ed84","type":"serial out","z":"c7df57b9.1814a8","name":"","serial":"bbc6e20b.5e3598","x":950,"y":130,"wires":[]},{"id":"bbc6e20b.5e3598","type":"serial-port","z":"","serialport":"/dev/ttyMySensorsGateway","serialbaud":"57600","databits":"8","parity":"none","stopbits":"1","newline":"\\n","bin":"false","out":"char","addchar":false},{"id":"89ca3250.f1665","type":"mysensorsdb","z":"","name":"MySensorsDatabase","file":"/home/nodered/mysensors.sqlite"}]
tbowmo commented 6 years ago

Ok, I think that I have found the issue.. It tries to assign node-id 0 (which is the gateway) so it never reaches the node. I only update the used node-table whenever I receive a message from a node. However due to a faulty nullcheck I filtered away all node 0 messages as well from the heard list. So I never got it marked as used, and hence.. It always tried to assign node-id 0 to nodes..

Anyways, I will prepare a new release later today, or tomorrow morning.

tbowmo commented 6 years ago

@Mirodin Could you please try the latest release (3.1.1)? Hopefully it should fix the issue for you.

Mirodin commented 6 years ago

I updates to 3.1.1 by removing my full Node-RED dir and reinstalling mysensors nodes (takes a while to compile on my poor Pi 1). Unfortunately the problem still persist. My node is still stuck in the request loop and seems not to receive an answer from the gateway. In the meantime I made the switch to MQTT and running both types brought the same result.

What irritates me is that my node is requesting an ID but changes the sensor id for every request. Is that supposed to happen?

This is my output running MQTT gateway however it is the same when I use the serial version.

116480 TSM:ID
116481 TSM:ID:REQ
116484 TSF:MSG:SEND,255-255-0-0,s=1,c=3,t=3,pt=0,l=0,sg=0,ft=0,st=OK:
118491 TSM:ID
118492 TSM:ID:REQ
118495 TSF:MSG:SEND,255-255-0-0,s=220,c=3,t=3,pt=0,l=0,sg=0,ft=0,st=OK:
120502 TSM:ID
120503 TSM:ID:REQ
120506 TSF:MSG:SEND,255-255-0-0,s=183,c=3,t=3,pt=0,l=0,sg=0,ft=0,st=OK:
122513 !TSM:ID:FAIL
122514 TSM:FAIL:CNT=7
122517 TSM:FAIL:DIS
122518 TSF:TDI:TSL
tbowmo commented 6 years ago

Could you please try and put a debug node on the output of the controller node in nodered, set it to dump the complete message, and paste the output in here?

Mirodin commented 6 years ago

This is what is comming in from MQTT gateway after mysdecode:

{"topic":"from-mys/255/2/3/0/3","payload":"","qos":0,"retain":false,"_topic":"from-mys/255/2/3/0/3","_msgid":"3970af5b.914d1","topicRoot":"from-mys","nodeId":255,"childSensorId":2,"messageType":3,"ack":0,"subType":3,"origin":2,"messageTypeStr":"C_INTERNAL","subTypeStr":"I_ID_REQUEST"}

Return value from myscontroller:

{"topic":"from-mys/255/2/3/0/4","payload":"1","qos":0,"retain":false,"_topic":"from-mys/255/2/3/0/3","_msgid":"3970af5b.914d1","topicRoot":"from-mys","nodeId":255,"childSensorId":2,"messageType":3,"ack":0,"subType":4,"origin":2,"messageTypeStr":"C_INTERNAL","subTypeStr":"I_ID_REQUEST"}

And here is my flow with a lot of debug nodes:

[{"id":"a0b1e173.09c1a","type":"tab","label":"Flow 1","disabled":false,"info":""},{"id":"d1afeaf8.1cf2f","type":"mqtt in","z":"a0b1e173.09c1a","name":"","topic":"to-myst/#","qos":"2","broker":"428d2059.905cb8","x":84,"y":36,"wires":[["73419f0a.3ab218"]]},{"id":"bb0be8bd.67d2","type":"mqtt in","z":"a0b1e173.09c1a","name":"","topic":"from-mys/#","qos":"2","broker":"428d2059.905cb8","x":84,"y":84,"wires":[["24697cf0.b8d43c","48d8fc9a.a68654"]]},{"id":"3fdd595c.a62a5e","type":"debug","z":"a0b1e173.09c1a","name":"","active":true,"tosidebar":true,"console":false,"tostatus":false,"complete":"true","x":446,"y":36,"wires":[]},{"id":"ebbb988e.e76588","type":"debug","z":"a0b1e173.09c1a","name":"","active":true,"tosidebar":true,"console":false,"tostatus":false,"complete":"true","x":446,"y":84,"wires":[]},{"id":"48d8fc9a.a68654","type":"mysdecode","z":"a0b1e173.09c1a","name":"","mqtt":true,"x":272,"y":84,"wires":[["ebbb988e.e76588"]]},{"id":"24697cf0.b8d43c","type":"myscontroller","z":"a0b1e173.09c1a","database":"d207250c.b03ee8","name":"","handleid":true,"timeresponse":true,"timezone":"UTC","measurementsystem":"M","x":262,"y":132,"wires":[["312d9712.005338","aac8e676.dee898","16632400.0c6484"]]},{"id":"312d9712.005338","type":"mqtt out","z":"a0b1e173.09c1a","name":"","topic":"to-mys","qos":"1","retain":"true","broker":"428d2059.905cb8","x":446,"y":132,"wires":[]},{"id":"73419f0a.3ab218","type":"mysdecode","z":"a0b1e173.09c1a","name":"","mqtt":true,"x":272,"y":36,"wires":[["3fdd595c.a62a5e"]]},{"id":"cca1d165.5a2af8","type":"mqtt in","z":"a0b1e173.09c1a","name":"","topic":"#","qos":"2","broker":"428d2059.905cb8","x":74,"y":252,"wires":[["1abb3764.af7109"]]},{"id":"1abb3764.af7109","type":"debug","z":"a0b1e173.09c1a","name":"","active":false,"tosidebar":true,"console":false,"tostatus":false,"complete":"true","x":242,"y":252,"wires":[]},{"id":"a98c2a41.04f828","type":"debug","z":"a0b1e173.09c1a","name":"","active":false,"tosidebar":true,"console":false,"tostatus":false,"complete":"true","x":650,"y":192,"wires":[]},{"id":"aac8e676.dee898","type":"mysdecode","z":"a0b1e173.09c1a","name":"","mqtt":true,"x":476,"y":192,"wires":[["a98c2a41.04f828"]]},{"id":"16632400.0c6484","type":"debug","z":"a0b1e173.09c1a","name":"","active":true,"tosidebar":true,"console":false,"tostatus":false,"complete":"true","x":424,"y":252,"wires":[]},{"id":"428d2059.905cb8","type":"mqtt-broker","z":"","name":"mosquitto","broker":"localhost","port":"1883","clientid":"nodered","usetls":false,"compatmode":true,"keepalive":"60","cleansession":true,"birthTopic":"/homie/nodered/$state","birthQos":"1","birthRetain":"true","birthPayload":"init","closeTopic":"/homie/nodered/$state","closeQos":"0","closeRetain":"true","closePayload":"disconnect","willTopic":"/homie/nodered/$state","willQos":"1","willRetain":"true","willPayload":"lost"},{"id":"d207250c.b03ee8","type":"mysensorsdb","z":"","name":"","file":"/home/nodered/mysensors.sqlite"}]
Mirodin commented 6 years ago

Maybe you want to check in on my flow as I am not quite sure how to setup myscontroller correctly and I am afraid I might misunderstand how it works. How is the controller supposed to be used? I understand from your thread on MySensors forums that it just passes messages it can handle (like ID_REQUEST). So do I have to filter out all messages the controller can handle from my normal flows?

Mirodin commented 6 years ago

Well I think I found some problem with my flow. As I had another client running and listening to MQTT I found that Node-RED was publishing to the same topic the gateway did and in fact the payload after the controller was "1" which is what I want. I think I have to change the topic property of the message object so it gets published to the correct topic. But which topic might that be as the node does not have an ID yet?

Mirodin commented 6 years ago

Well this is embarrassing, I screwed up in Node-RED setting the wrong MQTT message for my return message. The problem seems to be fixed now. Could you just explain in one line my question from above about the routing of message objects? How do I determine what messages go to the controller and what to the rest of the flow?

Thank you for your patience, I really appreciate it :)

tbowmo commented 6 years ago

The controller node filters input by itself, and only act upon the messages it knows about, that is I_CONFIG, I_TIME, and I_ID_REQUEST.

However, now that you mention it, I just discovered one caveat for MQTT, normally the MQTT gateway sends and receives messages on two different topics, like MYS-IN/# and MYS-OUT/#, however the controller node does not the topic root, so if a messages is received with a topic root of MYS-IN/ then it sends a message back to that topic, while the gateway expects a message to MYS-OUT, in order to act upon it.

I'll fix this, and add a configuration setting for changing the MQTT root topic.