Schlage BE469 no longer locking/unlocking or detecting lock state

[BenBaril]

Good morning,

I’m not sure when this started but I haven’t made any config changes, and my Schlage BE469 basically stopped working. I’m able to detect the battery level and a few other attributes, but it will not lock, unlock or detect lock status.

I’ve read some instruction that mentioned updating the openzwave stack, however I’m running Hassio and none of those instructions seem to fit the bill.

Any help is much appreciated.

Here is the latest zwave log files:
2018-08-15 00:00:33.197 Info, Requesting Neighbor Update for node 13
2018-08-15 00:00:33.198 Detail, Node013, Queuing (Command) ControllerCommand_RequestNodeNeighborUpdate (Node=13): 0x01, 0x05, 0x00, 0x48, 0x0d, 0x34, 0x8b
2018-08-15 00:00:33.198 Detail, Notification: ControllerCommand - Starting
2018-08-15 00:00:33.199 Detail,
2018-08-15 00:00:33.199 Info, Node013, Sending (Command) message (Callback ID=0x34, Expected Reply=0x48) - ControllerCommand_RequestNodeNeighborUpdate (Node=13): 0x01, 0x05, 0x00, 0x48, 0x0d, 0x34, 0x8b
2018-08-15 00:00:33.244 Detail, Node013, Received: 0x01, 0x05, 0x00, 0x48, 0x34, 0x21, 0xa7
2018-08-15 00:00:33.244 Detail,
2018-08-15 00:00:33.244 Info, Node013, REQUEST_NEIGHBOR_UPDATE_STARTED
2018-08-15 00:00:33.244 Detail, Node033, Expected callbackId was received
2018-08-15 00:00:33.244 Detail, Node033, Expected reply was received
2018-08-15 00:00:33.244 Detail, Node033, Message transaction complete
2018-08-15 00:00:33.244 Detail,
2018-08-15 00:00:33.244 Detail, Node013, Removing current message
2018-08-15 00:00:33.244 Detail, Notification: ControllerCommand - InProgress
2018-08-15 00:00:33.245 Info, WriteNextMsg Controller nothing to do
2018-08-15 00:01:36.713 Detail, Received: 0x01, 0x05, 0x00, 0x48, 0x34, 0x23, 0xa5
2018-08-15 00:01:36.713 Detail,
2018-08-15 00:01:36.713 Warning, WARNING: REQUEST_NEIGHBOR_UPDATE_FAILED
2018-08-15 00:01:36.713 Detail, Notification: ControllerCommand - Failed
2018-08-15 08:49:11.242 Info, Node013, Value::Set - COMMAND_CLASS_DOOR_LOCK - Locked - 0 - 1 - True
2018-08-15 08:49:11.242 Info, Node013, Value_Lock::Set - Requesting lock to be Locked
2018-08-15 08:49:11.242 Detail, Node013, Setting Encryption Flag on Message For Command Class COMMAND_CLASS_DOOR_LOCK
2018-08-15 08:49:11.242 Detail, Node013, Queuing (Send) DoorLockCmd_Set (Node=13): 0x01, 0x0a, 0x00, 0x13, 0x0d, 0x03, 0x62, 0x01, 0xff, 0x25, 0x35, 0x64
2018-08-15 08:49:11.242 Detail, Node013, Setting Encryption Flag on Message For Command Class COMMAND_CLASS_DOOR_LOCK
2018-08-15 08:49:11.243 Detail, Node013, Queuing (Send) DoorLockCmd_Get (Node=13): 0x01, 0x09, 0x00, 0x13, 0x0d, 0x02, 0x62, 0x02, 0x25, 0x36, 0x99
2018-08-15 08:49:11.243 Detail,
2018-08-15 08:49:11.243 Info, Node013, Processing (Send) Nonce Request message (Callback ID=0x35, Expected Reply=0x04)
2018-08-15 08:49:11.243 Info, Node013, Sending (Send) message (Callback ID=0x35, Expected Reply=0x04) - Nonce_Get(DoorLockCmd_Set) - 0x01, 0x09, 0x00, 0x13, 0x0d, 0x02, 0x98, 0x40, 0x05, 0x02:
2018-08-15 08:49:11.253 Detail, Node013, Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2018-08-15 08:49:11.254 Detail, Node013, ZW_SEND_DATA delivered to Z-Wave stack
2018-08-15 08:49:21.244 Error, Node013, ERROR: Dropping command, expected response not received after 1 attempt(s)
2018-08-15 08:49:21.245 Detail, Node013, Removing current message
2018-08-15 08:49:21.245 Detail, Node013, Notification: Notification - TimeOut
2018-08-15 08:49:21.251 Detail,
2018-08-15 08:49:21.251 Info, Node013, Processing (Send) Nonce Request message (Callback ID=0x36, Expected Reply=0x04)
2018-08-15 08:49:21.251 Info, Node013, Sending (Send) message (Callback ID=0x36, Expected Reply=0x04) - Nonce_Get(DoorLockCmd_Get) - 0x01, 0x09, 0x00, 0x13, 0x0d, 0x02, 0x98, 0x40, 0x05, 0x02:
2018-08-15 08:49:21.261 Detail, Node013, Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2018-08-15 08:49:21.261 Detail, Node013, ZW_SEND_DATA delivered to Z-Wave stack
2018-08-15 08:49:31.253 Error, Node013, ERROR: Dropping command, expected response not received after 1 attempt(s)
2018-08-15 08:49:31.253 Detail, Node013, Removing current message
2018-08-15 08:49:31.253 Detail, Node013, Notification: Notification - TimeOut
2018-08-15 08:49:38.065 Detail, Received: 0x01, 0x07, 0x00, 0x13, 0x02, 0x01, 0x06, 0x91, 0x7f
2018-08-15 08:49:38.065 Detail, ZW_SEND_DATA Request with callback ID 0x02 received (expected 0x02)
2018-08-15 08:49:38.066 Info, WARNING: ZW_SEND_DATA failed. No ACK received - device may be asleep.

