ZWave binding updates

Did you read the Relase Notes? restdocs moved from misc to ui .

I didn’t, but even if I did, I would never figure out that restdocs might somehow be related to Z-wave controller restarts. What’s more addons.cfg says Note: This is only regarded at the VERY FIRST START of openHAB. Given I’ve been upgrading openhab, it would also be difficult to find any relation to z-wave binding.
Edit: I’ve checked addons.cfg but all lines are commented out there. If I have invalid addons, how to find out which are the wrong ones? There isn’t anything in the logs.

It’s people have found issues in the addons.config in the userdata folder.

Noted, with the multitudes of folks having z-wave issues in 2.5 seemed good to share my experience - even if from a technical stand point it ‘has nothing to do with the binding’ the end result is z-wave breaks.

Even with the ‘restdocs’ issue cleared up, I’m still getting severe latency on my zwave network. This has been working reliably since a fresh 2.0 install several years back (and before that on 1.x) and nothing has changed in the hardware between 2.4 and 2.5.

Upon a reboot, z-wave works as it’s always done, but after ~20 mins we start to see 1 minute + latency between issuing a command and the desired action; also seeing events where triggering groups of zwave devices (timer or manually) will result in random devices being left on or off while others complete.

I see odd logs when this begins happening; the device thats just been triggered in the excerpt below (node 34) took over four minutes to react.

line that stand out are:

  • NODE 34: TID 80: Timeout at state ABORTED. 3 retries remaining.

  • TID 80: Transaction is current transaction, so clearing!!!""

  • TID 80: Transaction CANCELLED

    22:40:58.247 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT
    22:40:58.251 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
    22:41:10.238 [DEBUG] [nsactionManager$ZWaveTransactionTimer] - NODE 34: TID 80: Timeout at state ABORTED. 3 retries remaining.
    22:41:10.242 [DEBUG] [nsactionManager$ZWaveTransactionTimer] - TID 80: Transaction is current transaction, so clearing!!!
    22:41:10.246 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 80: Transaction CANCELLED
    22:41:10.249 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 34: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
    22:41:10.253 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 34: notifyTransactionResponse TID:80 CANCELLED
    22:41:10.258 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
    22:41:10.265 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 21 03 26 01 00 25 12 D4
    22:41:10.271 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 33: Sending REQUEST Message = 01 0A 00 13 21 03 26 01 00 25 12 D4
    22:41:10.275 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT
    22:41:10.279 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 81: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 18
    22:41:12.284 [DEBUG] [nsactionManager$ZWaveTransactionTimer] - NODE 33: TID 81: Timeout at state WAIT_RESPONSE. 3 retries remaining.
    22:41:12.288 [DEBUG] [nsactionManager$ZWaveTransactionTimer] - Aborting Transaction!
    22:41:12.291 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 81: Transaction ABORTED
    22:41:12.296 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 16 EA
    22:41:12.300 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 16 EA
    22:41:12.305 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT
    22:41:12.309 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
    22:41:24.296 [DEBUG] [nsactionManager$ZWaveTransactionTimer] - NODE 33: TID 81: Timeout at state ABORTED. 3 retries remaining.
    22:41:24.300 [DEBUG] [nsactionManager$ZWaveTransactionTimer] - TID 81: Transaction is current transaction, so clearing!!!
    22:41:24.304 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 81: Transaction CANCELLED
    22:41:24.308 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 33: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
    22:41:24.312 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 33: notifyTransactionResponse TID:81 CANCELLED
    22:41:24.316 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
    22:41:24.328 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 22 03 25 01 00 25 13 D5
    22:41:24.335 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 34: Sending REQUEST Message = 01 0A 00 13 22 03 25 01 00 25 13 D5
    22:41:24.339 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT
    22:41:24.343 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 82: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 19
    22:41:26.348 [DEBUG] [nsactionManager$ZWaveTransactionTimer] - NODE 34: TID 82: Timeout at state WAIT_RESPONSE. 3 retries remaining.
    22:41:26.352 [DEBUG] [nsactionManager$ZWaveTransactionTimer] - Aborting Transaction!
    22:41:26.356 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 82: Transaction ABORTED
    22:41:26.361 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 16 EA

