Z-wave (Schlage) Lock Support on OH1

dbadia · October 23, 2015, 4:05pm

@Bill
Thanks for posting your log file. Looks like the original secure pairing didn’t work:

2015-10-22 21:18:18.772 [ERROR] [.p.c.ZWaveSecurityCommandClass:1013]- NODE 2: Invalid state! secure inclusion has not completed and we are not in inclusion mode, aborting

which explains the command class not found.

When you did the original pairing, did you follow the instructions on the wiki and use habmin to put the controller into inclusion mode?

mganapa · October 23, 2015, 4:06pm

So I seemed to have pinned the line in the Z-Wave log that corresponds to my Smartstip not working. When I tried to switch off an outlet, I get the following message at the end of the transaction.

2015-10-22 20:18:26.554 [DEBUG] [ApplicationCommandMessageClass:115 ]- Transaction not completed: node address inconsistent.

The transactions for this node are as below. Note that this is a multiinstance device and I was trying to control endpoint 4

2015-10-22 20:18:26.554 [DEBUG] [ApplicationCommandMessageClass:39  ]- NODE 21: Application Command Request (ALIVE:DONE)
2015-10-22 20:18:26.554 [DEBUG] [ApplicationCommandMessageClass:135 ]- NODE 21: Incoming command class MULTI_INSTANCE (0x60)
2015-10-22 20:18:26.554 [TRACE] [.z.internal.protocol.ZWaveNode:861 ]- NODE 21: Does message require security encapsulation: Message: class = ApplicationCommandHandler (0x04), type = Request (0x00), payload = 00 15 07 60 0D 04 01 25 03 00 
2015-10-22 20:18:26.554 [TRACE] [.z.internal.protocol.ZWaveNode:864 ]- NODE 21: Message class is not SendData, so security not required: ApplicationCommandHandler
2015-10-22 20:18:26.554 [DEBUG] [.z.internal.protocol.ZWaveNode:902 ]- NODE: 21 Incoming message Message: class = ApplicationCommandHandler (0x04), type = Request (0x00), payload = 00 15 07 60 0D 04 01 25 03 00  required security encapsulation=false
2015-10-22 20:18:26.554 [TRACE] [ApplicationCommandMessageClass:107 ]- NODE 21: Found Command Class MULTI_INSTANCE, passing to handleApplicationCommandRequest
2015-10-22 20:18:26.554 [DEBUG] [ZWaveMultiInstanceCommandClass:145 ]- NODE 21: Received Multi-instance/Multi-channel Request
2015-10-22 20:18:26.554 [TRACE] [ZWaveMultiInstanceCommandClass:433 ]- Process Multi-channel Encapsulation
2015-10-22 20:18:26.554 [DEBUG] [ZWaveMultiInstanceCommandClass:452 ]- NODE 21: Requested Command Class = SWITCH_BINARY (0x25)
2015-10-22 20:18:26.554 [DEBUG] [ZWaveMultiInstanceCommandClass:472 ]- NODE 21: Endpoint = 4, calling handleApplicationCommandRequest.
2015-10-22 20:18:26.554 [TRACE] [.ZWaveBinarySwitchCommandClass:78  ]- Handle Message Switch Binary Request
2015-10-22 20:18:26.554 [DEBUG] [.ZWaveBinarySwitchCommandClass:79  ]- Received Switch Binary Request for Node ID = 21
2015-10-22 20:18:26.554 [TRACE] [.ZWaveBinarySwitchCommandClass:93  ]- Process Switch Binary Report
2015-10-22 20:18:26.554 [DEBUG] [.ZWaveBinarySwitchCommandClass:115 ]- NODE 21: Switch Binary report, value = 0x00
2015-10-22 20:18:26.554 [DEBUG] [b.z.i.protocol.ZWaveController:612 ]- NODE 21: Notifying event listeners: ZWaveCommandClassValueEvent: org.openhab.binding.zwave.internal.protocol.event.ZWaveCommandClassValueEvent@1a4242a
2015-10-22 20:18:26.554 [DEBUG] [.z.internal.ZWaveActiveBinding:443 ]- ZwaveIncomingEvent
2015-10-22 20:18:26.554 [DEBUG] [.z.internal.ZWaveActiveBinding:460 ]- NODE 21: Got a value event from Z-Wave network, endpoint = 4, command class = SWITCH_BINARY, value = 0
2015-10-22 20:18:26.554 [TRACE] [.b.z.i.c.ZWaveConverterHandler:341 ]- Getting converter for item = MB_SmartStrip_pwr4, command class = SWITCH_BINARY, item command class = meter
2015-10-22 20:18:26.554 [TRACE] [.b.z.i.c.ZWaveConverterHandler:341 ]- Getting converter for item = MB_SmartStrip_nrg4, command class = SWITCH_BINARY, item command class = meter
2015-10-22 20:18:26.554 [TRACE] [.b.z.i.c.ZWaveConverterHandler:341 ]- Getting converter for item = MB_SmartStrip_4, command class = SWITCH_BINARY, item command class = switch_binary
2015-10-22 20:18:26.554 [DEBUG] [b.z.i.protocol.ZWaveController:623 ]- NODE 21: Processing event ourselves

