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

If by -:

… you mean the device is still not discovered, then we need to understand why, so logs would be needed for this. If you can debug this device to work out exactly the conditions, and what is stopping it working, it would really be great. The best thing is if you can reproduce this in a test case.

It’s unlikely since in my experience the manufacturer information is not secure, so it should be available even if not securely included. If we’re still talking about the garage door opener (??) then this definitely works for others without security so this information is definitely available in the clear.

Secure inclusion is basically the same as normal inclusion, but with some extra stuff on the end - if you want to send a log, then please feel free and I’ll have a look. I would recommend using the log viewer though - it makes things a LOT easier to visualise. This is especially true when security is involved as things otherwise become very complex with all the additional transactions for handling the nonce.

Thanks everybody and specially @chris for your patience with all my questions.
I still have some problems adding my Danalock V2 with security (node18).
The lock is found but Attributes show Using Security=x.
My actions to try and change this is to delete the think and try to add it again, with no luck.

21:58:30.095 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:15a32b9cacd:node18' changed from ONLINE to UNINITIALIZED
21:58:30.343 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:15a32b9cacd:node18' changed from ONLINE to UNINITIALIZED (HANDLER_MISSING_ERROR)
21:58:30.358 [INFO ] [smarthome.event.ThingRemovedEvent   ] - Thing 'zwave:device:15a32b9cacd:node18' has been removed.
21:58:36.887 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'zwave:device:15a32b9cacd:node18' to inbox.
21:58:36.889 [INFO ] [smarthome.event.InboxAddedEvent     ] - Discovery Result with UID 'zwave:device:15a32b9cacd:node18' has been added.
21:58:36.900 [INFO ] [smarthome.event.BindingEvent        ] - org.openhab.binding.zwave.event.BindingEvent@24e53b3d
21:58:43.709 [INFO ] [smarthome.event.InboxRemovedEvent   ] - Discovery Result with UID 'zwave:device:15a32b9cacd:node18' has been removed.
21:58:43.710 [INFO ] [smarthome.event.ThingAddedEvent     ] - Thing 'zwave:device:15a32b9cacd:node18' has been added.
21:58:43.713 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:15a32b9cacd:node18' changed from UNINITIALIZED to INITIALIZING
21:58:43.714 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:15a32b9cacd:node18' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline
21:58:43.715 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:15a32b9cacd:node18' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to UNINITIALIZED
21:58:43.723 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:15a32b9cacd:node18' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
21:58:43.740 [ERROR] [ome.core.thing.link.ThingLinkManager] - Exception occured while informing handler:null
java.lang.UnsupportedOperationException
	at java.util.AbstractList.add(AbstractList.java:148)[:1.8.0_121]
	at java.util.AbstractList.add(AbstractList.java:108)[:1.8.0_121]
	at org.openhab.binding.zwave.handler.ZWaveThingHandler.channelLinked(ZWaveThingHandler.java:432)[190:org.openhab.binding.zwave:2.1.0.201702122241]
	at org.eclipse.smarthome.core.thing.link.ThingLinkManager.informHandlerAboutLinkedChannel(ThingLinkManager.java:264)[105:org.eclipse.smarthome.core.thing:0.9.0.201702100936]
	at org.eclipse.smarthome.core.thing.link.ThingLinkManager.receiveTypedEvent(ThingLinkManager.java:304)[105:org.eclipse.smarthome.core.thing:0.9.0.201702100936]
	at org.eclipse.smarthome.core.thing.link.ThingLinkManager.receiveTypedEvent(ThingLinkManager.java:1)[105:org.eclipse.smarthome.core.thing:0.9.0.201702100936]
	at org.eclipse.smarthome.core.events.AbstractTypedEventSubscriber.receive(AbstractTypedEventSubscriber.java:50)[98:org.eclipse.smarthome.core:0.9.0.201702100936]
	at org.eclipse.smarthome.core.internal.events.OSGiEventManager$1.call(OSGiEventManager.java:192)[98:org.eclipse.smarthome.core:0.9.0.201702100936]
	at org.eclipse.smarthome.core.internal.events.OSGiEventManager$1.call(OSGiEventManager.java:1)[98:org.eclipse.smarthome.core:0.9.0.201702100936]
	at org.eclipse.smarthome.core.common.SafeMethodCaller$CallableWrapper.call(SafeMethodCaller.java:181)[98:org.eclipse.smarthome.core:0.9.0.201702100936]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)[:1.8.0_121]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)[:1.8.0_121]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)[:1.8.0_121]
	at java.lang.Thread.run(Thread.java:745)[:1.8.0_121]
