I’m noticing a night and day difference in Z-Wave JS performance since updating to 2022.6.0 (HA OS 8.1). Quite literally I was toggling some Z-Wave switches prior to the update and it was, as usual, instant, but now it’s taking between 5 and 60 seconds to send the command.
My CPU is < 3%, memory is 5% and the rest of HA works normally, but Z-Wave actions are super slow.
zwavejs2mqtt: 6.11.0 (which is confusing, the add-on shows 0.42.0)
zwave-js: 9.3.0
I checked before I upgraded that the ZWave JS components were compatible since there is a breaking change if they are not, and everything is up to snuff with what the release notes require.
Perhaps the new version is doing some kind of self diagnostics or healing as part of the update and things will return to normal in a couple of hours?
I can confirm this, and I can’t believe there aren’t hundreds of posts in this thread from others.
The biggest impact on my setup if when doing an “all off” automation that targets a light group and a switch group. The automation was next to instant prior to 2022.6 and now, Z-Wave devices, as Co_4x4 mentioned, can take upwards of 30 seconds to respond. Last night I had one device that didn’t respond at all - and that’s not something I’d seen before.
I’ll have to make some time to test and log with debug options - nothing out of the ordinary showed up in the default logs the first time I saw the issue.
Here’s output from last night with the default “info” level. The groups of switches and lights contain Z-Wave, Shelly WiFi and a few Zigbee entities. AFAIK, there’s no issue with the non-Z-Wave integrations when using this automation.
Subscribed to Z-Wave JS Log Messages…
2022-06-17T03:38:54.693Z CNTRLR « [Node 028] received CentralScene notification {
"nodeId": 28,
"ccId": "Central Scene",
"ccCommand": "0x03",
"payload": "0x258402"
}
2022-06-17T03:38:55.922Z CNTRLR [Node 006] Timed out while waiting for a response from the node (ZW0201)
2022-06-17T03:39:00.883Z CNTRLR Failed to execute controller command after 1/3 attempts. Scheduling next try i
n 100 ms.
2022-06-17T03:39:01.039Z CNTRLR Failed to execute controller command after 1/3 attempts. Scheduling next try i
n 100 ms.
2022-06-17T03:39:01.260Z CNTRLR Failed to execute controller command after 1/3 attempts. Scheduling next try i
n 100 ms.
2022-06-17T03:39:01.590Z CNTRLR Failed to execute controller command after 1/3 attempts. Scheduling next try i
n 100 ms.
2022-06-17T03:39:01.960Z DRIVER Dropping message with invalid payload
2022-06-17T03:39:02.026Z DRIVER Dropping message with invalid payload
2022-06-17T03:39:02.119Z DRIVER Dropping message with invalid payload
2022-06-17T03:39:02.145Z DRIVER Dropping message with invalid payload
2022-06-17T03:39:02.190Z DRIVER Dropping message with invalid payload
2022-06-17T03:39:02.683Z DRIVER Dropping message with invalid payload
2022-06-17T03:39:02.741Z DRIVER Dropping message with invalid payload
2022-06-17T03:39:02.790Z DRIVER Dropping message with invalid payload
2022-06-17T03:39:03.114Z DRIVER Dropping message with invalid payload
2022-06-17T03:39:03.140Z DRIVER Dropping message with invalid payload
2022-06-17T03:39:03.218Z DRIVER Dropping message with invalid payload
2022-06-17T03:39:03.350Z DRIVER Dropping message with invalid payload
2022-06-17T03:39:03.692Z DRIVER Dropping message with invalid payload
2022-06-17T03:39:03.949Z CNTRLR Failed to execute controller command after 1/3 attempts. Scheduling next try i
n 100 ms.
2022-06-17T03:39:05.311Z DRIVER Dropping message with invalid payload
2022-06-17T03:39:05.362Z DRIVER Dropping message with invalid payload
As the OP of this topic: my original issue cleared up on its own after a day or two, not sure why but it did (and yes, I have my Z-Stick on an extension - not that it makes any difference to your request since you were responding to someone else).
My Z-Wave stick has been on an extension for about 5 years
Node 6 was OFF at the time the automation was fired. It might have been relaying to another node that was ON, not sure, so will log debug info next time. There were only 3 devices ON that were supposed to turn off with the automation last night and they’re all a few feet from node 6.
Going to roll back HA, test, capture logs, then restore newest backup, test and capture logs.
I can’t duplicate the issue at the moment. Response is quick on the automation, unlike every other time since the 2022.6 update. I typically run it only once every night so that was over a dozen times with very slow response.
It’s like CO_4x4’s magic words made it all clear up on this end too. Until I test again tonight.
What’s odd is I started having this issue only at night after these 6.x updates as well. if I try to operate any wall switches at night within the home assistant ui, the odd 30/60 second delay occurs. But during the day, it works as normal… it’s very odd behavior.
In addition, if i do use the UI to operate a wall switch, any attempt to turn it off gets lost in the send.
So sure enough, tonight as I’m using the automation in earnest, the slowness is back. The first time I did it, on my way upstairs, I forgot about capturing the log… One of the lights took about 45 seconds to turn off.
I manually turned some lights back on and then triggered the automation again while capturing the log. Unfortunately it exceeds the post length limit here.
Sorry, it’s not in any different format, the issue was the file was uploaded/linked with a .txt extension and the browser is displaying invisible characters.
I’ve renamed it above so it can be downloaded and properly opened, but also pasted it here: dpaste/KTfoR (YAML)
Whatever the invisible characters are (maybe tabs?) are output from the Z-WaveJS logger.
Typically there are 2 or 3 in-wall switches that are in the ON state when I trigger that automation at night to turn them off.
The two groups that contain those 2-3 entities contain additional switches and lights. Light group has 12 entities and switch group 16 total. Mix of Z-Wave, Shelly WiFi and a couple of Zigbee.
Yesterday evening, same 3 on and they turned off almost instantly. It’s the same setup more or less I’ve been running for months in HA. When I started, before groups were in the UI, I had a “night off” scene where I collected all the relevant entities and their states. When groups were exposed as helpers I switched over to using two groups and turning them off. It worked well.
Previous to HA, I used to use Indigo and something similar to HA’s groups to collect all the devices which would then be turned off with the same type of scene command from the same Z-Wave switch. HA with Z-Wave JS has always been quite a bit faster than Indigo until this month.
Just noticed some talk of changes/fixes upcoming for Z-WaveJS - @raman325 is it possible the changes leading to inclusion /discovery/timeout problems from other threads can be attributed to slow response being observed here?
