Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Zwave Lock toggle immediately jumps back on lock/unlock #11099

Closed
marthoc opened this issue Dec 12, 2017 · 35 comments
Closed

Zwave Lock toggle immediately jumps back on lock/unlock #11099

marthoc opened this issue Dec 12, 2017 · 35 comments

Comments

@marthoc
Copy link
Contributor

marthoc commented Dec 12, 2017

Make sure you are running the latest version of Home Assistant before reporting an issue.

You should only file an issue if you found a bug. Feature and enhancement requests should go in the Feature Requests section of our community forum:

Home Assistant release (hass --version): 59.2

Python release (python3 --version): 3.6 (running in Docker)

Component/platform: Zwave Lock

Description of problem:
Successfully securely paired a Kwikset Signature Series Deadbolt with Home Connect (model 910 S TRL ZW 15 SMT). It’s detected as a Kwikset Touchpad Electronic Deadbolt, which I understand is down to its entry in the OZW database.

The issue I’m seeing is that on pressing the toggle in the frontend, the switch moves but then immediately jumps back to its previous state. Meanwhile, the physical lock has reacted almost immediately and locks/unlocks as it should. Three to five seconds later, the toggle in the frontend moves to reflect the true state of the physical lock.

Checking the OZW log, the whole transaction from first message to the Lock Report reporting the state of the lock looks like it takes just under 1 second.

Expected:

Toggle to move and stay in it’s new position.

Problem-relevant configuration.yaml entries and steps to reproduce:

Traceback (if applicable):

Additional info:

@marthoc
Copy link
Contributor Author

marthoc commented Dec 14, 2017

@andrey-git I hate to ping anyone directly, but any idea at all on this? It seems like the Zwave transaction completes so quickly, I’m not sure why there would be a delay in updating the lock state.

@andrey-git
Copy link
Contributor

Put ozw log of the transaction on hastebin and link to it here.

@marthoc
Copy link
Contributor Author

marthoc commented Dec 14, 2017

@andrey-git The hastebin link is here: https://hastebin.com/rurifuroci.sql. After really examining the whole transaction I can see I was wrong about the length of the transaction. The whole thing (from command send to lock to receiving Lock Report) is almost 13 seconds (!). An Alarm Report arrives after about 4 seconds, indicating a lock operation, but then there is a timeout (it seems to happen every time, I'm not sure if that's just a quirk of this lock) which adds about 6 seconds of delay to the transaction.

I guess the platform is looking for the Lock Report before changing the toggle, rather than the Alarm Report? The delay in this could just be down to the health of my Zwave network and the location of my lock (away from, but still only one hop from, the controller, though it is less than 10 feet from a powered node).

Thanks for any insight!

@andrey-git
Copy link
Contributor

You have RTT of 3 seconds that a lot.

You should add some repeater.

@spacesuitdiver
Copy link

spacesuitdiver commented Dec 17, 2017

Hi, new here, coming from SmartThings and my lock is the first thing I am automating. I'm getting about a 8 second delay, this happens in the web interface too homebridge interface was just handy. Any idea how to troubleshoot?

2017-12-17 14_56_27