21:58:43.741 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:15a32b9cacd:node18' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING
21:58:43.740 [ERROR] [ome.core.thing.link.ThingLinkManager] - Exception occured while informing handler:null
java.lang.UnsupportedOperationException
	at java.util.AbstractList.add(AbstractList.java:148)[:1.8.0_121]
	at java.util.AbstractList.add(AbstractList.java:108)[:1.8.0_121]
	at org.openhab.binding.zwave.handler.ZWaveThingHandler.channelLinked(ZWaveThingHandler.java:432)[190:org.openhab.binding.zwave:2.1.0.201702122241]
	at org.eclipse.smarthome.core.thing.link.ThingLinkManager.informHandlerAboutLinkedChannel(ThingLinkManager.java:264)[105:org.eclipse.smarthome.core.thing:0.9.0.201702100936]
	at org.eclipse.smarthome.core.thing.link.ThingLinkManager.receiveTypedEvent(ThingLinkManager.java:304)[105:org.eclipse.smarthome.core.thing:0.9.0.201702100936]
	at org.eclipse.smarthome.core.thing.link.ThingLinkManager.receiveTypedEvent(ThingLinkManager.java:1)[105:org.eclipse.smarthome.core.thing:0.9.0.201702100936]
	at org.eclipse.smarthome.core.events.AbstractTypedEventSubscriber.receive(AbstractTypedEventSubscriber.java:50)[98:org.eclipse.smarthome.core:0.9.0.201702100936]
	at org.eclipse.smarthome.core.internal.events.OSGiEventManager$1.call(OSGiEventManager.java:192)[98:org.eclipse.smarthome.core:0.9.0.201702100936]
	at org.eclipse.smarthome.core.internal.events.OSGiEventManager$1.call(OSGiEventManager.java:1)[98:org.eclipse.smarthome.core:0.9.0.201702100936]
	at org.eclipse.smarthome.core.common.SafeMethodCaller$CallableWrapper.call(SafeMethodCaller.java:181)[98:org.eclipse.smarthome.core:0.9.0.201702100936]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)[:1.8.0_121]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)[:1.8.0_121]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)[:1.8.0_121]
	at java.lang.Thread.run(Thread.java:745)[:1.8.0_121]
21:58:43.741 [INFO ] [smarthome.event.ThingUpdatedEvent   ] - Thing 'zwave:device:15a32b9cacd:node18' has been updated.
21:58:43.741 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:15a32b9cacd:node18' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline
21:58:43.742 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:15a32b9cacd:node18' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE

Any idea?
Thanks in advance

@chris - I know you’re not releasing official versions or anything, but to help the rest of us testing out this pre-release binding - could you change the numbering/naming somehow on the download from the above link? I think by following through the thread I see there is a new version, but I’m not sure I can actually tell when new versions are released. Would be helpful if the file could just be changed in the initial thread to point to a new date/time or version # release to let us know it’s available? And/or to let us subscribe to the possible notification of just that update.

1 Like

Also wanted to report, I’m seeing an odd message in my logs and I think this may possibly be related to why I was unsuccessful in sending the PIN codes to my lock:
16:37:00.365 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 26: Sent Data was not placed on stack.
Node26 obviously being my lock. I saw some odd messages like this when my pairing was failing too. It doesn’t seem “frequent” but it’s appeared a few different times.

Should I drop down to debug level logs and catch some more activity to report?

Ok, I see what happened with my build. There was some code that didn’t update correctly. Not used to how Eclipse works with git. Now the garage door device is identified correctly.

I used the log viewer to see what’s happening. Looks like it gets to the SECURITY_REPORT stage and never gets a response. I believe this was with the last posted jar. Going to wait and try again tomorrow and see what happens with the updated jar I built tonight. Will post the logs if I get the same errors.

I think that the error that’s in your log was fixed so I’d double check that you’re running the latest binding from the download link.

This is an error from the controller itself - a debug log will help, but I think the binding should retry the message.

I could post a new link each time, but that doesn’t really help I think. You’d still need to search through this thread to find the latest link which is the same as having to search through looking for a message simply sending a message with the same link? I don’t have an easy way to provide a list of different versions which I think is what you really want?

Ok - that’s good :slight_smile: .

That sounds like it’s already included, but not securely, or not with the correct password. During initialisation the binding will send a couple of secure requests to see if it gets a response before deciding if (or not) to continue securely or in the open.

That’s correct. It’s included, but without security currently.

Then it sounds correct that it will timeout at this stage if it’s not securely included. There should be a few timeouts, and it should then continue insecurely.

That’s what I’m seeing. It looks like it’s sending a SECURITY_SCHEME_GET a number of times. Then moves onto MANUFACTURER and gets responses there.

Ok I’ll try to do some more testing and throw it in debug mode. I’ll let you know if I see anything troubling and provide further feedback on my lock and functionality.

On the link topic - I was thinking more along the line of just editing the first topmost post each time, just adding a quick indicator to the link. It was just a thought to save from folks not being able to follow where to grab from. Totally understand your points though.

The latest binding has solved my unknown device issues. Bulbs showed right up after the restart as the correct items. Only thing I had to do was add the items to the channels then send some on/off commands to get them communicating with the stick again (they were marked as failed in between the original add and this updated binding).

Sir @chris does it again!! Thanks for the great work!!

Ok - this might be a good idea - I don’t think I need to change the link then, just update the top post each time…

Good stuff - at least something is heading in the right direction :slight_smile:

Ok, then that’s 100% correct if it’s not securely included… :slight_smile:


Checked and I’m using the latest…

Could it be that my lock was matched with a key that was randomly generated by the binding and when I reinstalled the binding it generated a new key but it doesn’t match with what’s in my lock?

Exclude the lock from your controller and re add it

I’m still having problems showing the network view in habmin. It only shows the controller. @chris do I need an updated habmin jar as well? If yes where can I get it?

Hmmm - I’ve not looked at this for the new version, but you might be right as the node id was moved from a property to a config item, and the network diagram code hasn’t updated for that.

So, yes, probably it needs to be updated - it should be a quick change so I’ll see if I can do it this weekend.

Great, thanks Chris!

I just updated to the latest test binding from the same/original down load link, and now both my battery devices which are a 1) garage door sensor and 2) recessed door sensors both show as “not communicating with the controller”

I have manually woke up these devices up as well. Has anything possibly changed?