Has the Process For Secure Inclusion of Z-Wave Locks Changed?

Setup, Configuration and Use Installation
1

I have had a smart lock installed in OH for around a year. I have also installed two other smart locks along the way. I never had any problem getting them included securely.

Recently, the original lock started “acting up”. I tried a lot of minor things then finally performed a factory reset. Now I can’t seem to get it to include securely.
I have tried many things that I never had to do before and still, not “Using Security” displayed in Habmin and “zwave_secure false” in PaperUI.
The lock used to be NODE8, now it is NODE30, crawling it’s way up the NODE count as my efforts failed.
Is there a foolproof process to follow to get a lock to include securely?

2

When you factory reset a zwave device and don’t run an exclusion first you duplicated the device on your zwave controller.

I believe the way to fix this, using a laptop (to avoid having to run back and forth) set your lock to go into exclusion mode and in Habmin tell your controller to go into exclusion mode. If successful you should be able to do a inclusion with the lock and Habmin and restore the zwave_secure.

Also fun fact I learned the hardware, if you give a working light switch to a friend and don’t run the exclusion first you still have to run an exclusion process, even if you factory reset the switch.

3

That has not been true, in my experience.

4

I can’t speak to every zwave device, but the one that I tried to factory reset at my friend’s house was this one:
https://www.amazon.com/GE-Wireless-Required-SmartThings-12722/dp/B0035YRCR2

Until I ran the exclusion was I able to get it to show up in the inclusion.

5

Well, I was very careful to follow all the steps (see below). I got the lock to appear as a new node (31) but the Habmin still shows a red x next to security.
I took the device all the way back to factory reset (after excluding). I believe I saw/heard all the correct flashes and beeps for the lock during the reset process (lock documentation sucks).
The procedure I followed was from here:
Adding Z-Wave Device Procedure starting at the section “Adding Z-Wave Devices”.

Since NODE 31 was created, can I assume the inclusion was successful?

Note, I did this many times over the last few days. I also went through the process using the PaperUI many times. That was how I added the device originally.
Somewhere back in the far reaches of my gray cells I remember some extra setting being needed for security but I can’t find that anymore.
I guess I still haven’t hit on the right process.

Believe me, I am pretty embarrassed to have to ask given that I had these three locks and a thermostat working correctly. The thermostat and two locks are working fine.

6

The inclusion can be successful, but secure inclusion may not have occurred. Habmin will show you whether secure inclusion was successful.

Maybe Habmin> Configuration> Things> Tools> Show Advanced settings> select your controller> Z-Wave Network Settings> Secure Inclusion Mode? Best for this to be on Entry Control Devices.

I didn’t see what lock you are using. Some locks, like the Schlage BE469, require the controller to be very close to the lock when including. I usually need to have them touching, and it may take 10 times to get it securely included. Exclude and hard reset the lock between attempts.

7

Don"t forget that secure inclusion is direct communication between the lock and controller device. So short distance during first inclusion is essential.

8

Scott,
You nailed the problem. I went into the controller settings and changed Inclusion Mode to Network wide and secure to all devices and followed the inclusion process. It worked like a champ. The lock is now secure.
But the darn thing was not responding to:

Switch Front_Lock_Door "F Lock State" <door> {channel="zwave:device:fe40ab17:node32:lock_door"}

node 32 is the new node number.
I kept trying it over and over and after 5 or 6 tries the lock began responding to the lock_door.

But the other items never updated:

Number Front_Battery_Level "F Lock Battery [%d %%]" <battery>  {channel="zwave:device:fe40ab17:node32:battery-level"}
String Front_Alarm_Virtual "F Lock StateV " //For front Lock Status in Habpanel and sitemap
String Front_Alarm_Virtual_Short "FS State" //State for small Widgits   // For Front State in Habpanel

For them to show a response in Habpanel a rule has to execute. Now are you ready for the Twilight Zone? The get the rule to execute I had to Save the rule file. No changes, just Save it. Well, I can’t Save it without changing it. So I just insert a space at the end of some comment line in the rule file and, BAM. The rules file executes and the lock reports appear in Habpanel.

