Schlage FE599 ZWave Lock Issues

RonJ103 · November 29, 2018, 12:15am

I am having issues with my Schlage FE599 lock.

This is the lock: https://www.amazon.com/Schlage-FE599NX-CAM-619-ACC/dp/B0083GJ17G/ref=sr_1_2?ie=UTF8&qid=1543448823&sr=8-2&keywords=schlage+fe599

There are several threads discussing issues with Schlage Locks. Schlage has a few different models and much of the information is years old and not applicable anymore or is not relevant to the FE599 lock. I am starting this thread to try and fix my own issues and hopefully it will be useful to others with the same lock.

I have the Aeotec Z-Stick Gen 5 as the ZWave controller. It is plugged into a Raspberry Pi running HASSIO. I have 38 ZWave devices that are powered (No batteries). They are all over the house, so I can’t imagine that I am having range issues.

The lock was added securely through the ZWave control panel in HASSIO.

I added group2 node associations as outlined here: Schlage Connect ZWave Locks

At one point I was able to remove the group 1 node association, and things were working, at least for a little while. Then the lock stopped working and would be “presumed dead”. Sometimes it would come back on it’s own, sometimes healing the network seemed to work. Now I am noticing that the group 1 node association is back and I am unable to remove it. I click “remove from group” as shown below, but it isn’t going away for some reason.
fe599_node_association

This is what I see in the Zwave log (full log at end of post). It shows the node 1 association being removed, then it shows it coming back. No idea what kind of voodoo is going on here.

2018-11-28 18:38:56.442 Info, Node055, Received Association report from node 55, group 1, containing 0 associations

That seems like a good sign.

2018-11-28 18:38:56.642 Info, Node055, Received Association report from node 55, group 2, containing 1 associations

Another good sign.

2018-11-28 18:38:56.925 Info, Node055, Received Association report from node 55, group 1, containing 1 associations

Not sure why the node 1 association suddenly comes back… So frustrating.

Furthermore, 2 new entities showed up that were not there before. (cover and switch)

Here is the complete log (for node 55 which is my lock that is not working right):