None of the devices on my network are battery powered, all hard wired Eaton or Leviton devices that have worked reliably for years.

Disable the daily heal, restart OH, and perform manual heals on all mains powered devices. If you still have latency, heal again. Also, search your log for “Queue full” (restart OH if you do). See…

BTW, please read up on how to use code fences.

1 Like

Please provide a full debug log and I will take a look.

This normally means there was no response to a message.

This is perfectly normal.

This means there was no response after multiple tries.

These sort of things will introduce delays in your network - if there are nodes that are not responding, then this is the inevitable endpoint.

Been reading up on other threads complaining about slow zWave performance; no sense wasting your time if it’s a topology issue :slight_smile: Several suggestions were to confirm the zWave network and look for missing nodes - Checking HABmin, I see this:


What do the red arrows / links mean? As per this post earlier in the year, even @rlkoshak is unclear… I’d be great to have a legend to decode the map.

@chris I issued another re-initialize of the controller so will see if that helps; I am still puzzled why an update to 2.5 would manifest these issues… both your earlier comments in this thread and release notes confirm no changes to the plugin.

Thank you for taking the time on this; I’ll report back if still an issue - the debug logs requested in your previous post are from Karaf with log:set DEBUG org.openhab.binding.zwave option enabled?

They mean that there is only a one way connection reported from the neighbour tables. So one side reports the other is a neighbour, but the opposite is not true.

I’m by no means an expert on Zwave. The fact that I don’t know should not be all that surprising.

1 Like

Have the daily network heal issue been fixed in 2.5 Release?

@5iver what is your experience?

No - I’ve not had time to look at this.

There have not been any PRs to address it and the issue is still open.

No worry… I just didnt want to activate this option, if it´s still an issue…

If the process in the first post don’t work, what is the next thing I should try? Should I go ahead and also remove the controller? Exclude everything? Remove items?

Setting on/off from OpenHAB isn’t working with my zwave switches. They’re all Zooz brand, and I mostly just use them for monitoring power usage. They still report on/off when I manually press it, they still report power, and my other Zooz sensors are working. So OpenHAB is receiving updates from them, but they’re not obeying changes made in OpenHAB. I don’t use them very often, but they were definitely working when I was on 2.5 milestone 3. I’ve updated to each milestone and then the final since then. My version of the binding doesn’t seem to be stuck or anything (according to the console). Thanks!

Please advise what the devices are and provide a debug log showing what happens when you send the command.

Here’s some of the log for this device:
Z-Wave Node 009: ZEN15 Power Switch
Debug logging gets really loud with my other sensors, so I tried to boil it down. Let me know if you need more. Thanks you!
Node9-On-Off-Log.txt (9.0 KB)

Filtered logs are of no use for troubleshooting.

I have 2 of ZEN 15 I received in the past few months.

I see we have 2 entries in the database. What firmware version do you have?

1 Like

Thanks. The log shows that the controller is not accepting the commands. Normally this happens when the controller is overloaded.

What controller do you have? Does it work for other devices?

1 Like

I think you solved it. It’s an Aeotec Z-Stick Gen5. I don’t have any other zwave devices that receive commands from OpenHAB (they only send), so I couldn’t tell you if other devices worked. I’d guess they wouldn’t have. But suspecting my controller, I unplugged it and plugged it back in, then rebooted. Seems fine now, and responding faster than before. I’ve rebooted before, but it is on a powered hub, so I don’t think that was enough. I’ll move things around and get it off of the USB hub.

Bruce,
The firmware is 1.4 according to OpenHAB. Although, that doesn’t seem to exactly match with the versions listed on Zooz’s website.

Sorry to waste your time with this, but I really appreciate the help!