12-17 21:11:46.507 Info, Node009, Value::Set - COMMAND_CLASS_DOOR_LOCK - Locked - 0 - 1 - False
2017-12-17 21:11:46.508 Info, Node009, Value_Lock::Set - Requesting lock to be Unlocked
2017-12-17 21:11:46.508 Detail, Node009, Setting Encryption Flag on Message For Command Class COMMAND_CLASS_DOOR_LOCK
2017-12-17 21:11:46.508 Detail, Node009, Queuing (Send) DoorLockCmd_Set (Node=9): 0x01, 0x0a, 0x00, 0x13, 0x09, 0x03, 0x62, 0x01, 0x00, 0x25, 0x68, 0xc2
2017-12-17 21:11:46.508 Detail, Node009, Setting Encryption Flag on Message For Command Class COMMAND_CLASS_DOOR_LOCK
2017-12-17 21:11:46.508 Detail, Node009, Queuing (Send) DoorLockCmd_Get (Node=9): 0x01, 0x09, 0x00, 0x13, 0x09, 0x02, 0x62, 0x02, 0x25, 0x69, 0xc2
2017-12-17 21:11:46.508 Detail, 
2017-12-17 21:11:46.508 Info, Node009, Processing (Send) Nonce Request message (Callback ID=0x68, Expected Reply=0x04)
2017-12-17 21:11:46.508 Info, Node009, Sending (Send) message (Callback ID=0x68, Expected Reply=0x04) - Nonce_Get(DoorLockCmd_Set) - 0x01, 0x09, 0x00, 0x13, 0x09, 0x02, 0x98, 0x40, 0x05, 0x02:
2017-12-17 21:11:46.516 Detail, Node009,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2017-12-17 21:11:46.517 Detail, Node009,   ZW_SEND_DATA delivered to Z-Wave stack
2017-12-17 21:11:47.807 Detail, Node009,   Received: 0x01, 0x07, 0x00, 0x13, 0x02, 0x00, 0x00, 0x82, 0x6b
2017-12-17 21:11:47.808 Detail, Node009,   ZW_SEND_DATA Request with callback ID 0x02 received (expected 0x02)
2017-12-17 21:11:47.808 Info, Node009, Request RTT 1299 Average Request RTT 700
2017-12-17 21:11:47.820 Detail, Node009,   Received: 0x01, 0x10, 0x00, 0x04, 0x00, 0x09, 0x0a, 0x98, 0x80, 0x6a, 0xa6, 0xc6, 0xb9, 0xec, 0x22, 0x9a, 0x01, 0x16
2017-12-17 21:11:47.820 Info, Node009, Received SecurityCmd_NonceReport from node 9
2017-12-17 21:11:47.820 Info, Node009, Sending (Send) message (Callback ID=0x6a, Expected Reply=0x04) - DoorLockCmd_Set (Node=9): 0x01, 0x0a, 0x00, 0x13, 0x09, 0x03, 0x62, 0x01, 0x00, 0x25, 0x6a, 0xc0
2017-12-17 21:11:47.831 Detail, Node009,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2017-12-17 21:11:47.832 Detail, Node009,   ZW_SEND_DATA delivered to Z-Wave stack
2017-12-17 21:11:47.853 Detail, Node009,   Received: 0x01, 0x07, 0x00, 0x13, 0x6a, 0x00, 0x00, 0x03, 0x82
2017-12-17 21:11:47.853 Detail, Node009,   ZW_SEND_DATA Request with callback ID 0x6a received (expected 0x6a)
2017-12-17 21:11:47.853 Info, Node009, Request RTT 1344 Average Request RTT 1022
2017-12-17 21:11:47.853 Detail,   Expected callbackId was received
2017-12-17 21:11:48.879 Detail, Node009,   Received: 0x01, 0x08, 0x00, 0x04, 0x00, 0x09, 0x02, 0x98, 0x40, 0x20
2017-12-17 21:11:48.880 Info, Node009, Received SecurityCmd_NonceGet from node 9
2017-12-17 21:11:48.880 Info, NONCES: 0xcf, 0x21, 0x0d, 0x0d, 0x75, 0xc7, 0xb1, 0x71
2017-12-17 21:11:48.880 Info, NONCES: 0x1f, 0x96, 0x94, 0x87, 0x98, 0x5c, 0x4d, 0xe3
2017-12-17 21:11:48.880 Info, NONCES: 0x12, 0x19, 0xec, 0x2b, 0x7b, 0x39, 0xd3, 0x4a
2017-12-17 21:11:48.880 Info, NONCES: 0xa0, 0xd6, 0x4e, 0x38, 0x32, 0x9c, 0x1c, 0xac
2017-12-17 21:11:48.880 Info, NONCES: 0x65, 0xa8, 0x9b, 0x42, 0x26, 0x12, 0x1b, 0xa5
2017-12-17 21:11:48.880 Info, NONCES: 0xa8, 0xc3, 0x7c, 0x28, 0xe2, 0xa0, 0x84, 0x35
2017-12-17 21:11:48.880 Info, NONCES: 0xfc, 0x56, 0xe5, 0x22, 0x69, 0x01, 0xc8, 0xc6
2017-12-17 21:11:48.880 Info, NONCES: 0x4b, 0x1d, 0xdd, 0xb8, 0x0c, 0x72, 0xfc, 0xb5
2017-12-17 21:11:48.880 Info, Node009, Sending (Send) message (Callback ID=0x01, Expected Reply=0x04) - Nonce_Report - 0x01, 0x11, 0x00, 0x13, 0x09, 0x0a, 0x98, 0x80, 0xa0, 0xd6, 0x4e, 0x38, 0x32, 0x9c, 0x1c, 0xac, 0x05, 0x01, 0xfc:
2017-12-17 21:11:48.889 Detail, Node009,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2017-12-17 21:11:48.890 Detail, Node009,   ZW_SEND_DATA delivered to Z-Wave stack
2017-12-17 21:11:48.908 Detail, Node009,   Received: 0x01, 0x07, 0x00, 0x13, 0x01, 0x00, 0x00, 0x03, 0xe9
2017-12-17 21:11:48.908 Detail, Node009,   ZW_SEND_DATA Request with callback ID 0x01 received (expected 0x01)
2017-12-17 21:11:48.909 Info, Node009, Request RTT 2399 Average Request RTT 1710
2017-12-17 21:11:48.930 Detail, Node009,   Received: 0x01, 0x1e, 0x00, 0x04, 0x00, 0x09, 0x18, 0x98, 0x81, 0x6c, 0x80, 0x0c, 0x4c, 0xe9, 0xb7, 0xd2, 0x6f, 0xbe, 0x93, 0x2e, 0x7e, 0x1b, 0xa0, 0xec, 0x6f, 0x9c, 0x1c, 0xa1, 0xaf, 0xb3, 0x2e, 0xf4
2017-12-17 21:11:48.930 Info, Raw: 0x98, 0x81, 0x6c, 0x80, 0x0c, 0x4c, 0xe9, 0xb7, 0xd2, 0x6f, 0xbe, 0x93, 0x2e, 0x7e, 0x1b, 0xa0, 0xec, 0x6f, 0x9c, 0x1c, 0xa1, 0xaf, 0xb3, 0x2e, 0xf4
2017-12-17 21:11:48.930 Detail, Node009, Decrypted Packet: 0x00, 0x71, 0x05, 0x19, 0x01
2017-12-17 21:11:48.930 Detail, 
2017-12-17 21:11:48.930 Info, Node009, Response RTT 2421 Average Response RTT 1569
2017-12-17 21:11:48.930 Info, Node009, Received Alarm report: type=25, level=1
2017-12-17 21:11:48.931 Detail, Node009, Refreshed Value: old value=21, new value=25, type=byte
2017-12-17 21:11:48.931 Detail, Node009, Changes to this value are not verified
2017-12-17 21:11:48.931 Detail, Node009, Setting Encryption Flag on Message For Command Class COMMAND_CLASS_DOOR_LOCK
2017-12-17 21:11:48.931 Detail, Node009, Queuing (Send) DoorLockCmd_Get (Node=9): 0x01, 0x09, 0x00, 0x13, 0x09, 0x02, 0x62, 0x02, 0x25, 0x6b, 0xc0
2017-12-17 21:11:48.931 Detail, Node009, Refreshed Value: old value=1, new value=1, type=byte
2017-12-17 21:11:48.931 Detail, Node009, Changes to this value are not verified
2017-12-17 21:11:48.931 Detail, Node009, Notification: ValueChanged
2017-12-17 21:11:48.942 Detail, Node009, Notification: ValueChanged
2017-12-17 21:11:56.509 Error, Node009, ERROR: Dropping command, expected response not received after 1 attempt(s)
2017-12-17 21:11:56.509 Detail, Node009, Removing current message
2017-12-17 21:11:56.509 Detail, Node009, Notification: Notification - TimeOut
2017-12-17 21:11:56.515 Detail, 
2017-12-17 21:11:56.516 Info, Node009, Processing (Send) Nonce Request message (Callback ID=0x69, Expected Reply=0x04)
2017-12-17 21:11:56.516 Info, Node009, Sending (Send) message (Callback ID=0x69, Expected Reply=0x04) - Nonce_Get(DoorLockCmd_Get) - 0x01, 0x09, 0x00, 0x13, 0x09, 0x02, 0x98, 0x40, 0x05, 0x02:
2017-12-17 21:11:56.524 Detail, Node009,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2017-12-17 21:11:56.524 Detail, Node009,   ZW_SEND_DATA delivered to Z-Wave stack
2017-12-17 21:11:57.770 Detail, Node009,   Received: 0x01, 0x07, 0x00, 0x13, 0x02, 0x00, 0x00, 0x7d, 0x94
2017-12-17 21:11:57.771 Detail, Node009,   ZW_SEND_DATA Request with callback ID 0x02 received (expected 0x02)
2017-12-17 21:11:57.771 Info, Node009, Request RTT 1254 Average Request RTT 1482
2017-12-17 21:11:57.783 Detail, Node009,   Received: 0x01, 0x10, 0x00, 0x04, 0x00, 0x09, 0x0a, 0x98, 0x80, 0x7c, 0xf7, 0x8e, 0x38, 0x21, 0x89, 0xec, 0x33, 0xba
2017-12-17 21:11:57.783 Info, Node009, Received SecurityCmd_NonceReport from node 9
2017-12-17 21:11:57.783 Info, Node009, Sending (Send) message (Callback ID=0x6c, Expected Reply=0x04) - DoorLockCmd_Get (Node=9): 0x01, 0x09, 0x00, 0x13, 0x09, 0x02, 0x62, 0x02, 0x25, 0x6c, 0xc7
2017-12-17 21:11:57.794 Detail, Node009,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2017-12-17 21:11:57.794 Detail, Node009,   ZW_SEND_DATA delivered to Z-Wave stack
2017-12-17 21:11:57.816 Detail, Node009,   Received: 0x01, 0x07, 0x00, 0x13, 0x6c, 0x00, 0x00, 0x02, 0x85
2017-12-17 21:11:57.816 Detail, Node009,   ZW_SEND_DATA Request with callback ID 0x6c received (expected 0x6c)
2017-12-17 21:11:57.816 Info, Node009, Request RTT 1300 Average Request RTT 1391
2017-12-17 21:11:57.816 Detail,   Expected callbackId was received
2017-12-17 21:11:57.853 Detail, Node009,   Received: 0x01, 0x08, 0x00, 0x04, 0x00, 0x09, 0x02, 0x98, 0x40, 0x20
2017-12-17 21:11:57.854 Info, Node009, Received SecurityCmd_NonceGet from node 9
2017-12-17 21:11:57.854 Info, NONCES: 0xcf, 0x21, 0x0d, 0x0d, 0x75, 0xc7, 0xb1, 0x71
2017-12-17 21:11:57.854 Info, NONCES: 0x1f, 0x96, 0x94, 0x87, 0x98, 0x5c, 0x4d, 0xe3
2017-12-17 21:11:57.854 Info, NONCES: 0x12, 0x19, 0xec, 0x2b, 0x7b, 0x39, 0xd3, 0x4a
2017-12-17 21:11:57.855 Info, NONCES: 0xa0, 0xd6, 0x4e, 0x38, 0x32, 0x9c, 0x1c, 0xac
2017-12-17 21:11:57.855 Info, NONCES: 0x88, 0x27, 0x8e, 0x03, 0x61, 0x61, 0x4e, 0xbc
2017-12-17 21:11:57.855 Info, NONCES: 0xa8, 0xc3, 0x7c, 0x28, 0xe2, 0xa0, 0x84, 0x35
2017-12-17 21:11:57.855 Info, NONCES: 0xfc, 0x56, 0xe5, 0x22, 0x69, 0x01, 0xc8, 0xc6
2017-12-17 21:11:57.856 Info, NONCES: 0x4b, 0x1d, 0xdd, 0xb8, 0x0c, 0x72, 0xfc, 0xb5
2017-12-17 21:11:57.856 Info, Node009, Sending (Send) message (Callback ID=0x01, Expected Reply=0x04) - Nonce_Report - 0x01, 0x11, 0x00, 0x13, 0x09, 0x0a, 0x98, 0x80, 0x88, 0x27, 0x8e, 0x03, 0x61, 0x61, 0x4e, 0xbc, 0x05, 0x01, 0x32:
2017-12-17 21:11:57.865 Detail, Node009,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2017-12-17 21:11:57.866 Detail, Node009,   ZW_SEND_DATA delivered to Z-Wave stack
2017-12-17 21:11:57.884 Detail, Node009,   Received: 0x01, 0x07, 0x00, 0x13, 0x01, 0x00, 0x00, 0x02, 0xe8
2017-12-17 21:11:57.884 Detail, Node009,   ZW_SEND_DATA Request with callback ID 0x01 received (expected 0x01)
2017-12-17 21:11:57.884 Info, Node009, Request RTT 1368 Average Request RTT 1379
2017-12-17 21:11:57.906 Detail, Node009,   Received: 0x01, 0x21, 0x00, 0x04, 0x00, 0x09, 0x1b, 0x98, 0x81, 0xed, 0xb6, 0x4d, 0x45, 0xd9, 0xbf, 0x5c, 0xa0, 0xb7, 0x96, 0x5c, 0x4e, 0x85, 0xe5, 0xcb, 0x9c, 0x88, 0xe2, 0x1c, 0xf3, 0x4c, 0xca, 0xbe, 0x71, 0xa1, 0x71
2017-12-17 21:11:57.906 Info, Raw: 0x98, 0x81, 0xed, 0xb6, 0x4d, 0x45, 0xd9, 0xbf, 0x5c, 0xa0, 0xb7, 0x96, 0x5c, 0x4e, 0x85, 0xe5, 0xcb, 0x9c, 0x88, 0xe2, 0x1c, 0xf3, 0x4c, 0xca, 0xbe, 0x71, 0xa1, 0x71
2017-12-17 21:11:57.906 Detail, Node009, Decrypted Packet: 0x00, 0x62, 0x03, 0x00, 0x00, 0x02, 0xfe, 0xfe
2017-12-17 21:11:57.906 Detail, 
2017-12-17 21:11:57.907 Info, Node009, Response RTT 1390 Average Response RTT 1479
2017-12-17 21:11:57.907 Info, Node009, Received DoorLock report: DoorLock is Unsecure
2017-12-17 21:11:57.907 Detail, Node009, Refreshed Value: old value=true, new value=false, type=bool
2017-12-17 21:11:57.907 Detail, Node009, Changes to this value are not verified
2017-12-17 21:11:57.907 Detail, Node009, Refreshed Value: old value=0, new value=0, type=list
2017-12-17 21:11:57.907 Detail, Node009, Changes to this value are not verified
2017-12-17 21:11:57.907 Detail, Node009,   Expected reply and command class was received
2017-12-17 21:11:57.907 Detail, Node009,   Message transaction complete
2017-12-17 21:11:57.907 Detail, 
2017-12-17 21:11:57.907 Detail, Node009, Removing current message
2017-12-17 21:11:57.908 Detail, Node009, Notification: ValueChanged
2017-12-17 21:11:57.918 Detail, Node009, Notification: ValueChanged
2017-12-17 21:11:57.929 Detail, 
2017-12-17 21:11:57.929 Info, Node009, Processing (Send) Nonce Request message (Callback ID=0x6b, Expected Reply=0x04)
2017-12-17 21:11:57.929 Info, Node009, Sending (Send) message (Callback ID=0x6b, Expected Reply=0x04) - Nonce_Get(DoorLockCmd_Get) - 0x01, 0x09, 0x00, 0x13, 0x09, 0x02, 0x98, 0x40, 0x05, 0x02:
2017-12-17 21:11:57.937 Detail, Node009,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2017-12-17 21:11:57.938 Detail, Node009,   ZW_SEND_DATA delivered to Z-Wave stack
2017-12-17 21:11:57.954 Detail, Node009,   Received: 0x01, 0x07, 0x00, 0x13, 0x02, 0x00, 0x00, 0x02, 0xeb
2017-12-17 21:11:57.954 Detail, Node009,   ZW_SEND_DATA Request with callback ID 0x02 received (expected 0x02)
2017-12-17 21:11:57.954 Info, Node009, Request RTT 24 Average Request RTT 701
2017-12-17 21:11:57.966 Detail, Node009,   Received: 0x01, 0x10, 0x00, 0x04, 0x00, 0x09, 0x0a, 0x98, 0x80, 0x54, 0x66, 0xac, 0x1e, 0x16, 0xbe, 0x31, 0x0e, 0xe7
2017-12-17 21:11:57.967 Info, Node009, Received SecurityCmd_NonceReport from node 9
2017-12-17 21:11:57.967 Info, Node009, Sending (Send) message (Callback ID=0x6d, Expected Reply=0x04) - DoorLockCmd_Get (Node=9): 0x01, 0x09, 0x00, 0x13, 0x09, 0x02, 0x62, 0x02, 0x25, 0x6d, 0xc6
2017-12-17 21:11:57.978 Detail, Node009,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2017-12-17 21:11:57.978 Detail, Node009,   ZW_SEND_DATA delivered to Z-Wave stack
2017-12-17 21:11:57.998 Detail, Node009,   Received: 0x01, 0x07, 0x00, 0x13, 0x6d, 0x00, 0x00, 0x03, 0x85
2017-12-17 21:11:57.998 Detail, Node009,   ZW_SEND_DATA Request with callback ID 0x6d received (expected 0x6d)
2017-12-17 21:11:57.998 Info, Node009, Request RTT 68 Average Request RTT 384
2017-12-17 21:11:57.998 Detail,   Expected callbackId was received
2017-12-17 21:11:58.037 Detail, Node009,   Received: 0x01, 0x08, 0x00, 0x04, 0x00, 0x09, 0x02, 0x98, 0x40, 0x20
2017-12-17 21:11:58.037 Info, Node009, Received SecurityCmd_NonceGet from node 9
2017-12-17 21:11:58.038 Info, NONCES: 0xcf, 0x21, 0x0d, 0x0d, 0x75, 0xc7, 0xb1, 0x71
2017-12-17 21:11:58.038 Info, NONCES: 0x1f, 0x96, 0x94, 0x87, 0x98, 0x5c, 0x4d, 0xe3
2017-12-17 21:11:58.038 Info, NONCES: 0x12, 0x19, 0xec, 0x2b, 0x7b, 0x39, 0xd3, 0x4a
2017-12-17 21:11:58.038 Info, NONCES: 0xa0, 0xd6, 0x4e, 0x38, 0x32, 0x9c, 0x1c, 0xac
2017-12-17 21:11:58.038 Info, NONCES: 0x88, 0x27, 0x8e, 0x03, 0x61, 0x61, 0x4e, 0xbc
2017-12-17 21:11:58.038 Info, NONCES: 0xa5, 0x01, 0x88, 0xd8, 0x9e, 0xa4, 0x84, 0x66
2017-12-17 21:11:58.038 Info, NONCES: 0xfc, 0x56, 0xe5, 0x22, 0x69, 0x01, 0xc8, 0xc6
2017-12-17 21:11:58.038 Info, NONCES: 0x4b, 0x1d, 0xdd, 0xb8, 0x0c, 0x72, 0xfc, 0xb5
2017-12-17 21:11:58.038 Info, Node009, Sending (Send) message (Callback ID=0x01, Expected Reply=0x04) - Nonce_Report - 0x01, 0x11, 0x00, 0x13, 0x09, 0x0a, 0x98, 0x80, 0xa5, 0x01, 0x88, 0xd8, 0x9e, 0xa4, 0x84, 0x66, 0x05, 0x01, 0xce:
2017-12-17 21:11:58.048 Detail, Node009,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2017-12-17 21:11:58.048 Detail, Node009,   ZW_SEND_DATA delivered to Z-Wave stack
2017-12-17 21:11:58.066 Detail, Node009,   Received: 0x01, 0x07, 0x00, 0x13, 0x01, 0x00, 0x00, 0x02, 0xe8
2017-12-17 21:11:58.067 Detail, Node009,   ZW_SEND_DATA Request with callback ID 0x01 received (expected 0x01)
2017-12-17 21:11:58.067 Info, Node009, Request RTT 138 Average Request RTT 261
2017-12-17 21:11:58.089 Detail, Node009,   Received: 0x01, 0x21, 0x00, 0x04, 0x00, 0x09, 0x1b, 0x98, 0x81, 0xbb, 0x56, 0x2f, 0x01, 0x50, 0xea, 0x99, 0x95, 0xc7, 0xe3, 0x89, 0xf3, 0xf6, 0x98, 0x15, 0x46, 0xa5, 0x4a, 0x50, 0x05, 0xf9, 0xde, 0xc4, 0x38, 0x21, 0x87
2017-12-17 21:11:58.095 Info, Raw: 0x98, 0x81, 0xbb, 0x56, 0x2f, 0x01, 0x50, 0xea, 0x99, 0x95, 0xc7, 0xe3, 0x89, 0xf3, 0xf6, 0x98, 0x15, 0x46, 0xa5, 0x4a, 0x50, 0x05, 0xf9, 0xde, 0xc4, 0x38, 0x21, 0x87
2017-12-17 21:11:58.095 Detail, Node009, Decrypted Packet: 0x00, 0x62, 0x03, 0x00, 0x00, 0x02, 0xfe, 0xfe
2017-12-17 21:11:58.095 Detail, 
2017-12-17 21:11:58.095 Info, Node009, Response RTT 166 Average Response RTT 822
2017-12-17 21:11:58.095 Info, Node009, Received DoorLock report: DoorLock is Unsecure
2017-12-17 21:11:58.096 Detail, Node009, Refreshed Value: old value=false, new value=false, type=bool
2017-12-17 21:11:58.096 Detail, Node009, Changes to this value are not verified
2017-12-17 21:11:58.096 Detail, Node009, Refreshed Value: old value=0, new value=0, type=list
2017-12-17 21:11:58.096 Detail, Node009, Changes to this value are not verified
2017-12-17 21:11:58.096 Detail, Node009,   Expected reply and command class was received
2017-12-17 21:11:58.096 Detail, Node009,   Message transaction complete
2017-12-17 21:11:58.096 Detail, 
2017-12-17 21:11:58.096 Detail, Node009, Removing current message
2017-12-17 21:11:58.096 Detail, Node009, Notification: ValueChanged
2017-12-17 21:11:58.109 Detail, Node009, Notification: ValueChanged

@spacesuitdiver
Copy link

@marthoc any luck with this issue? I just tried removing all of the other devices in my zwave network and readding the lock, it works fine just the delay of the reporting status again is annoying as hell. I do not have this issue with SmartThings hub.

@marthoc
Copy link
Contributor Author

marthoc commented Dec 18, 2017

I’m still having the issue. What kind of lock do you have? Same as mine? I notice that in your log you also have a timeout after about 8s to the first request made to the lock by the controller. I think that’s the issue. For some reason that first request always seems to time out for me.

It’s a bit frustrating but eventually my toggle in the frontend and in HomeKit does update to the correct status.

As an aside - what’s your experience like with SmartThings and the lock? What’s the delay like to lock or unlock it? I assume unsatisfactory or you wouldn’t be moving it to HA.

@dshokouhi
Copy link
Member

I have just switched over my schlage lock to home assistant using HUSBZB-1. The range on the stick itself is not that great but I have a light switch right next to it so that probably improves the speed. I don't have much delay if anything. Its a lot faster than smartthings, I think ST's hub simply has better range than most USB sticks. Try adding some devices that act as repeaters.

@marthoc
Copy link
Contributor Author

marthoc commented Dec 18, 2017

I suspect it’s a Kwikset specific issue I’m having with my lock, as no matter how close or far my HUSBZB-1 is from the lock, I get Timeout errors, which slows down the transaction by 8-10 seconds.

@kernehed
Copy link

I have a Danalock V3 and I have some problems aswell. My lock just name itself zwave._ and lock.locked.
The switch just jumps back. I've had luck two times but after reboot is dead.

@spacesuitdiver
Copy link

spacesuitdiver commented Dec 19, 2017

@marthoc I'm using a Kwikset 910, yea I wish someone with more z-wave experience would chime in on the timeout, we definitely aren't the only ones experiencing it nor the only lock brand. @tinkerer on discord attempted to help and seemed to think it was reception issue but this device is not fair away and the hub is one of it's neighbors. I even went so far as to deleting all the other devices I added in case they weren't relaying properly.

I was looking to switch from SmartThings because homebridge seemed formally supported. The homebridge on ST, although it works just fine, is just maintained by one guy. I also think the response time to thermostats is slightly slower because they go up to the cloud to do some massaging I think of the request.

All of that said, I'm back on SmartThings for now, I don't think it's immensely faster I just think it doesn't flip flop between states so it's less annoying.

Here's a screenshot of it working remotely, it's anywhere between 5-10 seconds to complete.

2017-12-19 10_24_46

@marthoc
Copy link
Contributor Author

marthoc commented Dec 19, 2017

@LeBlaaanc I think it has to do with OpenZwave - the problem I think is partly traceable to the fact that all Kwikset locks seem to have the same ID (0001) so there’s no differentiation in the database between locks with keypads and without, etc. I think there’s something in the config specific to this lock that just isn’t coming through. Obviously it works with SmartThings and Wink so it has to be down to the lock’s implementation in OZW. I’ve emailed Kwikset requesting detailed Zwave information for this specific lock but it’s been a couple of weeks since my request with no response so I guess that’s a dead end.