I mention this because that is how this fiasco started. The lock would be fine for a few days then the reports from the lock would not go through the rules file. A lock report like:

NODE 32: Updating channel state zwave:device:fe40ab17:node32:alarm_raw to {"type":"25","value":"1"} [StringType]

Should have triggered an update in the Habpanel but it didn’t. All I had to do was Save the rules file without any changes except a space in some comment line to enable Save. This must have happened 15 or 20 times. It would work fine for a few days, then stop updating via rules, then Save the rules file and back working.
I really couldn’t believe it. I was going to post it here but it seemed just so far out, I couldn’t believe it. Then the lock quit responding all together and I started this thread.
Twilight Zone!

I also wonder about the changes to inclusion. In particular Network Wide Inclusion. I have seen warnings that this causes high battery drain. To me, I would think that is only during inclusion so is no big deal. Am I wrong?

9

This sounds normal. Secure devices take a long time to initialize, so can take a while before they are usable.

What worked fine? The lock reporting its state, control through a UI, rules? What is the make/model of the lock and what are the rules yiu are referring to?

Yes, this is just for inclusion and would not have any effect on battery devices.

10

I don’t have any datasheet for the lock because it was installed in this house when I bought it. It was part of a very expensive Vivint security system. Vivint didn’t treat me very well so I took over the system. All the devices, door sensors, window sensors, smoke/heat, CO, glass break, thermostat, and this lock all report to my OpenHab installation now.
The lock is labled “Kwikset”. It most closly resembles the Black & Decker Kwikset SmartCode 910 from the Z-Wave database. But the node always comes up 914TRL Touchpad Electronic Deadbolt in Habmin and PaperUI.

I use three of the four channels Door Lock, Raw alarm (json) and Battery Level. The raw alarm has some 17 Alarm Types and Levels.

When it is “working fine” I can initiate a Door Lock action and it will report things like:

 NODE 32: Updating channel state  NODE 32: Updating channel state zwave:device:fe40ab17:node32:alarm_raw to {"type":"24","value":"1"} [StringType]

My rules file will convert this to, “Lock Secured by Controller-Successful (Fully extended)”. That text string comes from the “Thing Type Description Overview” in Habmin or PaperUI.

Other actions like manually changing the lock, battery level, keypad user, all report correctly. The openhab.log will also have entries that correspond.

When it stops working, it won’t respond to the Door Lock action. It also doesn’t report manual actions, etc. The Openhab.log is flooded with what must be 150 entries but I can’t make hide nor hare out of it. But there are definitely no “type” and “value” entries to feed to the rules file.

As I said, all I had to do is Save the rules file, identical to what was Saved the last time (except for a mod to a comment line). The log would report that the rules file was refreshed and the lock would start working again.

11

What are you referring to by ‘a Door Lock action’? Manual use, UI, something else?

In what log file? With the zwave binding in debug mode, is anything logged? When ‘not working’, does the Item linked to the alarm_raw Channel update when the lock is manually locked/unlocked?

Please post them.

This sounds to me like not a zwave issue, but your rule threads all being busy. Do any other rules execute when this is occurring? Please post the contents of your rule file.

12

To help explain, see the items file for this device below:

// Door Lock to Garage: Black & Decker 	914TRL but image shown as 910 in documents  

Switch Front_Lock_Door "F Lock State" <door> {channel="zwave:device:fe40ab17:node32:lock_door"} 
String Front_Alarm_Raw "F Alarm Raw type" {channel="zwave:device:fe40ab17:node32:alarm_raw"}
Number Front_Battery_Level "F Lock Battery [%d %%]" <battery>  {channel="zwave:device:fe40ab17:node32:battery-level"}
String Front_Alarm_Virtual "F Lock StateV "
String Front_Alarm_Virtual_Short "FS State"