dbadia · October 23, 2015, 10:19pm

@mganpa
Hmm, smartswitch problem looks like a regression defect with 1.8. Can try testing eight be main 1.8 branch and see if you get that error?

Like logview plus a lot! Hadn’t used it before

mganapa · October 24, 2015, 1:40am

@dbadia The current snapshot from cloudbees works without issues (except for the lock of course).
Z-Wave binding Version is 1.8.0.201510180139. OpenHAB runtime was also from the cloudbees snapshot.

Bill · October 24, 2015, 2:03am

@dbadia

That would be surprising because the lock was showing up as a node in habmin (the only zwave module I have, actually).

Regardless, I did a hardware reset on my lock to ensure it was definitely removed from the zwave network. Verified from the LED on the lock that it was no longer paired to a zwave network… so, back to square one. (In hindsight, I should have started by putting the Z-Stick into Exclude mode, first, and unpaired the lock…)

I then tried to pair the lock to the network only to find that the lock wouldn’t pair. Reset my Z-Stick (unplugged for a bit then plugged back in), restarted openhab and reloaded habmin. My lock was showing in the zwave device list again (now as Node 3… was Node 2) but the lock indicated repeatedly that it wasn’t on a zwave network. Tried pairing the lock a number of times with no success… the lock refused. Weirdly, I could still see the lock in the zwave device list and pull up it’s parameters (like battery status). Tried healing, excluding, etc… no good. Lock didn’t think it was paired, habmin thought it was still paired.

I’ve dumped my logs into my dropbox (link above) in the folder labelled “Step 1”.

I’ve deleted my openhab runtime completely and am in the process of re-compiling to get everything back to the state where I can re-pair my lock successfully. I’ll post with an update when I have one.

Bill · October 24, 2015, 2:56am

Wow… this is getting pretty frustrating…

My lock refuses to believe it’s paired to my Z-Stick any longer and habmin continually shows the lock in the list of nodes. So habmin and my Z-Stick think they’re paired, but my lock doesn’t.

I’ve factory reset my Z-Stick (although not convinced that worked because it’s supposed to start flashing blue after 20 seconds and it still wasn’t after more than 60) and then used the hardware button on the Z-Stick to put it into exclusion mode and put my lock into exclusion mode. After restarting Openhab the lock was finally removed from the device list.

However, when I tried to include it again, it showed back up in the habmin device list (now as Node 5… it’s incrementing every time) but the lock wouldn’t acknowledge the pairing.

I dumped these latest set of logs into Dropbox in the folder “Step 2”. Looking at the zwave.log, I can see

2015-10-23 22:44:32.929 [DEBUG] [.b.z.i.p.s.AddNodeMessageClass:79  ]- NODE 5: Adding slave.

Which looks promising and, along with all the other messages below, makes me think that it’s pairing and communicating fine… but why the heck isn’t my lock acknowledging the pairing?!?

I’m gonna poke at it a bit more before I call it a night…

mganapa · October 24, 2015, 3:08am

@bill try this
Make sure the lock is not more than a feet away from your controller.

Open habmin and select exclude. This should start the exclusion process on openHAB/controller side.
On your schlage lock hit the master_code+0, basically put the lock into include/ exclude mode.
You should see a check mark confirming exclusion. If not, repeat this process once more after a minute.
Then enroll the lock into the network again.

Bill · October 24, 2015, 3:32am

@mganapa

Hi Mahesh,