@spacesuitdiver
Copy link

Would anything in SmartThings help us?

@marthoc
Copy link
Contributor Author

marthoc commented Dec 19, 2017

I'm considering raising a issue on the OpenZwave repo (as I'm now pretty sure that the issue is really the timeout and that doesn't have anything to do with Home Assistant but with the actual communications to the lock, which is OZW territory), but unless I get something back from Kwikset I'm not sure how much can be done.

I don't know anything about SmartThings, so I'm not sure. I would expect though that implementing support for various vendors' devices is done at a level that isn't exposed to the user, just like Wink (in Wink, you just select Generic Wave Lock from the list and it pulls in the vendor name and device name once paired, but you can't see the database or anything it's pulling from).

@spacesuitdiver
Copy link

@marthoc it's definitely exposed in ST, I'm just not sure what you need to see. I'll post what I can find related:
image

/**
 * 	Z-Wave Lock
 *
 *  Copyright 2015 SmartThings
 *
 *  Licensed under the Apache License, Version 2.0 (the "License"); you may not use this file except
 *  in compliance with the License. You may obtain a copy of the License at:
 *
 *      http://www.apache.org/licenses/LICENSE-2.0
 *
 *  Unless required by applicable law or agreed to in writing, software distributed under the License is distributed
 *  on an "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the License
 *  for the specific language governing permissions and limitations under the License.
 *
 */
metadata {
	definition (name: "Z-Wave Lock", namespace: "smartthings", author: "SmartThings") {
		capability "Actuator"
		capability "Lock"
		capability "Polling"
		capability "Refresh"
		capability "Sensor"
		capability "Lock Codes"
		capability "Battery"
		capability "Health Check"
		capability "Configuration"

		// Generic
		fingerprint deviceId: "0x4003", inClusters: "0x98"
		fingerprint deviceId: "0x4004", inClusters: "0x98"
		// KwikSet
		fingerprint mfr:"0090", prod:"0001", model:"0236", deviceJoinName: "KwikSet SmartCode 910 Deadbolt Door Lock"
		fingerprint mfr:"0090", prod:"0003", model:"0238", deviceJoinName: "KwikSet SmartCode 910 Deadbolt Door Lock"
		fingerprint mfr:"0090", prod:"0001", model:"0001", deviceJoinName: "KwikSet SmartCode 910 Contemporary Deadbolt Door Lock"
		fingerprint mfr:"0090", prod:"0003", model:"0339", deviceJoinName: "KwikSet SmartCode 912 Lever Door Lock"
		fingerprint mfr:"0090", prod:"0003", model:"4006", deviceJoinName: "KwikSet SmartCode 914 Deadbolt Door Lock" //backlit version
		fingerprint mfr:"0090", prod:"0003", model:"0440", deviceJoinName: "KwikSet SmartCode 914 Deadbolt Door Lock"
		fingerprint mfr:"0090", prod:"0001", model:"0642", deviceJoinName: "KwikSet SmartCode 916 Touchscreen Deadbolt Door Lock"
		fingerprint mfr:"0090", prod:"0003", model:"0642", deviceJoinName: "KwikSet SmartCode 916 Touchscreen Deadbolt Door Lock"
		// Schlage
		fingerprint mfr:"003B", prod:"6341", model:"0544", deviceJoinName: "Schlage Camelot Touchscreen Deadbolt Door Lock"
		fingerprint mfr:"003B", prod:"6341", model:"5044", deviceJoinName: "Schlage Century Touchscreen Deadbolt Door Lock"
		fingerprint mfr:"003B", prod:"634B", model:"504C", deviceJoinName: "Schlage Connected Keypad Lever Door Lock"
		// Yale
		fingerprint mfr:"0129", prod:"0002", model:"0800", deviceJoinName: "Yale Touchscreen Deadbolt Door Lock" // YRD120
		fingerprint mfr:"0129", prod:"0002", model:"0000", deviceJoinName: "Yale Touchscreen Deadbolt Door Lock" // YRD220, YRD240
		fingerprint mfr:"0129", prod:"0002", model:"FFFF", deviceJoinName: "Yale Touchscreen Lever Door Lock" // YRD220
		fingerprint mfr:"0129", prod:"0004", model:"0800", deviceJoinName: "Yale Push Button Deadbolt Door Lock" // YRD110
		fingerprint mfr:"0129", prod:"0004", model:"0000", deviceJoinName: "Yale Push Button Deadbolt Door Lock" // YRD210
		fingerprint mfr:"0129", prod:"0001", model:"0000", deviceJoinName: "Yale Push Button Lever Door Lock" // YRD210
		fingerprint mfr:"0129", prod:"8002", model:"0600", deviceJoinName: "Yale Assure Lock with Bluetooth" //YRD416, YRD426, YRD446
		fingerprint mfr:"0129", prod:"0007", model:"0001", deviceJoinName: "Yale Keyless Connected Smart Door Lock"
		fingerprint mfr:"0129", prod:"8004", model:"0600", deviceJoinName: "Yale Assure Lock Push Button Deadbolt" //YRD216
		// Samsung
		fingerprint mfr:"022E", prod:"0001", model:"0001", deviceJoinName: "Samsung Digital Lock" // SHP-DS705, SHP-DHP728, SHP-DHP525
	}

	simulator {
		status "locked": "command: 9881, payload: 00 62 03 FF 00 00 FE FE"
		status "unlocked": "command: 9881, payload: 00 62 03 00 00 00 FE FE"

		reply "9881006201FF,delay 4200,9881006202": "command: 9881, payload: 00 62 03 FF 00 00 FE FE"
		reply "988100620100,delay 4200,9881006202": "command: 9881, payload: 00 62 03 00 00 00 FE FE"
	}

	tiles(scale: 2) {
		multiAttributeTile(name:"toggle", type: "generic", width: 6, height: 4){
			tileAttribute ("device.lock", key: "PRIMARY_CONTROL") {
				attributeState "locked", label:'locked', action:"lock.unlock", icon:"st.locks.lock.locked", backgroundColor:"#00A0DC", nextState:"unlocking"
				attributeState "unlocked", label:'unlocked', action:"lock.lock", icon:"st.locks.lock.unlocked", backgroundColor:"#ffffff", nextState:"locking"
				attributeState "unlocked with timeout", label:'unlocked', action:"lock.lock", icon:"st.locks.lock.unlocked", backgroundColor:"#ffffff", nextState:"locking"
				attributeState "unknown", label:"unknown", action:"lock.lock", icon:"st.locks.lock.unknown", backgroundColor:"#ffffff", nextState:"locking"
				attributeState "locking", label:'locking', icon:"st.locks.lock.locked", backgroundColor:"#00A0DC"
				attributeState "unlocking", label:'unlocking', icon:"st.locks.lock.unlocked", backgroundColor:"#ffffff"
			}
		}
		standardTile("lock", "device.lock", inactiveLabel: false, decoration: "flat", width: 2, height: 2) {
			state "default", label:'lock', action:"lock.lock", icon:"st.locks.lock.locked", nextState:"locking"
		}
		standardTile("unlock", "device.lock", inactiveLabel: false, decoration: "flat", width: 2, height: 2) {
			state "default", label:'unlock', action:"lock.unlock", icon:"st.locks.lock.unlocked", nextState:"unlocking"
		}
		valueTile("battery", "device.battery", inactiveLabel: false, decoration: "flat", width: 2, height: 2) {
			state "battery", label:'${currentValue}% battery', unit:""
		}
		standardTile("refresh", "device.lock", inactiveLabel: false, decoration: "flat", width: 2, height: 2) {
			state "default", label:'', action:"refresh.refresh", icon:"st.secondary.refresh"
		}

		main "toggle"
		details(["toggle", "lock", "unlock", "battery", "refresh"])
	}
}

import physicalgraph.zwave.commands.doorlockv1.*
import physicalgraph.zwave.commands.usercodev1.*

/**
 * Called on app installed
 */
def installed() {
	// Device-Watch pings if no device events received for 1 hour (checkInterval)
	sendEvent(name: "checkInterval", value: 1 * 60 * 60, displayed: false, data: [protocol: "zwave", hubHardwareId: device.hub.hardwareID, offlinePingable: "1"])
}

/**
 * Called on app uninstalled
 */
def uninstalled() {
	def deviceName = device.displayName
	log.trace "[DTH] Executing 'uninstalled()' for device $deviceName"
	sendEvent(name: "lockRemoved", value: device.id, isStateChange: true, displayed: false)
}

/**
 * Executed when the user taps on the 'Done' button on the device settings screen. Sends the values to lock.
 *
 * @return hubAction: The commands to be executed
 */
def updated() {
	// Device-Watch pings if no device events received for 1 hour (checkInterval)
	sendEvent(name: "checkInterval", value: 1 * 60 * 60, displayed: false, data: [protocol: "zwave", hubHardwareId: device.hub.hardwareID, offlinePingable: "1"])
	def hubAction = null
	try {
		def cmds = []
		if (!state.init || !state.configured) {
			state.init = true
			log.debug "Returning commands for lock operation get and battery get"
			if (!state.configured) {
				cmds << doConfigure()
			}
			cmds << refresh()
			cmds << reloadAllCodes()
			if (!state.MSR) {
				cmds << zwave.manufacturerSpecificV1.manufacturerSpecificGet().format()
			}
			if (!state.fw) {
				cmds << zwave.versionV1.versionGet().format()
			}
			hubAction = response(delayBetween(cmds, 4200))
		}
	} catch (e) {
		log.warn "updated() threw $e"
	}
	hubAction
}

/**
 * Configures the device to settings needed by SmarthThings at device discovery time
 *
 */
def configure() {
	log.trace "[DTH] Executing 'configure()' for device ${device.displayName}"
	def cmds = doConfigure()
	log.debug "Configure returning with commands := $cmds"
	cmds
}

/**
 * Returns the list of commands to be executed when the device is being configured/paired
 *
 */
def doConfigure() {
	log.trace "[DTH] Executing 'doConfigure()' for device ${device.displayName}"
	state.configured = true
	def cmds = []
	cmds << secure(zwave.doorLockV1.doorLockOperationGet())
	cmds << secure(zwave.batteryV1.batteryGet())
	if (isSchlageLock()) {
		cmds << secure(zwave.configurationV2.configurationGet(parameterNumber: getSchlageLockParam().codeLength.number))
	}
	cmds = delayBetween(cmds, 4200)
	log.debug "Do configure returning with commands := $cmds"
	cmds
}

/**
 * Responsible for parsing incoming device messages to generate events
 *
 * @param description: The incoming description from the device
 *
 * @return result: The list of events to be sent out
 *
 */
def parse(String description) {
	log.trace "[DTH] Executing 'parse(String description)' for device ${device.displayName} with description = $description"

	def result = null
	if (description.startsWith("Err")) {
		if (state.sec) {
			result = createEvent(descriptionText:description, isStateChange:true, displayed:false)
		} else {
			result = createEvent(
					descriptionText: "This lock failed to complete the network security key exchange. If you are unable to control it via SmartThings, you must remove it from your network and add it again.",
					eventType: "ALERT",
					name: "secureInclusion",
					value: "failed",
					displayed: true,
					)
		}
	} else {
		def cmd = zwave.parse(description, [ 0x98: 1, 0x72: 2, 0x85: 2, 0x86: 1 ])
		if (cmd) {
			result = zwaveEvent(cmd)
		}
	}
	log.info "[DTH] parse() - returning result=$result"
	result
}

/**
 * Responsible for parsing ConfigurationReport command
 *
 * @param cmd: The ConfigurationReport command to be parsed
 *
 * @return The event(s) to be sent out
 *
 */
def zwaveEvent(physicalgraph.zwave.commands.configurationv2.ConfigurationReport cmd) {
	log.trace "[DTH] Executing 'zwaveEvent(physicalgraph.zwave.commands.configurationv2.ConfigurationReport cmd)' with cmd = $cmd"
	if (isSchlageLock() && cmd.parameterNumber == getSchlageLockParam().codeLength.number) {
		def result = []
		def length = cmd.scaledConfigurationValue
		def deviceName = device.displayName
		log.trace "[DTH] Executing 'ConfigurationReport' for device $deviceName with code length := $length"
		def codeLength = device.currentValue("codeLength")
		if (codeLength && codeLength != length) {
			log.trace "[DTH] Executing 'ConfigurationReport' for device $deviceName - all codes deleted"
			result = allCodesDeletedEvent()
			result << createEvent(name: "codeChanged", value: "all deleted", descriptionText: "Deleted all user codes",
			isStateChange: true, data: [lockName: deviceName, notify: true,
				notificationText: "Deleted all user codes in $deviceName at ${location.name}"])
			result << createEvent(name: "lockCodes", value: util.toJson([:]), displayed: false, descriptionText: "'lockCodes' attribute updated")
		}
		result << createEvent(name:"codeLength", value: length, descriptionText: "Code length is $length", displayed: false)
		return result
	}
	return null
}

/**
 * Responsible for parsing SecurityMessageEncapsulation command
 *
 * @param cmd: The SecurityMessageEncapsulation command to be parsed
 *
 * @return The event(s) to be sent out
 *
 */
def zwaveEvent(physicalgraph.zwave.commands.securityv1.SecurityMessageEncapsulation cmd) {
	log.trace "[DTH] Executing 'zwaveEvent(physicalgraph.zwave.commands.securityv1.SecurityMessageEncapsulation)' with cmd = $cmd"
	def encapsulatedCommand = cmd.encapsulatedCommand([0x62: 1, 0x71: 2, 0x80: 1, 0x85: 2, 0x63: 1, 0x98: 1, 0x86: 1])
	if (encapsulatedCommand) {
		zwaveEvent(encapsulatedCommand)
	}
}

/**
 * Responsible for parsing NetworkKeyVerify command
 *
 * @param cmd: The NetworkKeyVerify command to be parsed
 *
 * @return The event(s) to be sent out
 *
 */
def zwaveEvent(physicalgraph.zwave.commands.securityv1.NetworkKeyVerify cmd) {
	log.trace "[DTH] Executing 'zwaveEvent(physicalgraph.zwave.commands.securityv1.NetworkKeyVerify)' with cmd = $cmd"
	createEvent(name:"secureInclusion", value:"success", descriptionText:"Secure inclusion was successful", isStateChange: true)
}

/**
 * Responsible for parsing SecurityCommandsSupportedReport command
 *
 * @param cmd: The SecurityCommandsSupportedReport command to be parsed
 *
 * @return The event(s) to be sent out
 *
 */