Note, the last two Virtual items are used to avoid what I called bogus reports from the lock. It would report the correct action/state {“type”:“xx”,“value”:“x”) then sometimes later report something like {“type”:“0”,“value”:“0”} which is not in the “reference of Alarm_Number related messages”. The Alarm_Raw item would then change to the bogus report not the actual report. So in the rules file (below) I set the Virtual items to the correct report and ignore the bogus reports. I don’t claim this method, it was suggested by Chris Jackson a while back. I have the first Virtual one to display the full text of the Alarm and the Short one for use on my cellphone.

By “Door Lock” action I am referring to the name used by the first channel. It is also the first item in the items file above.

The log file I am referring to is openhab.log. When the lock is not responding, executing lock_door or manual actions result in a blast of log entries, like drinking from a fire hose, but there is no entry like {“type”:“25”,“value”:“1”} so, no, the alarm channel does not change.

I will post the log file when(if) it starts failing again. Right now it is working fine. Would you want the text from the openhab.log file or the one from Chris’s log viewer. That may be a problem because I seem to be locked out of it right now. I know he was moving to to a new site and I registered there but just now I tried the old one and the new one and I can’t get passed the sign-in page. It also says the email address I used isn’t valid. But I used it in the last few days. I also can’t get to a place to create a new registration.

Below is the only rules file for this device. Note, when failing, none of the logDebug lines get logged, especially the first one that is place before the “if” statement so I am pretty sure the file is never run.

rule "Ignore Bogus Reports"

when
    Item Front_Alarm_Raw changed   //not Item Front_Battery_Level changed
	// Note, I used "changed" so subsequent identical bogus messages won't get here.      
then

//Process the JSON from the raw alarm to get the Type and Value 
    var actionType = transform("JSONPATH", "$.type",triggeringItem.state.toString)  // these SOBs are strings 
    var actionTypeValue = transform("JSONPATH", "$.value", triggeringItem.state.toString)
    logDebug("RULE_SYSTEM", "Lock: Alarm events: TFormed State: {}, StateValue: {}", actionType, actionTypeValue)
	
	
	if(actionTypeValue != "0"){ 
	


    /*  Alarm types and levels from the documentation
    Alarm Type    Alarm Level            Notification Event     

    017              001                 Lock Secured at Keypad – Bolt Jammed (Not fully extended)
    018              000 or User-ID#*    Lock Secured at Keypad – Successful (Fully extended) 
    019              User-ID#*           Lock Un-Secured by User (User-ID) at Keypad
	021              001                 Lock Secured using Keyed cylinder or inside thumb-turn
    022              001                 Lock Un-Secured using Keyed cylinder or inside thumb-turn
	023              001                 Lock Secured by Controller – Bolt Jammed (Not fully extended)
    024              001                 Lock Secured by Controller – Successful (Fully extended)
    025              001                 Lock Un-Secured by Controller – Successful (Fully retracted)
    026              001                 Lock Auto Secured – Bolt Jammed (Not fully extended)
    027              001                 Lock Auto Secured – Successful (Fully extended)
    032              001                 All User Codes deleted from lock
	033				 User-ID#*			 User Code Removed	(Not shown in the Device but discovered by experiment.)
    112              User-ID#*           New User Code (User-ID#) added to the lock
    161              001                 Failed User Code attempt at Keypad
    162              User-ID#*           Attempted access by user (User-ID#) outside of scheduled 
    167              001                 Low battery level
    168              001                 Critical battery level
    169              001                 Battery level too low to operate lock

I was getting others like 19/0, 21/0
* User-ID# values: 001 to 030
    Rule inspired by this but modified to work with our locks
    https://community.openhab.org/t/zwave-yale-yrd220-lock/34180/5  
    */
	
    switch (actionType) {
        //Locking actions
        case "17": {
            Front_Alarm_Virtual.postUpdate("Lock Secured at Keypad by User #  – Bolt Jammed (Not fully extended)")
	    Front_Alarm_Virtual_Short.postUpdate("Secured_Jammed")
            logDebug("RULE_SYSTEM", "{} Lock Secured at Keypad – Bolt Jammed (Not fully extended)", "FrontLock")
        }
        case "18": {
            Front_Alarm_Virtual.postUpdate("Lock Secured at Keypad by User #   " + actionTypeValue + " – Successful (Fully extended)")
            Front_Alarm_Virtual_Short.postUpdate("Secured")
			logDebug("RULE_SYSTEM", "{} Lock Secured at Keypad by User [{}] – Successful (Fully extended)", "FrontLock", actionTypeValue)
        }
		case "19": {
            Front_Alarm_Virtual.postUpdate("Lock Un-Secured by User #  " + actionTypeValue + " at Keypad" )
	    Front_Alarm_Virtual_Short.postUpdate("Un-Secured")
            logDebug("RULE_SYSTEM", "{} Lock Un-Secured by User ({}) at Keypad", "FrontLock", actionTypeValue)
        }
        case "21": {
            Front_Alarm_Virtual.postUpdate("Lock Secured using Keyed cylinder or inside thumb-turn")
	    Front_Alarm_Virtual_Short.postUpdate("Secured")
            logDebug("RULE_SYSTEM", "{} Lock Secured using Keyed cylinder or inside thumb-turn", "FrontLock")
        }
		case "22": {
            Front_Alarm_Virtual.postUpdate("Lock Un-Secured using Keyed cylinder or inside thumb-turn")  
	    Front_Alarm_Virtual_Short.postUpdate("Un-Secured")
            logDebug("RULE_SYSTEM", "{} Lock Un-Secured using Keyed cylinder or inside thumb-turn", "FrontLock")
        }
        case "23": {
            Front_Alarm_Virtual.postUpdate("Lock Secured by Controller – Bolt Jammed (Not fully extended)")
            Front_Alarm_Virtual_Short.postUpdate("Secured_Jammed")
			logDebug("RULE_SYSTEM", "{} Lock Secured by Controller – Bolt Jammed (Not fully extended)", "FrontLock")
        }
        case "24": {
              Front_Alarm_Virtual.postUpdate("Lock Secured by Controller – Successful (Fully extended)")
	      Front_Alarm_Virtual_Short.postUpdate("Secured")
              logDebug("RULE_SYSTEM", "{} Lock Secured by Controller – Successful (Fully extended)", "FrontLock")
        }
		case "25": {
            Front_Alarm_Virtual.postUpdate("Lock Un-Secured by Controller – Successful (Fully retracted)")
	    Front_Alarm_Virtual_Short.postUpdate("Un-Secured") 
            logDebug("RULE_SYSTEM", "{} Lock Un-Secured by Controller – Successful (Fully retracted)", "FrontLock")
        }
        case "26": {
            Front_Alarm_Virtual.postUpdate("Lock Auto Secured – Bolt Jammed (Not fully extended)")
	    Front_Alarm_Virtual_Short.postUpdate("Secured_Jammed")
            logDebug("RULE_SYSTEM", "{} Lock Auto Secured – Bolt Jammed (Not fully extended)", "FrontLock")
        }
        case "27": {
            Front_Alarm_Virtual.postUpdate("Lock Auto Secured – Successful (Fully extended)")
	    Front_Alarm_Virtual_Short.postUpdate("Secured")
            logDebug("RULE_SYSTEM", "{} Lock Auto Secured – Successful (Fully extended)", "FrontLock")
        }
	case "32":  {
	    Front_Alarm_Virtual.postUpdate ("All User Codes deleted from lock")
	    logDebug("RULE_SYSTEM", "All User Codes deleted from lock", "FrontLock")
			}
	case "33":  {
	    Front_Alarm_Virtual.postUpdate ("User Number " + actionTypeValue + "  Removed")
	    logDebug("RULE_SYSTEM", "{} User Number " + actionTypeValue + "  Removed", "FrontLock")
			}
	case "112":  {
	     Front_Alarm_Virtual.postUpdate ("User Number " + actionTypeValue + "  Added")
	    logDebug("RULE_SYSTEM", "{} User Number " + actionTypeValue + "  Added", "FrontLock")
			}
        case "161": {
	    Front_Alarm_Virtual.postUpdate  ("Failed User Code attempt at Keypad")
            logDebug("RULE_SYSTEM", "{} Failed User Code attempt at Keypad", "FrontLock")
        }
        case "167": {
	    Front_Alarm_Virtual.postUpdate ("Low battery level")
            logDebug("RULE_SYSTEM", "{} Low battery level", "FrontLock")
        }
        case "168": {
	    Front_Alarm_Virtual.postUpdate ("Critical battery level")
            logDebug("RULE_SYSTEM", "{} Critical battery level", "FrontLock")
        }
        case "169": {
	    Front_Alarm_Virtual.postUpdate ("Critical battery level")
            logDebug("RULE_SYSTEM", "{} Critical battery level", "FrontLock")
        }
        default : {
            Front_Alarm_Virtual.postUpdate ("Unknown Alarm Type " +actionType + "  Value " +actionTypeValue)
            logDebug("RULE_SYSTEM_Default", "{} Unknown Alarm Type  " +actionType + "  Value  " +actionTypeValue, "FrontLock")
        }
    }
	}