I’m thinking this is actually a bug in the Schlage lock. When the lock was listed in the habmin zwave device list, I did exactly as you suggested and the lock excluded/unpaired fine (gave me the checkmark). This worked every time the lock was shown in habmin (as shown below). When I try to enrol the lock, it shows up in habmin but the lock shows an X after 30 seconds or so but shows up in the device list… every time. When I power up the lock, the LED should flash indicating it is paired to a zwave network, which it did on Wednesday when I paired the first time, but it won’t any more tonight even when habmin swears it’s paired (and it’s clearly talking to the lock).

I then went through the exclude/include process using Aeotec’s IMA Tool and I saw the exact same behaviour… and I can see that the IMA Tool is communicating just fine with the lock… but the lock doesn’t think it’s paired.

Now, I have no idea if this behaviour means the lock won’t communicate at all (or will be wonky) or if it’ll work just fine and its just all the indicators are saying it’s not paired, but it actually is and will run fine. For the purposes of debugging openhab, however, I’d rather not introduce another unknown variable, so I will likely go and exchange the lock for a new one tomorrow. I have a feeling that when I did the factory reset on the lock with openhab running (and the Z-Stick still paired) it borked it somehow so the lock is still retaining the Z-Stick address and won’t re-include properly.

As it is, when I hit the lock button on the web UI, nothing happens (still) and I still get the following errors in the zwave.log:

2015-10-23 23:29:28.895 [WARN ] [.b.z.i.c.ZWaveConverterHandler:206 ]- No command class found for item = Door_Lock, command class name = door_lock, ignoring execute refresh.
2015-10-23 23:29:28.895 [WARN ] [.b.z.i.c.ZWaveConverterHandler:295 ]- No command class found for item = Door_Lock, command class name = door_lock, using 0 refresh interval.
2015-10-23 23:29:28.895 [WARN ] [.b.z.i.c.ZWaveConverterHandler:295 ]- No command class found for item = Door_Lock, command class name = door_lock, using 0 refresh interval.
2015-10-23 23:29:28.895 [WARN ] [.b.z.i.c.ZWaveConverterHandler:206 ]- No command class found for item = Door_Basic, command class name = door_lock, ignoring execute refresh.
2015-10-23 23:29:28.895 [WARN ] [.b.z.i.c.ZWaveConverterHandler:295 ]- No command class found for item = Door_Lock, command class name = door_lock, using 0 refresh interval.
2015-10-23 23:29:28.895 [WARN ] [.b.z.i.c.ZWaveConverterHandler:295 ]- No command class found for item = Door_Lock, command class name = door_lock, using 0 refresh interval.
2015-10-23 23:29:28.895 [WARN ] [.b.z.i.c.ZWaveConverterHandler:295 ]- No command class found for item = Door_Basic, command class name = door_lock, using 0 refresh interval.
2015-10-23 23:29:28.895 [WARN ] [.b.z.i.c.ZWaveConverterHandler:295 ]- No command class found for item = Door_Basic, command class name = door_lock, using 0 refresh interval.
2015-10-23 23:29:28.895 [WARN ] [.b.z.i.c.ZWaveConverterHandler:206 ]- No command class found for item = Door_Corridor_Battery, command class name = battery, ignoring execute refresh.
2015-10-23 23:29:28.895 [WARN ] [.b.z.i.c.ZWaveConverterHandler:295 ]- No command class found for item = Door_Corridor_Battery, command class name = battery, using 0 refresh interval.
2015-10-23 23:29:28.896 [WARN ] [.b.z.i.c.ZWaveConverterHandler:295 ]- No command class found for item = Door_Corridor_Battery, command class name = battery, using 0 refresh interval.
2015-10-23 23:29:28.896 [WARN ] [.b.z.i.c.ZWaveConverterHandler:295 ]- No command class found for item = Door_Lock, command class name = door_lock, using 0 refresh interval.
2015-10-23 23:29:28.896 [WARN ] [.b.z.i.c.ZWaveConverterHandler:295 ]- No command class found for item = Door_Lock, command class name = door_lock, using 0 refresh interval.
2015-10-23 23:29:28.896 [WARN ] [.b.z.i.c.ZWaveConverterHandler:295 ]- No command class found for item = Door_Basic, command class name = door_lock, using 0 refresh interval.
2015-10-23 23:29:28.896 [WARN ] [.b.z.i.c.ZWaveConverterHandler:295 ]- No command class found for item = Door_Basic, command class name = door_lock, using 0 refresh interval.
2015-10-23 23:29:33.814 [WARN ] [.b.z.i.c.ZWaveConverterHandler:394 ]- NODE 8: No command class found for item = Door_Lock. Class = door_lock(DOOR_LOCK), endpoint = 0. Ignoring command.

