Christian-Me / node-red-contrib-homie-convention

Node-RED node for MQTT communication according the Homie Convention
Apache License 2.0
13 stars 2 forks source link

Node-Red crashes when Homie device is found #1

Closed philkry closed 4 years ago

philkry commented 4 years ago

hey there,

i'm trying to get your node to work, however my NR instance crashes when a new Homie device is discovered:

node-red_1 | 12 Oct 16:24:06 - [info] [mqtt-broker:MQTT] Connected to broker: mqtt://mqtt:1883 node-red_1 | 12 Oct 16:24:06 - [info] contrib-homie-convention homie.device.config: Homie: new Device found :a4cf12250ffc node-red_1 | 12 Oct 16:24:06 - [info] contrib-homie-convention homie.device.config: Homie Device: a4cf12250ffc has 1 nodes: doser node-red_1 | 12 Oct 16:24:06 - [info] contrib-homie-convention homie.device.config: Validation of DEVICE: a4cf12250ffc sucess! node-red_1 | 12 Oct 16:24:06 - [red] Uncaught Exception: node-red_1 | 12 Oct 16:24:06 - TypeError: Cannot set property 'error' of undefined node-red_1 | at homieDeviceConfig.storeMessage (/data/node_modules/node-red-contrib-homie-convention/nodes/homie-device-config/homie-device-config.js:260:22) node-red_1 | at MqttClient.messageArrived (/data/node_modules/node-red-contrib-homie-convention/nodes/homie-device-config/homie-device-config.js:451:22) node-red_1 | at MqttClient.emit (events.js:198:13) node-red_1 | at MqttClient._handlePublish (/data/node_modules/mqtt/lib/client.js:792:12) node-red_1 | at MqttClient._handlePacket (/data/node_modules/mqtt/lib/client.js:282:12) node-red_1 | at process (/data/node_modules/mqtt/lib/client.js:238:12) node-red_1 | at MqttClient.handleMessage (/data/node_modules/mqtt/lib/client.js:811:3) node-red_1 | at MqttClient._handlePublish (/data/node_modules/mqtt/lib/client.js:793:12) node-red_1 | at MqttClient._handlePacket (/data/node_modules/mqtt/lib/client.js:282:12) node-red_1 | at process (/data/node_modules/mqtt/lib/client.js:238:12) node-red_1 | npm ERR! code ELIFECYCLE node-red_1 | npm ERR! errno 1 node-red_1 | npm ERR! node-red-docker@1.0.1 start: node $NODE_OPTIONS node_modules/node-red/red.js $FLOWS "--userDir" "/data" node-red_1 | npm ERR! Exit status 1

any idea what could be going on here?

Christian-Me commented 4 years ago

Thank you for the feedback. I will look into it tomorrow, the log seams to be quite clear.

Perhaps you can uncheck the store homie data in the extra tab. I think the problem is located there. But probably you can’t reach it before it crashes.

Node-RED 1.x makes problems but this will be fixed tomorrow too, I hope

philkry commented 4 years ago

will check later today, one think that crossed my mind: your docs do not specify which version(s) of Homie convention are supported.

I'm using v3 on my ESP32, maybe that the issue already?

Christian-Me commented 4 years ago

Hi, the node designed for 4.0.0 and 3.0.x and lower too. Lower versions can perhaps limit the functionality but should defiantly not cause a crash. I can warp try {} catch (err) {} around nearly everything but this makes bug fixes very difficult because it only points to the error handler and not the problem itself. The mqtt broker sends messages in the order of their appearance and latest update so I can't depend on the order. And reconstructing the homie tree is difficult. It is easier to build the tree from the root up and not starting with a leaf. In addition there can be garbage on the broker that must be filtered.

it would be helpful if you can dump the mqtt server homie/# banch mosquitto_sub -v -t homie/# or only your device mosquitto_sub -v -t homie/a4cf12250ffc/#