def zwaveEvent(physicalgraph.zwave.commands.securityv1.SecurityCommandsSupportedReport cmd) {
	log.trace "[DTH] Executing 'zwaveEvent(physicalgraph.zwave.commands.securityv1.SecurityCommandsSupportedReport)' with cmd = $cmd"
	state.sec = cmd.commandClassSupport.collect { String.format("%02X ", it) }.join()
	if (cmd.commandClassControl) {
		state.secCon = cmd.commandClassControl.collect { String.format("%02X ", it) }.join()
	}
	createEvent(name:"secureInclusion", value:"success", descriptionText:"Lock is securely included", isStateChange: true)
}

/**
 * Responsible for parsing DoorLockOperationReport command
 *
 * @param cmd: The DoorLockOperationReport command to be parsed
 *
 * @return The event(s) to be sent out
 *
 */
def zwaveEvent(DoorLockOperationReport cmd) {
	log.trace "[DTH] Executing 'zwaveEvent(DoorLockOperationReport)' with cmd = $cmd"
	def result = []
	
	unschedule("followupStateCheck")
	unschedule("stateCheck")
	
	// DoorLockOperationReport is called when trying to read the lock state or when the lock is locked/unlocked from the DTH or the smart app
	def map = [ name: "lock" ]
	map.data = [ lockName: device.displayName ]
	if (cmd.doorLockMode == 0xFF) {
		map.value = "locked"
		map.descriptionText = "Locked"
	} else if (cmd.doorLockMode >= 0x40) {
		map.value = "unknown"
		map.descriptionText = "Unknown state"
	} else if (cmd.doorLockMode == 0x01) {
		map.value = "unlocked with timeout"
		map.descriptionText = "Unlocked with timeout"
	}  else {
		map.value = "unlocked"
		map.descriptionText = "Unlocked"
		if (state.assoc != zwaveHubNodeId) {
			result << response(secure(zwave.associationV1.associationSet(groupingIdentifier:1, nodeId:zwaveHubNodeId)))
			result << response(zwave.associationV1.associationSet(groupingIdentifier:2, nodeId:zwaveHubNodeId))
			result << response(secure(zwave.associationV1.associationGet(groupingIdentifier:1)))
		}
	}
	result ? [createEvent(map), *result] : createEvent(map)
}

/**
 * Responsible for parsing AlarmReport command
 *
 * @param cmd: The AlarmReport command to be parsed
 *
 * @return The event(s) to be sent out
 *
 */
def zwaveEvent(physicalgraph.zwave.commands.alarmv2.AlarmReport cmd) {
	log.trace "[DTH] Executing 'zwaveEvent(physicalgraph.zwave.commands.alarmv2.AlarmReport)' with cmd = $cmd"
	def result = []
	
	if (cmd.zwaveAlarmType == 6) {
		result = handleAccessAlarmReport(cmd)
	} else if (cmd.zwaveAlarmType == 7) {
		result = handleBurglarAlarmReport(cmd)
	} else if(cmd.zwaveAlarmType == 8) {
		result = handleBatteryAlarmReport(cmd)
	} else {
		result = handleAlarmReportUsingAlarmType(cmd)
	}
		
	result = result ?: null
	log.debug "[DTH] zwaveEvent(physicalgraph.zwave.commands.alarmv2.AlarmReport) returning with result = $result"
	result
}

/**
 * Responsible for handling Access AlarmReport command
 *
 * @param cmd: The AlarmReport command to be parsed
 *
 * @return The event(s) to be sent out
 *
 */
private def handleAccessAlarmReport(cmd) {
	log.trace "[DTH] Executing 'handleAccessAlarmReport' with cmd = $cmd"
	def result = []
	def map = null
	def codeID, changeType, lockCodes, codeName
	def deviceName = device.displayName
	lockCodes = loadLockCodes()
	if (1 <= cmd.zwaveAlarmEvent && cmd.zwaveAlarmEvent < 10) {
		map = [ name: "lock", value: (cmd.zwaveAlarmEvent & 1) ? "locked" : "unlocked" ]
	}
	switch(cmd.zwaveAlarmEvent) {
		case 1: // Manually locked
			map.descriptionText = "Locked manually"
			map.data = [ method: (cmd.alarmLevel == 2) ? "keypad" : "manual" ]
			break
		case 2: // Manually unlocked
			map.descriptionText = "Unlocked manually"
			map.data = [ method: "manual" ]
			break
		case 3: // Locked by command
			map.descriptionText = "Locked"
			map.data = [ method: "command" ]
			break
		case 4: // Unlocked by command
			map.descriptionText = "Unlocked"
			map.data = [ method: "command" ]
			break
		case 5: // Locked with keypad
			if (cmd.eventParameter || cmd.alarmLevel) {
				codeID = cmd.eventParameter[2] ?: cmd.alarmLevel
				codeName = getCodeName(lockCodes, codeID)
				map.descriptionText = "Locked by \"$codeName\""
				map.data = [ usedCode: codeID, codeName: codeName, method: "keypad" ]
			} else {
				// locked by pressing the Schlage button
				map.descriptionText = "Locked manually"
			}
			break
		case 6: // Unlocked with keypad
			if (cmd.eventParameter || cmd.alarmLevel) {
				codeID = cmd.eventParameter[2] ?: cmd.alarmLevel
				codeName = getCodeName(lockCodes, codeID)
				map.descriptionText = "Unlocked by \"$codeName\""
				map.data = [ usedCode: codeID, codeName: codeName, method: "keypad" ]
			}
			break
		case 7:
			map = [ name: "lock", value: "unknown", descriptionText: "Unknown state" ]
			map.data = [ method: "manual" ]
			break
		case 8:
			map = [ name: "lock", value: "unknown", descriptionText: "Unknown state" ]
			map.data = [ method: "command" ]
			break
		case 9: // Auto locked
			map = [ name: "lock", value: "locked", data: [ method: "auto" ] ]
			map.descriptionText = "Auto locked"
			break
		case 0xA:
			map = [ name: "lock", value: "unknown", descriptionText: "Unknown state" ]
			map.data = [ method: "auto" ]
			break
		case 0xB:
			map = [ name: "lock", value: "unknown", descriptionText: "Unknown state" ]
			break
		case 0xC: // All user codes deleted
			result = allCodesDeletedEvent()
			map = [ name: "codeChanged", value: "all deleted", descriptionText: "Deleted all user codes", isStateChange: true ]
			map.data = [notify: true, notificationText: "Deleted all user codes in $deviceName at ${location.name}"]
			result << createEvent(name: "lockCodes", value: util.toJson([:]), displayed: false, descriptionText: "'lockCodes' attribute updated")
			break
		case 0xD: // User code deleted
			if (cmd.eventParameter || cmd.alarmLevel) {
				codeID = cmd.eventParameter[2] ?: cmd.alarmLevel
				if (lockCodes[codeID.toString()]) {
					codeName = getCodeName(lockCodes, codeID)
					map = [ name: "codeChanged", value: "$codeID deleted", isStateChange: true ]
					map.descriptionText = "Deleted \"$codeName\""
					map.data = [ codeName: codeName, notify: true, notificationText: "Deleted \"$codeName\" in $deviceName at ${location.name}" ]
					result << codeDeletedEvent(lockCodes, codeID)
				}
			}
			break
		case 0xE: // Master or user code changed/set
			if (cmd.eventParameter || cmd.alarmLevel) {
				codeID = cmd.eventParameter[2] ?: cmd.alarmLevel
				if(codeID == 0 && isKwiksetLock()) {
					//Ignoring this AlarmReport as Kwikset reports codeID 0 when all slots are full and user tries to set another lock code manually
					//Kwikset locks don't send AlarmReport when Master code is set
					log.trace "Ignoring this alarm report in case of Kwikset locks"
					break
				}
				codeName = getCodeNameFromState(lockCodes, codeID)
				changeType = getChangeType(lockCodes, codeID)
				map = [ name: "codeChanged", value: "$codeID $changeType",  descriptionText: "${getStatusForDescription(changeType)} \"$codeName\"", isStateChange: true ]
				map.data = [ codeName: codeName, notify: true, notificationText: "${getStatusForDescription(changeType)} \"$codeName\" in $deviceName at ${location.name}" ]
				if(!isMasterCode(codeID)) {
					result << codeSetEvent(lockCodes, codeID, codeName)
				} else {
					map.descriptionText = "${getStatusForDescription('set')} \"$codeName\""
					map.data.notificationText = "${getStatusForDescription('set')} \"$codeName\" in $deviceName at ${location.name}"
				}
			}
			break
		case 0xF: // Duplicate Pin-code error
			if (cmd.eventParameter || cmd.alarmLevel) {
				codeID = cmd.eventParameter[2] ?: cmd.alarmLevel
				clearStateForSlot(codeID)
				map = [ name: "codeChanged", value: "$codeID failed", descriptionText: "User code is duplicate and not added",
					isStateChange: true, data: [isCodeDuplicate: true] ]
			}
			break
		case 0x10: // Tamper Alarm
		case 0x13:
			map = [ name: "tamper", value: "detected", descriptionText: "Keypad attempts exceed code entry limit", isStateChange: true, displayed: true ]
			break
		case 0x11: // Keypad busy
			map = [ descriptionText: "Keypad is busy" ]
			break
		case 0x12: // Master code changed
			codeName = getCodeNameFromState(lockCodes, 0)
			map = [ name: "codeChanged", value: "0 set", descriptionText: "${getStatusForDescription('set')} \"$codeName\"", isStateChange: true ]
			map.data = [ codeName: codeName, notify: true, notificationText: "${getStatusForDescription('set')} \"$codeName\" in $deviceName at ${location.name}" ]
			break
		case 0xFE:
			// delegating it to handleAlarmReportUsingAlarmType
			return handleAlarmReportUsingAlarmType(cmd)
		default:
			// delegating it to handleAlarmReportUsingAlarmType
			return handleAlarmReportUsingAlarmType(cmd)
	}
	
	if (map) {
		if (map.data) {
			map.data.lockName = deviceName
		} else {
			map.data = [ lockName: deviceName ]
		}
		result << createEvent(map)
	}
	result = result.flatten()
	result
}

/**
 * Responsible for handling Burglar AlarmReport command
 *
 * @param cmd: The AlarmReport command to be parsed
 *
 * @return The event(s) to be sent out
 *
 */
private def handleBurglarAlarmReport(cmd) {
	log.trace "[DTH] Executing 'handleBurglarAlarmReport' with cmd = $cmd"
	def result = []
	def deviceName = device.displayName
	
	def map = [ name: "tamper", value: "detected" ]
	map.data = [ lockName: deviceName ]
	switch (cmd.zwaveAlarmEvent) {
		case 0:
			map.value = "clear"
			map.descriptionText = "Tamper alert cleared"
			break
		case 1:
		case 2:
			map.descriptionText = "Intrusion attempt detected"
			break
		case 3:
			map.descriptionText = "Covering removed"
			break
		case 4:
			map.descriptionText = "Invalid code"
			break
		default:
			// delegating it to handleAlarmReportUsingAlarmType
			return handleAlarmReportUsingAlarmType(cmd)
	}
	
	result << createEvent(map)
	result
}

/**
 * Responsible for handling Battery AlarmReport command
 *
 * @param cmd: The AlarmReport command to be parsed
 *
 * @return The event(s) to be sent out
 */
private def handleBatteryAlarmReport(cmd) {
	log.trace "[DTH] Executing 'handleBatteryAlarmReport' with cmd = $cmd"
	def result = []
	def deviceName = device.displayName
	def map = null
	switch(cmd.zwaveAlarmEvent) {
		case 0x0A:
			map = [ name: "battery", value: 1, descriptionText: "Battery level critical", displayed: true, data: [ lockName: deviceName ] ]
			break
		case 0x0B:
			map = [ name: "battery", value: 0, descriptionText: "Battery too low to operate lock", isStateChange: true, displayed: true, data: [ lockName: deviceName ] ]
			break
		default:
			// delegating it to handleAlarmReportUsingAlarmType
			return handleAlarmReportUsingAlarmType(cmd)
	}
	result << createEvent(map)
	result
}

/**
 * Responsible for handling AlarmReport commands which are ignored by Access & Burglar handlers
 *
 * @param cmd: The AlarmReport command to be parsed
 *
 * @return The event(s) to be sent out
 *
 */