Thanks!
Ben

[ptdalen]

I’ve had this happen once or twice. If you’ve made no changes to your system, I would assume it’s probably your lock. At least it has been for me.

Just unplug the lock, wait about 10 seconds, plug it back in. Wait a minute or two and try again. Restart HA if needed. if it still does not work, your batteries may be low and not reporting level correctly. Replace batteries, restart HA, etc.

Lastly if that does not work. Also go into the zwave contol area, select the lock and do a repair (or refresh, cannot remember name).

Bottom line, the few times this has happed have all been related to the locks/batteries. I think (just a guess), that sometimes it gets hung up and either drains the batteries (maybe polling too much, etc), or it tries to do something that causes the zwave controller on the lock to hang.

[BenBaril]

Tried this…the battery level went back to 100 (impossible). So now I’m more confused.

[ptdalen]

Did it stay at 100%? How old are the batteries? Are they rechargeable?

[BenBaril]

Stil at 100%, and yes they are rechargeable. Not sure why that matters though?

[ptdalen]

Rechargables dont output the same voltage as non rechargable batteries. It often causes battery reporting issues with zwave devices that use the voltage output to determine how much is left. AA batteries output 1.5 volts, and rechargable batteries output 1.2 volts. There defintielty more to it than that though. The recharable batteries may last longer than normal batteries (may not as well), because the discharge slower.

Bottom line: rechargable batteries will usually report incorrrectly, but my usual experience has been that they show lower starting percentage (like starts fully charged and shows 75%). I’m ok with the differences, but you should just know that your battery results will not be as accurate. They may go from 50% to 0% in one swoop. If they are at 0% they cannot report that they are at 0%, etc.

Rechargeables disrupt zwave battery reporting

Wanted to share this observation with my fellow z-wavers. Several months ago the template sensors I use to track my motion sensor battery levels stopped working: the motion sensors consistently reported battery levels of 0% even though the motion sensors were operating normally. After trying all kinds of things to fix this issue I eventually just gave up and hoped a HASS update would one day miraculously fix them. Earlier this week one of them stopped reporting motion so I swapped the recharge…

Search for rechargeable batteries, and you’ll find plenty of results, this was just one.

Hope this helps. In your case, if your batteries were recently charged, and the deadbolt opens and closes quickly and sounds like it’s running on fully charged batteries, I’d say you’re good to go.

Last thing. I use rechargable batteries in my locks, because I have more than one smart lock to get into my house (I dont carry a key anymore), and the odds of both going dead at the same time are slim. I personally would not use rechargables in a lock unless that was the case. I dont know your situation, but thats something to consider.

[BenBaril]

@ptdalen

Wanted to share this observation with my fellow z-wavers. Several months ago the template sensors I use to track my motion sensor battery levels stopped working: the motion sensors consistently reported battery levels of 0% even though the motion sensors were operating normally. After trying all kinds of things to fix this issue I eventually just gave up and hoped a HASS update would one day miraculously fix them. Earlier this week one of them stopped reporting motion so I swapped the recharge…

This is helpful regarding the battery level, but it doesn’t explain why I can’t lock/unlock the lock anymore (or why the lock status doesn’t change).

[luma]

Have you tried swapping the batteries? Don’t rely on the battery indicator as reported over ZWave. I have 3 of these locks and they eat batteries pretty regularly and the reporting is typically inaccurate.

[BenBaril]

@luma

Have you tried swapping the batteries? Don’t rely on the battery indicator as reported over ZWave. I have 3 of these locks and they eat batteries pretty regularly and the reporting is typically inaccurate.

What I’m hearing is that I should swap my rechargeables for regular batteries, so I’ll try that and report back.

[ptdalen]

Sorry misunderstood your comment about going back to 100%. Assumed (incorrectly) that you were saying that it worked, but battery was reporting incorrectly.