2018-11-28 18:38:54.808 Info, Node055, Association::Remove - Removing node 1 from group 1 of node 55
2018-11-28 18:38:54.809 Detail, Node055, Queuing (Send) AssociationCmd_Remove (Node=55): 0x01, 0x0b, 0x00, 0x13, 0x37, 0x04, 0x85, 0x04, 0x01, 0x01, 0x25, 0xfb, 0x8b
2018-11-28 18:38:54.810 Info, Node055, Get Associations for group 1 of node 55
2018-11-28 18:38:54.810 Detail, Node055, Queuing (Send) AssociationCmd_Get (Node=55): 0x01, 0x0a, 0x00, 0x13, 0x37, 0x03, 0x85, 0x02, 0x01, 0x25, 0xfc, 0x8d
2018-11-28 18:38:54.810 Detail,
2018-11-28 18:38:54.810 Info, Node055, Sending (Send) message (Callback ID=0xfb, Expected Reply=0x13) - AssociationCmd_Remove (Node=55): 0x01, 0x0b, 0x00, 0x13, 0x37, 0x04, 0x85, 0x04, 0x01, 0x01, 0x25, 0xfb, 0x8b
2018-11-28 18:38:54.818 Detail, Node055,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2018-11-28 18:38:54.819 Detail, Node055,   ZW_SEND_DATA delivered to Z-Wave stack
2018-11-28 18:38:56.309 Detail, Node055,   Received: 0x01, 0x07, 0x00, 0x13, 0xfb, 0x00, 0x00, 0x95, 0x85
2018-11-28 18:38:56.309 Detail, Node055,   ZW_SEND_DATA Request with callback ID 0xfb received (expected 0xfb)
2018-11-28 18:38:56.310 Info, Node055, Request RTT 1500 Average Request RTT 1689
2018-11-28 18:38:56.310 Detail,   Expected callbackId was received
2018-11-28 18:38:56.310 Detail,   Expected reply was received
2018-11-28 18:38:56.310 Detail,   Message transaction complete
2018-11-28 18:38:56.310 Detail,
2018-11-28 18:38:56.310 Detail, Node055, Removing current message
2018-11-28 18:38:56.310 Detail,
2018-11-28 18:38:56.310 Info, Node055, Sending (Send) message (Callback ID=0xfc, Expected Reply=0x04) - AssociationCmd_Get (Node=55): 0x01, 0x0a, 0x00, 0x13, 0x37, 0x03, 0x85, 0x02, 0x01, 0x25, 0xfc, 0x8d
2018-11-28 18:38:56.319 Detail, Node055,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2018-11-28 18:38:56.319 Detail, Node055,   ZW_SEND_DATA delivered to Z-Wave stack
2018-11-28 18:38:56.389 Detail, Node055,   Received: 0x01, 0x07, 0x00, 0x13, 0xfc, 0x00, 0x00, 0x07, 0x10
2018-11-28 18:38:56.389 Detail, Node055,   ZW_SEND_DATA Request with callback ID 0xfc received (expected 0xfc)
2018-11-28 18:38:56.390 Info, Node055, Request RTT 79 Average Request RTT 884
2018-11-28 18:38:56.390 Detail,   Expected callbackId was received
2018-11-28 18:38:56.442 Detail, Node055,   Received: 0x01, 0x0b, 0x00, 0x04, 0x00, 0x37, 0x05, 0x85, 0x03, 0x01, 0x03, 0x00, 0x46
2018-11-28 18:38:56.442 Detail,
2018-11-28 18:38:56.442 Info, Node055, Response RTT 131 Average Response RTT 1153
2018-11-28 18:38:56.442 Info, Node055, Received Association report from node 55, group 1, containing 0 associations
2018-11-28 18:38:56.443 Info, Node055, Get Associations for group 2 of node 55
2018-11-28 18:38:56.443 Detail, Node055, Queuing (Send) AssociationCmd_Get (Node=55): 0x01, 0x0a, 0x00, 0x13, 0x37, 0x03, 0x85, 0x02, 0x02, 0x25, 0xfd, 0x8f
2018-11-28 18:38:56.443 Detail, Node055,   Expected reply and command class was received
2018-11-28 18:38:56.443 Detail, Node055,   Message transaction complete
2018-11-28 18:38:56.443 Detail,
2018-11-28 18:38:56.443 Detail, Node055, Removing current message
2018-11-28 18:38:56.443 Detail, Node055, Notification: Group
2018-11-28 18:38:56.445 Detail,
2018-11-28 18:38:56.445 Info, Node055, Sending (Send) message (Callback ID=0xfd, Expected Reply=0x04) - AssociationCmd_Get (Node=55): 0x01, 0x0a, 0x00, 0x13, 0x37, 0x03, 0x85, 0x02, 0x02, 0x25, 0xfd, 0x8f
2018-11-28 18:38:56.453 Detail, Node055,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2018-11-28 18:38:56.454 Detail, Node055,   ZW_SEND_DATA delivered to Z-Wave stack
2018-11-28 18:38:56.589 Detail, Node055,   Received: 0x01, 0x07, 0x00, 0x13, 0xfd, 0x00, 0x00, 0x0e, 0x18
2018-11-28 18:38:56.589 Detail, Node055,   ZW_SEND_DATA Request with callback ID 0xfd received (expected 0xfd)
2018-11-28 18:38:56.589 Info, Node055, Request RTT 143 Average Request RTT 513
2018-11-28 18:38:56.589 Detail,   Expected callbackId was received
2018-11-28 18:38:56.642 Detail, Node055,   Received: 0x01, 0x0c, 0x00, 0x04, 0x00, 0x37, 0x06, 0x85, 0x03, 0x02, 0x02, 0x00, 0x01, 0x41
2018-11-28 18:38:56.642 Detail,
2018-11-28 18:38:56.642 Info, Node055, Response RTT 197 Average Response RTT 675
2018-11-28 18:38:56.642 Info, Node055, Received Association report from node 55, group 2, containing 1 associations
2018-11-28 18:38:56.642 Info, Node055,   The group contains:
2018-11-28 18:38:56.642 Info, Node055,     Node 1
2018-11-28 18:38:56.643 Info, Node055, Querying associations for node 55 is complete.
2018-11-28 18:38:56.643 Info, Node055, Adding the controller to group 1 (Group 1) of node 55
2018-11-28 18:38:56.643 Info, Node055, Association::Set - Adding node 1 to group 1 of node 55
2018-11-28 18:38:56.643 Detail, Node055, Queuing (Send) AssociationCmd_Set (Node=55): 0x01, 0x0b, 0x00, 0x13, 0x37, 0x04, 0x85, 0x01, 0x01, 0x01, 0x25, 0xfe, 0x8b
2018-11-28 18:38:56.643 Info, Node055, Get Associations for group 1 of node 55
2018-11-28 18:38:56.643 Detail, Node055, Queuing (Send) AssociationCmd_Get (Node=55): 0x01, 0x0a, 0x00, 0x13, 0x37, 0x03, 0x85, 0x02, 0x01, 0x25, 0xff, 0x8e
2018-11-28 18:38:56.643 Detail, Node055,   Expected reply and command class was received
2018-11-28 18:38:56.643 Detail, Node055,   Message transaction complete
2018-11-28 18:38:56.644 Detail,
2018-11-28 18:38:56.644 Detail, Node055, Removing current message
2018-11-28 18:38:56.644 Detail,
2018-11-28 18:38:56.644 Info, Node055, Sending (Send) message (Callback ID=0xfe, Expected Reply=0x13) - AssociationCmd_Set (Node=55): 0x01, 0x0b, 0x00, 0x13, 0x37, 0x04, 0x85, 0x01, 0x01, 0x01, 0x25, 0xfe, 0x8b
2018-11-28 18:38:56.653 Detail, Node055,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2018-11-28 18:38:56.653 Detail, Node055,   ZW_SEND_DATA delivered to Z-Wave stack
2018-11-28 18:38:56.790 Detail, Node055,   Received: 0x01, 0x07, 0x00, 0x13, 0xfe, 0x00, 0x00, 0x0f, 0x1a
2018-11-28 18:38:56.790 Detail, Node055,   ZW_SEND_DATA Request with callback ID 0xfe received (expected 0xfe)
2018-11-28 18:38:56.790 Info, Node055, Request RTT 145 Average Request RTT 329
2018-11-28 18:38:56.790 Detail,   Expected callbackId was received
2018-11-28 18:38:56.790 Detail,   Expected reply was received
2018-11-28 18:38:56.790 Detail,   Message transaction complete
2018-11-28 18:38:56.790 Detail,
2018-11-28 18:38:56.790 Detail, Node055, Removing current message
2018-11-28 18:38:56.791 Detail,
2018-11-28 18:38:56.791 Info, Node055, Sending (Send) message (Callback ID=0xff, Expected Reply=0x04) - AssociationCmd_Get (Node=55): 0x01, 0x0a, 0x00, 0x13, 0x37, 0x03, 0x85, 0x02, 0x01, 0x25, 0xff, 0x8e
2018-11-28 18:38:56.800 Detail, Node055,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2018-11-28 18:38:56.800 Detail, Node055,   ZW_SEND_DATA delivered to Z-Wave stack
2018-11-28 18:38:56.871 Detail, Node055,   Received: 0x01, 0x07, 0x00, 0x13, 0xff, 0x00, 0x00, 0x08, 0x1c
2018-11-28 18:38:56.872 Detail, Node055,   ZW_SEND_DATA Request with callback ID 0xff received (expected 0xff)
2018-11-28 18:38:56.872 Info, Node055, Request RTT 80 Average Request RTT 204
2018-11-28 18:38:56.872 Detail,   Expected callbackId was received
2018-11-28 18:38:56.924 Detail, Node055,   Received: 0x01, 0x0c, 0x00, 0x04, 0x00, 0x37, 0x06, 0x85, 0x03, 0x01, 0x03, 0x00, 0x01, 0x43
2018-11-28 18:38:56.925 Detail,
2018-11-28 18:38:56.925 Info, Node055, Response RTT 133 Average Response RTT 404
2018-11-28 18:38:56.925 Info, Node055, Received Association report from node 55, group 1, containing 1 associations
2018-11-28 18:38:56.925 Info, Node055,   The group contains:
2018-11-28 18:38:56.925 Info, Node055,     Node 1
2018-11-28 18:38:56.925 Detail, Node055,   Expected reply and command class was received
2018-11-28 18:38:56.925 Detail, Node055,   Message transaction complete
2018-11-28 18:38:56.925 Detail,
2018-11-28 18:38:56.925 Detail, Node055, Removing current message
2018-11-28 18:38:56.926 Detail, Node055, Notification: Group