private def handleAlarmReportUsingAlarmType(cmd) {
	log.trace "[DTH] Executing 'handleAlarmReportUsingAlarmType' with cmd = $cmd"
	def result = []
	def map = null
	def codeID, lockCodes, codeName
	def deviceName = device.displayName
	lockCodes = loadLockCodes()
	switch(cmd.alarmType) {
		case 9:
		case 17:
			map = [ name: "lock", value: "unknown", descriptionText: "Unknown state" ]
			break
		case 16: // Note: for levers this means it's unlocked, for non-motorized deadbolt, it's just unsecured and might not get unlocked
		case 19: // Unlocked with keypad
			map = [ name: "lock", value: "unlocked" ]
			if (cmd.alarmLevel != null) {
				codeID = cmd.alarmLevel
				codeName = getCodeName(lockCodes, codeID)
				map.descriptionText = "Unlocked by \"$codeName\""
				map.data = [ usedCode: codeID, codeName: codeName, method: "keypad" ]
			}
			break
		case 18: // Locked with keypad
			codeID = cmd.alarmLevel
			map = [ name: "lock", value: "locked" ]
			// Kwikset lock reporting code id as 0 when locked using the lock keypad button
			if (isKwiksetLock() && codeID == 0) {
				map.descriptionText = "Locked manually"
				map.data = [ method: "manual" ]
			} else {
				codeName = getCodeName(lockCodes, codeID)
				map.descriptionText = "Locked by \"$codeName\""
				map.data = [ usedCode: codeID, codeName: codeName, method: "keypad" ]
			}
			break
		case 21: // Manually locked
			map = [ name: "lock", value: "locked", data: [ method: (cmd.alarmLevel == 2) ? "keypad" : "manual" ] ]
			map.descriptionText = "Locked manually"
			break
		case 22: // Manually unlocked
			map = [ name: "lock", value: "unlocked", data: [ method: "manual" ] ]
			map.descriptionText = "Unlocked manually"
			break
		case 23:
			map = [ name: "lock", value: "unknown", descriptionText: "Unknown state" ]
			map.data = [ method: "command" ]
			break
		case 24: // Locked by command
			map = [ name: "lock", value: "locked", data: [ method: "command" ] ]
			map.descriptionText = "Locked"
			break
		case 25: // Unlocked by command
			map = [ name: "lock", value: "unlocked", data: [ method: "command" ] ]
			map.descriptionText = "Unlocked"
			break
		case 26:
			map = [ name: "lock", value: "unknown", descriptionText: "Unknown state" ]
			map.data = [ method: "auto" ]
			break
		case 27: // Auto locked
			map = [ name: "lock", value: "locked", data: [ method: "auto" ] ]
			map.descriptionText = "Auto locked"
			break
		case 32: // All user codes deleted
			result = allCodesDeletedEvent()
			map = [ name: "codeChanged", value: "all deleted", descriptionText: "Deleted all user codes", isStateChange: true ]
			map.data = [notify: true, notificationText: "Deleted all user codes in $deviceName at ${location.name}"]
			result << createEvent(name: "lockCodes", value: util.toJson([:]), displayed: false, descriptionText: "'lockCodes' attribute updated")
			break
		case 33: // User code deleted
			codeID = cmd.alarmLevel
			if (lockCodes[codeID.toString()]) {
				codeName = getCodeName(lockCodes, codeID)
				map = [ name: "codeChanged", value: "$codeID deleted", isStateChange: true ]
				map.descriptionText = "Deleted \"$codeName\""
				map.data = [ codeName: codeName, notify: true, notificationText: "Deleted \"$codeName\" in $deviceName at ${location.name}" ]
				result << codeDeletedEvent(lockCodes, codeID)
			}
			break
		case 38: // Non Access
			map = [ descriptionText: "A Non Access Code was entered at the lock", isStateChange: true ]
			break
		case 13:
		case 112: // Master or user code changed/set
			codeID = cmd.alarmLevel
			if(codeID == 0 && isKwiksetLock()) {
				//Ignoring this AlarmReport as Kwikset reports codeID 0 when all slots are full and user tries to set another lock code manually
				//Kwikset locks don't send AlarmReport when Master code is set
				log.trace "Ignoring this alarm report in case of Kwikset locks"
				break
			}
			codeName = getCodeNameFromState(lockCodes, codeID)
			def changeType = getChangeType(lockCodes, codeID)
			map = [ name: "codeChanged", value: "$codeID $changeType", descriptionText:
				"${getStatusForDescription(changeType)} \"$codeName\"", isStateChange: true ]
			map.data = [ codeName: codeName, notify: true, notificationText: "${getStatusForDescription(changeType)} \"$codeName\" in $deviceName at ${location.name}" ]
			if(!isMasterCode(codeID)) {
				result << codeSetEvent(lockCodes, codeID, codeName)
			} else {
				map.descriptionText = "${getStatusForDescription('set')} \"$codeName\""
				map.data.notificationText = "${getStatusForDescription('set')} \"$codeName\" in $deviceName at ${location.name}"
			}
			break
		case 34:
		case 113: // Duplicate Pin-code error
			codeID = cmd.alarmLevel
			clearStateForSlot(codeID)
			map = [ name: "codeChanged", value: "$codeID failed", descriptionText: "User code is duplicate and not added",
				isStateChange: true, data: [isCodeDuplicate: true] ]
			break
		case 130:  // Batteries replaced
			map = [ descriptionText: "Batteries replaced", isStateChange: true ]
			break
		case 131: // Disabled user entered at keypad
			map = [ descriptionText: "Code ${cmd.alarmLevel} is disabled", isStateChange: false ]
			break
		case 161: // Tamper Alarm
			if (cmd.alarmLevel == 2) {
				map = [ name: "tamper", value: "detected", descriptionText: "Front escutcheon removed", isStateChange: true ]
			} else {
				map = [ name: "tamper", value: "detected", descriptionText: "Keypad attempts exceed code entry limit", isStateChange: true, displayed: true ]
			}
			break
		case 167: // Low Battery Alarm
			if (!state.lastbatt || now() - state.lastbatt > 12*60*60*1000) {
				map = [ descriptionText: "Battery low", isStateChange: true ]
				result << response(secure(zwave.batteryV1.batteryGet()))
			} else {
				map = [ name: "battery", value: device.currentValue("battery"), descriptionText: "Battery low", isStateChange: true ]
			}
			break
		case 168: // Critical Battery Alarms
			map = [ name: "battery", value: 1, descriptionText: "Battery level critical", displayed: true ]
			break
		case 169: // Battery too low to operate
			map = [ name: "battery", value: 0, descriptionText: "Battery too low to operate lock", isStateChange: true, displayed: true ]
			break
		default:
			map = [ displayed: false, descriptionText: "Alarm event ${cmd.alarmType} level ${cmd.alarmLevel}" ]
			break
	}
	
	if (map) {
		if (map.data) {
			map.data.lockName = deviceName
		} else {
			map.data = [ lockName: deviceName ]
		}
		result << createEvent(map)
	}
	result = result.flatten()
	result
}

/**
 * Responsible for parsing UserCodeReport command
 *
 * @param cmd: The UserCodeReport command to be parsed
 *
 * @return The event(s) to be sent out
 *
 */
def zwaveEvent(UserCodeReport cmd) {
	log.trace "[DTH] Executing 'zwaveEvent(UserCodeReport)' with userIdentifier: ${cmd.userIdentifier} and status: ${cmd.userIdStatus}"
	def result = []
	// cmd.userIdentifier seems to be an int primitive type
	def codeID = cmd.userIdentifier.toString()
	def lockCodes = loadLockCodes()
	def map = [ name: "codeChanged", isStateChange: true ]
	def deviceName = device.displayName
	def userIdStatus = cmd.userIdStatus
	
	if (userIdStatus == UserCodeReport.USER_ID_STATUS_OCCUPIED ||
				(userIdStatus == UserCodeReport.USER_ID_STATUS_STATUS_NOT_AVAILABLE && cmd.user)) {
				
		def codeName
		
		// Schlage locks sends a blank/empty code during code creation/updation where as it sends "**********" during scanning
		// Some Schlage locks send "**********" during code creation also. The state check will work for them
		if ((!cmd.code || state["setname$codeID"]) && isSchlageLock()) {
			// this will be executed when the user tries to create/update a user code through the
			// smart app or manually on the lock. This is specific to Schlage locks.
			log.trace "[DTH] User code creation successful for Schlage lock"
			codeName = getCodeNameFromState(lockCodes, codeID)
			def changeType = getChangeType(lockCodes, codeID)

			map.value = "$codeID $changeType"
			map.isStateChange = true
			map.descriptionText = "${getStatusForDescription(changeType)} \"$codeName\""
			map.data = [ codeName: codeName, lockName: deviceName, notify: true, notificationText: "${getStatusForDescription(changeType)} \"$codeName\" in $deviceName at ${location.name}" ]
			if(!isMasterCode(codeID)) {
				result << codeSetEvent(lockCodes, codeID, codeName)
			} else {
				map.descriptionText = "${getStatusForDescription('set')} \"$codeName\""
				map.data.notificationText = "${getStatusForDescription('set')} \"$codeName\" in $deviceName at ${location.name}"
				map.data.lockName = deviceName
			}
		} else {
			// We'll land here during scanning of codes
			codeName = getCodeName(lockCodes, codeID)
			def changeType = getChangeType(lockCodes, codeID)
			if (!lockCodes[codeID]) {
				result << codeSetEvent(lockCodes, codeID, codeName)
			} else {
				map.displayed = false
			}
			map.value = "$codeID $changeType"
			map.descriptionText = "${getStatusForDescription(changeType)} \"$codeName\""
			map.data = [ codeName: codeName, lockName: deviceName ]
		}
	} else if(userIdStatus == 254 && isSchlageLock()) {
		// This is code creation/updation error for Schlage locks.
		// It should be OK to mark this as duplicate pin code error since in case the batteries are down, or lock is not in range,
		// or wireless interference is there, the UserCodeReport will anyway not be received.
		map = [ name: "codeChanged", value: "$codeID failed", descriptionText: "User code is not added", isStateChange: true,
			data: [ lockName: deviceName, isCodeDuplicate: true] ]
	} else {
		// We are using userIdStatus here because codeID = 0 is reported when user tries to set programming code as the user code
		if (codeID == "0" && userIdStatus == UserCodeReport.USER_ID_STATUS_AVAILABLE_NOT_SET && isSchlageLock()) {
			// all codes deleted for Schlage locks
			log.trace "[DTH] All user codes deleted for Schlage lock"
			result << allCodesDeletedEvent()
			map = [ name: "codeChanged", value: "all deleted", descriptionText: "Deleted all user codes", isStateChange: true,
				data: [ lockName: deviceName, notify: true,
					notificationText: "Deleted all user codes in $deviceName at ${location.name}"] ]
			lockCodes = [:]
			result << lockCodesEvent(lockCodes)
		} else {
			// code is not set
			if (lockCodes[codeID]) {
				def codeName = getCodeName(lockCodes, codeID)
				map.value = "$codeID deleted"
				map.descriptionText = "Deleted \"$codeName\""
				map.data = [ codeName: codeName, lockName: deviceName, notify: true, notificationText: "Deleted \"$codeName\" in $deviceName at ${location.name}" ]
				result << codeDeletedEvent(lockCodes, codeID)
			} else {
				map.value = "$codeID unset"
				map.displayed = false
				map.data = [ lockName: deviceName ]
			}
		}
	}
	
	clearStateForSlot(codeID)
	result << createEvent(map)
	
	if (codeID.toInteger() == state.checkCode) {  // reloadAllCodes() was called, keep requesting the codes in order
		if (state.checkCode + 1 > state.codes || state.checkCode >= 8) {
			state.remove("checkCode")  // done
			state["checkCode"] = null
			sendEvent(name: "scanCodes", value: "Complete", descriptionText: "Code scan completed", displayed: false)
		} else {
			state.checkCode = state.checkCode + 1  // get next
			result << response(requestCode(state.checkCode))
		}
	}
	if (codeID == state.pollCode) {
		if (state.pollCode + 1 > state.codes || state.pollCode >= 15) {
			state.remove("pollCode")  // done
			state["pollCode"] = null
		} else {
			state.pollCode = state.pollCode + 1
		}
	}

	result = result.flatten()
	result
}

/**
 * Responsible for parsing UsersNumberReport command
 *
 * @param cmd: The UsersNumberReport command to be parsed
 *
 * @return The event(s) to be sent out
 *
 */
def zwaveEvent(UsersNumberReport cmd) {
	log.trace "[DTH] Executing 'zwaveEvent(UsersNumberReport)' with cmd = $cmd"
	def result = [createEvent(name: "maxCodes", value: cmd.supportedUsers, displayed: false)]
	state.codes = cmd.supportedUsers
	if (state.checkCode) {
		if (state.checkCode <= cmd.supportedUsers) {
			result << response(requestCode(state.checkCode))
		} else {
			state.remove("checkCode")
			state["checkCode"] = null
		}
	}
	result
}

/**
 * Responsible for parsing AssociationReport command
 *
 * @param cmd: The AssociationReport command to be parsed
 *
 * @return The event(s) to be sent out
 *
 */
def zwaveEvent(physicalgraph.zwave.commands.associationv2.AssociationReport cmd) {
	log.trace "[DTH] Executing 'zwaveEvent(physicalgraph.zwave.commands.associationv2.AssociationReport)' with cmd = $cmd"
	def result = []
	if (cmd.nodeId.any { it == zwaveHubNodeId }) {
		state.remove("associationQuery")
		state["associationQuery"] = null
		result << createEvent(descriptionText: "Is associated")
		state.assoc = zwaveHubNodeId
		if (cmd.groupingIdentifier == 2) {
			result << response(zwave.associationV1.associationRemove(groupingIdentifier:1, nodeId:zwaveHubNodeId))
		}
	} else if (cmd.groupingIdentifier == 1) {
		result << response(secure(zwave.associationV1.associationSet(groupingIdentifier:1, nodeId:zwaveHubNodeId)))
	} else if (cmd.groupingIdentifier == 2) {
		result << response(zwave.associationV1.associationSet(groupingIdentifier:2, nodeId:zwaveHubNodeId))
	}
	result
}

/**
 * Responsible for parsing TimeGet command
 *
 * @param cmd: The TimeGet command to be parsed
 *
 * @return The event(s) to be sent out
 *
 */
def zwaveEvent(physicalgraph.zwave.commands.timev1.TimeGet cmd) {
	log.trace "[DTH] Executing 'zwaveEvent(physicalgraph.zwave.commands.timev1.TimeGet)' with cmd = $cmd"
	def result = []
	def now = new Date().toCalendar()
	if(location.timeZone) now.timeZone = location.timeZone
	result << createEvent(descriptionText: "Requested time update", displayed: false)
	result << response(secure(zwave.timeV1.timeReport(
		hourLocalTime: now.get(Calendar.HOUR_OF_DAY),
		minuteLocalTime: now.get(Calendar.MINUTE),
		secondLocalTime: now.get(Calendar.SECOND)))
	)
	result
}

/**
 * Responsible for parsing BasicSet command
 *
 * @param cmd: The BasicSet command to be parsed
 *
 * @return The event(s) to be sent out
 *
 */
def zwaveEvent(physicalgraph.zwave.commands.basicv1.BasicSet cmd) {
	log.trace "[DTH] Executing 'zwaveEvent(physicalgraph.zwave.commands.basicv1.BasicSet)' with cmd = $cmd"
	// The old Schlage locks use group 1 for basic control - we don't want that, so unsubscribe from group 1
	def result = [ createEvent(name: "lock", value: cmd.value ? "unlocked" : "locked") ]
	def cmds = [
			zwave.associationV1.associationRemove(groupingIdentifier:1, nodeId:zwaveHubNodeId).format(),
			"delay 1200",
			zwave.associationV1.associationGet(groupingIdentifier:2).format()
	]
	[result, response(cmds)]
}

/**
 * Responsible for parsing BatteryReport command
 *
 * @param cmd: The BatteryReport command to be parsed
 *
 * @return The event(s) to be sent out
 *
 */
def zwaveEvent(physicalgraph.zwave.commands.batteryv1.BatteryReport cmd) {
	log.trace "[DTH] Executing 'zwaveEvent(physicalgraph.zwave.commands.batteryv1.BatteryReport)' with cmd = $cmd"
	def map = [ name: "battery", unit: "%" ]
	if (cmd.batteryLevel == 0xFF) {
		map.value = 1
		map.descriptionText = "Has a low battery"
	} else {
		map.value = cmd.batteryLevel
		map.descriptionText = "Battery is at ${cmd.batteryLevel}%"
	}
	state.lastbatt = now()
	createEvent(map)
}

/**
 * Responsible for parsing ManufacturerSpecificReport command
 *
 * @param cmd: The ManufacturerSpecificReport command to be parsed
 *
 * @return The event(s) to be sent out
 *
 */
