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

Thanks @chris! I try it out shortly.

For the alarm_entry - I just aggregate all the different alarms into one - so MANUAL, AUTO, KEYPAD etc are all used to show the lock state. I think this is fine - if we need to spit this at some stage to provide more detail, then we can look at that later…

@chris I’m not having any luck with this version. Here’s a log from node 72 (Wallmote).

https://drive.google.com/open?id=1ISFE4r-kVFjms0OZiF9U2Sn561MSqsEr

15:54:59.555    Discovery started (thank you for the change to TRACE log level)
15:55:12.980    Added thing from inbox
15:55:47.911    Woke up device

It looks like the change I made worked, and I think this will help, but it’s obviously not the root cause…

thank you @sihui for your answer.

That’s were I took that from:

openHAB 2.3.0 Build #1232

but how do I know if it is stable, snapshot or whatever else?

Yes, that’s the one in addons folder. It is installed but not active, so it’s not working.

It seems to work:

19 │ Active │ 80 │ 3.12.0.OH │ nrjavaserial

and yet I receive that error:

openhab> bundle:start 277
    Error executing command: Error executing command on bundles:
    	Error starting bundle 277: Could not resolve module: org.openhab.binding.zwave [277]
      Unresolved requirement: Import-Package: org.eclipse.jdt.annotation; resolution:="optional"
      Unresolved requirement: Import-Package: org.eclipse.smarthome.config.discovery.usbserial

(I reinstalled so the number changed from 272 to 277).
The zwave binding I had running was installed in habmin, so I went to karaf and uninstalled zwave from there (bundle:uninstall xxx). Then I dropped new binding in the addons folder (to keep the dependencies, as proposed by @chris). It reported installed (but not active) and starting failed with errors as above. I “chown”-ed the binding to openhab:openhab btw, should I not?

Has anybody seen those errors before? Is my only hope to reinstall openhab?
What are those “jdt.annotation” and “smarthome.config.discovery.usbserial” anyway?

Sidenote:
All I want is to get the Fibaro Dimmer2 and Qubino Flush Dimmer to report their state. It’s only possible in development binding, isn’t it? (Associations seem not to work well as well ATM, but that’s sth I can live with, or without to be strict.)

That is a pretty old snapshot version. Current snapshot is #1307.

You should at least upgrade to openHAB 2.3 stable.

The proper way to do that is:
uninstall the binding the way you did install it. So if you did install it via GUI, uninstall it via GUI.
If it does not work uninstall it via karaf.
If it is still not gone (check via bundle:list), clear cache and tmp.
After you got rid of the binding drop the jar into the addons folder. It should be active automatically.

If the transport serial is missing install it.

If you are finished restart openHAB. It will take a while because you cleared tmp and Cache …

Just FYI, I understand the issue now - it’s caused by this change -:

I just need to work out how to resolve it…

EDIT: @mhilbush please try this version.

I think that once this issue with the wakeup is resolved, I will merge this new DEAD NODE code into the main dev branch, and if there’s no major complaints merge dev into master in a week or two. @5iver I’m not really sure where we are with your issues?

Seems obvious now that you point it out. :man_facepalming:

The change makes sense, maybe with the exception of the WAKE_UP command class. :wink:

I’ll try this version out now.

@chris I’m still seeing the “Node doesn’t support WAKEUP” message in the logs when I wake up the device.

As before, I deleted a Wallmote thing, rediscovered, added from the inbox, then woke it up. Do you want to see the log?

I also tried resetting a Minimote and reincluding it. Same behavior.

When I woke up the Minimote…

2018-07-01 07:38:07.735 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 04 04 5F 02 84 07 29 
2018-07-01 07:38:07.735 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=95, callback=4, payload=04 5F 02 84 07 
2018-07-01 07:38:07.735 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage past lock Message: class=ApplicationCommandHandler[4], type=Request[0], dest=95, callback=4, payload=04 5F 02 84 07 
2018-07-01 07:38:07.735 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=95, callback=4, payload=04 5F 02 84 07 
2018-07-01 07:38:07.735 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction null
2018-07-01 07:38:07.735 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 95: Application Command Request (ALIVE:UPDATE_NEIGHBORS)
2018-07-01 07:38:07.735 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 95: Node doesn't support WAKEUP - ignore wakeup
2018-07-01 07:38:07.735 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 95: Commands processed 1.
2018-07-01 07:38:07.735 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 95: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@6593c6af.

There’s still a check for the WAKE_UP class in setAwake?

This is now a different error - I’ll take a look at this…

Yep - my initial change was ok, but it was caught by this one :unamused: . I will remove this check - it should be safe as it should only get this far if it is a battery device (as there’s a listening check above). There may be some corner cases though where devices don’t listen, but also don’t support the wakeup class (I know there are one or two that strangely do this!).

Please try this.

Edit: Let’s see what you see with this - there might be another error I think (for sure you will have another similar error, and maybe even an exception for good luck!). I’m rushing as I’m about to go out - I really need to spend a bit more time on it either late tonight or tomorrow…

Here’s what I’ve found so far. Results are mostly good.

  • Aeon Wallmote - discovered correctly and is working correctly

  • Fibaro Button - discovered correctly and is working correctly

  • Ecolink TILTZWAVE2 - discovered correctly and is working correctly

  • Minimotes - I have 3 devices with mixed results (I’m really starting to hate these devices :frowning:)