ptdalen · November 29, 2018, 1:09am

I’ll add my details. I also have this lock as well as the BE469. This was one of the first things I added. When I added it months ago I did add the group 2 association but never removed it from group 1. It has pretty much worked flawlessly for months. I have set and cleared codes. I lock and unlock with HA several times a day.
I did remove it from group 1 a few weeks ago after reading that I should. I just checked and like you it’s back. But. Still working great.

I have a similar setup with 30+ powered as well as battery devices.

I do see people posting issues with locks all the time. I guess I’m just lucky. I’ve not been able to figure out a common issue for others with issues.

I am not running 82.1 that added cover supppet. MYbe that’s the issue with the two new entities

freshcoast · November 29, 2018, 2:10am

I believe OZW will auto-associate the controller to group 1, unless told otherwise. This is just my speculation from looking at code and config files, but you might want to confirm with the devs. There are some configs that set an “auto=false” flag for group 1. An example: https://github.com/OpenZWave/open-zwave/blob/a0ab44f65985abc1b6e8e70df5cb483a81143247/config/fibaro/fgs222.xml#L151

You might check your zwcfg*.xml file and see if “auto=true” is set for the node. Try changing it to false. Most of mine are true, my Aeotec Minimote is false.

winter · November 29, 2018, 6:57am

I suspect there is another device on the network causing some issue. I’m planning to move mine back to Smartthings and see if I have the same issue.

RonJ103 · November 29, 2018, 12:12pm

This should outline the features you should expect with SmartThings (according to Schlage at least).
https://www.schlage.com/partners/intg-feat/home/products/prod-feat.html?tagID=micro:prod/fe599

RonJ103 · November 29, 2018, 12:31pm

Yes, auto=“true” in the zwcfg*.xml. I changed it to “false” and restarted HASSIO. It automatically changed back to “true”. Any ideas on how to make the change stick?

ptdalen · November 29, 2018, 2:21pm

Maybe the zwave controller makes a difference, but with the HUSBZB-1 controller I have the FE599 and the controller associated with Both 1 and 2, and it works perfectly. I have not had to do anything to it in months.

So at least in my case, having it associated with Group 1 is not an issue, but NOT having it associated with Group 2 was.

When I first added it months ago, I did have issues and had to remove and re add it a few times, but in hind sight, I’m sure it was more about me learning about HA more than it was a lock issue.

Honestly I’m more curiosus about the cover. and switch. that somehow got assiocated with the lock.

What version of HA are you running? Are you using the version of OpenZwave that installs by default with HA, or do you have a customized branch?

freshcoast · November 29, 2018, 3:36pm

You have to stop HA first, then edit the file.

RonJ103 · November 29, 2018, 5:48pm

How do you “stop” HA?

I see these options under the SYSTEM (under Hass.io menu):

I also see these options under the ZWave Control Panel:

freshcoast · November 29, 2018, 6:21pm

How do you “stop” HA?

I don’t use Hass.io , so I can’t say, but maybe from an ssh prompt?

$ hassio homeassistant stop

Found here:

Alternatively you could do the “STOP NETWORK” in the Z-Wave controller, which will shutdown the Z-Wave network and flush the zwcfg*.xml file. After it’s stopped (monitor the OZW_Log.txt file to see when), you could then modify the file and reboot Hass.io. But it would much easier stop and restart the HA process.

RonJ103 · December 2, 2018, 4:24am

Stopping the ZWave network, setting auto=false, then starting the network seems to have done the trick as far as removing the group1 association. Now I’ll have to see how things behave.

RonJ103 · December 5, 2018, 12:13am

The lock has been working well for the past few days.

david202 · December 7, 2018, 3:33am

Just to clarify - this is correct. For the FE599/BE369 locks, you need to add node 1 to group 2 to get events at the lock pushed to your controller in real time. Leaving node 1 in group 1 is ok, it will just generate another (useless) message on every operation at the lock in addition to the useful alarm report.

RonJ103 · December 7, 2018, 12:11pm

The lock didn’t work this morning. This was in the log file:

2018-12-07 06:58:00.037 Info, Node055, Value::Set - COMMAND_CLASS_DOOR_LOCK - Locked - 0 - 1 - False
2018-12-07 06:58:00.037 Info, Node055, Value_Lock::Set - Requesting lock to be Unlocked
2018-12-07 06:58:00.037 Detail, Node055, Setting Encryption Flag on Message For Command Class COMMAND_CLASS_DOOR_LOCK
2018-12-07 06:58:00.037 Detail, Node055, Queuing (Send) DoorLockCmd_Set (Node=55): 0x01, 0x0a, 0x00, 0x13, 0x37, 0x03, 0x62, 0x01, 0x00, 0x25, 0xba, 0x2e
2018-12-07 06:58:00.037 Detail, Node055, Setting Encryption Flag on Message For Command Class COMMAND_CLASS_DOOR_LOCK
2018-12-07 06:58:00.037 Detail, Node055, Queuing (Send) DoorLockCmd_Get (Node=55): 0x01, 0x09, 0x00, 0x13, 0x37, 0x02, 0x62, 0x02, 0x25, 0xbb, 0x2e
2018-12-07 06:58:00.037 Detail,
2018-12-07 06:58:00.037 Info, Node055, Processing (Send) Nonce Request message (Callback ID=0xba, Expected Reply=0x04)
2018-12-07 06:58:00.038 Info, Node055, Sending (Send) message (Callback ID=0xba, Expected Reply=0x04) - Nonce_Get(DoorLockCmd_Set) - 0x01, 0x09, 0x00, 0x13, 0x37, 0x02, 0x98, 0x40, 0x05, 0x02:
2018-12-07 06:58:00.175 Detail, Node055,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2018-12-07 06:58:00.176 Detail, Node055,   ZW_SEND_DATA delivered to Z-Wave stack
2018-12-07 06:58:05.409 Detail, Node055,   Received: 0x01, 0x07, 0x00, 0x13, 0x02, 0x01, 0x02, 0x19, 0xf3
2018-12-07 06:58:05.409 Detail, Node055,   ZW_SEND_DATA Request with callback ID 0x02 received (expected 0x02)
2018-12-07 06:58:05.409 Info, Node055, WARNING: ZW_SEND_DATA failed. No ACK received - device may be asleep.
2018-12-07 06:58:05.409 Warning, Node055, WARNING: Device is not a sleeping node.

ptdalen · December 7, 2018, 5:23pm

Dead batteries? Did it wake up after manually locking/unlocking? How long was it between actions, as in did it sit for days without being controlled by HA?

RonJ103 · December 7, 2018, 5:43pm

Batteries are at 50%. It gets used multiple times per day as it is on the main door that we use. I just tried to use it now and it worked fine. It generally works fine, until it doesn’t…