def zwaveEvent(physicalgraph.zwave.commands.manufacturerspecificv2.ManufacturerSpecificReport cmd) {
	log.trace "[DTH] Executing 'zwaveEvent(physicalgraph.zwave.commands.manufacturerspecificv2.ManufacturerSpecificReport)' with cmd = $cmd"
	def result = []
	def msr = String.format("%04X-%04X-%04X", cmd.manufacturerId, cmd.productTypeId, cmd.productId)
	updateDataValue("MSR", msr)
	result << createEvent(descriptionText: "MSR: $msr", isStateChange: false)
	result
}

/**
 * Responsible for parsing VersionReport command
 *
 * @param cmd: The VersionReport command to be parsed
 *
 * @return The event(s) to be sent out
 *
 */
def zwaveEvent(physicalgraph.zwave.commands.versionv1.VersionReport cmd) {
	log.trace "[DTH] Executing 'zwaveEvent(physicalgraph.zwave.commands.versionv1.VersionReport)' with cmd = $cmd"
	def fw = "${cmd.applicationVersion}.${cmd.applicationSubVersion}"
	updateDataValue("fw", fw)
	if (getDataValue("MSR") == "003B-6341-5044") {
		updateDataValue("ver", "${cmd.applicationVersion >> 4}.${cmd.applicationVersion & 0xF}")
	}
	def text = "${device.displayName}: firmware version: $fw, Z-Wave version: ${cmd.zWaveProtocolVersion}.${cmd.zWaveProtocolSubVersion}"
	createEvent(descriptionText: text, isStateChange: false)
}

/**
 * Responsible for parsing ApplicationBusy command
 *
 * @param cmd: The ApplicationBusy command to be parsed
 *
 * @return The event(s) to be sent out
 *
 */
def zwaveEvent(physicalgraph.zwave.commands.applicationstatusv1.ApplicationBusy cmd) {
	log.trace "[DTH] Executing 'zwaveEvent(physicalgraph.zwave.commands.applicationstatusv1.ApplicationBusy)' with cmd = $cmd"
	def msg = cmd.status == 0 ? "try again later" :
			  cmd.status == 1 ? "try again in ${cmd.waitTime} seconds" :
			  cmd.status == 2 ? "request queued" : "sorry"
	createEvent(displayed: true, descriptionText: "Is busy, $msg")
}

/**
 * Responsible for parsing ApplicationRejectedRequest command
 *
 * @param cmd: The ApplicationRejectedRequest command to be parsed
 *
 * @return The event(s) to be sent out
 *
 */
def zwaveEvent(physicalgraph.zwave.commands.applicationstatusv1.ApplicationRejectedRequest cmd) {
	log.trace "[DTH] Executing 'zwaveEvent(physicalgraph.zwave.commands.applicationstatusv1.ApplicationRejectedRequest)' with cmd = $cmd"
	createEvent(displayed: true, descriptionText: "Rejected the last request")
}

/**
 * Responsible for parsing zwave command
 *
 * @param cmd: The zwave command to be parsed
 *
 * @return The event(s) to be sent out
 *
 */
def zwaveEvent(physicalgraph.zwave.Command cmd) {
	log.trace "[DTH] Executing 'zwaveEvent(physicalgraph.zwave.Command)' with cmd = $cmd"
	createEvent(displayed: false, descriptionText: "$cmd")
}

/**
 * Executes lock and then check command with a delay on a lock
 */
def lockAndCheck(doorLockMode) {
	secureSequence([
		zwave.doorLockV1.doorLockOperationSet(doorLockMode: doorLockMode),
		zwave.doorLockV1.doorLockOperationGet()
	], 4200)
}

/**
 * Executes lock command on a lock
 */
def lock() {
	log.trace "[DTH] Executing lock() for device ${device.displayName}"
	lockAndCheck(DoorLockOperationSet.DOOR_LOCK_MODE_DOOR_SECURED)
}

/**
 * Executes unlock command on a lock
 */
def unlock() {
	log.trace "[DTH] Executing unlock() for device ${device.displayName}"
	lockAndCheck(DoorLockOperationSet.DOOR_LOCK_MODE_DOOR_UNSECURED)
}

/**
 * Executes unlock with timeout command on a lock
 */
def unlockWithTimeout() {
	log.trace "[DTH] Executing unlockWithTimeout() for device ${device.displayName}"
	lockAndCheck(DoorLockOperationSet.DOOR_LOCK_MODE_DOOR_UNSECURED_WITH_TIMEOUT)
}

/**
 * PING is used by Device-Watch in attempt to reach the Device
 */
def ping() {
	log.trace "[DTH] Executing ping() for device ${device.displayName}"
	runIn(30, followupStateCheck)
	secure(zwave.doorLockV1.doorLockOperationGet())
}

/**
 * Checks the door lock state. Also, schedules checking of door lock state every one hour.
 */
def followupStateCheck() {
	runEvery1Hour(stateCheck)
	stateCheck()
}

/**
 * Checks the door lock state
 */
def stateCheck() {
	sendHubCommand(new physicalgraph.device.HubAction(secure(zwave.doorLockV1.doorLockOperationGet())))
}

/**
 * Called when the user taps on the refresh button
 */
def refresh() {
	log.trace "[DTH] Executing refresh() for device ${device.displayName}"

	def cmds = secureSequence([zwave.doorLockV1.doorLockOperationGet(), zwave.batteryV1.batteryGet()])
	if (!state.associationQuery) {
		cmds << "delay 4200"
		cmds << zwave.associationV1.associationGet(groupingIdentifier:2).format()  // old Schlage locks use group 2 and don't secure the Association CC
		cmds << secure(zwave.associationV1.associationGet(groupingIdentifier:1))
		state.associationQuery = now()
	} else if (now() - state.associationQuery.toLong() > 9000) {
		cmds << "delay 6000"
		cmds << zwave.associationV1.associationSet(groupingIdentifier:2, nodeId:zwaveHubNodeId).format()
		cmds << secure(zwave.associationV1.associationSet(groupingIdentifier:1, nodeId:zwaveHubNodeId))
		cmds << zwave.associationV1.associationGet(groupingIdentifier:2).format()
		cmds << secure(zwave.associationV1.associationGet(groupingIdentifier:1))
		state.associationQuery = now()
	}
	cmds
}

/**
 * Called by the Smart Things platform in case Polling capability is added to the device type
 */
def poll() {
	log.trace "[DTH] Executing poll() for device ${device.displayName}"
	def cmds = []
	// Only check lock state if it changed recently or we haven't had an update in an hour
	def latest = device.currentState("lock")?.date?.time
	if (!latest || !secondsPast(latest, 6 * 60) || secondsPast(state.lastPoll, 55 * 60)) {
		cmds << secure(zwave.doorLockV1.doorLockOperationGet())
		state.lastPoll = now()
	} else if (!state.lastbatt || now() - state.lastbatt > 53*60*60*1000) {
		cmds << secure(zwave.batteryV1.batteryGet())
		state.lastbatt = now()  //inside-214
	}
	if (state.assoc != zwaveHubNodeId && secondsPast(state.associationQuery, 19 * 60)) {
		cmds << zwave.associationV1.associationSet(groupingIdentifier:2, nodeId:zwaveHubNodeId).format()
		cmds << secure(zwave.associationV1.associationSet(groupingIdentifier:1, nodeId:zwaveHubNodeId))
		cmds << zwave.associationV1.associationGet(groupingIdentifier:2).format()
		cmds << "delay 6000"
		cmds << secure(zwave.associationV1.associationGet(groupingIdentifier:1))
		cmds << "delay 6000"
		state.associationQuery = now()
	} else {
		// Only check lock state once per hour
		if (secondsPast(state.lastPoll, 55 * 60)) {
			cmds << secure(zwave.doorLockV1.doorLockOperationGet())
			state.lastPoll = now()
		} else if (!state.MSR) {
			cmds << zwave.manufacturerSpecificV1.manufacturerSpecificGet().format()
		} else if (!state.fw) {
			cmds << zwave.versionV1.versionGet().format()
		} else if (!device.currentValue("maxCodes")) {
			state.pollCode = 1
			cmds << secure(zwave.userCodeV1.usersNumberGet())
		} else if (state.pollCode && state.pollCode <= state.codes) {
			cmds << requestCode(state.pollCode)
		} else if (!state.lastbatt || now() - state.lastbatt > 53*60*60*1000) {
			cmds << secure(zwave.batteryV1.batteryGet())
		}
	}

	if (cmds) {
		log.debug "poll is sending ${cmds.inspect()}"
		cmds
	} else {
		// workaround to keep polling from stopping due to lack of activity
		sendEvent(descriptionText: "skipping poll", isStateChange: true, displayed: false)
		null
	}
}

/**
 * Returns the command for user code get
 *
 * @param codeID: The code slot number
 *
 * @return The command for user code get
 */
def requestCode(codeID) {
	secure(zwave.userCodeV1.userCodeGet(userIdentifier: codeID))
}

/**
 * API endpoint for server smart app to populate the attributes. Called only when the attributes are not populated.
 *
 * @return The command(s) fired for reading attributes
 */
def reloadAllCodes() {
	log.trace "[DTH] Executing 'reloadAllCodes()' by ${device.displayName}"
	sendEvent(name: "scanCodes", value: "Scanning", descriptionText: "Code scan in progress", displayed: false)
	def lockCodes = loadLockCodes()
	sendEvent(lockCodesEvent(lockCodes))
	state.checkCode = state.checkCode ?: 1

	def cmds = []
	// Not calling validateAttributes() here because userNumberGet command will be added twice
	if(!device.currentValue("codeLength") && isSchlageLock()) {
		cmds << secure(zwave.configurationV2.configurationGet(parameterNumber: getSchlageLockParam().codeLength.number))
	}
	if (!state.codes) {
		// BUG: There might be a bug where Schlage does not return the below number of codes
		cmds << secure(zwave.userCodeV1.usersNumberGet())
	} else {
		sendEvent(name: "maxCodes", value: state.codes, displayed: false)
		cmds << requestCode(state.checkCode)
	}
	if(cmds.size() > 1) {
		cmds = delayBetween(cmds, 4200)
	}
	cmds
}

/**
 * API endpoint for setting the user code length on a lock. This is specific to Schlage locks.
 *
 * @param length: The user code length
 *
 * @returns The command fired for writing the code length attribute
 */
def setCodeLength(length) {
	if (isSchlageLock()) {
		length = length.toInteger()
		if (length >= 4 && length <= 8) {
			log.trace "[DTH] Executing 'setCodeLength()' by ${device.displayName}"
			def val = []
			val << length
			def param = getSchlageLockParam()
			return secure(zwave.configurationV2.configurationSet(parameterNumber: param.codeLength.number, size: param.codeLength.size, configurationValue: val))
		}
	}
	return null
}

/**
 * API endpoint for setting a user code on a lock
 *
 * @param codeID: The code slot number
 *
 * @param code: The code PIN
 *
 * @param codeName: The name of the code
 *
 * @returns cmds: The commands fired for creation and checking of a lock code
 */
def setCode(codeID, code, codeName = null) {
	if (!code) {
		log.trace "[DTH] Executing 'nameSlot()' by ${this.device.displayName}"
		nameSlot(codeID, codeName)
		return
	}
	
	log.trace "[DTH] Executing 'setCode()' by ${this.device.displayName}"
	def strcode = code
	if (code instanceof String) {
		code = code.toList().findResults { if(it > ' ' && it != ',' && it != '-') it.toCharacter() as Short }
	} else {
		strcode = code.collect{ it as Character }.join()
	}

	def strname = (codeName ?: "Code $codeID")
	state["setname$codeID"] = strname
	
	def cmds = validateAttributes()
	cmds << secure(zwave.userCodeV1.userCodeSet(userIdentifier:codeID, userIdStatus:1, user:code))
	if(cmds.size() > 1) {
		cmds = delayBetween(cmds, 4200)
	}
	cmds
}

/**
 * Validates attributes and if attributes are not populated, adds the command maps to list of commands
 * @return List of commands or empty list
 */
def validateAttributes() {
	def cmds = []
	if(!device.currentValue("maxCodes")) {
		cmds << secure(zwave.userCodeV1.usersNumberGet())
	}
	if(!device.currentValue("codeLength") && isSchlageLock()) {
		cmds << secure(zwave.configurationV2.configurationGet(parameterNumber: getSchlageLockParam().codeLength.number))
	}
	log.trace "validateAttributes returning commands list: " + cmds
	cmds
}

/**
 * API endpoint for setting/deleting multiple user codes on a lock
 *
 * @param codeSettings: The map with code slot numbers and code pins (in case of update)
 *
 * @returns The commands fired for creation and deletion of lock codes
 */
def updateCodes(codeSettings) {
	log.trace "[DTH] Executing updateCodes() for device ${device.displayName}"
	if(codeSettings instanceof String) codeSettings = util.parseJson(codeSettings)
	def set_cmds = []
	codeSettings.each { name, updated ->
		if (name.startsWith("code")) {
			def n = name[4..-1].toInteger()
			if (updated && updated.size() >= 4 && updated.size() <= 8) {
				log.debug "Setting code number $n"
				set_cmds << secure(zwave.userCodeV1.userCodeSet(userIdentifier:n, userIdStatus:1, user:updated))
			} else if (updated == null || updated == "" || updated == "0") {
				log.debug "Deleting code number $n"
				set_cmds << deleteCode(n)
			}
		} else log.warn("unexpected entry $name: $updated")
	}
	if (set_cmds) {
		return response(delayBetween(set_cmds, 2200))
	}
	return null
}

/**
 * Renames an existing lock slot
 *
 * @param codeSlot: The code slot number
 *
 * @param codeName The new name of the code
 */
void nameSlot(codeSlot, codeName) {
	codeSlot = codeSlot.toString()
	if (!isCodeSet(codeSlot)) {
		return
	}
	def deviceName = device.displayName
	log.trace "[DTH] - Executing nameSlot() for device $deviceName"
	def lockCodes = loadLockCodes()
	def oldCodeName = getCodeName(lockCodes, codeSlot)
	def newCodeName = codeName ?: "Code $codeSlot"
	lockCodes[codeSlot] = newCodeName
	sendEvent(lockCodesEvent(lockCodes))
	sendEvent(name: "codeChanged", value: "$codeSlot renamed", data: [ lockName: deviceName, notify: false, notificationText: "Renamed \"$oldCodeName\" to \"$newCodeName\" in $deviceName at ${location.name}" ],
		descriptionText: "Renamed \"$oldCodeName\" to \"$newCodeName\"", displayed: true, isStateChange: true)
}

/**
 * API endpoint for deleting a user code on a lock
 *
 * @param codeID: The code slot number
 *
 * @returns cmds: The command fired for deletion of a lock code
 */
def deleteCode(codeID) {
	log.trace "[DTH] Executing 'deleteCode()' by ${this.device.displayName}"
	// Calling user code get when deleting a code because some Kwikset locks do not generate
	// AlarmReport when a code is deleted manually on the lock
	secureSequence([
		zwave.userCodeV1.userCodeSet(userIdentifier:codeID, userIdStatus:0),
		zwave.userCodeV1.userCodeGet(userIdentifier:codeID)
	], 4200)
}

/**
 * Encapsulates a command
 *
 * @param cmd: The command to be encapsulated
 *
 * @returns ret: The encapsulated command
 */
private secure(physicalgraph.zwave.Command cmd) {
	zwave.securityV1.securityMessageEncapsulation().encapsulate(cmd).format()
}

/**
 * Encapsulates list of command and adds a delay
 *
 * @param commands: The list of command to be encapsulated
 *
 * @param delay: The delay between commands
 *
 * @returns The encapsulated commands
 */
private secureSequence(commands, delay=4200) {
	delayBetween(commands.collect{ secure(it) }, delay)
}

/**
 * Checks if the time elapsed from the provided timestamp is greater than the number of senconds provided
 *
 * @param timestamp: The timestamp
 *
 * @param seconds: The number of seconds
 *
 * @returns true if elapsed time is greater than number of seconds provided, else false
 */
private Boolean secondsPast(timestamp, seconds) {
	if (!(timestamp instanceof Number)) {
		if (timestamp instanceof Date) {
			timestamp = timestamp.time
		} else if ((timestamp instanceof String) && timestamp.isNumber()) {
			timestamp = timestamp.toLong()
		} else {
			return true
		}
	}
	return (now() - timestamp) > (seconds * 1000)
}

/**
 * Reads the code name from the 'lockCodes' map
 *
 * @param lockCodes: map with lock code names
 *
 * @param codeID: The code slot number
 *
 * @returns The code name
 */
private String getCodeName(lockCodes, codeID) {
	if (isMasterCode(codeID)) {
		return "Master Code"
	}
	lockCodes[codeID.toString()] ?: "Code $codeID"
}

/**
 * Reads the code name from the device state
 *
 * @param lockCodes: map with lock code names
 *
 * @param codeID: The code slot number
 *
 * @returns The code name
 */
private String getCodeNameFromState(lockCodes, codeID) {
	if (isMasterCode(codeID)) {
		return "Master Code"
	}
	def nameFromLockCodes = lockCodes[codeID.toString()]
	def nameFromState = state["setname$codeID"]
	if(nameFromLockCodes) {
		if(nameFromState) {
			//Updated from smart app
			return nameFromState
		} else {
			//Updated from lock
			return nameFromLockCodes
		}
	} else if(nameFromState) {
		//Set from smart app
		return nameFromState
	}
	//Set from lock
	return "Code $codeID"
}

/**
 * Check if a user code is present in the 'lockCodes' map
 *
 * @param codeID: The code slot number
 *
 * @returns true if code is present, else false
 */
private Boolean isCodeSet(codeID) {
	// BUG: Needed to add loadLockCodes to resolve null pointer when using schlage?
	def lockCodes = loadLockCodes()
	lockCodes[codeID.toString()] ? true : false
}

/**
 * Reads the 'lockCodes' attribute and parses the same
 *
 * @returns Map: The lockCodes map
 */
private Map loadLockCodes() {
	parseJson(device.currentValue("lockCodes") ?: "{}") ?: [:]
}

/**
 * Populates the 'lockCodes' attribute by calling create event
 *
 * @param lockCodes The user codes in a lock
 */
private Map lockCodesEvent(lockCodes) {
	createEvent(name: "lockCodes", value: util.toJson(lockCodes), displayed: false,
	descriptionText: "'lockCodes' attribute updated")
}

/**
 * Utility function to figure out if code id pertains to master code or not
 *
 * @param codeID - The slot number in which code is set
 * @return - true if slot is for master code, false otherwise
 */
private boolean isMasterCode(codeID) {
	if(codeID instanceof String) {
		codeID = codeID.toInteger()
	}
	(codeID == 0) ? true : false
}

/**
 * Creates the event map for user code creation
 *
 * @param lockCodes: The user codes in a lock
 *
 * @param codeID: The code slot number
 *
 * @param codeName: The name of the user code
 *
 * @return The list of events to be sent out
 */
private def codeSetEvent(lockCodes, codeID, codeName) {
	clearStateForSlot(codeID)
	// codeID seems to be an int primitive type
	lockCodes[codeID.toString()] = (codeName ?: "Code $codeID")
	def result = []
	result << lockCodesEvent(lockCodes)
	def codeReportMap = [ name: "codeReport", value: codeID, data: [ code: "" ], isStateChange: true, displayed: false ]
	codeReportMap.descriptionText = "${device.displayName} code $codeID is set"
	result << createEvent(codeReportMap)
	result
}

/**
 * Creates the event map for user code deletion
 *
 * @param lockCodes: The user codes in a lock
 *
 * @param codeID: The code slot number
 *
 * @return The list of events to be sent out
 */
private def codeDeletedEvent(lockCodes, codeID) {
	lockCodes.remove("$codeID".toString())
	// not sure if the trigger has done this or not
	clearStateForSlot(codeID)
	def result = []
	result << lockCodesEvent(lockCodes)
	def codeReportMap = [ name: "codeReport", value: codeID, data: [ code: "" ], isStateChange: true, displayed: false ]
	codeReportMap.descriptionText = "${device.displayName} code $codeID was deleted"
	result << createEvent(codeReportMap)
	result
}

/**
 * Creates the event map for all user code deletion
 *
 * @return The List of events to be sent out
 */
private def allCodesDeletedEvent() {
	def result = []
	def lockCodes = loadLockCodes()
	def deviceName = device.displayName
	lockCodes.each { id, code ->
		result << createEvent(name: "codeReport", value: id, data: [ code: "" ], descriptionText: "code $id was deleted",
					displayed: false, isStateChange: true)
		
		def codeName = code
		result << createEvent(name: "codeChanged", value: "$id deleted", data: [ codeName: codeName, lockName: deviceName,
			notify: true, notificationText: "Deleted \"$codeName\" in $deviceName at ${location.name}" ],
		descriptionText: "Deleted \"$codeName\"",
		displayed: true, isStateChange: true)
		clearStateForSlot(id)
	}
	result
}

/**
 * Checks if a change type is set or update
 *
 * @param lockCodes: The user codes in a lock
 *
 * @param codeID The code slot number
 *
 * @return "set" or "update" basis the presence of the code id in the lockCodes map
 */
private def getChangeType(lockCodes, codeID) {
	def changeType = "set"
	if (lockCodes[codeID.toString()]) {
		changeType = "changed"
	}
	changeType
}

/**
 * Method to obtain status for descriptuion based on change type
 * @param changeType: Either "set" or "changed"
 * @return "Added" for "set", "Updated" for "changed", "" otherwise
 */
private def getStatusForDescription(changeType) {
	if("set" == changeType) {
		return "Added"
	} else if("changed" == changeType) {
		return "Updated"
	}
	//Don't return null as it cause trouble
	return ""
}

/**
 * Clears the code name and pin from the state basis the code slot number
 *
 * @param codeID: The code slot number
 */
def clearStateForSlot(codeID) {
	state.remove("setname$codeID")
	state["setname$codeID"] = null
}

/**
 * Constructs a map of the code length parameter in Schlage lock
 *
 * @return map: The map with key and values for parameter number, and size
 */
def getSchlageLockParam() {
	def map = [
		codeLength: [ number: 16, size: 1]
	]
	map
}

/**
 * Utility function to check if the lock manufacturer is Schlage
 *
 * @return true if the lock manufacturer is Schlage, else false
 */
def isSchlageLock() {
	if ("003B" == zwaveInfo.mfr) {
		if("Schlage" != getDataValue("manufacturer")) {
			updateDataValue("manufacturer", "Schlage")
		}
		return true
	}
	return false
}

/**
 * Utility function to check if the lock manufacturer is Kwikset
 *
 * @return true if the lock manufacturer is Kwikset, else false
 */
def isKwiksetLock() {
	if ("0090" == zwaveInfo.mfr) {
		if("Kwikset" != getDataValue("manufacturer")) {
			updateDataValue("manufacturer", "Kwikset")
		}
		return true
	}
	return false
}

/**
 * Utility function to check if the lock manufacturer is Yale
 *
 * @return true if the lock manufacturer is Yale, else false
 */
def isYaleLock() {
	if ("0129" == zwaveInfo.mfr) {
		if("Yale" != getDataValue("manufacturer")) {
			updateDataValue("manufacturer", "Yale")
		}
		return true
	}
	return false
}

@marthoc
Copy link
Contributor Author

marthoc commented Dec 22, 2017

For further information on this issue: I’ve now tried the Lock with a Vera Edge via the Vera component and locking and unlocking is almost immediate with only a slight toggle jumping issue (which makes sense as it does take several seconds from start to status report). Status update is also very quick after manually locking/unlocking.

For another test I also downloaded the trial version of Homeseer and loaded it on a spare RaspberryPi and tried it with the same Zwave USB stick, and there are no communication errors and the lock responds quickly and updates it’s status quickly (though of course there’s no HA integration, but I’m just talking strictly about Zwave communication with the lock). So I don’t think it’s down to the USB I'm using.

So I think this is ultimately a problem with how OZW is configuring/handling this lock; when I get time I’ll raise an issue on that repo and link here, would be good if @LeBlaaanc you could chime in there with your logs too once I do.

@spacesuitdiver
Copy link

I can confirm the same issue with a z-wave shield. I'm officially back to ST again, was hoping there was some benefit with home-assistant but there's none I've seen :(

@shaun040
Copy link

shaun040 commented Jan 6, 2018

I seem to be having the same issue with an August Gen 3 Smartlock. However, it did work at one point. I'm wondering if a package upgrade broke it recently.

It was working fine on January 3rd then broke on the 4th when I did some Ubuntu package upgrades.