end
13

Have you tried disabling Command Polling for the Thing representing the lock?

The log file. FYI, the OSH site is currently down.

If there are no alarm_raw reports, then the rule couldn’t be triggered. It sounds to me like your zwave network or this lock is having some problems, and you will need to start looking into the zwave debug logs. But if you are getting a lot of log entries, maybe you already have the binding set to DEBUG?

1 Like
14

Never heard of it but I found it in Habmin and changed it to disable. Well I thought I did but didn’t notice it had flipped back to 1500 before I hit the Save button. I finally tricked it to stay Disabled.

It seems to be back this morning. I have been using it for a couple hours.

Yes, the Debug entries are present now. But everything is working. I’ll see for how long.
Maybe I did enough “factory resets” during this recent problem and with Command Polling disabled I may be solid. Hah, I should be so lucky.
If it stays stable for a week or so I’ll mark yours as the solution.
Thanks

15

And set the zwave binding to INFO, or you will be thrashing your SSD/HDD/SD.

1 Like
16

Well, guess what. This afternoon I saw that the rules file did not run when the lock changed but all I had to do to fix it was type a character in a comment area in the rule and save the file. Thereafter the rule executed each time the lock changed.
I captured the openhab.log file and uploaded to google drive.
Log Failing then Fixed

I’ll walk through that file.
At first I was running with Debug off (as suggested above). Only events show up but they include:

2020-12-07 14:04:16.451 [vent.ItemStateChangedEvent] - Front_Alarm_Raw changed from {"type":"24","value":"1"} to {"type":"25","value":"1"}

but my habpanel widget that was supposed to update via the rules file would not change.
When I saw this I turned on Debug (about 2020-12-07 14:06:34.482). Note that at 2020-12-07 14:06:37.410, the Alarm_Raw entry but there is no RULE_SYSTEM log entry that should come from the rule.
Then at 2020-12-07 14:07:09.743 I saved the rule file and the log reports, “Refreshing model 'B&D Lock.rules”
At 2020-12-07 14:07:13.951 I sent the lock command and received Alarm_Raw at 2020-12-07 14:07:16.843 followed by the RULE_SYSTEM entry at 2020-12-07 14:07:17.995 which comes from the rule file.

I feel sorry for dumping all this here but I am convinced that my rule file stops running and all I have to do is Refresh it and it will run thereafter for days.

Note, I also captured the Log Viewer but it doesn’t seem to show the RULE_SYSTEM entries and I don’t know how to show it here other then multiple jpg files.

17

Z-Wave looks fine. Did other rules stop responding at this time too? It sounds to me like you have run out of rule threads. Reloading the rule file resets them, so things start working again. There are LOTS of threads in the forum about what can cause rules to lock up, but there is nothing in this particular rule that would cause it. What else is in the rule file? Do you have any long Thread::sleeps? Or executeCommandLines with a long or nonexistent timeout? This is one of the things that makes the new rule engine so nice… no threadpool! Although, that is not a free pass to write bad rules.

18

No, in fact I have two other locks, Yale YRD110 and they have very similar rules and have never experienced this. The only differences are that the “Type and Level” codes are different but the overall structure is the same. Many case statements

Yep, I couldn’t see anything in the threads I looked at.

The file I posted on Dec. 6 is the total file.

Nope, nothing like that. In fact the rules directory has only 5 rule files in it. But somewhere in the back of my mind I remember using the rule engine, maybe a year ago but I can’t remember why.

I’ll see if I can think of anything else or see if other situations develop that might shed more light on this.

Thank you very much.

19

Have you considered combining all of the lock rules into one, like in the original example? The name of the rule (“Ignore Bogus Reports”) is very generic. What are the names of the other rules? All rules need to have a unique name.

You have a few of these. I’m not sure if there is any issue with combining string concatenation with parameterized logging, but just to be sure, use this format…

logDebug("RULE_SYSTEM", "{} User Number {} Added", "FrontLock", actionTypeValue)
20

I think combining the three lock rules could be confusing. The three are named:

rule "Ignore Bogus Reports"
rule "Yale YRD110 Rule"
rule "New Yale YRD110 Rule"

For the Black and Decker, Old Yale and New Yale respectively.
The Old and New Yale are identical so that wouldn’t be a problem, just an OR in the “when” statement. However the “action Type” codes for the B&D are different. For example, the Yales report actionType=“21” “Manual lock by thumb” but the B&D reports “21” as “Lock Secured using Keyed cylinder or inside thumb-turn”. There are many other conflicts among the 17 or 18 different codes in the “case” statement.

Perhaps but the Yale lock rules are constructed the same way and they never fail to report the correct state. That also means their rules files always execute.

I haven’t been idle for the last few days. I have been collecting data. Some things I have found out (subject to change pending more date collection).

The B&D lock (the one that stops executing its rule file until I re-save it) always performs the instruction and always reports correctly in the openhab.log.

I say “stops executing” because the text in the habpanel wizard doesn’t change and the logDebug(“RULE_SYSTEM”…) doesn’t show in the log. It will show after I do a re-save. Those entries always appear for the Yale locks.

Now the plot thickens. I have discovered two other habpanel widgets that stopped updating. But but they don’t even use a rule. I have a watchdog timer set up to reboot the RPi if an external (to openhab but running in another thread in the RPi) event doesn’t happen within 4,000 seconds. The thread sends below every hour.

String WatchDogBurp "Burp the WatchDog  [MAP(my.map):%s]" <battery> {mqtt="<[mosquitto:WatchDogBurp:state:default]"}

The event alternates between “BurpUp” and “BurpDown”. Since it changes it causes an entry in the event.log.
The watchdog.conf file contains:

file = /var/log/openhab2/events.log
change =4000

Which has worked fine for many weeks. I have two habpanel widgets, one reports the last mqtt message. The other reports the time of that message. Those two have stopped updating. The first is (was) reporting BurpUp and the second widget, “12/08 10:30”. But the openhab. log shows the watchdog changed from BurpUp to BurpDown. and back every hour or so. (Now is 12/10 12:04), about two days since the widget was updated.
Now, do you see the “(was)” a few sentences back? Well I was sure it was reporting BurpUp when I started this post but then as I typed I saw it was BurpDn. I could be loosing it! That mqtt came 30 minutes earlier. Also the RPi never rebooted over many weeks because of a missed Burp.

So my plan going forward is to create a basicUI and a classicUI and see if they report identically or differently then the habpanel…I don’t think that makes sense but it can’t hurt.
I will continue to watch for other anomalies. Is there anything else that anyone can think of for me to do?

Thanks,
Pete