ZWave Door Lock - OH2 - Help

So first off I must say thank you to all the folks working on OH2 and the ZWave binding. I stopped using OH 1.x about 4 months ago as we moved out of our house. Temporary living and just now getting setup in the new house. It’s like a whole new world setting up OH2 instead. I love how easy it’s been (minus some light reading of course).

I am now trying to get the last piece setup which is my door lock which I knew would be somewhat cumbersome as the security class in OH is a newer thing. I have a Schlage door lock - FE469NX is listed as the item number on the manual, with a FW Ver: MAIN_7.1. I’ve managed to get the lock off the front door to bring down to my ZStick attached to its system running OH in the basement. I enrolled it successfully (or so I thought), and was left with a device that is unknown.

It seems we may need to have this added in. I needed to see what I need to supply to add this into the DB? It looks to be the same and have the same features as the BE469 in the DB, but I don’t know where to go from here. I have some logs and screenshots if that’s helpful to sort any details out. Just looking more for some direction here.

Was in a bit of a rush earlier. Attached to this post is an image of the output in HABmin inside OpenHAB, and second is the logs I could gander from a simple GREP of the Node.

The other issue I face now, is I tried excluding the lock from my network to start over, thinking perhaps I didn’t wait long enough the first time (just to double check before I bother anyone). But to no avail as Node 27 gave the same results. Unfortunately no luck, but now I have a second Thing in the system I can’t seem to get rid of. Any help there would be useful.