Not sure if you’ve had this working for months,and for no reason at all it stopped working, or you made some minor changes else where, added a new zwave device, etc. I have 3 schlage locks, and they were a bit of a pain at 1st, but that was also when I 1st started. In the last few months, the only issue I have had was resolved by batteries unplugging and plugging back in.

Anyway you probably know this, but here are the steps in order that most people will recommend

1. Replace the batteries, restart HA
2. After the reboot, In zwave node management, find the device, does it say Complete? Dead? cacheload, etc). If its communicated correctly it will say Complete.
3. If after a few minutes (maybe up to 5 depending on how many devices you have) its still not complete select the device and try “refresh Node”, wait a few mintues, try heal node, wait a few minutes. Did it come back?
4. Restart HA again, heal network. Did it come back?
5. Or you could just come to these steps if you’d like. Remove the node, readd the node securely, reanme the entity the same name as before so you dont have to update you automations/scripts, etc. If you need help removing and readding, there is a good post somewhere on here about exactly how to remove/add this exact lock (I know I had to do that several times when I was 1st adding my locks).

Other than that, there is no need to update zwave stack, or make system changes,

[winter]

Found this thread and I have a slightly related issue. My Schlage lock will randomly stop responding to messages. Disconnecting and reconnecting the battery fixes the issue.

The problem:

1. Often this happens when I’m not home, so stuck with a non-remoteable lock
2. When in this mode, it CHEWS through battery. Basically a new set of batteries will be dead within a day. I assume the z-wave radio in the lock is permanently on.

Ended up having to remove the device from my HUSBZB because of the battery issue. Has anyone else had a problem like this?

[ptdalen]

I have had this happen once or twice. it was in the begining when I was 1st getting things set up, and making a lot of changes via the zwave control panel. Now that I rarely go into the control panel, I have not had that issuse. I defniitely had the issue where it “locked up” and drained the batteries. I do think there is probably something being sent that causes the lock to get stuck in some sort of loop until the batteries die.

But, again only had this happen when making zwave change, like tamper alerts, beeper, vacation mode, etc.

[winter]

At this point I’m rarely making changes and am still having this lock issue. The funny thing is, I had a replacement lock sent out and they let me keep the old one, so I installed the old one on my back door. Now the front door still locks up every few days, but the back door (the original lock) seems to be fine.

[winter]

At this point I think I will move these back to my smartthings hub and wait for some improvements to openzwave to see if this gets better.

I did try the openzwave dev branch a while ago, and I did have the same issue, but one thing I noticed was that a zwave reset of the device got it working again without having to pull the battery pack.

[KageKeeper (Robert Horton)]

I have been struggling to get my Schlage BE469 lock to work within HA for well over a month now. I have successfully added the lock to my Z-Wave network via ‘Add Node Secure’. I am using the Aeotek ZW090 Z-Stick Gen 5.

What will happen after factory resetting the lock and the Aeotek is that the Schlage will be added just fine. However, the correct lock status is NEVER shown correctly, and attempting to lock or unlock the device via HA does nothing. Invariably, within a short amount of time, the Aeotek thinks the Schlage is a Dead device.

Occasionally the Schlage will come out of a Dead state and return to Ready, but I am still unable to interact with it via HA, and invariably it will not be long until the Schlage is Dead, again.

I have done the remove the batteries and restart HA solution. It did not help. I checked the batteries with a multimeter, and they are all out putting ~1.4 V.

Here are some, I hope, helpful and appropriate logs from OZW_Log.txt:

