Schlage Lock and Zwave snapshot binding [Solved]

[Aaaaron (Aaron Chree)]

• OpenHab 2.3 on Raspberry Pi 3

So I’m another poor sap trying to get this Schlage Connect Lock working with Openhab.

I managed to successfully complete the installation of the snapshot Zwave finding as per:

https://community.openhab.org/t/how-to-upgrade-zwave-binding-to-latest-snapshot/23268/49

I’m pretty sure I’ve got the right binding running… when I check it I get this:

openhab> bundle:list | grep ZWave
250 │ Active │ 80 │ 2.3.0.201806262322 │ ZWave Binding

Before upgrading to the snapshot binding, the lock was excluded on the network map, doing this got me as far as showing a connection between the lock and the Z-Stick.

Then, after quite a bit of fighting for signal, managed to get HabMin to find the deadbolt and add it.

This is where the confusion starts. The exact order of operations to do this is a bit unclear. In the documentation for the lock it instructs to put in the 6-didget pin to put it in pairing mode, but I’m not exactly sure when. I’ve been going with:

1. Scan for Zwave devices using Habmin
2. Let Lock show up in inbox (AS the lock, delete if it shows up as “Node 6, unknown device”
3. Add Lock
4. Enter PIN on lock to put in pairing mode.

Or variations thereof. In the logs I’m not quite sure what I’m looking at, but I’m think I’m seeing a lot of indications that the lock isn’t talking much. Of interest also is that Habmin had a RED popup which I’m pretty sure read “Secure Initialization Failed”, but I didn’t see it repeated in the log. This popup happened at the moment the Lock arrived in the inbox as a lock (As opposed to an unknown device.

I’m left with a lock that’s been added as a “thing” but doesn’t work. When I go to open it I get this in the log:

2018-12-03 00:27:45.307 [WARN ] [nal.converter.ZWaveDoorLockConverter] - NODE 6: Command class COMMAND_CLASS_DOOR_LOCK not found

2018-12-03 00:27:45.314 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: No messages returned from converter

2018-12-03 00:27:46.153 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Command received zwave:device:512:node6:lock_door --> OFF

2018-12-03 00:27:46.162 [WARN ] [nal.converter.ZWaveDoorLockConverter] - NODE 6: Command class COMMAND_CLASS_DOOR_LOCK not found

2018-12-03 00:27:46.165 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: No messages returned from converter 

Am I pairing wrong? Am I using the wrong binding still? Do I need to have the lock pin entered when the zstick listens for it? . I’ve been reading all kinds threads about “including/excluding” zwave devices and I’m getting pretty burried here, hoping the answer is a little more simple than that.

Here are my logs during pairing. As always, any help provided is greatly appreciated.

2018-12-03 00:10:36.228 [DEBUG] [org.openhab.binding.zwave           ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.core.status.ConfigStatusProvider}={service.id=406, service.bundleid=250, service.scope=singleton} - org.openhab.binding.zwave

2018-12-03 00:10:36.262 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:512:node6.

2018-12-03 00:10:36.273 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Controller status changed to ONLINE.

2018-12-03 00:10:36.276 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Controller is ONLINE. Starting device initialisation.

2018-12-03 00:10:36.289 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Channel zwave:device:512:node6:lock_door linked - polling started.

2018-12-03 00:10:36.293 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Channel zwave:device:512:node6:alarm_raw linked - polling started.

2018-12-03 00:10:36.297 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Channel zwave:device:512:node6:battery-level linked - polling started.

2018-12-03 00:10:36.381 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Updating node properties.

2018-12-03 00:10:36.493 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Updating node properties. MAN=59

2018-12-03 00:10:36.496 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Updating node properties. MAN=59. SET. Was 59

2018-12-03 00:10:36.500 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Properties synchronised

2018-12-03 00:10:36.949 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added.

2018-12-03 00:10:36.951 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Initialising Thing Node...

2018-12-03 00:10:36.953 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Initialising cmd channel zwave:device:512:node6:lock_door for OnOffType

2018-12-03 00:10:36.955 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Initialising state channel zwave:device:512:node6:lock_door for OnOffType

2018-12-03 00:10:36.957 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Initialising cmd channel zwave:device:512:node6:alarm_raw for StringType

2018-12-03 00:10:36.959 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Initialising state channel zwave:device:512:node6:alarm_raw for StringType

2018-12-03 00:10:36.961 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Initialising cmd channel zwave:device:512:node6:battery-level for PercentType

2018-12-03 00:10:36.962 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Initialising state channel zwave:device:512:node6:battery-level for PercentType

2018-12-03 00:10:36.964 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Polling intialised at 1800 seconds - start in 248400 milliseconds.

2018-12-03 00:10:36.965 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Device initialisation complete.

2018-12-03 00:10:37.362 [ERROR] [e.internal.WriterInterceptorExecutor] - MessageBodyWriter not found for media type=text/plain, type=class java.util.Collections$UnmodifiableCollection, genericType=class java.util.Collections$UnmodifiableCollection.

2018-12-03 00:11:34.773 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Received SOF

2018-12-03 00:11:34.781 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0E 00 49 84 06 08 04 40 03 22 72 7A 98 86 41 

2018-12-03 00:11:34.784 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Creating new SerialMessage from buffer = 01 0E 00 49 84 06 08 04 40 03 22 72 7A 98 86 41 

2018-12-03 00:11:34.786 [TRACE] [wave.internal.protocol.SerialMessage] - Calculated checksum = 65

2018-12-03 00:11:34.788 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 255: Checksum matched

2018-12-03 00:11:34.792 [TRACE] [wave.internal.protocol.SerialMessage] - NODE 6: Message payload = 84 06 08 04 40 03 22 72 7A 98 86 

2018-12-03 00:11:34.800 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Message is valid, sending ACK

2018-12-03 00:11:34.804 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT 6

2018-12-03 00:11:34.807 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationUpdate[73], type=Request[0], dest=6, callback=132, payload=84 06 08 04 40 03 22 72 7A 98 86 

2018-12-03 00:11:34.811 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lock Message: class=ApplicationUpdate[73], type=Request[0], dest=6, callback=132, payload=84 06 08 04 40 03 22 72 7A 98 86 

2018-12-03 00:11:34.814 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationUpdate[73], type=Request[0], dest=6, callback=132, payload=84 06 08 04 40 03 22 72 7A 98 86 

2018-12-03 00:11:34.816 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null

2018-12-03 00:11:34.818 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 0

2018-12-03 00:11:34.820 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: null

2018-12-03 00:11:34.822 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ****************** Transaction not correlated

2018-12-03 00:11:34.825 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=ApplicationUpdate[73], type=Request[0], dest=6, callback=132, payload=84 06 08 04 40 03 22 72 7A 98 86 

2018-12-03 00:11:34.827 [TRACE] [ve.internal.protocol.ZWaveController] - Incoming Message type = REQUEST

2018-12-03 00:11:34.829 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 6: Application update request. Node information received. Transaction null

2018-12-03 00:11:34.831 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 6: resetResendCount initComplete=true isDead=false

2018-12-03 00:11:34.833 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 6: Application update request. Requesting node state.

2018-12-03 00:11:34.835 [TRACE] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveDelayedPollEvent

2018-12-03 00:11:34.837 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Got an event from Z-Wave network: ZWaveDelayedPollEvent

2018-12-03 00:11:34.840 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Polling intialised at 1800 seconds - start in 75 milliseconds.

2018-12-03 00:11:34.842 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 6: Application update - no transaction.

2018-12-03 00:11:34.844 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty

2018-12-03 00:11:34.846 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start

2018-12-03 00:11:34.848 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction from controllerQueue

2018-12-03 00:11:34.850 [TRACE] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage nothing

2018-12-03 00:11:34.915 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Polling...

2018-12-03 00:11:34.917 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Polling zwave:device:512:node6:lock_door

2018-12-03 00:11:34.919 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Polling zwave:device:512:node6:alarm_raw

2018-12-03 00:11:34.922 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Polling zwave:device:512:node6:battery-level

2018-12-03 00:11:35.095 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 6: Node is listening - ignore wakeup```

[5iver (Scott Rushworth)]

@Aaaaron

openhab> bundle:list | grep ZWave
250 │ Active │ 80 │ 2.3.0.201806262322 │ ZWave Binding

This is not a version that supports security. You can use a recent snapshot or a milestone build (M3 or newer). See here…

ZWave binding updates

I have now merged the development version of the ZWave binding into master, so it will be available in the 2.4 snapshot version. If you are using the ZWave binding, please read this post as the binding contains some breaking changes so you will need to manually update your configuration. Firstly though - the major enhancements (there are tons more smaller updates) -: Security has been added using the S0 security class. This should allow all devices supporting security to be included into the…

For inclusion, you will need to exclude the lock first (it will include with the older bindings but will not function). Put the binding in inclusion mode, then put the lock in inclusion mode. This lock requires the controller to be less than 10 feet (closer is better) from the controller for secure inclusion. I have found that it also helps to let it sit for a while after inclusion to let it complete initialization.

[chris (Chris Jackson)]

@5iver

This does not look like a version that supports security.

I was just about to post the same thing, but the logs further down are coming from 2.4 (there are TransactionManager logs there which are only available in 2.4).

@Aaaaron

• Scan for Zwave devices using Habmin
• Let Lock show up in inbox (AS the lock, delete if it shows up as “Node 6, unknown device”
• Add Lock
• Enter PIN on lock to put in pairing mode.

This doesn’t sound right. If you are “letting the lock show up in the inbox” before you put the lock into pairing mode by entering the PIN, then it is likely including in a non-secure way. There are very tight timing constraints - the device must be securely included (ie the key exchange must take place) within 15 seconds of the network inclusion.

[Aaaaron (Aaron Chree)]

It’s been quite a while since I put this project down, but I’d like to report that I’ve got the deadbolt completely working!

It was a combination of both of these posts that got it going.

First I did update the binding to the 2.4.0 version. I did this by removing all the z-wave bindings in karaf, and then downloading the proper binding file to apps folder and rebooting the Pi.

Second I went into habmin, selected the Z-Wave USB stick, and excluded all z-wave devices.

Third I waited for the “Exclusion completed” Message.

Fourth, I punched the 6-didget code, followed by zero as per the inclusion instructions for the lock. This is the time sensitive part, so I can’t guarantee the lock was in pairing mode at the exact time it was “discovered” by the z-wave stick. I think it was.

Fifth, I put the z-wave stick back into inclusion mode and re-included the lock.

This took a number of attempts before I got it working, especially because the lock kept showing up as “unknown device”, but I included it as an “unknown device”, after which open-hab figured out what it was.

The whole time I was doing this I was watching a tail on the log, with the z-wave binding in debug mode. That way I could at least watch for any message indicating that secure inclusion was at least being attempted.

There was a little red box that popped up in habmin during one of my attempts to include the lock in secure mode that read “Secure inclusion failed”. I knew I was getting close! Another few attempts later a green box popped up indicating that secure inclusion was successful, and after that, the lock was fully functional!

During the secure pairing operation, I did pull the lock out of the door and move it to my desk, which is about 6 feet from my R-Pi running OpenHab with the z-wave stick in it. This proved a heck of a lot easier than trying to move the whole operation up to the front entrance!

Hope this helps anyone else who decides to get one of these Schlage locks for their OpenHab installation. I’m pretty happy with mine, it seems to be the only lock out there with a keypad and z-wave for less than $200 (Canadian). Hopefully the 2.4 binding will go live soon and this will simply be a matter of installing the paper UI binding rather than the manual install which is currently required.

[rpwong (Russ)]

Wow, your post is perfect timing for me. my Schlage Connect added to OH and I can send commands to it, but the lock refuses to send status updates to OH. Is yours now sending updates every time you lock/unlock by hand? I’m wondering if I need to wipe out Z-Wave completely and start over again.

[5iver (Scott Rushworth)]

@Aaaaron

Hopefully the 2.4 binding will go live soon and this will simply be a matter of installing the paper UI binding rather than the manual install which is currently required.

It’s been out since September… see the link I had posted.

@rpwong

I can send commands to it, but the lock refuses to send status updates to OH.

IIRC, some of the newer Schlage locks with zwave plus report status. The older ones do not…

Zwave - Yale YRD220 Lock

Here is my current rule for parsing alarm_raw. My locks (Schlage BE469) do not update the lock_door channel, so I use alarm_raw to update the items linked to lock_door, and base rules off of that item’s state. Maybe all locks behave this way? You’ll find several examples of using the JSONPATH transform to parse the data in the lambda. This can be tricky though, because JSONPATH will throw an exception if the element name you are searching for does not exist in the JSON. I haven’t had any issues…

[rpwong (Russ)]

@5iver

IIRC, some of the newer Schlage locks with zwave plus report status. The older ones do not…

Ah, okay. I bought the lock a few years ago, so I guess that’s the issue. I’ll take a shot at implementing your rule to parse alarm_raw. Thanks!

[Aaaaron (Aaron Chree)]

To be honest due to the way the servo is set up, it never even occured to me that it ought to be able to do that. So no, not getting status updates. The lock is only about 6 months old though, so I’d be surprised if it was that out kd date.

As for what I said about the 2.4 binding well… My paper UI still says 2.3. Maybe I need to update something?

[5iver (Scott Rushworth)]

@Aaaaron

My paper UI still says 2.3. Maybe I need to update something?

Yes, upgrade openHAB… openHAB on Linux | openHAB. If you are using openHABian, there is a menu option… openHABian | openHAB.