Could you or Dave check my items and sitemap files back in my second post to ensure I’ve set them up properly? I’m still not 100% certain they are.

Here’s my zwave device list showing my lock which doesn’t think it’s paired…

Bill · October 24, 2015, 4:00am

@dbadia & @mganapa

So I looked through the log and saw the same message Dave saw on my first attempt:

2015-10-23 23:51:00.987 [ERROR] [.p.c.ZWaveSecurityCommandClass:1013]- NODE 8: Invalid state! secure inclusion has not completed and we are not in inclusion mode, aborting

Is it possible that the lock is successfully performing the unsecured zwave pairing, so it’s showing up in the device list in habmin, but not completing the secured pairing, which is why the lock isn’t acknowledging the pair is successful (and why I’m getting the above error)? (I’m just thinking out loud here and not really expecting an answer.) The only part of that theory which doesn’t jive is that the lock DID give me the checkmark when I paired it on Wednesday night… but I still saw the above error.

Unless either of you have any other ideas, I’m gonna exchange the lock tomorrow and try with a fresh one.

Bill · October 24, 2015, 4:15am

@dbadia

Out of curiosity, I tried changing my zwave network key to all zeros (had the random thought that perhaps I’d picked a sequence that wouldn’t work… long shot, I know) and tried to include my lock again. No luck & still got the secure inclusion not completed error. However, I also saw the following errors in my log:

2015-10-24 00:09:43.069 [ERROR] [.p.c.ZWaveSecurityCommandClass:988 ]- NODE 9: Secure Inclusion FAILED at step 4, no reply received, waitForReplyTimeout=1445659766755
2015-10-24 00:09:43.071 [DEBUG] [.z.internal.protocol.ZWaveNode:873 ]- NODE 9: doesMessageRequireSecurityEncapsulation commandClassOfMessage=MANUFACTURER_SPECIFIC

Aside from this possibly being a problem with my borked lock, does the “no reply received” message tell you anything further, Dave?

dbadia · October 24, 2015, 10:39am

@mganapa ok thanks Mahesh. Don’t think my changes should have effected multiinstance at all, but obviously something is going on here.

dbadia · October 24, 2015, 11:32am

@Bill

I took a quick look at your Step 2 - Attempting repairing logs, it looks like the controller was in inclusion mode (good) and controller sent the first secure inclusion message but it never got a response.

So a couple of thoughts here:

Yes, your device can be paired one of two ways: insecure or secured. If the device is already paired insecurely OR the zwave controller already has it registered, the secure pairing process will fail.
So, do an exclude between the zwave controller and the lock, then check habmin to ensure it doesn’t appear.
Then do a factory reset on the lock to clear it’s state
Then stop OH, clear out your existing logs, restart OH. Then put OH into inclusion mode and trigger the inclusion process from the lock
The zwave network key should be random, it’s value has no impact on the success or failure of the secure inclusion process.
Each time the secure inclusion process fails, you will have to exclude the lock from the controller and factory reset the lock (a pain, I know as I’ve done it 50+ times during my development work!). I’m trying to find a way to programmatically do this but I’m not sure it’s possible
The message Secure Inclusion FAILED at step 4 means that the controller sent the first security message SECURITY_SCHEME_GET but didn’t get a reply. Be sure the lock is within a few feet of the controller during inclusion, as I also see some communication failures around that time.

Hang in there… the secure inclusion is a one time process…

That’s all for now. Have family coming into town this weekend so I won’t be back online until late monday.

Thanks again for testing

Dave

Bill · October 24, 2015, 12:42pm

@dbadia
Thanks for helping me through this!!

Excluded the lock. It’s no longer in the list of devices in habmin & checked the log to find this:

2015-10-24 08:03:45.545 [DEBUG] [b.z.i.protocol.ZWaveController:642 ]- NODE 9: Excluding node.

Factory reset the lock twice. Cleared out all my log files.