2019-01-28 17:32:52.839 Info, Node005, Sending (NoOp) message (Callback ID=0x0a, Expected Reply=0x13) - NoOperation_Set (Node=5): 0x01, 0x09, 0x00, 0x13, 0x05, 0x02, 0x00, 0x00, 0x25, 0x0a, 0xcd
2019-01-28 17:32:52.849 Detail, Node005, Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2019-01-28 17:32:52.850 Detail, Node005, ZW_SEND_DATA delivered to Z-Wave stack
2019-01-28 17:32:56.347 Detail, Node005, Received: 0x01, 0x07, 0x00, 0x13, 0x0a, 0x01, 0x01, 0x5e, 0xbf
2019-01-28 17:32:56.348 Detail, Node005, ZW_SEND_DATA Request with callback ID 0x0a received (expected 0x0a)
2019-01-28 17:32:56.348 Info, Node005, WARNING: ZW_SEND_DATA failed. No ACK received - device may be asleep.
2019-01-28 17:32:56.348 Warning, Node005, WARNING: Device is not a sleeping node.
2019-01-28 17:32:56.348 Info, Node005, QueryStageRetry stage CacheLoad requested stage CacheLoad max 3 retries 0 pending 1
2019-01-28 17:32:56.348 Detail, Node001, Expected callbackId was received
2019-01-28 17:32:56.348 Detail, Node001, Expected reply was received
2019-01-28 17:32:56.348 Detail, Node001, Message transaction complete
2019-01-28 17:32:56.354 Detail,
2019-01-28 17:32:56.354 Detail, Node005, Removing current message
2019-01-28 17:32:56.354 Detail, Node005, Notification: Notification - NoOperation
2019-01-28 17:32:56.361 Detail, Node001, Query Stage Complete (Neighbors)
2019-01-28 17:32:56.361 Detail, Node001, AdvanceQueries queryPending=0 queryRetries=0 queryStage=Session live=1
2019-01-28 17:32:56.361 Detail, Node001, QueryStage_Session
2019-01-28 17:32:56.361 Detail, Node001, QueryStage_Dynamic
2019-01-28 17:32:56.361 Detail, Node001, QueryStage_Configuration
2019-01-28 17:32:56.361 Detail, Node001, QueryStage_Complete
2019-01-28 17:32:56.361 Warning, CheckCompletedNodeQueries m_allNodesQueried=0 m_awakeNodesQueried=0
2019-01-28 17:32:56.361 Warning, CheckCompletedNodeQueries all=0, deadFound=0 sleepingOnly=1
2019-01-28 17:32:56.361 Info, Node query processing complete except for sleeping nodes.
2019-01-28 17:32:56.361 Detail, Node001, Notification: NodeQueriesComplete
2019-01-28 17:32:56.374 Detail, contrlr, Notification: AwakeNodesQueried
2019-01-28 17:32:56.382 Detail, Node005, Query Stage Complete (CacheLoad)
2019-01-28 17:32:56.383 Detail, Node005, AdvanceQueries queryPending=0 queryRetries=1 queryStage=CacheLoad live=1
2019-01-28 17:32:56.383 Detail, Node005, QueryStage_CacheLoad
2019-01-28 17:32:56.383 Info, Node005, Node Identity Codes: 003b:6341:5044
2019-01-28 17:32:56.383 Info, Node005, NoOperation::Set - Routing=true
2019-01-28 17:32:56.383 Detail, Node005, Queuing (NoOp) NoOperation_Set (Node=5): 0x01, 0x09, 0x00, 0x13, 0x05, 0x02, 0x00, 0x00, 0x25, 0x0b, 0xcc
2019-01-28 17:32:56.383 Detail, Node005, Queuing (Query) Query Stage Complete (CacheLoad)
2019-01-28 17:32:56.383 Detail,
2019-01-28 17:32:56.383 Info, Node005, Sending (NoOp) message (Callback ID=0x0b, Expected Reply=0x13) - NoOperation_Set (Node=5): 0x01, 0x09, 0x00, 0x13, 0x05, 0x02, 0x00, 0x00, 0x25, 0x0b, 0xcc
2019-01-28 17:32:56.393 Detail, Node005, Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2019-01-28 17:32:56.394 Detail, Node005, ZW_SEND_DATA delivered to Z-Wave stack
2019-01-28 17:32:59.928 Detail, Node005, Received: 0x01, 0x07, 0x00, 0x13, 0x0b, 0x01, 0x01, 0x62, 0x82
2019-01-28 17:32:59.928 Detail, Node005, ZW_SEND_DATA Request with callback ID 0x0b received (expected 0x0b)
2019-01-28 17:32:59.928 Info, Node005, WARNING: ZW_SEND_DATA failed. No ACK received - device may be asleep.
2019-01-28 17:32:59.928 Warning, Node005, WARNING: Device is not a sleeping node.
2019-01-28 17:32:59.928 Info, Node005, QueryStageRetry stage CacheLoad requested stage CacheLoad max 3 retries 1 pending 1
2019-01-28 17:32:59.928 Detail, Node001, Expected callbackId was received
2019-01-28 17:32:59.929 Detail, Node001, Expected reply was received
2019-01-28 17:32:59.929 Detail, Node001, Message transaction complete
2019-01-28 17:32:59.929 Detail,
2019-01-28 17:32:59.929 Detail, Node005, Removing current message
2019-01-28 17:32:59.929 Detail, Node005, Notification: Notification - NoOperation
2019-01-28 17:32:59.935 Detail, Node005, Query Stage Complete (CacheLoad)
2019-01-28 17:32:59.935 Detail, Node005, AdvanceQueries queryPending=0 queryRetries=2 queryStage=CacheLoad live=1
2019-01-28 17:32:59.935 Detail, Node005, QueryStage_CacheLoad
2019-01-28 17:32:59.935 Info, Node005, Node Identity Codes: 003b:6341:5044
2019-01-28 17:32:59.935 Info, Node005, NoOperation::Set - Routing=true
2019-01-28 17:32:59.935 Detail, Node005, Queuing (NoOp) NoOperation_Set (Node=5): 0x01, 0x09, 0x00, 0x13, 0x05, 0x02, 0x00, 0x00, 0x25, 0x0c, 0xcb
2019-01-28 17:32:59.935 Detail, Node005, Queuing (Query) Query Stage Complete (CacheLoad)
2019-01-28 17:32:59.935 Detail,
2019-01-28 17:32:59.935 Info, Node005, Sending (NoOp) message (Callback ID=0x0c, Expected Reply=0x13) - NoOperation_Set (Node=5): 0x01, 0x09, 0x00, 0x13, 0x05, 0x02, 0x00, 0x00, 0x25, 0x0c, 0xcb
2019-01-28 17:32:59.945 Detail, Node005, Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2019-01-28 17:32:59.945 Detail, Node005, ZW_SEND_DATA delivered to Z-Wave stack
2019-01-28 17:33:02.286 Detail, Node005, Received: 0x01, 0x07, 0x00, 0x13, 0x0c, 0x00, 0x00, 0xeb, 0x0c
2019-01-28 17:33:02.286 Detail, Node005, ZW_SEND_DATA Request with callback ID 0x0c received (expected 0x0c)
2019-01-28 17:33:02.286 Info, Node005, Request RTT 2351 Average Request RTT 2351
2019-01-28 17:33:02.286 Detail, Expected callbackId was received
2019-01-28 17:33:02.286 Detail, Expected reply was received
2019-01-28 17:33:02.286 Detail, Message transaction complete
2019-01-28 17:33:02.286 Detail,
2019-01-28 17:33:02.286 Detail, Node005, Removing current message
2019-01-28 17:33:02.286 Detail, Node005, Notification: Notification - NoOperation
2019-01-28 17:33:02.292 Detail, Node005, Query Stage Complete (CacheLoad)
2019-01-28 17:33:02.292 Detail, Node005, AdvanceQueries queryPending=0 queryRetries=0 queryStage=Associations live=1
2019-01-28 17:33:02.292 Detail, Node005, QueryStage_Associations
2019-01-28 17:33:02.292 Info, Node005, Number of association groups reported for node 5 is 0.
2019-01-28 17:33:02.292 Info, Node005, Get Associations for group 1 of node 5
2019-01-28 17:33:02.292 Detail, Node005, Setting Encryption Flag on Message For Command Class COMMAND_CLASS_ASSOCIATION
2019-01-28 17:33:02.293 Detail, Node005, Queuing (Send) AssociationCmd_Get (Node=5): 0x01, 0x0a, 0x00, 0x13, 0x05, 0x03, 0x85, 0x02, 0x01, 0x25, 0x0d, 0x4e
2019-01-28 17:33:02.293 Detail, Node005, Queuing (Query) Query Stage Complete (Associations)
2019-01-28 17:33:02.293 Detail,
2019-01-28 17:33:02.293 Info, Node005, Processing (Send) Nonce Request message (Callback ID=0x0d, Expected Reply=0x04)
2019-01-28 17:33:02.293 Info, Node005, Sending (Send) message (Callback ID=0x0d, Expected Reply=0x04) - Nonce_Get(AssociationCmd_Get) - 0x01, 0x09, 0x00, 0x13, 0x05, 0x02, 0x98, 0x40, 0x05, 0x02:
2019-01-28 17:33:02.300 Detail, Node005, Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2019-01-28 17:33:02.300 Detail, Node005, ZW_SEND_DATA delivered to Z-Wave stack
2019-01-28 17:33:02.318 Detail, Node005, Received: 0x01, 0x07, 0x00, 0x13, 0x02, 0x00, 0x00, 0x02, 0xeb
2019-01-28 17:33:02.318 Detail, Node005, ZW_SEND_DATA Request with callback ID 0x02 received (expected 0x02)
2019-01-28 17:33:02.318 Info, Node005, Request RTT 24 Average Request RTT 1187
2019-01-28 17:33:12.293 Error, Node005, ERROR: Dropping command, expected response not received after 1 attempt(s)
2019-01-28 17:33:12.293 Detail, Node005, Removing current message
2019-01-28 17:33:12.293 Detail, Node005, Notification: Notification - TimeOut
2019-01-28 17:33:12.308 Detail, Node005, Query Stage Complete (Associations)
2019-01-28 17:33:12.308 Detail, Node005, AdvanceQueries queryPending=0 queryRetries=0 queryStage=Neighbors live=1
2019-01-28 17:33:12.308 Detail, Node005, QueryStage_Neighbors
2019-01-28 17:33:12.308 Detail, Requesting routing info (neighbor list) for Node 5
2019-01-28 17:33:12.308 Detail, Node005, Queuing (Command) Get Routing Info (Node=5): 0x01, 0x07, 0x00, 0x80, 0x05, 0x00, 0x00, 0x03, 0x7e
2019-01-28 17:33:12.308 Detail, Node005, Queuing (Query) Query Stage Complete (Neighbors)
2019-01-28 17:33:12.308 Detail,
2019-01-28 17:33:12.308 Info, Node005, Sending (Command) message (Callback ID=0x00, Expected Reply=0x80) - Get Routing Info (Node=5): 0x01, 0x07, 0x00, 0x80, 0x05, 0x00, 0x00, 0x03, 0x7e
2019-01-28 17:33:12.313 Detail, Node005, Received: 0x01, 0x20, 0x01, 0x80, 0x01, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x5f
2019-01-28 17:33:12.313 Detail,
2019-01-28 17:33:12.313 Info, Node005, Received reply to FUNC_ID_ZW_GET_ROUTING_INFO
2019-01-28 17:33:12.313 Info, Node005, Neighbors of this node are:
2019-01-28 17:33:12.313 Info, Node005, Node 1
2019-01-28 17:33:12.313 Detail, Expected reply was received
2019-01-28 17:33:12.313 Detail, Message transaction complete
2019-01-28 17:33:12.313 Detail,
2019-01-28 17:33:12.313 Detail, Node005, Removing current message
2019-01-28 17:33:12.313 Detail, Node005, Query Stage Complete (Neighbors)
2019-01-28 17:33:12.313 Detail, Node005, AdvanceQueries queryPending=0 queryRetries=0 queryStage=Session live=1
2019-01-28 17:33:12.313 Detail, Node005, QueryStage_Session
2019-01-28 17:33:12.313 Detail, Node005, Setting Encryption Flag on Message For Command Class COMMAND_CLASS_USER_CODE
2019-01-28 17:33:12.313 Detail, Node005, Queuing (Query) UserCodeCmd_Get (Node=5): 0x01, 0x0a, 0x00, 0x13, 0x05, 0x03, 0x63, 0x02, 0x01, 0x25, 0x0e, 0xab
2019-01-28 17:33:12.313 Detail, Node005, Queuing (Query) Query Stage Complete (Session)
2019-01-28 17:33:12.313 Detail,
2019-01-28 17:33:12.313 Info, Node005, Processing (Query) Nonce Request message (Callback ID=0x0e, Expected Reply=0x04)
2019-01-28 17:33:12.314 Info, Node005, Sending (Query) message (Callback ID=0x0e, Expected Reply=0x04) - Nonce_Get(UserCodeCmd_Get) - 0x01, 0x09, 0x00, 0x13, 0x05, 0x02, 0x98, 0x40, 0x05, 0x02:
2019-01-28 17:33:12.325 Detail, Node005, Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2019-01-28 17:33:12.325 Detail, Node005, ZW_SEND_DATA delivered to Z-Wave stack
2019-01-28 17:33:15.929 Detail, Node005, Received: 0x01, 0x07, 0x00, 0x13, 0x02, 0x00, 0x01, 0x69, 0x81
2019-01-28 17:33:15.930 Detail, Node005, ZW_SEND_DATA Request with callback ID 0x02 received (expected 0x02)
2019-01-28 17:33:15.930 Info, Node005, Request RTT 3616 Average Request RTT 2401
2019-01-28 17:33:16.419 Detail, Node005, Received: 0x01, 0x10, 0x00, 0x04, 0x00, 0x05, 0x0a, 0x98, 0x80, 0x5b, 0x83, 0x8b, 0x07, 0xfd, 0xeb, 0xbf, 0x1d, 0x1c
2019-01-28 17:33:16.419 Info, Node005, Received SecurityCmd_NonceReport from node 5
2019-01-28 17:33:16.420 Info, Node005, Sending (Query) message (Callback ID=0x0f, Expected Reply=0x04) - UserCodeCmd_Get (Node=5): 0x01, 0x0a, 0x00, 0x13, 0x05, 0x03, 0x63, 0x02, 0x01, 0x25, 0x0f, 0xaa
2019-01-28 17:33:16.431 Detail, Node005, Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2019-01-28 17:33:16.431 Detail, Node005, ZW_SEND_DATA delivered to Z-Wave stack
2019-01-28 17:33:16.452 Detail, Node005, Received: 0x01, 0x07, 0x00, 0x13, 0x0f, 0x00, 0x00, 0x03, 0xe7
2019-01-28 17:33:16.452 Detail, Node005, ZW_SEND_DATA Request with callback ID 0x0f received (expected 0x0f)
2019-01-28 17:33:16.452 Info, Node005, Request RTT 4138 Average Request RTT 3269
2019-01-28 17:33:16.452 Detail, Expected callbackId was received
2019-01-28 17:33:16.666 Detail, Node005, Received: 0x01, 0x08, 0x00, 0x04, 0x00, 0x05, 0x02, 0x98, 0x40, 0x2c
2019-01-28 17:33:16.666 Info, Node005, Received SecurityCmd_NonceGet from node 5
2019-01-28 17:33:16.666 Info, NONCES: 0x50, 0xab, 0x6c, 0x88, 0xb4, 0x70, 0xa8, 0xfd
2019-01-28 17:33:16.666 Info, NONCES: 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00
2019-01-28 17:33:16.666 Info, NONCES: 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00
2019-01-28 17:33:16.666 Info, NONCES: 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00
2019-01-28 17:33:16.666 Info, NONCES: 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00
2019-01-28 17:33:16.666 Info, NONCES: 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00
2019-01-28 17:33:16.666 Info, NONCES: 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00
2019-01-28 17:33:16.666 Info, NONCES: 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00
2019-01-28 17:33:16.666 Info, Node005, Sending (Query) message (Callback ID=0x01, Expected Reply=0x04) - Nonce_Report - 0x01, 0x11, 0x00, 0x13, 0x05, 0x0a, 0x98, 0x80, 0x50, 0xab, 0x6c, 0x88, 0xb4, 0x70, 0xa8, 0xfd, 0x05, 0x01, 0x60:
2019-01-28 17:33:16.675 Detail, Node005, Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2019-01-28 17:33:16.675 Detail, Node005, ZW_SEND_DATA delivered to Z-Wave stack
2019-01-28 17:33:16.803 Detail, Node005, Received: 0x01, 0x07, 0x00, 0x13, 0x01, 0x00, 0x00, 0x0e, 0xe4
2019-01-28 17:33:16.804 Detail, Node005, ZW_SEND_DATA Request with callback ID 0x01 received (expected 0x01)
2019-01-28 17:33:16.804 Info, Node005, Request RTT 4489 Average Request RTT 3879
2019-01-28 17:33:22.314 Detail,
2019-01-28 17:33:22.314 Info, NONCES: 0x50, 0xab, 0x6c, 0x88, 0xb4, 0x70, 0xa8, 0xfd
2019-01-28 17:33:22.314 Info, NONCES: 0x8b, 0x74, 0x0d, 0x76, 0x40, 0x6f, 0xaa, 0x58
2019-01-28 17:33:22.314 Info, NONCES: 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00
2019-01-28 17:33:22.314 Info, NONCES: 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00
2019-01-28 17:33:22.315 Info, NONCES: 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00
2019-01-28 17:33:22.315 Info, NONCES: 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00
2019-01-28 17:33:22.315 Info, NONCES: 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00
2019-01-28 17:33:22.315 Info, NONCES: 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00
2019-01-28 17:33:22.315 Info, Node005, Sending (Query) message (Callback ID=0x01, Expected Reply=0x04) - Nonce_Report - 0x01, 0x11, 0x00, 0x13, 0x05, 0x0a, 0x98, 0x80, 0x8b, 0x74, 0x0d, 0x76, 0x40, 0x6f, 0xaa, 0x58, 0x05, 0x01, 0xb7:
2019-01-28 17:33:22.316 Detail, Node005, Notification: Notification - TimeOut
2019-01-28 17:33:22.326 Detail, Node005, Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2019-01-28 17:33:22.326 Detail, Node005, ZW_SEND_DATA delivered to Z-Wave stack
2019-01-28 17:33:29.599 Detail, Node005, Received: 0x01, 0x07, 0x00, 0x13, 0x01, 0x01, 0x02, 0xd8, 0x31
2019-01-28 17:33:29.599 Detail, Node005, ZW_SEND_DATA Request with callback ID 0x01 received (expected 0x01)
2019-01-28 17:33:29.599 Info, Node005, WARNING: ZW_SEND_DATA failed. No ACK received - device may be asleep.
2019-01-28 17:33:29.599 Warning, Node005, WARNING: Device is not a sleeping node.
2019-01-28 17:33:29.599 Error, Node005, ERROR: node presumed dead
2019-01-28 17:33:29.599 Warning, CheckCompletedNodeQueries m_allNodesQueried=0 m_awakeNodesQueried=1
2019-01-28 17:33:29.599 Warning, CheckCompletedNodeQueries all=1, deadFound=1 sleepingOnly=1
2019-01-28 17:33:29.599 Info, Node query processing complete except for dead nodes.
2019-01-28 17:33:29.599 Detail, contrlr, Notification: AllNodesQueriedSomeDead
2019-01-28 17:33:29.602 Detail, Node005, Notification: Notification - Node Dead
2019-01-28 17:33:32.316 Error, Node005, ERROR: Dropping command because node is presumed dead
2019-01-28 17:33:32.316 Detail, Node005, Removing current message
2019-01-28 17:33:32.317 Detail, Node005, Notification: Notification - TimeOut
2019-01-28 17:33:32.325 Detail, Node005, Query Stage Complete (Session)
2019-01-28 17:33:32.325 Detail, Node005, AdvanceQueries queryPending=0 queryRetries=0 queryStage=Dynamic live=0
2019-01-28 17:35:56.619 Detail, Node005, AdvanceQueries queryPending=0 queryRetries=0 queryStage=ProtocolInfo live=0
2019-01-28 17:36:25.467 Detail, Node005, Queuing (Controller) Request Node Neighbor Update
2019-01-28 17:36:25.467 Detail, Node005, Queuing (Controller) Delete All Return Routes
2019-01-28 17:36:25.467 Info, Requesting Neighbor Update for node 5
2019-01-28 17:36:25.467 Detail, Node005, Queuing (Command) ControllerCommand_RequestNodeNeighborUpdate (Node=5): 0x01, 0x05, 0x00, 0x48, 0x05, 0x10, 0xa7
2019-01-28 17:36:25.468 Detail, Notification: ControllerCommand - Starting
2019-01-28 17:36:25.472 Error, Node005, ERROR: Dropping command because node is presumed dead
2019-01-28 17:36:25.472 Detail, Node005, Removing current message
2019-01-28 17:36:25.472 Detail, Notification: ControllerCommand - Error - Failed
2019-01-28 17:36:25.475 Info, Deleting all return routes from node 5
2019-01-28 17:36:25.475 Detail, Node005, Queuing (Command) ControllerCommand_DeleteAllReturnRoutess (Node=5): 0x01, 0x05, 0x00, 0x47, 0x05, 0x11, 0xa9
2019-01-28 17:36:25.475 Detail, Notification: ControllerCommand - Starting
2019-01-28 17:36:25.477 Error, Node005, ERROR: Dropping command because node is presumed dead
2019-01-28 17:36:25.477 Detail, Node005, Removing current message
2019-01-28 17:36:25.477 Detail, Notification: ControllerCommand - Error - Failed
2019-01-28 17:36:44.029 Info, Node005, Value::Set - COMMAND_CLASS_DOOR_LOCK - Locked - 0 - 1 - True
2019-01-28 17:36:44.029 Info, Node005, Value_Lock::Set - Requesting lock to be Locked
2019-01-28 17:36:44.029 Detail, Node005, Setting Encryption Flag on Message For Command Class COMMAND_CLASS_DOOR_LOCK
2019-01-28 17:36:44.029 Detail, Node005, Queuing (Send) DoorLockCmd_Set (Node=5): 0x01, 0x0a, 0x00, 0x13, 0x05, 0x03, 0x62, 0x01, 0xff, 0x25, 0x12, 0x4b
2019-01-28 17:36:44.029 Detail, Node005, Setting Encryption Flag on Message For Command Class COMMAND_CLASS_DOOR_LOCK
2019-01-28 17:36:44.030 Detail, Node005, Queuing (Send) DoorLockCmd_Get (Node=5): 0x01, 0x09, 0x00, 0x13, 0x05, 0x02, 0x62, 0x02, 0x25, 0x13, 0xb4
2019-01-28 17:36:44.030 Error, Node005, ERROR: Dropping command because node is presumed dead
2019-01-28 17:36:44.030 Detail, Node005, Removing current message
2019-01-28 17:36:44.030 Error, Node005, ERROR: Dropping command because node is presumed dead
2019-01-28 17:36:44.030 Detail, Node005, Removing current message
2019-01-29 00:00:00.022 Detail, Node001, Queuing (Controller) Request Node Neighbor Update
2019-01-29 00:00:00.023 Detail, Node005, Queuing (Controller) Request Node Neighbor Update