– one was discovered correctly, and is working correctly :grinning:

– one was discovered correctly, but is complaining about the COMMAND_CLASS_SCENE_ACTIVATION not found when I press a scene button. This one and the one above both report the same firmware version (1.19). There is no node.xml for this one either. I also tried to exclude/reset/include the node. I’m not sure what to make of this at this point.

2018-07-01 09:13:12.633 [DEBUG] [wave.handler.ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0A 00 04 00 5F 04 2B 01 01 00 81 
2018-07-01 09:13:12.634 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=95, callback=0, payload=00 5F 04 2B 01 01 00 
2018-07-01 09:13:12.634 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - processReceiveMessage past lock Message: class=ApplicationCommandHandler[4], type=Request[0], dest=95, callback=0, payload=00 5F 04 2B 01 01 00 
2018-07-01 09:13:12.634 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=95, callback=0, payload=00 5F 04 2B 01 01 00 
2018-07-01 09:13:12.634 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - lastTransaction null
2018-07-01 09:13:12.634 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 95: Application Command Request (ALIVE:SET_WAKEUP)
2018-07-01 09:13:12.634 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 95: Incoming command class COMMAND_CLASS_SCENE_ACTIVATION, endpoint 0
2018-07-01 09:13:12.634 [DEBUG] [.openhab.binding.zwave.internal.protocol.ZWaveNode] - NODE 95: Command class COMMAND_CLASS_SCENE_ACTIVATION not found.
2018-07-01 09:13:12.635 [DEBUG] [ng.zwave.internal.protocol.ZWaveTransactionManager] - NODE 95: Commands processed 1.

– one won’t discover at all. HABmin is declaring that the node is not in the Z-Wave network. I’m going to reset this device and re-include it.

Thanks Mark,
That looks pretty promissing.

We’d need to look earlier in the initialisation to see what’s up. It’s not completed initialisation yet, although it should have received the NIF so should know the supported classes already. This will be why it’s not saved the XML - it’s not finished the static initialisation (ie still at SET_WAKEUP).

Agreed. Thanks for getting this sorted out!

I just restarted OH, so I’m going to wait a while for the zwave network traffic to settle down. Then I’ll do a delete/rediscover test on the 2 problematic Minimotes, nodes 95 and 96.

I’m having trouble securely pairing a Schlage BE469. I tried a while ago with one that was already installed, but put it off until I got my second one so I could have it on my desk rather than on a door while debugging.
I’m trying a version posted for mhilbush yesterday
196 │ Active │ 80 │ 2.3.0.201806301554 │ ZWave Binding
I start the secure inclusion using openhab, and then start the inclusion on the lock itself. The lock shows an X to indicate inclusion failure. I did end up with a new node (NODE 27 in the logs below), but it’s not securely included, and in habmin, it’s just listed as “Unknown Device” with no Manufacturer, Type/ID etc (although it does show Neighbors and SPECIFIC_TYPE_SECURE_KEYPAD_DOOR_LOCK)

Here’s a log from the first inclusion (which was my first inclusion event since my upgrade from 2.2 to 2.3, so there is a lot of messaging. I had TRACE turned on when I was trying to debug my first lock):

Here’s a subsequent inclusion attempt:

Note that the lock itself thinks it’s not included, according to an on-lock procedure

Any tips on how I can proceed?

Make sure that you reset the device, or exclude it before trying to securely include it. If the device is currently included it will not work since the secure inclusion (ie key exchange) must happen within 15 seconds of the inclusion of the device into the network.

So the device doesn’t think it’s included, but I think the controller does. I was unable to “remove device from the controller” using habmin. Anything else I can try, short of resetting the controller to default and having to reinclude my other 26 devices too?

Note also that the first log I provided was the initial pairing attempt with this lock, so it couldn’t have had that problem yet.

Why do you say that? I think the device is included ok, but it MUST be excluded and then included securely. Both the logs you provided had the same node ID, so clearly it was not excluded between these two inclusions.

If you don’t exclude, then it definately will not work.

To exclude a device, you must use the “Exclude device” option in the controller. Click this, then put the device into exclude mode.

Maybe - it’s hard to confirm. All I can say from this log is that the device acked the message relating to key exchange, but did not respond. This means that the RF link is working, but the device chose not to respond. This is normally an indicator that the device was already included and therefore it’s past the 15 second window.

There is a procedure on the device that, when performed, will blink a light a certain way if it thinks it is included in a network, and performing that task does not blink the light.

Also, I see no zwave traffic when I perform tasks on the lock that I would expect to generate traffic, like locking and unlocking with codes.

OK, I didn’t know that excluding had to start on the controller thing - the include and exclude commands on the device are the same, so I wasn’t sure how to put the device in exclude mode when it doesn’t think it’s included. I started “exclude devices” from the zwave controller thing in habmin, and performed the task on the lock, and it gave me a success code!

So after that, I deleted the node27 thing, and started discovery again. It did not pop up again immediately, so that seemed to have worked. I then included it, and it showed up as node 28 (same display as 27 showed), with habmin reporting secure inclusion failed, and another “x” failure on the lock itself.
Here’s the log from that inclusion: