Errors after updating to MQTTController build 25139

[RogerO]

@toggledbits
Hey Patrick,
Since switching to the zwavejs build, I have woken up to find that zwaveJS is down on my HA box, Yesterday both Home Assistant and zwavejs were off line and today it was just zwavejs.

{edit} I have been having occasional HA stability issues before so not implying that the beta is causing it, just that it might be exposing a point of failure I was not aware of.

Not sure if this is a related error message, but not seeing much else in the logs:

2022-02-20T11:22:05.185Z CNTRLR « [Node 061] received wakeup notification
2022-02-20T11:22:05.191Z CNTRLR   [Node 061] The node is now awake.
[zwavejs-22050]2022-02-20T11:22:05.192Z <ZWaveJSController:5:ZWaveJSController.js:652> ZWaveJSController#zwavejs handling node event wake up entity (undefined)
[zwavejs-22050]2022-02-20T11:22:05.193Z <ZWaveJSController:ERR> ZWaveJSController#zwavejs _wsmessage_event threw untrapped exception: [TypeError]TypeError: Cannot read properties of undefined (reading 'setAttributes')
[zwavejs-22050]2022-02-20T11:22:05.193Z <ZWaveJSController:CRIT> TypeError: Cannot read properties of undefined (reading 'setAttributes')
TypeError: Cannot read properties of undefined (reading 'setAttributes')
    at ZWaveJSController._wsmessage_event (/opt/reactor/server/lib/ZWaveJSController.js:686:34)
    at ZWaveJSController.ws_message (/opt/reactor/server/lib/ZWaveJSController.js:592:48)
    at WebSocket.<anonymous> (/opt/reactor/server/lib/Controller.js:684:52)
    at WebSocket.emit (node:events:390:28)
    at WebSocket.emit (node:domain:475:12)
    at Receiver.receiverOnMessage (/opt/reactor/node_modules/ws/lib/websocket.js:1047:20)
    at Receiver.emit (node:events:390:28)
    at Receiver.emit (node:domain:475:12)
    at Receiver.dataMessage (/opt/reactor/node_modules/ws/lib/receiver.js:517:14)
    at Receiver.getData (/opt/reactor/node_modules/ws/lib/receiver.js:435:17)
2022-02-20T11:22:06.195Z CNTRLR » [Node 061] Sending node back to sleep...
[zwavejs-22050]2022-02-20T11:22:06.225Z <ZWaveJSController:6:ZWaveJSController.js:710> ZWaveJSController#zwavejs handling controller event statistics updated
[zwavejs-22050]2022-02-20T11:22:06.298Z <ZWaveJSController:5:ZWaveJSController.js:652> ZWaveJSController#zwavejs handling node event statistics updated entity (undefined)
[zwavejs-22050]2022-02-20T11:22:06.299Z <ZWaveJSController:6:ZWaveJSController.js:702> ZWaveJSController#zwavejs received statistics for (undefined): [Object]{ "commandsTX": 1, "commandsRX": 1, "commandsDroppedRX": 0, "commandsDroppedTX": 0, "timeoutResponse": 0 }
2022-02-20T11:22:06.302Z CNTRLR   [Node 061] The node is now asleep.
[zwavejs-22050]2022-02-20T11:22:06.304Z <ZWaveJSController:5:ZWaveJSController.js:652> ZWaveJSController#zwavejs handling node event sleep entity (undefined)
[zwavejs-22050]2022-02-20T11:22:06.305Z <ZWaveJSController:ERR> ZWaveJSController#zwavejs _wsmessage_event threw untrapped exception: [TypeError]TypeError: Cannot read properties of undefined (reading 'setAttributes')
[zwavejs-22050]2022-02-20T11:22:06.305Z <ZWaveJSController:CRIT> TypeError: Cannot read properties of undefined (reading 'setAttributes')
TypeError: Cannot read properties of undefined (reading 'setAttributes')
    at ZWaveJSController._wsmessage_event (/opt/reactor/server/lib/ZWaveJSController.js:694:34)
    at ZWaveJSController.ws_message (/opt/reactor/server/lib/ZWaveJSController.js:592:48)
    at WebSocket.<anonymous> (/opt/reactor/server/lib/Controller.js:684:52)
    at WebSocket.emit (node:events:390:28)
    at WebSocket.emit (node:domain:475:12)
    at Receiver.receiverOnMessage (/opt/reactor/node_modules/ws/lib/websocket.js:1047:20)
    at Receiver.emit (node:events:390:28)
    at Receiver.emit (node:domain:475:12)
    at Receiver.dataMessage (/opt/reactor/node_modules/ws/lib/receiver.js:517:14)
    at Receiver.getData (/opt/reactor/node_modules/ws/lib/receiver.js:435:17)

Device 61 is a Ecolink TILTZWAVE1
What can I supply to you to help you solve the issue?

Yesterday when it had failed, I noticed that the z-wave.me Razberry card was showing status of "unavailable". I added a reactor test for that to power cycle the HA box but today it was still alive when MSR indicated it was down in the controller status window. What parameter are you testing for and is that exposed to me so I can monitor it?