I am unsure as to what to try next, so any pointers would be welcomed!

[ptdalen]

So, couple of starter questions

1. Do you have any other zwave devices securely added?
2. Do you have a lot of zwave devices on your network? How far is the lock from your usb zwave stick?
3. Did you set up your zwave network key for adding securely?

[KageKeeper (Robert Horton)]

@ptdalen

So, couple of starter questions

1. Do you have any other zwave devices securely added?
2. Do you have a lot of zwave devices on your network? How far is the lock from your usb zwave stick?
3. Did you set up your zwave network key for adding securely?

1. No. The Schlage is the only device, secure or otherwise, on the Aeotek network. I do have a Samsung SmartThings as well as Ring Alarm devices, but they are all separate from the Aeotek network.

2. Only this device on this network, and the USB zwave stick is in my basement next to the SmartThings. I say this because the Schlage used to be on the SmartThings, and worked fine from ST. I would estimate 30’ if I were to draw a straight line from the Schlage to the Aeotek.

3. I believe I did. There seems to be a bit of confusing info out there. I set up the ZWave intergration through the HA Configuration page. I do have a NetworkKey Option in options.xml, and according to zwcfg_0xd732c6b6.xml it looks like the Schlage was added securely:

Node id=“5” name=“” location=“” basic=“4” generic=“64” specific=“3” type=“Secure Keypad Door Lock”
listening=“false” frequentListening=“true” beaming=“true” routing=“true” max_baud_rate=“40000”
version=“4” secured=“true” query_stage=“Configuration”

[KageKeeper (Robert Horton)]

Weirdness abounds today.

After posting my above response, I restarted HA for a completely different reason. I have not messed with the Schlage since yesterday. After HA came back up I noticed the Schlage was no longer seen as dead, and I can CONTROL it, AND the STATUS is correct in HA now.

So…no idea.

[KageKeeper (Robert Horton)]

Annnnd now it’s Dead again.

Ug.

[ptdalen]

Yeah, your zwave signal is probably not strong enough to reach your lock. You really need a decent zwave mesh to work reliably over any distance. battery zwave devices do not work as repeaters. Smartthings has a good zwave controller, which is why it was working better for you. You need to either move closer to your lock, or add some powered zwave devices.

At least that’s my recommendation, if it works sometimes.