Node-Red crashes when Homie device is found

[philkry]

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]

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]

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]

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]

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]

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]

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:

the global context:

[Christian-Me]

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

here is your node working in simulation:

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

bings you that

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)

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

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

Chris

[philkry]

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

[Christian-Me]

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]

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.