Changed my network key back to random characters (so I wouldn’t have to go through this again to make the pairing more secure later).

Restarted openhab only to find the lock BACK in the device list! Attempted a factory reset of the Z-Stick (still not certain that’s working), restarted openhab and the lock was gone from the device list.

Attempted to include the lock 5-6 times (factory resetting the lock between each time) and it wouldn’t pair… it wouldn’t show up in the device list nor any sign of it in the logs.

I then did a hardware exclude on the Z-Stick by unplugging from my PC and using the button… the lock seemed to like that as I got the checkmark and the LED on the Z-Stick indicated that something had happened (it stopped flashing).

Plugged it back into my PC, started openhab and the lock was not on the device list. Tried an include again. The lock wouldn’t include (showed me the X, not the checkmark) but showed up in the device list when I refreshed. Checked the log, and there was definitely activity… but still got the “secure include not complete” error.

I’ve dumped my logs into a new folder (Oct24) in my dropbox if you want to take a look.

I’m going to swap the lock with a new one to see what happens.

Bill · October 24, 2015, 6:53pm

@dbadia & @mganapa

Still getting stuck including my lock on the network. Here’s what I’ve done so far:

Exchanged the lock for a new one
Downloaded a fresh copy of the SNAPSHOT openhab source with Dave’s security code… I remembered that I added the BE469 to the device database of my zwave binding source and wondered if my change had somehow messed up the binding. The lock was now no longer recognized (same error I had initially) but still wouldn’t secure include.
Tried the include with the Z-Stick at distances ranging from 0" (right on top of the lock circuit board) to 5 feet… no difference
Removed my nest binding entirely on the off chance that it was messing up the timing of the include… nope.
Added “zwave:masterController=true” to my openhab.cfg - Found that in the git wiki for the zwave binding… Didn’t think it would change anything and I was proven correct… no change.

In every case, the lock will pair with the Z-Stick (I can see it in the device list in both habmin AND in Aeotec’s IMA Tool) but the lock ends the include cycle flashing the X and not the checkmark. When I run an exclude (in habmin, the IMA Tool, or using the button on the Z-Stick), the lock quickly flashes the checkmark and it’s no longer in the device list in habmin or the IMA Tool. In every case, when I check the zwave log, I can see it’s paired but the secure include fails because of a message reply timeout.

Any other ideas?

The only other idea I wanted to explore to find out why I’m having issues and you guys aren’t is: What zwave controller are you both using? I bought the Gen5 Z-Stick because it’s newer and it explicitly includes the security classes… but if you’re running the Gen 2 (or other hardware) then maybe that’s where this is falling down. I see from the ticket here and the Z-Stick manual that there’s an explicit parameter to enable a Secure network, which is disabled by default… are you doing that, Dave, and is it the same parameter for the hardware you’re using?

Also, what lock models are you using?

mganapa · October 24, 2015, 8:47pm

@bill I am on the same platform as you are. I have the aeon gen5 and I have the be469 as well. One thing I did learn is not to pair the lock with the stick but always do it through the controller software.

Exclude the lock through habmin.
Exclude once more with just the stick (unplugged from USB port)
Reset the door lock. Prior to reset set a custom user code and this should no longer work if factory reset was successful.
Reset the zwave stick. The rest button is tricky even a slight release of pressure within 20 seconds breaks the reset process.
Download homeseer 3 pro and install it with 30 day trial. Download the zwave plugin and initialize that with HS3pro.
Pair the lock with HS3Pro and aeon z stick.
HS3Pro should now show a few devices (battery, lock, etc). Try locking and unlocking with HS3Pro.
If all works, make sure you exclude the lock from within HS3Pro and reset the aeon stick one more time.

Bill · October 25, 2015, 9:32pm

@mganapa Thanks for the help, Mahesh!

Performed the steps exactly as you described and had full control over the lock in HS3. Yay! Excluded the lock in HS3, factory reset the Z-Stick & the lock. Restarted openhab, ran the include cycle and had exactly the same problem as last time… lock will not secure pair to my Z-Stick. I can see it in the habmin device list, but the lock won’t acknowledge the pair (flashes the X). Same error in the zwave log.

This result means that my hardware is fine & pairing is definitely possible. It also means that the problem lies solely in the openhab code and/or zwave binding. Given that I’ve already tried downloading a fresh copy of the code and run through the compile steps using it and still had the same problem… I’m at a loss as to why you and Dave are running fine and I can’t.