And you can set your Node-RED log level to debug (open your settings.js file and change {logging:{console: {level: "info"}}} to debug. Should be in line 260

I think your ESP32 send $nodes in the beginning where the homie plugin on ESPEasy Firmware send this at the end.

philkry commented 4 years ago

just as some background info, i'm using https://github.com/homieiot/homie-esp8266/tree/develop-v3 on my ESP32

this is present on the broker:

homie/a4cf12250ffc/$state lost homie/a4cf12250ffc/$homie 3.0.1 homie/a4cf12250ffc/$name Doser1 homie/a4cf12250ffc/$mac A4:CF:12:25:0F:FC homie/a4cf12250ffc/$localip 192.168.1.182 homie/a4cf12250ffc/$nodes doser homie/a4cf12250ffc/$stats uptime homie/a4cf12250ffc/$stats/interval 65 homie/a4cf12250ffc/$stats/signal 60 homie/a4cf12250ffc/$stats/uptime 122 homie/a4cf12250ffc/$fw/name doser homie/a4cf12250ffc/$fw/version 1.0.0 homie/a4cf12250ffc/$fw/checksum 241b44a62762f5208d7df5a9cd7edde6 homie/a4cf12250ffc/$implementation esp32 homie/a4cf12250ffc/$implementation/config {"wifi":{"ssid":"MY SSID"},"mqtt":{"host":"192.168.1.98","port":1883,"auth":false},"name":"Doser1","ota":{"enabled":true}} homie/a4cf12250ffc/$implementation/version 3.0.0 homie/a4cf12250ffc/$implementation/ota/enabled true homie/a4cf12250ffc/doser/$name Doser homie/a4cf12250ffc/doser/$type dose homie/a4cf12250ffc/doser/$properties dose homie/a4cf12250ffc/doser/dose/$name Dose homie/a4cf12250ffc/doser/dose/$settable true homie/a4cf12250ffc/doser/dose/$datatype float homie/a4cf12250ffc/doser/dose/$unit mL

and this the debug output of NodeRed:

node-red_1 | 13 Oct 15:04:16 - [info] Starting flows node-red_1 | 13 Oct 15:04:16 - [debug] red/nodes/flows.start : starting flow : global node-red_1 | 13 Oct 15:04:16 - [debug] red/nodes/flows.start : starting flow : 27266e13.726cb2 node-red_1 | 13 Oct 15:04:16 - [info] Started flows node-red_1 | 13 Oct 15:04:16 - [info] Server now running at http://127.0.0.1:1880/ node-red_1 | 13 Oct 15:04:16 - [debug] contrib-homie-convention homie.device.config: MQTT connect node-red_1 | 13 Oct 15:04:16 - [info] [mqtt-broker:MQTT] Connected to broker: mqtt://mqtt:1883 node-red_1 | 13 Oct 15:04:16 - [info] contrib-homie-convention homie.device.config: Homie: new Device found :a4cf12250ffc node-red_1 | 13 Oct 15:04:16 - [debug] contrib-homie-convention homie.device.config: a4cf12250ffc $state=lost node-red_1 | 13 Oct 15:04:16 - [debug] contrib-homie-convention homie.device.config: a4cf12250ffc $homie=3.0.1 node-red_1 | 13 Oct 15:04:16 - [debug] contrib-homie-convention homie.device.config: a4cf12250ffc $name=Doser1 node-red_1 | 13 Oct 15:04:16 - [debug] contrib-homie-convention homie.device.config: a4cf12250ffc $mac=A4:CF:12:25:0F:FC node-red_1 | 13 Oct 15:04:16 - [debug] contrib-homie-convention homie.device.config: a4cf12250ffc $localip=192.168.1.182 node-red_1 | 13 Oct 15:04:16 - [debug] contrib-homie-convention homie.device.config: a4cf12250ffc $nodes=doser node-red_1 | 13 Oct 15:04:16 - [info] contrib-homie-convention homie.device.config: Homie Device: a4cf12250ffc has 1 nodes: doser node-red_1 | 13 Oct 15:04:16 - [info] contrib-homie-convention homie.device.config: Validation of DEVICE: a4cf12250ffc sucess! node-red_1 | 13 Oct 15:04:16 - [debug] contrib-homie-convention homie.device.config: a4cf12250ffc $stats=uptime node-red_1 | 13 Oct 15:04:16 - [debug] contrib-homie-convention homie.device.config: a4cf12250ffc $stats=65 node-red_1 | 13 Oct 15:04:16 - [red] Uncaught Exception: node-red_1 | 13 Oct 15:04:16 - TypeError: Cannot set property 'error' of undefined node-red_1 | at homieDeviceConfig.storeMessage (/data/node_modules/node-red-contrib-homie-convention/nodes/homie-device-config/homie-device-config.js:261:22)

Christian-Me commented 4 years ago

Thank you. That`s interesting. Yes, you are using 3.0.1 and yes my node will do the wrong assumptions that the topic is always: device/node/property(/set). But in 3.x it is not the case for $fw and $stats (this is moved to extensions 4.0.0 but this is also not implemented yet because I have first to upgrade my ESPEasy plugins....

I have to copy your dump into my mqtt-broker and see if I can reproduce the problem. Hope I will get this done ASAP.

Christian-Me commented 4 years ago

OK ... that looks better.

First I got the $fw, $stats and $implementation working. But then I found my main main problem: in my setup the Id is always the same as $name. But this is only a limitation of my firmware. I used $name and Id as equal all over the place. So I have to go through all of my code ... this will take some time. Please be patient.

As you see Id and $name is all mixed up in the UI: image

the global context: image

Christian-Me commented 4 years ago

So, here we are ... more problems than expected but hey ... It's beta (or alpha? I don't know) image

here is your node working in simulation:

  1. Sending the property image
  2. Sending to property/set image

bings you that image

Label & Unit is configured through the homie node (set the label field in the text node to {{$msg.label}}

Homie 3.x and Homie 4.0 extensions are now supported up to one level (i.e. "homie/device/$stats/uptime)

image

but in global context everything schould be available (not extensively tested) image

I updated the github version if you like to get the latest version from there.

Chris

philkry commented 4 years ago

great stuff! just pulled your changes. seems to work fine now :)

Christian-Me commented 4 years ago

great! Let me know if you run into problems. This is my first Node-RED custom node and it instantly got bigger and bigger - sadly with no greater concept or architecture. Sometimes I have to redesign everything from scratch with everything I learned so far ... The biggest problem is that you can`t predict in witch Order the messages arrive. I started with the order my ESPEasy implementation works ,,,

philkry commented 4 years ago

no worries. happy to be alpha/beta tester! i did discover some other issue in the UI, i will create a separate issue for that. will close this one now as it is not crashing anymore.