2017-01-18 16:23:45.085 [INFO ] [mmandclass.ZWaveSecurityCommandClass] - NODE 26: setupNetworkKey useSchemeZero=false
2017-01-18 16:23:50.376 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 26: Timeout while sending message. Requeueing - 2 attempts left!
2017-01-18 16:23:50.376 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 26: Got an error while sending data. Resending message.
2017-01-18 16:23:55.676 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 26: Timeout while sending message. Requeueing - 1 attempts left!
2017-01-18 16:23:55.676 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 26: Got an error while sending data. Resending message.
2017-01-18 16:23:55.756 [INFO ] [mmandclass.ZWaveSecurityCommandClass] - NODE 26: setupNetworkKey useSchemeZero=true
2017-01-18 16:23:55.756 [INFO ] [mmandclass.ZWaveSecurityCommandClass] - NODE 26: Using Scheme0 Network Key for Key Exchange since we are in inclusion mode.
2017-01-18 16:23:55.978 [INFO ] [curityCommandClassWithInitialization] - NODE 26: Setting Network Key to real key after SECURITY_NETWORK_KEY_SET
2017-01-18 16:23:55.978 [INFO ] [mmandclass.ZWaveSecurityCommandClass] - NODE 26: setupNetworkKey useSchemeZero=false
2017-01-18 16:23:56.154 [ERROR] [col.security.ZWaveSecureNonceTracker] - NODE 26: SECURITY_ERROR Device message contained nonce that is unknown to us, id=-68.
2017-01-18 16:23:56.266 [WARN ] [mmandclass.ZWaveSecurityCommandClass] - NODE 26: payloadQueue was empty, returning!
2017-01-18 16:23:56.267 [ERROR] [ssage.ApplicationCommandMessageClass] - NODE 26: Unknown command class 0xffffff98
2017-01-18 16:24:01.995 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 26: Timeout while sending message. Requeueing - 2 attempts left!
2017-01-18 16:24:01.995 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 26: Got an error while sending data. Resending message.
2017-01-18 16:24:02.444 [ERROR] [col.security.ZWaveSecureNonceTracker] - NODE 26: SECURITY_ERROR Device message contained nonce that was previously used, id=-68.
2017-01-18 16:24:02.445 [ERROR] [ssage.ApplicationCommandMessageClass] - NODE 26: Failed to decrypt message out of Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 1A 16 98 81 9E 1B 8D A2 7C 3B 81 95 F7 DC 5B BC 7D FC 30 5D A5 7C 92 B7  .
2017-01-18 16:39:24.568 [WARN ] [ding.zwave.handler.ZWaveThingHandler] - NODE 26: Initialising Thing Node...
2017-01-18 17:15:29.314 [WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 26: Device discovery could not resolve to a thingType! 7FFFFFFF:7FFFFFFF:7FFFFFFF::0.0
2017-01-18 17:15:39.665 [WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 26: Device discovery could not resolve to a thingType! 7FFFFFFF:7FFFFFFF:7FFFFFFF::0.0
2017-01-18 17:26:37.643 [WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 26: Device discovery could not resolve to a thingType! 7FFFFFFF:7FFFFFFF:7FFFFFFF::0.0
2017-01-18 17:45:46.830 [WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 26: Device discovery could not resolve to a thingType! 7FFFFFFF:7FFFFFFF:7FFFFFFF::0.0
2017-01-18 17:46:00.957 [WARN ] [ding.zwave.handler.ZWaveThingHandler] - NODE 26: Initialising Thing Node...

Oh2 doesn’t currently support security so you won’t be able to get the lock working. I will try and make a development version available in a week or so that does have security - a few people are using this but it’s not available easily at the moment.

1 Like

@chris thanks for the quick response. I’m confused as I had seen some threads talking about OH2 and secure inclusion with different locks happening. I thought I might just be on the brink with a new device. Interestingly I did notice something has happened, it managed to get further and identify the device successfully now, and it looks like the process may have been interrupted but in progress none the less. Including logs here if it helps, it did identify it as the BE469 in HABmin, which was the good news.

If there is a development version or test version, I’m happy to guinea pig myself and test it out. For me this is an important function of our smart home setup. I’m wrangling a bunch of other issues with setup as we just moved into a new home, but I’m happy to try and provide as much feedback and info as possible to help better the product.

2017-01-18 17:26:48.577 [INFO ] [mmandclass.ZWaveSecurityCommandClass] - NODE 27: setupNetworkKey useSchemeZero=false
2017-01-18 17:26:53.923 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 27: Timeout while sending message. Requeueing - 2 attempts left!
2017-01-18 17:26:53.923 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 27: Got an error while sending data. Resending message.
2017-01-18 17:26:59.227 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 27: Timeout while sending message. Requeueing - 1 attempts left!
2017-01-18 17:26:59.227 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 27: Got an error while sending data. Resending message.
2017-01-18 17:26:59.301 [INFO ] [mmandclass.ZWaveSecurityCommandClass] - NODE 27: setupNetworkKey useSchemeZero=true
2017-01-18 17:26:59.301 [INFO ] [mmandclass.ZWaveSecurityCommandClass] - NODE 27: Using Scheme0 Network Key for Key Exchange since we are in inclusion mode.
2017-01-18 17:26:59.509 [INFO ] [curityCommandClassWithInitialization] - NODE 27: Setting Network Key to real key after SECURITY_NETWORK_KEY_SET
2017-01-18 17:26:59.509 [INFO ] [mmandclass.ZWaveSecurityCommandClass] - NODE 27: setupNetworkKey useSchemeZero=false
2017-01-18 17:26:59.680 [ERROR] [col.security.ZWaveSecureNonceTracker] - NODE 27: SECURITY_ERROR Device message contained nonce that is unknown to us, id=51.
2017-01-18 17:26:59.793 [WARN ] [mmandclass.ZWaveSecurityCommandClass] - NODE 27: payloadQueue was empty, returning!
2017-01-18 17:26:59.793 [ERROR] [ssage.ApplicationCommandMessageClass] - NODE 27: Unknown command class 0xffffff98
2017-01-18 17:27:04.684 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 27: Timeout while sending message. Requeueing - 2 attempts left!
2017-01-18 17:27:04.684 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 27: Got an error while sending data. Resending message.
2017-01-18 17:27:05.123 [ERROR] [col.security.ZWaveSecureNonceTracker] - NODE 27: SECURITY_ERROR Device message contained nonce that was previously used, id=51.
2017-01-18 17:27:05.124 [ERROR] [ssage.ApplicationCommandMessageClass] - NODE 27: Failed to decrypt message out of Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 1B 16 98 81 AC 29 9E AF 0F 1F 71 73 1D 30 CE 33 0F FB D8 15 19 91 61 CE  .
2017-01-18 17:27:31.151 [WARN ] [ding.zwave.handler.ZWaveThingHandler] - NODE 27: Initialising Thing Node...

This section starts to repeat itself over and over again.

2017-01-18 22:57:39.996 [INFO ] [age.SerialApiGetInitDataMessageClass] - NODE 27: Node found
2017-01-18 22:57:40.287 [INFO ] [mmandclass.ZWaveSecurityCommandClass] - NODE 27: setupNetworkKey useSchemeZero=false
2017-01-18 22:57:40.484 [WARN ] [ding.zwave.handler.ZWaveThingHandler] - NODE 27: Initialising Thing Node...
2017-01-18 22:57:48.909 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 27: Timeout while sending message. Requeueing - 0 attempts left!
2017-01-18 22:57:48.910 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 27: Got an error while sending data. Resending message.
2017-01-18 22:57:50.267 [INFO ] [mmandclass.ZWaveSecurityCommandClass] - NODE 27: setupNetworkKey useSchemeZero=false
2017-01-18 22:57:50.332 [ERROR] [curityCommandClassWithInitialization] - NODE 27: SECURITY_ERROR Invalid state! Secure inclusion has not completed and we are not in inclusion mode. Aborting
2017-01-18 22:57:54.065 [INFO ] [ommandclass.ZWaveVersionCommandClass] - NODE 27: Command Class LOCK has version 0!
2017-01-18 22:58:08.048 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 27: Timeout while sending message. Requeueing - 2 attempts left!
2017-01-18 22:58:08.048 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 27: Got an error while sending data. Resending message.
2017-01-18 22:58:13.577 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 27: Timeout while sending message. Requeueing - 1 attempts left!
2017-01-18 22:58:13.577 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 27: Got an error while sending data. Resending message.
2017-01-18 22:58:19.856 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 27: Timeout while sending message. Requeueing - 0 attempts left!
2017-01-18 22:58:19.857 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 27: Got an error while sending data. Resending message.
2017-01-18 22:58:25.387 [WARN ] [ocol.ZWaveController$ZWaveSendThread] - NODE 27: Too many retries. Discarding message: Message: class=SendData[0x13], type=Request[0x00], priority=Get, dest=27, callback=105, payload=1B 02 63 04 
2017-01-18 22:58:30.861 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 27: Timeout while sending message. Requeueing - 2 attempts left!
2017-01-18 22:58:30.861 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 27: Got an error while sending data. Resending message.
2017-01-18 22:58:36.345 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 27: Timeout while sending message. Requeueing - 1 attempts left!
2017-01-18 22:58:36.346 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 27: Got an error while sending data. Resending message.
2017-01-18 22:58:41.876 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 27: Timeout while sending message. Requeueing - 0 attempts left!
2017-01-18 22:58:41.876 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 27: Got an error while sending data. Resending message.
2017-01-18 22:58:47.389 [WARN ] [ocol.ZWaveController$ZWaveSendThread] - NODE 27: Too many retries. Discarding message: Message: class=SendData[0x13], type=Request[0x00], priority=Get, dest=27, callback=109, payload=1B 02 63 04 
2017-01-18 22:58:53.660 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 27: Timeout while sending message. Requeueing - 2 attempts left!
2017-01-18 22:58:53.660 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 27: Got an error while sending data. Resending message.
2017-01-18 22:58:59.203 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 27: Timeout while sending message. Requeueing - 1 attempts left!
2017-01-18 22:58:59.203 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 27: Got an error while sending data. Resending message.
2017-01-18 22:59:04.706 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 27: Timeout while sending message. Requeueing - 0 attempts left!
2017-01-18 22:59:04.706 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 27: Got an error while sending data. Resending message.
2017-01-18 22:59:10.214 [WARN ] [ocol.ZWaveController$ZWaveSendThread] - NODE 27: Too many retries. Discarding message: Message: class=SendData[0x13], type=Request[0x00], priority=Get, dest=27, callback=133, payload=1B 02 63 04 
2017-01-18 22:59:15.726 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 27: Timeout while sending message. Requeueing - 2 attempts left!
2017-01-18 22:59:15.727 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 27: Got an error while sending data. Resending message.
2017-01-18 22:59:21.232 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 27: Timeout while sending message. Requeueing - 1 attempts left!
2017-01-18 22:59:21.232 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 27: Got an error while sending data. Resending message.
2017-01-18 22:59:27.513 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 27: Timeout while sending message. Requeueing - 0 attempts left!
2017-01-18 22:59:27.514 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 27: Got an error while sending data. Resending message.
2017-01-18 22:59:33.018 [WARN ] [ocol.ZWaveController$ZWaveSendThread] - NODE 27: Too many retries. Discarding message: Message: class=SendData[0x13], type=Request[0x00], priority=Get, dest=27, callback=137, payload=1B 02 63 04 
2017-01-18 22:59:38.492 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 27: Timeout while sending message. Requeueing - 2 attempts left!
2017-01-18 22:59:38.493 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 27: Got an error while sending data. Resending message.
2017-01-18 22:59:44.002 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 27: Timeout while sending message. Requeueing - 1 attempts left!
2017-01-18 22:59:44.002 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 27: Got an error while sending data. Resending message.
2017-01-18 22:59:49.558 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 27: Timeout while sending message. Requeueing - 0 attempts left!
2017-01-18 22:59:49.561 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 27: Got an error while sending data. Resending message.
2017-01-18 22:59:55.049 [WARN ] [ocol.ZWaveController$ZWaveSendThread] - NODE 27: Too many retries. Discarding message: Message: class=SendData[0x13], type=Request[0x00], priority=Get, dest=27, callback=140, payload=1B 02 63 04 
2017-01-18 23:00:47.061 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 27: Timeout while sending message. Requeueing - 2 attempts left!
2017-01-18 23:00:47.061 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 27: Got an error while sending data. Resending message.
2017-01-18 23:00:52.583 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 27: Timeout while sending message. Requeueing - 1 attempts left!
2017-01-18 23:00:52.584 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 27: Got an error while sending data. Resending message.
2017-01-18 23:00:58.046 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 27: Timeout while sending message. Requeueing - 0 attempts left!
2017-01-18 23:00:58.046 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 27: Got an error while sending data. Resending message.
2017-01-18 23:01:04.403 [WARN ] [ocol.ZWaveController$ZWaveSendThread] - NODE 27: Too many retries. Discarding message: Message: class=SendData[0x13], type=Request[0x00], priority=Get, dest=27, callback=16, payload=1B 02 63 04 
2017-01-18 23:03:26.239 [ERROR] [alization.ZWaveNodeInitStageAdvancer] - NODE 27: Node advancer: Retries exceeded at STATIC_VALUES

There is some secure code in the oh2 binding - it was copied from the oh1 binding but for various reasons it didn’t work well. The log messages you see are remnants of this…

The development branch is a total rewrite and has a bunch of other stuff in it, but the secure stuff is working well I think (it’s not missed a beat with my lock in a number of weeks of running).

I’ll get it available when I get back home next week…

@chris - you are the man! that would be great. If you don’t mind, just drop me a note on the community board, or on this thread when you’ve done so and I’ll be sure to pull a copy and test it out.

One unique thing I’ll illustrate about my setup is that I’m using Docker to run my OH instance. I’ve had some woes and still sorting them out, but the underlying functionality seems to work perfectly - including the current ZWave implementation. I was able to easily get everything else up and running. This is the downside/difficulty with trying to pair my lock, since I have to disassemble it from the front door each time to bring it to my server in the basement! :unamused:

Is there a suggested way that I can remove Node 26 and Node 27 from the ZStick so they stop being discovered? I’d like to start a fresh inclusion/pairing of this lock once the dev branch is available. I tried using the exclusion mechanism in HABmin, but it didn’t seem to actually get rid of the pairing for some reason (hence why I have 2 Nodes paired and showing up).

If you already reset these devices and added them again as new nodes, then you can try the options “Add device to FAILed list” and “Remove Device” (I’m going from memory here so this will no doubt be wrong!). These two options are advanced options so in HABmin, select advanced mode in the menu in the top right of the screen (in the thing configuration screen). Then you should find these two options (or something that sounds similar).

We can only delete nodes from the controller when the controller thinks they are dead. For mains devices, my experience is that they go to this state quickly so you can remove them. For batery devices, sometimes they aren’t places in the FAILed list so you need to use the “add to failed list” option.

This is a bit flakey in that there’s no docs on this and it doesn’t always work - good luck :wink: .

Well in all fairness, OH2 isn’t really official yet anyway, so isn’t it all just testing?! :wink:

I will try that out and hopefully that can help. What you’re saying makes sense to me in logic that is. So I’ll try that out and see if I can rid myself of them. In the meantime until the dev branch comes, I’ll start trying to get my rules set back up now since I have all new devices in the new house. I can’t tell you how much we are missing Alexa turning everything on/off and having all our scenes. It’s amazing how much we really did rely on this system.

Thanks again, and safe travels!

I think this worked! It may be that they finally FAILed on their own, but I managed to remove them both and they are not appearing at this point again. I’ll update if something changes. PROGRESS!

1 Like

I too am following this; Chris, I’m the guy with the BE369 that’s also unknown right now. Looking forward to the security release…

As I undestand, the secure transmission for locks is not supported yet in OH2. If I have a lock that is running in OH 1.9, will I have to re-initialize it (secure include) again once finally OH2 supports it or it will work if same security network key is used?

Where can I get the development stuff mentioned by Chris from? I assume it’s at Cloudbees, should I download the .kar from openHAB-Distribution integration built?

I downloaded version 2.1.0, but zwave binding still reports as 2.0.0.

I am eager to give it a test drive, so far my fresh OH2 instance does not talk to my Danalock.

So long as you don’t loose the key, you shouldn’t need to reinitialise it.

I’ll try and get an announcement out about this tomorrow. I have been trying to find the easiest way to provide the updates - I was thinking about setting up a CI task, but I think for now I’ll just provide a JAR (somewhere!).

Thanks.

As my milage with OH2 is just 10 days, please remember to explain in your tomorrow update how to handle jar in relation to kar (which is a new concept for me as I am rookie with Karaf), should it be pasted into addons along with kar?

Thanks Chris! I’m excited to test this out, even though I haven’t even gotten past including all my devices, and getting Alexa to control them. It’s been too long since I set my original OH 1.x setup. Now I have to re-learn all I did before, and the new adaptations. So it’s taking some time to say the least. But I look forward to the endeavor of testing out the lock integration.

@chris I’m sure you’re a busy man, but just wanted to check on the test version of the secure lock inclusion function? You’ve seen my chaos lately with having to swap out some switches (thanks for the help btw!) - so I figure for now I can focus on the lock functionality.

See here -:

I would like to confirm that the new binding mentioned above works with Danalock/Gerdalock.

@JjS I would suggest posting in the referenced post from Chris. This thread seems to be the place that this information should be noted/confirmed.

I’ll be looking to test this out as well and post my results there. To help reduce confusion and continued add-on to this thread, I’m going to repeat the link Chris supplied here:

And will mark this thread as “resolved” so folks can direct to the correct thread. Thanks again @chris for pointing us in the right direction here and all your hard work on the ZWave support.

I posted in both threads, so either way one can find the confirmation.

Another question about the lock, about feeding back lock status to OH2.
In previous version of the binding there was a lock status channel. It was quite useful, as if someone turns the lock by hand/key, it does not change the state of the zwave:device:controller:nodexx:lock_door now. It seems that the switch works like toggle switch, everytime I change it in OH, the lock starts to move (locking if it was unlocked or unlocking if it wasn’t), but with no correlation between lock status and the switch state.

My lock is BTZW125 Danalock v2 circle.