Way back in the thread you indicating you were using openhab 1.6… was that the version you used when you included your lock successfully? Have you tried excluding & re-including your lock in the latest openhab version?

@dbadia - Is it possible that recent code changes to your zwave binding (since you paired your/Mahesh have paired your locks) has broken the secure include process? Can you exclude & include your lock successfully?

I’m now looking into rooting a wink hub to get this working. If you or @dbadia have any other suggestions in the meantime, let me know… I’m outta ideas.

dbadia · October 27, 2015, 12:21am

@bill A bug between 1.6 and 1.8 is certainly possible. Go ahead and trying pairing with the 1.6 branch. I always test inclusion with each branch, so yes, I am able to pair my kwikset lock with all branches.

I’ll take a look at your Oct24 logs to see if anything jumps out at me

Thanks
Dave

mganapa · October 29, 2015, 9:20pm

@dbadia & @Bill Sorry I have been busy this weekend. I will be trying to exclude and include the lock again into my network today.
@dbadia, I am running the zwave binding at your last commit yesterday. Happy to report that all switched, dimmers and power strip are working fine. I will report on the lock later today. One thing I did notice is the following messages. Not sure if your support for ANTITHEFT is complete (I am guess it is still WIP).

2015-10-29 16:02:57.240 [WARN ] [.o.b.z.i.p.c.ZWaveCommandClass:220 ]- NODE 23: Unsupported command class ANTITHEFT
2015-10-29 16:02:57.240 [WARN ] [.o.b.z.i.p.c.ZWaveCommandClass:220 ]- NODE 23: Unsupported command class USER_CODE

dbadia · October 30, 2015, 12:57pm

@mganapa thanks for pulling the latest changes. Be curious to see if your issues are resolved with the lock/unlock requests not getting passed to the zwave binding. I can’t think of anything I changed that would solve it, but you never know…

Regarding ANTITHEFT, I added the definition to get rid of the “Unknown command class” errors. We now get “Unsupported command class” since there is no implementation. I’m not sure what ANTITHEFT does, but If I can find some documentation (or a working example), I’ll put on my list to be added.

Right now I’m still working on the basic security support, I need to cleanup a few workarounds I had in place and do some additional testing. Need to get @bill working with his setup as well.

Dave

mganapa · October 30, 2015, 8:51pm

@dbadia Things got messy and interesting last night with your latest code.

Running 1.8.0 SNAPSHOT and Z-Wave binding from your latest commit.
I was able to exclude my existing lock and was able to enroll it back again. Visual confirmation with the checkbox on the lock and the new node in habmin.
Lock/Unlock did not work but battery status and Lock state was correct.
All my devices started showing up as dead on my main PC. I use my laptop with the Z-Stick to test the door lock and once paired, I move the working copy back to my desktop with the same Z-Stick controller.
Network Heal did was not of any help.
Rebooted the PC, cleaned up the logs and restarted OpenHAB with your binding in place. Ran a full network heal and individual node heals on some nodes. This caused the nodes to be back online including my smart strip.
The smart strip would not respond to command from the UI (classic-ui, habdroid on android and ios, imperihab)
Ran a full network heal once more and after 15 minutes smartstrip started responding to commands.
The lock/unlock action still does not work.

Below is the screenshot from my habmin

Below is a snippet from my Z-Wave log:

2015-10-29 22:18:27.030 [INFO ] [.z.internal.ZWaveActiveBinding:330 ]- Update config, port = COM2
2015-10-29 22:18:27.030 [INFO ] [.z.internal.ZWaveActiveBinding:335 ]- Update config, healtime = 2
2015-10-29 22:18:27.031 [INFO ] [.z.internal.ZWaveActiveBinding:389 ]- Update config, softReset = false
2015-10-29 22:18:27.031 [INFO ] [.z.internal.ZWaveActiveBinding:398 ]- Update config, masterController = true
2015-10-29 22:18:27.033 [INFO ] [.p.c.ZWaveSecurityCommandClass:1268]- Update networkKey
2015-10-29 22:18:27.046 [INFO ] [b.z.i.protocol.ZWaveController:152 ]- Starting Z-Wave controller
2015-10-29 22:18:27.046 [INFO ] [b.z.i.protocol.ZWaveController:160 ]- Z-Wave timeout is set to 5000ms. Soft reset is false.
2015-10-29 22:18:27.046 [INFO ] [b.z.i.protocol.ZWaveController:326 ]- Connecting to serial port COM2
2015-10-29 22:18:27.578 [INFO ] [b.z.i.protocol.ZWaveController:348 ]- Serial port is initialized
2015-10-29 22:18:30.698 [INFO ] [rialApiGetInitDataMessageClass:57  ]- NODE 1: Node found
2015-10-29 22:18:30.698 [INFO ] [rialApiGetInitDataMessageClass:57  ]- NODE 4: Node found
2015-10-29 22:18:30.698 [INFO ] [rialApiGetInitDataMessageClass:57  ]- NODE 5: Node found
2015-10-29 22:18:30.698 [INFO ] [rialApiGetInitDataMessageClass:57  ]- NODE 6: Node found
2015-10-29 22:18:30.698 [INFO ] [rialApiGetInitDataMessageClass:57  ]- NODE 8: Node found
2015-10-29 22:18:30.698 [INFO ] [rialApiGetInitDataMessageClass:57  ]- NODE 9: Node found
2015-10-29 22:18:30.698 [INFO ] [rialApiGetInitDataMessageClass:57  ]- NODE 10: Node found
2015-10-29 22:18:30.698 [INFO ] [rialApiGetInitDataMessageClass:57  ]- NODE 11: Node found
2015-10-29 22:18:30.698 [INFO ] [rialApiGetInitDataMessageClass:57  ]- NODE 12: Node found
2015-10-29 22:18:30.699 [INFO ] [rialApiGetInitDataMessageClass:57  ]- NODE 13: Node found
2015-10-29 22:18:30.699 [INFO ] [rialApiGetInitDataMessageClass:57  ]- NODE 14: Node found
2015-10-29 22:18:30.699 [INFO ] [rialApiGetInitDataMessageClass:57  ]- NODE 15: Node found
2015-10-29 22:18:30.699 [INFO ] [rialApiGetInitDataMessageClass:57  ]- NODE 16: Node found
2015-10-29 22:18:30.699 [INFO ] [rialApiGetInitDataMessageClass:57  ]- NODE 18: Node found
2015-10-29 22:18:30.699 [INFO ] [rialApiGetInitDataMessageClass:57  ]- NODE 19: Node found
2015-10-29 22:18:30.699 [INFO ] [rialApiGetInitDataMessageClass:57  ]- NODE 20: Node found
2015-10-29 22:18:30.699 [INFO ] [rialApiGetInitDataMessageClass:57  ]- NODE 21: Node found
2015-10-29 22:18:30.699 [INFO ] [rialApiGetInitDataMessageClass:57  ]- NODE 25: Node found
2015-10-29 22:18:30.699 [INFO ] [rialApiGetInitDataMessageClass:65  ]- ZWave Controller using Controller API
2015-10-29 22:18:30.699 [INFO ] [rialApiGetInitDataMessageClass:66  ]- ZWave Controller is Primary Controller
2015-10-29 22:18:30.699 [INFO ] [rialApiGetInitDataMessageClass:67  ]- ------------Number of Nodes Found Registered to ZWave Controller------------
2015-10-29 22:18:30.699 [INFO ] [rialApiGetInitDataMessageClass:68  ]- # Nodes = 18
2015-10-29 22:18:30.699 [INFO ] [rialApiGetInitDataMessageClass:69  ]- ----------------------------------------------------------------------------


2015-10-29 22:18:30.699 [INFO ] [rialApiGetInitDataMessageClass:57  ]- NODE 25: Node found
2015-10-29 22:19:43.663 [ERROR] [.p.c.ZWaveSecurityCommandClass:1019]- NODE 25: Invalid state! secure inclusion has not completed and we are not in inclusion mode, aborting

As you can see, secure inclusion is not completed per the log message but my status is working fine.

Below is the screenshot of the openHAB console and you can see that the commands are sent to the event bus but there is no matching entries in the Zwave log despite the level being set to trace.

All the logs can be found here.

EDIT: I wanted to clarify that the lock nonlonger updates the status when opened/closed manually. The status in the screenshot is based on the initial polling that happened. I will be attempting another exclude/include later this weekend. I hope it’s going to be a treat and not a trick