OH2 Z-Wave refactoring and testing... and SECURITY

r27 · July 22, 2018, 11:37am

My bad, yes this is new log from today.

chris · July 22, 2018, 11:45am

It looks to be the same as the new binding -:

r27 · July 22, 2018, 11:51am

Ok, then I don’t know why it works with 2.2 and doesn’t with 2.3. I am gonna do one more test, I’ll setup new OH 2.3 and try, if it doesn’t work I’ll give up. My options will be 1. replace dimmers 2. go back to 2.2 and don’t use security features and lock. 3. Test HomeAssistant (less likely).

chris · July 22, 2018, 11:53am

I thought that this log was from 2.2? You said -:

But this log shows that the same issue exists in 2.2. This isn’t really a surprise since it’s what everyone else has seen.

r27 · July 22, 2018, 11:57am

Correct this log from 2.2. And using 2.2 I get immediate updates from dimmers. So may be that “busy” issue is not issue, could be something else.

chris · July 22, 2018, 12:05pm

Ok, I think I know what the issue is. In the old binding, command classes were added if a command was received and the class wasn’t known. In the new binding, that was changed to avoid issues with corrupt data generating incorrect classes.

These devices are not reporting that they support a certain command class, and this means that there is no repoll.

@5iver I may reconsider this issue and add unknown classes as that change is causing quite a few problems…

chris · July 22, 2018, 12:06pm

@r27 an you remind me again what these two devices are and I’ll update the database.

r27 · July 22, 2018, 12:09pm

Ok, I this proves that I am not crazy I don’t know how it works for @5iver, but I just setup fresh new OH, used Zwave 2.4 add-on that he shared with me. Node was initialized but updates don’t work.
We are talking about DZMX1-1LZ devices. *both devices DZMX1-1LZ

chris · July 22, 2018, 12:16pm

Ok, please try the latest version.

dan12345 · July 22, 2018, 12:22pm

many thanks for this. Small bug - when starting up I get:

2018-07-22 13:20:58.063 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'zwave:serial_zstick:512' to inbox.

when I already have a zstick Thing. Otherwise working fine (so far!)

r27 · July 22, 2018, 12:25pm

From first post ?

chris · July 22, 2018, 12:25pm

This is a “feature” of the new USB search feature - not so much I can do about this at the moment, but it’s not new either…

chris · July 22, 2018, 12:26pm

Yes.

r27 · July 22, 2018, 12:42pm

@chris
Good news - initializing works now. I deleted and added thing back and can control it.
Bad news - still no ON/OFF updates from device. I see updates if I adjust brightness manually (pushing buttons on actual switch).

chris · July 22, 2018, 12:43pm

Please provide the log showing the device initialisation and the manual state update.

r27 · July 22, 2018, 12:57pm

https://anonfile.com/a1V4x1fcba/openhab.log

Steps: deleted thing (node6)> enabled debug > shutdown OH > clean logs> start OH > add thing (node6) > turn on/off using UI > physical ON/OFF > physical brightness > shutdown OH .

5iver · July 22, 2018, 12:58pm

Do you think it is possible the APP BUSY could be due to the device being busy routing? I can’t think of anything else the device would be doing that would make it too busy to reply.

Are there retries after getting this ack (or was that the 175ms poll period)? Putting my data into a pivot table, it looks like the devices will stay busy for up to 30s! I do now see some periodic patterns that I didn’t see with my naked eyes. Most seem to clear up in April. Maybe the polling randomization went in at that time? Or more likely, the retries… There are still some recent ones. Here’s the biggest example…

31	2018-07-07	07:01:42 PM
	2018-07-08	07:00:33 AM
		04:43:03 PM
	2018-07-09	02:43:06 AM
		03:43:08 AM
		04:43:10 AM
		06:13:22 AM
		09:13:24 AM
		11:13:26 AM
		04:13:29 PM
		07:43:31 PM
		07:43:33 PM
		07:43:35 PM
		08:43:39 PM

The poll times of my devices should all be set to 2 days, but there seems to be an hourly pattern. No big ideas yet… still processing. I never noticed an issue caused by this though.

Yeah… I wince a little every time I see them come up. Which command class is this device not reporting, and how could mine be working? I know I deleted the XMLs a few times… but maybe that was during the initialization issue.

chris · July 22, 2018, 1:00pm

Please try a reinitialisation as the device has not reinitialised (at least not in this log) - probably because it restored from existing data file. If the device hasn’t reinitialised, then it won’t add the required command class.

chris · July 22, 2018, 1:07pm

Not really. Routing is not a time consuming task - it just needs to send a single message. Routing is as simple as receive a message, check the routing information in that message, and send it again. I don’t think it’s going to break that process up by receiving another message, let alone sending a busy response.

Not if the device responds that it’s busy.

I’m not sure I understand what this is showing - is this a list of times the device is reporting busy?

The binding logs when it’s polling (search for “Polling…” I think). Should be easy to see if this is related to polling or something else…

It’s APPLICATION_STATUS - I don’t know why yours is working. Maybe it’s just “less busy” . The issue only exists if the device reports that it’s busy - without this CC, it won’t do the retry.

r27 · July 22, 2018, 1:09pm

@chris
YOU ARE GENIUS! SUCCESS! I did manual reinitialize using Habmin and now everything works. There is delay, but I don’t care It works! Thank you

After 2 days of troubleshooting

“In the old binding, command classes were added if a command was received and the class wasn’t known. In the new binding, that was changed to avoid issues with corrupt data generating incorrect classes”