Upgrade: apport:amd64 (2.20.1-0ubuntu2.14, 2.20.1-0ubuntu2.15), python3-apport:amd64 (2.20.1-0ubuntu2.14, 2.20.1-0ubuntu2.15), python3-problem-report:amd64 (2.20.1-0ubuntu2.14, 2.20.1-0ubuntu2.15
libseccomp2

Going to see if reverting some fixes it

UPDATE - I removed the batteries from the lock and reinserted them and it worked like a charm...

@ryanwinter
Copy link

I'm seeing a similar problem with the Schlage Connect lock.

When unlocking through the UI, the control moves to unlocked (the lock physically unlocks), then moves back to locked after a second, the moves back to unlocked after another second.

@spacesuitdiver
Copy link

@marthoc back again seeing if anything has improved here as I'd like to use HA for some stuff. Everyone here still just "dealing" with this?

@spacesuitdiver
Copy link

OpenZWave/open-zwave#845 maybe related?

@marthoc
Copy link
Contributor Author

marthoc commented Mar 28, 2018

My theory was that the default smartcode.xml was giving me problems on my 910 because it doesn’t have any of the features the xml implements (it has no codes, it’s just the basic version with a normal key turn outside and the Zwave unit inside). However, I “solved” my problem by moving to a Vera Edge for all my Zwave devices and passing that to HA. Now it works really well and the toggle updates as it should.

One way to test my theory would be to: exclude the lock, shutdown HA, find the ozw device database in your HA install and delete the entries for Kwikset in manufacturer_specific, then delete the zwcfg xml in the HA config dir. Restart HA, and pair the lock. It will pull command class info from the device without any specific info from the Zwave database (which will mean that it will be listed as an unknown device but that’s fine for testing). And then see how it works. If it works better or as it should then we can see about a PR to ozw to update the settings.

@spacesuitdiver
Copy link

@marthoc I did what you mentioned and here's the result...

2018-04-23 00:45:18.319 Info, Node035, Value::Set - COMMAND_CLASS_DOOR_LOCK - Locked - 0 - 1 - True
2018-04-23 00:45:18.320 Info, Node035, Value_Lock::Set - Requesting lock to be Locked
2018-04-23 00:45:18.320 Detail, Node035, Setting Encryption Flag on Message For Command Class COMMAND_CLASS_DOOR_LOCK
2018-04-23 00:45:18.320 Detail, Node035, Queuing (Send) DoorLockCmd_Set (Node=35): 0x01, 0x0a, 0x00, 0x13, 0x23, 0x03, 0x62, 0x01, 0xff, 0x25, 0xe4, 0x9b
2018-04-23 00:45:18.321 Detail, Node035, Setting Encryption Flag on Message For Command Class COMMAND_CLASS_DOOR_LOCK
2018-04-23 00:45:18.321 Detail, Node035, Queuing (Send) DoorLockCmd_Get (Node=35): 0x01, 0x09, 0x00, 0x13, 0x23, 0x02, 0x62, 0x02, 0x25, 0xe5, 0x64
2018-04-23 00:45:18.322 Detail, 
2018-04-23 00:45:18.322 Info, Node035, Processing (Send) Nonce Request message (Callback ID=0xe4, Expected Reply=0x04)
2018-04-23 00:45:18.323 Info, Node035, Sending (Send) message (Callback ID=0xe4, Expected Reply=0x04) - Nonce_Get(DoorLockCmd_Set) - 0x01, 0x09, 0x00, 0x13, 0x23, 0x02, 0x98, 0x40, 0x05, 0x02:
2018-04-23 00:45:18.330 Detail, Node035,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2018-04-23 00:45:18.331 Detail, Node035,   ZW_SEND_DATA delivered to Z-Wave stack
2018-04-23 00:45:19.470 Detail, Node035,   Received: 0x01, 0x07, 0x00, 0x13, 0x02, 0x00, 0x00, 0x73, 0x9a
2018-04-23 00:45:19.471 Detail, Node035,   ZW_SEND_DATA Request with callback ID 0x02 received (expected 0x02)
2018-04-23 00:45:19.471 Info, Node035, Request RTT 1147 Average Request RTT 1256
2018-04-23 00:45:19.482 Detail, Node035,   Received: 0x01, 0x10, 0x00, 0x04, 0x00, 0x23, 0x0a, 0x98, 0x80, 0xa8, 0x87, 0x42, 0x30, 0xdc, 0xe2, 0x31, 0x2d, 0xa5
2018-04-23 00:45:19.482 Info, Node035, Received SecurityCmd_NonceReport from node 35
2018-04-23 00:45:19.483 Info, Node035, Sending (Send) message (Callback ID=0xe6, Expected Reply=0x04) - DoorLockCmd_Set (Node=35): 0x01, 0x0a, 0x00, 0x13, 0x23, 0x03, 0x62, 0x01, 0xff, 0x25, 0xe6, 0x99
2018-04-23 00:45:19.491 Detail, Node035,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2018-04-23 00:45:19.492 Detail, Node035,   ZW_SEND_DATA delivered to Z-Wave stack
2018-04-23 00:45:19.511 Detail, Node035,   Received: 0x01, 0x07, 0x00, 0x13, 0xe6, 0x00, 0x00, 0x03, 0x0e
2018-04-23 00:45:19.512 Detail, Node035,   ZW_SEND_DATA Request with callback ID 0xe6 received (expected 0xe6)
2018-04-23 00:45:19.512 Info, Node035, Request RTT 1188 Average Request RTT 1222
2018-04-23 00:45:19.512 Detail,   Expected callbackId was received
2018-04-23 00:45:20.759 Detail, Node035,   Received: 0x01, 0x08, 0x00, 0x04, 0x00, 0x23, 0x02, 0x98, 0x40, 0x0a
2018-04-23 00:45:20.759 Info, Node035, Received SecurityCmd_NonceGet from node 35
2018-04-23 00:45:20.760 Info, NONCES: 0x1a, 0xec, 0x2b, 0x7b, 0x39, 0xd3, 0x4a, 0x5b
2018-04-23 00:45:20.760 Info, NONCES: 0xd6, 0x4e, 0x38, 0x32, 0x9c, 0x1c, 0xac, 0xc8
2018-04-23 00:45:20.760 Info, NONCES: 0x28, 0x8e, 0x03, 0x61, 0x61, 0x4e, 0xbc, 0x42
2018-04-23 00:45:20.761 Info, NONCES: 0x02, 0x88, 0xd8, 0x9e, 0xa4, 0x84, 0x66, 0x5c
2018-04-23 00:45:20.761 Info, NONCES: 0xa8, 0xc3, 0x7c, 0x28, 0xe2, 0xa0, 0x84, 0x35
2018-04-23 00:45:20.761 Info, NONCES: 0x57, 0xe5, 0x22, 0x69, 0x01, 0xc8, 0xc6, 0x4b
2018-04-23 00:45:20.762 Info, NONCES: 0x79, 0xdd, 0x18, 0x19, 0x62, 0x4d, 0xa8, 0xcf
2018-04-23 00:45:20.762 Info, NONCES: 0x97, 0x94, 0x87, 0x98, 0x5c, 0x4d, 0xe3, 0x7a
2018-04-23 00:45:20.762 Info, Node035, Sending (Send) message (Callback ID=0x01, Expected Reply=0x04) - Nonce_Report - 0x01, 0x11, 0x00, 0x13, 0x23, 0x0a, 0x98, 0x80, 0x02, 0x88, 0xd8, 0x9e, 0xa4, 0x84, 0x66, 0x5c, 0x05, 0x01, 0x1e:
2018-04-23 00:45:20.769 Detail, Node035,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2018-04-23 00:45:20.769 Detail, Node035,   ZW_SEND_DATA delivered to Z-Wave stack
2018-04-23 00:45:20.786 Detail, Node035,   Received: 0x01, 0x07, 0x00, 0x13, 0x01, 0x00, 0x00, 0x02, 0xe8
2018-04-23 00:45:20.787 Detail, Node035,   ZW_SEND_DATA Request with callback ID 0x01 received (expected 0x01)
2018-04-23 00:45:20.787 Info, Node035, Request RTT 2463 Average Request RTT 1842
2018-04-23 00:45:20.807 Detail, Node035,   Received: 0x01, 0x1e, 0x00, 0x04, 0x00, 0x23, 0x18, 0x98, 0x81, 0xa0, 0x07, 0xc4, 0x5d, 0x3c, 0x0e, 0xcc, 0x5a, 0x1d, 0x0a, 0x1f, 0xe5, 0x90, 0x02, 0x88, 0xb0, 0xc7, 0xdf, 0x2d, 0x51, 0x46, 0xf0, 0xc8
2018-04-23 00:45:20.808 Info, Raw: 0x98, 0x81, 0xa0, 0x07, 0xc4, 0x5d, 0x3c, 0x0e, 0xcc, 0x5a, 0x1d, 0x0a, 0x1f, 0xe5, 0x90, 0x02, 0x88, 0xb0, 0xc7, 0xdf, 0x2d, 0x51, 0x46, 0xf0, 0xc8
2018-04-23 00:45:20.808 Detail, Node035, Decrypted Packet: 0x00, 0x71, 0x05, 0x18, 0x01
2018-04-23 00:45:20.808 Detail, 
2018-04-23 00:45:20.809 Info, Node035, Response RTT 2484 Average Response RTT 2114
2018-04-23 00:45:20.809 Info, Node035, Received Alarm report: type=24, level=1
2018-04-23 00:45:20.809 Detail, Node035, Refreshed Value: old value=25, new value=24, type=byte
2018-04-23 00:45:20.809 Detail, Node035, Changes to this value are not verified
2018-04-23 00:45:20.810 Detail, Node035, Refreshed Value: old value=1, new value=1, type=byte
2018-04-23 00:45:20.810 Detail, Node035, Changes to this value are not verified
2018-04-23 00:45:20.810 Detail, Node035, Notification: ValueChanged
2018-04-23 00:45:20.834 Detail, Node035, Notification: ValueChanged
2018-04-23 00:45:28.324 Error, Node035, ERROR: Dropping command, expected response not received after 1 attempt(s)
2018-04-23 00:45:28.325 Detail, Node035, Removing current message
2018-04-23 00:45:28.325 Detail, Node035, Notification: Notification - TimeOut
2018-04-23 00:45:28.334 Detail, 
2018-04-23 00:45:28.334 Info, Node035, Processing (Send) Nonce Request message (Callback ID=0xe5, Expected Reply=0x04)
2018-04-23 00:45:28.335 Info, Node035, Sending (Send) message (Callback ID=0xe5, Expected Reply=0x04) - Nonce_Get(DoorLockCmd_Get) - 0x01, 0x09, 0x00, 0x13, 0x23, 0x02, 0x98, 0x40, 0x05, 0x02:
2018-04-23 00:45:28.341 Detail, Node035,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2018-04-23 00:45:28.342 Detail, Node035,   ZW_SEND_DATA delivered to Z-Wave stack
2018-04-23 00:45:29.613 Detail, Node035,   Received: 0x01, 0x07, 0x00, 0x13, 0x02, 0x00, 0x00, 0x80, 0x69
2018-04-23 00:45:29.614 Detail, Node035,   ZW_SEND_DATA Request with callback ID 0x02 received (expected 0x02)
2018-04-23 00:45:29.614 Info, Node035, Request RTT 1277 Average Request RTT 1559
2018-04-23 00:45:29.625 Detail, Node035,   Received: 0x01, 0x10, 0x00, 0x04, 0x00, 0x23, 0x0a, 0x98, 0x80, 0x6f, 0x7d, 0xc4, 0x46, 0xca, 0x36, 0x59, 0xaa, 0x45
2018-04-23 00:45:29.625 Info, Node035, Received SecurityCmd_NonceReport from node 35
2018-04-23 00:45:29.626 Info, Node035, Sending (Send) message (Callback ID=0xe7, Expected Reply=0x04) - DoorLockCmd_Get (Node=35): 0x01, 0x09, 0x00, 0x13, 0x23, 0x02, 0x62, 0x02, 0x25, 0xe7, 0x66
2018-04-23 00:45:29.634 Detail, Node035,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2018-04-23 00:45:29.634 Detail, Node035,   ZW_SEND_DATA delivered to Z-Wave stack
2018-04-23 00:45:29.654 Detail, Node035,   Received: 0x01, 0x07, 0x00, 0x13, 0xe7, 0x00, 0x00, 0x02, 0x0e
2018-04-23 00:45:29.654 Detail, Node035,   ZW_SEND_DATA Request with callback ID 0xe7 received (expected 0xe7)
2018-04-23 00:45:29.654 Info, Node035, Request RTT 1318 Average Request RTT 1438
2018-04-23 00:45:29.655 Detail,   Expected callbackId was received
2018-04-23 00:45:29.689 Detail, Node035,   Received: 0x01, 0x08, 0x00, 0x04, 0x00, 0x23, 0x02, 0x98, 0x40, 0x0a
2018-04-23 00:45:29.690 Info, Node035, Received SecurityCmd_NonceGet from node 35
2018-04-23 00:45:29.690 Info, NONCES: 0x1a, 0xec, 0x2b, 0x7b, 0x39, 0xd3, 0x4a, 0x5b
2018-04-23 00:45:29.690 Info, NONCES: 0xd6, 0x4e, 0x38, 0x32, 0x9c, 0x1c, 0xac, 0xc8
2018-04-23 00:45:29.691 Info, NONCES: 0x28, 0x8e, 0x03, 0x61, 0x61, 0x4e, 0xbc, 0x42
2018-04-23 00:45:29.691 Info, NONCES: 0x02, 0x88, 0xd8, 0x9e, 0xa4, 0x84, 0x66, 0x5c
2018-04-23 00:45:29.691 Info, NONCES: 0x9e, 0xb3, 0x91, 0x00, 0x01, 0x4e, 0x42, 0xa7
2018-04-23 00:45:29.692 Info, NONCES: 0x57, 0xe5, 0x22, 0x69, 0x01, 0xc8, 0xc6, 0x4b
2018-04-23 00:45:29.692 Info, NONCES: 0x79, 0xdd, 0x18, 0x19, 0x62, 0x4d, 0xa8, 0xcf
2018-04-23 00:45:29.692 Info, NONCES: 0x97, 0x94, 0x87, 0x98, 0x5c, 0x4d, 0xe3, 0x7a
2018-04-23 00:45:29.693 Info, Node035, Sending (Send) message (Callback ID=0x01, Expected Reply=0x04) - Nonce_Report - 0x01, 0x11, 0x00, 0x13, 0x23, 0x0a, 0x98, 0x80, 0x9e, 0xb3, 0x91, 0x00, 0x01, 0x4e, 0x42, 0xa7, 0x05, 0x01, 0xde:
2018-04-23 00:45:29.700 Detail, Node035,   Received: 0x01, 0x04, 0x01, 0x13, 0x01, 0xe8
2018-04-23 00:45:29.700 Detail, Node035,   ZW_SEND_DATA delivered to Z-Wave stack
2018-04-23 00:45:29.717 Detail, Node035,   Received: 0x01, 0x07, 0x00, 0x13, 0x01, 0x00, 0x00, 0x02, 0xe8
2018-04-23 00:45:29.717 Detail, Node035,   ZW_SEND_DATA Request with callback ID 0x01 received (expected 0x01)
2018-04-23 00:45:29.718 Info, Node035, Request RTT 1381 Average Request RTT 1409
2018-04-23 00:45:29.739 Detail, Node035,   Received: 0x01, 0x21, 0x00, 0x04, 0x00, 0x23, 0x1b, 0x98, 0x81, 0xe0, 0x80, 0xe3, 0x04, 0x3f, 0x21, 0xdc, 0xfe, 0x87, 0x5c, 0xff, 0x1e, 0x13, 0xe0, 0x49, 0x33, 0x9e, 0xe0, 0x8a, 0xb8, 0x8a, 0xe6, 0xfa, 0xbf, 0x69, 0xff
2018-04-23 00:45:29.740 Info, Raw: 0x98, 0x81, 0xe0, 0x80, 0xe3, 0x04, 0x3f, 0x21, 0xdc, 0xfe, 0x87, 0x5c, 0xff, 0x1e, 0x13, 0xe0, 0x49, 0x33, 0x9e, 0xe0, 0x8a, 0xb8, 0x8a, 0xe6, 0xfa, 0xbf, 0x69, 0xff
2018-04-23 00:45:29.740 Detail, Node035, Decrypted Packet: 0x00, 0x62, 0x03, 0xff, 0x00, 0x00, 0xfe, 0xfe
2018-04-23 00:45:29.740 Detail, 
2018-04-23 00:45:29.741 Info, Node035, Response RTT 1404 Average Response RTT 1759
2018-04-23 00:45:29.741 Info, Node035, Received DoorLock report: DoorLock is Secured
2018-04-23 00:45:29.741 Detail, Node035, Refreshed Value: old value=false, new value=true, type=bool
2018-04-23 00:45:29.742 Detail, Node035, Changes to this value are not verified
2018-04-23 00:45:29.742 Detail, Node035,   Expected reply and command class was received
2018-04-23 00:45:29.742 Detail, Node035,   Message transaction complete
2018-04-23 00:45:29.743 Detail, 
2018-04-23 00:45:29.743 Detail, Node035, Removing current message
2018-04-23 00:45:29.743 Detail, Node035, Notification: ValueChanged

At 2018-04-23 00:45:20.834 Detail, Node035, Notification: ValueChanged the lock flips states back to what it "was" and then 8 seconds later it receives an update from the device.

@spacesuitdiver
Copy link

I realize I didn't put my thoughts here... I'm not sure whether OZW or HA should be optimistic but it seems it could for the 8 seconds of delay.

@nathanfaber
Copy link

I'm also seeing this on 3 Yale YRD110 locks.

@spacesuitdiver
Copy link

@nathanfaber they work fine otherwise on other platforms? My lock is on SmartThings just because of this weirdness. The issue is most likely an issue with OZW.

@turbokongen
Copy link
Contributor

@marthoc If you could look at the log in the vera to see the Sent and received timing that would be great starting point to tell where the issue is/should be improved.
I am certain the problem is with Ozw, but would be nice to have a confirmation.
HA's 2second optimistic time is a fine line. If you have it too long, you will get the exact opposite "error" if it does not lock after a lock command.

@nathanfaber
Copy link

@spacesuitdiver yes, I currently use them on an ISY-994i and they can be controlled as expected.

@balloobbot
Copy link

There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates.

Please make sure to update to the latest Home Assistant version and check if that solves the issue. Let us know if that works for you by adding a comment 👍

@plinss
Copy link

plinss commented Oct 26, 2018

I'm running V0.80.0 with a Kwikset lock and the state no longer bounces around when toggled. However it doesn't update at all when the lock is manually locked/unlocked. FWIW, I have a custom sensor that reads access control and alarm type which does update for manual changes.

@spacesuitdiver
Copy link

Something to keep in mind, there's like 3 different Kwikset firmwares even across the same product name.

@balloobbot
Copy link

There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates.

Please make sure to update to the latest Home Assistant version and check if that solves the issue. Let us know if that works for you by adding a comment 👍

@finish06
Copy link
Contributor

Is this still an issue you are experiencing? Can you please try upgrading to the latest version of Home Assistant (0.90) and report back if this is still a problem? Thanks!

@dshokouhi
Copy link
Member

@finish06 I think this issue can be closed since we no longer show a toggle in lovelace and just show text, at least for me its no longer an issue

@plinss
Copy link

plinss commented Mar 22, 2019

Works for me as well, Kwikset Zwave lock, v0.90. Doesn't bounce and reflects the lock state immediately when operated manually.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests