I got my second Danalock v2 to secure include by setting “Secure Inclusion Mode” to “All Devices” when including the device and back to Entry Control Devices after. I couldn’t get it to work on the second lock, so tried this workaround and it worked
@chris - I’m getting weird behavior out of my locks (I have three operating as 914TRL’s - all Kwicksets. 1 - 910 / 2 - 914). I updated the binding last night to make sure I had the latest and am still seeing the issue.
The main lock channel is only reporting ON events and not OFF events. The alarm channel is reporting all activity for lock/unlock. Here is a debug file (Node 107) showing a lock then unlock event. You can see the alarm channel reporting both events (is that Alarm Type the new channel to get userid’s from?) but only see ON reporting for activity. I’m seeing this across all my locks. Let me know any other tests you want me to run to isolate the issue.
https://drive.google.com/file/d/0B77VHtwPft8eekY3cUlxZFczZ2M/view?usp=sharing
TIA
Can you provide the log slightly earlier than this, or is this everything? The door_lock channel uses the DOOR_LOCK command class and I don’t see any such message in the log.
I’ll get it to you when I get back home later. Thanks
@chris Here is slightly before the log snippet I sent (I had only put it in debug right before I ran the test so maybe it wasn’t fully recording yet, can definitely do it again to see if it gets more?). I don’t see DOOR_LOCK command class in it. This was one of the locks i included by using zensys tools and then had OpenHAB discover it off my Zwave stick.
2017-08-24 09:48:05.043 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=107, callback=0, payload=00 6B 02 98 40
2017-08-24 09:48:05.045 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lock Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=107, callback=0, payload=00 6B 02 98 40
2017-08-24 09:48:05.048 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=107, callback=0, payload=00 6B 02 98 40
2017-08-24 09:48:05.049 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2017-08-24 09:48:05.051 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 107: Application Command Request (ALIVE:DONE)
2017-08-24 09:48:05.052 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 107: resetResendCount initComplete=true isDead=false
2017-08-24 09:48:05.053 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 107: Incoming command class COMMAND_CLASS_SECURITY, endpoint 0
2017-08-24 09:48:05.054 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 107: SECURITY check internal
2017-08-24 09:48:05.055 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 107: Received COMMAND_CLASS_SECURITY V1 SECURITY_NONCE_GET
2017-08-24 09:48:05.056 [DEBUG] [andclass.impl.CommandClassSecurityV1] - Creating command message SECURITY_NONCE_REPORT version 1
2017-08-24 09:48:05.063 [DEBUG] [ommandClassTransactionPayloadBuilder] - At build null
2017-08-24 09:48:05.064 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 107: Added to secure queue - size 1
2017-08-24 09:48:05.066 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 107: Commands processed 1.
2017-08-24 09:48:05.067 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 107: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@94a3ea.
2017-08-24 09:48:05.078 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2017-08-24 09:48:05.080 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2017-08-24 09:48:05.081 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2017-08-24 09:48:05.082 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start
2017-08-24 09:48:05.083 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction from secureQueue
2017-08-24 09:48:05.085 [DEBUG] [nal.protocol.ZWaveTransactionManager] - getTransactionToSend 6
2017-08-24 09:48:05.089 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 11 00 13 6B 0A 98 80 FC CA AF E4 EE 37 FE 89 25 54 26
2017-08-24 09:48:05.092 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 107: Sending REQUEST Message = 01 11 00 13 6B 0A 98 80 FC CA AF E4 EE 37 FE 89 25 54 26
2017-08-24 09:48:05.094 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2017-08-24 09:48:05.096 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 9478: Transaction Start type SendData
2017-08-24 09:48:05.097 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 9478: [WAIT_RESPONSE] requiresResponse=true callback: 84
2017-08-24 09:48:05.098 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd class: null
2017-08-24 09:48:05.100 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd: 0
2017-08-24 09:48:05.101 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage Transactions outstanding: 1
2017-08-24 09:48:05.103 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Thu Aug 24 09:48:07 MDT 2017 - 1999ms
2017-08-24 09:48:05.104 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2017-08-24 09:48:05.105 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage lastTransaction: TID 9478: [WAIT_RESPONSE] requiresResponse=true callback: 84
2017-08-24 09:48:05.106 [DEBUG] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
2017-08-24 09:48:05.106 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0x00], type=ACK[0x02], dest=255, callback=0, payload=
2017-08-24 09:48:05.108 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Thu Aug 24 09:48:07 MDT 2017 - 1995ms
2017-08-24 09:48:05.108 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lock Message: class=null[0x00], type=ACK[0x02], dest=255, callback=0, payload=
2017-08-24 09:48:05.109 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0x00], type=ACK[0x02], dest=255, callback=0, payload=
2017-08-24 09:48:05.110 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 9478: [WAIT_RESPONSE] requiresResponse=true callback: 84
2017-08-24 09:48:05.111 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2017-08-24 09:48:05.111 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2017-08-24 09:48:05.112 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start
2017-08-24 09:48:05.112 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2017-08-24 09:48:05.113 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction lastTransaction outstanding...
2017-08-24 09:48:05.114 [DEBUG] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
2017-08-24 09:48:05.114 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT 6
2017-08-24 09:48:05.115 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Thu Aug 24 09:48:07 MDT 2017 - 1987ms
2017-08-24 09:48:05.115 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[0x13], type=Response[0x01], dest=255, callback=0, payload=01
2017-08-24 09:48:05.117 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lock Message: class=SendData[0x13], type=Response[0x01], dest=255, callback=0, payload=01
2017-08-24 09:48:05.118 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[0x13], type=Response[0x01], dest=255, callback=0, payload=01
2017-08-24 09:48:05.119 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 9478: [WAIT_RESPONSE] requiresResponse=true callback: 84
2017-08-24 09:48:05.119 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2017-08-24 09:48:05.120 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 9478: [WAIT_RESPONSE] requiresResponse=true callback: 84
2017-08-24 09:48:05.122 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[0x13], type=Response[0x01], dest=255, callback=0, payload=01
2017-08-24 09:48:05.123 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 107: Sent Data successfully placed on stack.
2017-08-24 09:48:05.124 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 9478: TransactionAdvance ST: WAIT_RESPONSE
2017-08-24 09:48:05.125 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 9478: TransactionAdvance WT: null {}
2017-08-24 09:48:05.129 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 54 00 00 02 BD
2017-08-24 09:48:05.136 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT 6
2017-08-24 09:48:05.136 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 9478: TransactionAdvance RX: Message: class=SendData[0x13], type=Response[0x01], dest=255, callback=0, payload=01
2017-08-24 09:48:05.138 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 9478: TransactionAdvance TO: WAIT_REQUEST
2017-08-24 09:48:05.139 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 9478: Advanced to WAIT_REQUEST
2017-08-24 09:48:05.140 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 107: TID 9478: Transaction not completed
2017-08-24 09:48:05.140 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2017-08-24 09:48:05.141 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start
2017-08-24 09:48:05.142 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction lastTransaction outstanding...
2017-08-24 09:48:05.142 [DEBUG] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
2017-08-24 09:48:05.143 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Thu Aug 24 09:48:10 MDT 2017 - 4996ms
2017-08-24 09:48:05.145 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[0x13], type=Request[0x00], dest=0, callback=84, payload=54 00 00 02
2017-08-24 09:48:05.147 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lock Message: class=SendData[0x13], type=Request[0x00], dest=0, callback=84, payload=54 00 00 02
2017-08-24 09:48:05.153 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 1E 00 04 00 6B 18 98 81 96 7D 53 8F 46 66 AE A0 A8 87 08 3A F6 FC 51 3B 84 B2 37 CF F9 CC 10
2017-08-24 09:48:05.154 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[0x13], type=Request[0x00], dest=0, callback=84, payload=54 00 00 02
2017-08-24 09:48:05.156 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 9478: [WAIT_REQUEST] requiresResponse=true callback: 84
2017-08-24 09:48:05.157 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT 6
2017-08-24 09:48:05.158 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2017-08-24 09:48:05.159 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=107, callback=0, payload=00 6B 18 98 81 96 7D 53 8F 46 66 AE A0 A8 87 08 3A F6 FC 51 3B 84 B2 37 CF F9 CC
2017-08-24 09:48:05.159 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 9478: [WAIT_REQUEST] requiresResponse=true callback: 84
2017-08-24 09:48:05.160 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 9478: (Callback 84)
2017-08-24 09:48:05.161 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lock Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=107, callback=0, payload=00 6B 18 98 81 96 7D 53 8F 46 66 AE A0 A8 87 08 3A F6 FC 51 3B 84 B2 37 CF F9 CC
2017-08-24 09:48:05.162 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2017-08-24 09:48:05.164 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 9478: callback 84So if the lock doesn’t send the lock status, then the channel won’t be updated. Unfortunately I get the same issue with my Yale - the locks send the alarm notification, and not the lock status updates which doesn’t make sense, but that’s where we are unfortunately.
I’d suggest to use the alarm notifications to update the status with the rules as discussed elsewhere. At some stage I’d like to have something a bit better, but as different locks do different things, it’s not very standard.
No problem, that’s what I did as a work around so should be all set. Thanks.
I have a NGD00Z-4 garage door opener that I got secure inclusion successful on last night. However, sometime in the last hour it has defaulted back to not “using security”. Any ideas?
edit: And now, after a system restart, the majority of my Z-Wave devices are not communicating with the controller. I did look through my logs and it appears a network reset triggered the issue with the Garage Door opener but left everything else in tact. The system restart has knocked out all but one of my devices. I only have a few so I don’t mind rebuilding the network, but the only way I was able to get “secure inclusion” with the garage door opener was to uninstall it and do the inclusion next to my computer with the z-stick plugged in from within HABmin. It is currently reinstalled and I’d like to avoid bring it back up here for reinclusion. Any help at all would be great.
My Danalock v2 sometimes dont respond to sendcommand, after they have been inactive for a long periode (hours), like in the morning and when i come home from work, but if i resend the sendcommand a couple of times they do respond. In the log i see the sendcommand and item changed to, like everything is OK
Im trying now to get the bug in a DEBUG log and will post it
@cporourke I don’t really see how it would stop using security. Is it able to communicate at all? Maybe when you moved it to the new location it’s now not contactable?
You could try a reinitialisation of the device - in Habmin, select the thing, in the top right menu select advanced mode and then select reinitialise.
If it really has stopped using security for some reason it must be included in range of the controller with the controller plugged in to the computer.
I think i found the error after “Item AlarmState received command” i needed a Thread::sleep(500) so the state could change before checking the state in the rule
So apparently it’s more complicated than I thought. I’m now using the zwave jar you built a few days ago in a separate openhab install (i.e. different controller, different location, different lock). When I initially tried to install the lock (a kwikset 910) I got the familiar error.
I then removed all nodes from this controller and tried including the lock again and this time it worked. I then removed the lock and added additional devices to the controller. I tried adding the lock again. Secure lock inclusion worked. I then removed the lock, added 9 devices, and the lock included securely again (see below)
I then configured my 9 devices and removed/included the lock again. It included securely without issue.
The behavior in my experiment is very strange and it proves my secure lock inclusion issues are not solely related to the number of included devices prior to lock inclusion. Perhaps an update to the binding fixed things.
This error is not from the development binding.
Yes. Somewhere along the lines, you managed to change binding versions - the first attempt is with the old binding (which simply won’t work), and the new one is with the new binding (which works).
Also, please post logs as logs - not images. Format using the </> button and they are readable, and processable in the log viewer.
Chris, is alarm_raw ready to be tested? I see it in the binding (I had added it to the db), but even after reinitializing or deleting/readding locks, it is not showing up as a channel. I even tried stopping OH and removing the things from the jsondb. Locks are BE469s.
As best as I can tell, it should be included for the BE469. I assume you’re using the version from yesterday?
I had updated on Saturday and was on 2.1.0.201708201145, so it was in the binding because I updated the db 
. I didn’t notice the update yesterday, so now I’m updated to 2.1.0.201708272249 and waiting for the devices to initialize. Thank you!
Well, the code wasn’t merged until the 24th which is after the 20th, and before the 27th 
Let’s see though…
Yeah, I updated the db before the code was even merged. It sure would be nice if the reinitialize button wasn’t hidden…
The reinitialise button won’t change the thing - it just does the low level interrogation. If you enable advanced mode, then it’s visible though - right?
Not if the device hasn’t initialized after a restart of the binding 
. We’ve previously discussed.
I thought in the past I had been able to pull in db changes for a device by just reinitializing and not deleting the Thing. Maybe I’m not remembering correctly.
That’s correct - but why restart initialisation if it’s already initialising?
I think not, but I’m not 100% sure to be honest. I think it will only update the thing definition when the thing type changes which reinitialisation should do (I think). I’ve not looked at how it’s implemented in the deeper depths of ESH though either.