Roger

[toggledbits]

Doesn't look like it's an issue for me to resolve, at least not the ZWaveJS part. If ZwaveJS is crashing, and affecting both HA and Reactor, the digging needs to be done on ZWaveJS. From the rest of your text, it sounds like it may have an issue maintaining a connection to your Razberry card.

If you are running HA and ZWaveJS in docker containers, make sure they are configured to automatically restart.

The error message posted is because ZWaveJSController is getting node sleep/awake notifications for a node that wasn't in the device inventory when ZWaveJSController was started. I can definitely handle that more gracefully, but the error logged would not in any way stop operation of ZWaveJSController as a whole (i.e. it continues to function for nodes it knows about).

[RogerO]

ok, thanks. an you enlighten me on this part of the question" What parameter are you testing for and is that exposed to me so I can monitor it?"

[toggledbits]

If MSR indicates down in the list of controllers (in Status), that either means it is not connected to ZWaveJS at all, or it is in the process of establishing a new connection (if you have a large number of devices, going through the inventory can take some time). So it's not testing any parameter, it's looking at its own behavior. At this point, I haven't delved in enough to see what information I might get when ZWaveJS itself cannot communicate with the USB stick, so the zwave_network.state value on the controller's node (node 1) is just fixed at true.

If your rule is testing the ZWaveJSController status via sys_system.state, I would add a "sustained for" to that condition, because there may be occasions where any part of the plumbing is temporarily disconnected, and jumping to reboot the box may interrupt a recovery that otherwise would happen quickly and easily.

[RogerO]

I am testing this: "Entity Attribute: Z-Wave.Me Razberry Daughtercard: Node Status (hass>sensor_z_wave_me_razberry_daughtercard_node_status) string_sensor.value == unavailable; for at least 300 secs"

[toggledbits]

OK. I have no idea how that's going to go, given that it's Hass and ZWave.me originating that data, Reactor is just copying what it's given.

I did some testing on my setup, and I have to say, the results were disappointing and will need some research, possibly some discussion with the ZWave-JS team. In a nutshell, I yanked my Z-stick to see what happens. Answer: nothing. Lots of nothing. Nothing worked, but also nothing indicated any errors. Node 1 (the controller) showed no changes in values from ZWaveJS at all. I let it cook for quite a while, issued several commands (all of which failed after retries, as expected), but never was there an indication that the stick was unavailable. When I reconnected the stick, things didn't improve. ZWaveJS continued to not report any problems, and unfortunately also continued to give errors on commands (with retries). It apparently had/has no awareness that the USB/serial port connection had been severed. It took a restart of ZWaveJS to get everything back up and running. Stay tuned, because frankly, that aggression cannot stand, man. I cannot be the first to experience this...

[RogerO]

This post is deleted!

[RogerO]

Am I correct in reading that this update, https://github.com/home-assistant/core/pull/67209 removed the parameter I was monitoring a few entries up? Also, have you had any discussions with zwavejs team regarding your findings above.

Gotta say, sometimes I think my VeraPlus was more reliable then HA and Razeberry board.

[toggledbits]

I'm not sure if you're talking about Hass entities or ZWave-JS entities at this point. Can you clarify?

[RogerO]

In MSR I was monitoring the Zwave card availability as mentioned here" I am testing this: "Entity Attribute: Z-Wave.Me Razberry Daughtercard: Node Status (hass>sensor_z_wave_me_razberry_daughtercard_node_status) string_sensor.value == unavailable; for at least 300 secs".
After the most recent HASS update which I think included that code change I linked to, my monitor died so now when HASS looses its connection to the zwave hat, I have no way to detect it and power cycle the HA box.

[toggledbits]

OK, that's nothing to do with ZWaveJSController, that's a Hass entity, and I can't speak to where and how Hass sources and interprets that data for its (Hass') entity; the Reactor entity is just a reflection/copy of the Hass entity's data. And on top of that, I don't think the ZWave.Me/Z-Way interface has anything to do with the ZWave-JS interface in Hass; they are two different components that do the same thing, and in fact, if you are running both of them at the same time talking to the same Razberry card, they are likely to be stomping on each other and fighting for control of the Razberry, and I don't see that leading to any success. That may be the cause of your instability for both ZWave.me and zwave-js.

[RogerO]

Hi Patrick,
I am not running any software from zwave.me. My Home Assistant is a HASS build running zwavejs and zwavejs2mqtt as the UI. that is the recommended setup according to the instructions on their site. Only thing from zwave.me is the razberry board.

[toggledbits]

Got it. That's good. In any case, the first point... I have no idea how zwavejs reports board/interface communication or other problems (I mean, I see how it's supposed to, and I have coded for that, but I have never seen a detected change, so can't confirm that their mechanism is actually working as advertised). And Hass and ZwaveJSController can only present the data they are given. Given that you seem to not be seeing any change in the Hass entity, and same on the Reactor side, and given that my experience with an Aeotec Z-Stick Gen 5+ is similar, that's an issue for the zwavejs devs.