ABUS Z-Wave Doorlock HomeTec Pro CFA3010

stefan.hoehn · May 1, 2024, 4:10pm

Bob ( @apella12 ) and @chris , has anything been changed in the last weeks regarding security or locks on the binding? (At least I don’t see anything on github)

The reason I am asking is because my lock doesn’t work anymore since some time. What I know is though that I have updated my system around that time to 4.2.0.M2 (which the binding is also on) but that of course can be coincidence and I cannot say that exactly after that the dock wasn’t working anymore.

The device is online and it seems it is communicating over the bus. At least, when I debug the logs and I then set the device to inclusion mode (even though it is already included) then I receive these logs:

2024-05-01 17:53:50.941 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 136: Application update request. Node information received. Transaction null
2024-05-01 17:53:50.941 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 136: resetResendCount initComplete=true isDead=false
2024-05-01 17:53:50.942 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 136: Application update - no transaction.

I have made sure that the above S0 setting is configured on the lock (like I described above).

The controller’s setting is as follows (I changed the key for the screenshot)

When changing a state (like the intention to close the lock) I get the following logs

2024-05-01 18:04:25.390 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 136: notifyTransactionResponse TID:820 DONE
2024-05-01 18:04:25.392 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 136: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2024-05-01 18:04:25.394 [DEBUG] [mmandclass.ZWaveSecurityCommandClass] - NODE 136: SECURITY_TXD 62 02 
2024-05-01 18:04:25.395 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 136: Sending REQUEST Message = 01 1D 00 13 88 16 98 81 89 56 E1 21 2F 55 CD 87 05 CF 49 D3 F0 B7 EB FD F8 06 69 DB 25 BE 8F 
2024-05-01 18:04:25.408 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 136: sentData successfully placed on stack.
2024-05-01 18:04:25.409 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 136: TID 816: Transaction not completed
2024-05-01 18:04:28.070 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 136: SendData Request. CallBack ID = 190, Status = Transmission complete and ACK received(0)
2024-05-01 18:04:28.071 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 136: resetResendCount initComplete=true isDead=false
2024-05-01 18:04:28.071 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 136: TID 816: Transaction not completed
2024-05-01 18:04:33.071 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 136: TID 816: Timeout at state WAIT_DATA. 3 retries remaining.
2024-05-01 18:04:33.071 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 136: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2024-05-01 18:04:33.072 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 136: notifyTransactionResponse TID:816 CANCELLED
2024-05-01 18:04:33.073 [DEBUG] [mmandclass.ZWaveSecurityCommandClass] - NODE 136: isNonceAvailable = null
2024-05-01 18:04:33.074 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 136: Sending REQUEST Message = 01 09 00 13 88 02 98 40 25 BF 2D 
2024-05-01 18:04:33.083 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 136: sentData successfully placed on stack.
2024-05-01 18:04:33.084 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 136: TID 821: Transaction not completed
2024-05-01 18:04:34.520 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 136: SendData Request. CallBack ID = 191, Status = Transmission complete and ACK received(0)
2024-05-01 18:04:34.520 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 136: resetResendCount initComplete=true isDead=false
2024-05-01 18:04:34.520 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 136: TID 821: Transaction not completed
2024-05-01 18:04:34.610 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 136: Application Command Request (ALIVE:DONE)
2024-05-01 18:04:34.610 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 136: resetResendCount initComplete=true isDead=false
2024-05-01 18:04:34.610 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 136: Incoming command class COMMAND_CLASS_SECURITY, endpoint 0
2024-05-01 18:04:34.611 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 136: SECURITY check internal
2024-05-01 18:04:34.611 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 136: Received COMMAND_CLASS_SECURITY V1 SECURITY_NONCE_REPORT
2024-05-01 18:04:34.611 [DEBUG] [mmandclass.ZWaveSecurityCommandClass] - NODE 136: NONCE Received start...
2024-05-01 18:04:34.611 [DEBUG] [mmandclass.ZWaveSecurityCommandClass] - NODE 136: NONCE Received start null
2024-05-01 18:04:34.611 [DEBUG] [mmandclass.ZWaveSecurityCommandClass] - NODE 136: NONCE Received ZWaveNonce [nonceBytes=(47 C7 57 C0 ED 52 D8 EB ), timer=84517, valid=true]
2024-05-01 18:04:34.612 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 136: Commands processed 1.
2024-05-01 18:04:34.612 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 136: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@3e694906.
2024-05-01 18:04:34.612 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 136: Command verified org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@3e694906.
2024-05-01 18:04:34.612 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 136: notifyTransactionResponse TID:821 DONE
2024-05-01 18:04:34.613 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 136: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2024-05-01 18:04:34.615 [DEBUG] [mmandclass.ZWaveSecurityCommandClass] - NODE 136: SECURITY_TXD 80 02 
2024-05-01 18:04:34.617 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 136: Sending REQUEST Message = 01 1D 00 13 88 16 98 81 BC A1 61 89 A0 A5 87 69 AB B4 3E 47 3E F4 C7 45 75 F5 21 52 25 C0 50 
2024-05-01 18:04:34.632 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 136: sentData successfully placed on stack.
2024-05-01 18:04:34.632 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 136: TID 817: Transaction not completed
2024-05-01 18:04:34.746 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 136: SendData Request. CallBack ID = 192, Status = Transmission complete and ACK received(0)
2024-05-01 18:04:34.746 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 136: resetResendCount initComplete=true isDead=false
2024-05-01 18:04:34.746 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 136: TID 817: Transaction not completed
2024-05-01 18:04:39.747 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 136: TID 817: Timeout at state WAIT_DATA. 3 retries remaining.
2024-05-01 18:04:39.747 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 136: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2024-05-01 18:04:39.747 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 136: notifyTransactionResponse TID:817 CANCELLED

which to me looks like it is not processed by the device (and it does not react either).
When I do something on the hardware I don’t see nor receive anything on openHAB.

What is also strange is that after several days some of the a number of things go offline and when I restart the controller they are online again (I even have the feeling they still work, though, but I did not yet have the time to investigate that). I also never experienced that before.

Anything that comes to your mind with this?

apella12 · May 1, 2024, 6:36pm

Not from me. Also not aware of any security or lock PRs. As to the log snippet, it appears filtered, so is missing some data. From what you posted the message appears sent and Acked by the device but the device isn’t sending anything in response (the timeout at state WAIT DATA).

Only question is your real security key 16 bytes?

chris · May 1, 2024, 6:57pm

No - nothing has changed in the binding relating to this for a long time…

It seems the device sends the initial request, the binding responds, but then there’s no response from the device with the command (as you surmise). If this is repeatable (I guess so?) then I’d probably suggest to re install the lock.

stefan.hoehn · May 2, 2024, 5:51am

yes, it is, I just deleted some of the bytes for the screenshot.

Yes, that is also what I am thinking. I am just wondering why as it sends inclusion info with the node number - so it is included.

stefan.hoehn · May 2, 2024, 5:54am

Yes, it is reproducable. And I already re-included it 4 times with or without S0 / S2 (and already “lost” another 4 zwave ids).

apella12 · May 2, 2024, 2:06pm

I did look at that command class. Those messages are the binding reacting to an unsolicited NIF. I don’t think any conclusion can be drawn except that the device is able to communicate with the controller. In the second log snippet, again the device is sending an ACK. My guess is there is a security problem as I believe both the NIF and the ACK from the device are sent w/o security. It’s only the secure transmission that is not getting through. However, I don’t really know for sure.

What does this mean? There should be no impact on other devices. Are the lost nodes on security too?

stefan.hoehn · May 26, 2024, 2:34pm

Hi Bob,

I lately looked more closely on the setup of my zwave stick, in particular because I wanted to clean up dead nodes (which I did). While I was doing it, I read the configuration of the stick via the zensys software and discovered by chance that it can read the security code. Guess what, the security code it read is different from what is configured in openHAB!

So, I was thinking “what if I used the code that I have read from the USB stick”.

I therefore replaced the key with the new security code on the serial controller thing and saved it but then the controller went offline. I put back the original key, saved it but the controller did not come online again. Even stopping and starting the serial controller thing did not fix it.

Fortunately stopping and starting openHAB made it come online again.

What would be the right way to change the security key? Change it, save it and restart openHAB?
Is there a way to easily find out which things use security currently (maybe there is none ) because if these things currently do work (even in S0 mode) then the key I have in openHAB should be the right one.
However, if the latter would be the case, why would it work if the key I have read from the stick is different?
Should I be careful when changing the key for testing purposes? Could that break something (I don’t intend to include or exclude any thing during that test)?

apella12 · May 26, 2024, 5:42pm

Not to be too flippant, but the right way is to never do it, so yes, be careful. Any devices included with the old bytes will need to be reincluded (and possibly factory reset to get excluded)

Longer answer is I have little experience with this area. @chris would know a lot better. I’ve seen a post or two from him in the last few days, so he might be around to respond.

In case he is not, FWIW my thoughts

OH binding only has S0 security
One way to see if a device is on security is if the debug logs to a device (thing) show NONCEs, then it is on security. There might be something on the UI properties page for the device, but I don’t have any security devices to check ATM.
I believe the keys from both Simplicity studio and the OH binding are generated randomly and are completely different. What counts IMO is the key that gets installed on the device during inclusion. That is why you can’t security include a device outside the binding (if you want it work in OH). I’ve wondered, if after inclusion you can copy the OH key into Simplicity and then communicate with the device from that program. That is something to maybe try
From the code, changing the key in OH will dispose and initialize the controller, so I’d have to get logs to see why that didn’t work and you needed to restart OH. Did the controller go offline for a few seconds after changing the key? I have sometimes found changing in the “Code” tab is needed. Never investigated why.

stefan.hoehn · May 26, 2024, 6:13pm

Thanks for the comprehensive answer, Bob.

I though that Simplicity would read the key but not create one. Who knows.

Anyways, maybe @chris can share additional notes and I will investigate further the next days.

chris · May 29, 2024, 8:51pm

Sorry - just seen this…

I believe that some software stores “a” key in the controllers non-volatile memory. OH doesn’t do that - the key is stored in the OH configuration. So, what you saw was possibly a random key, or maybe a key used by some other control software - but not the key used by OH, and all the security “stuff” is performed by the binding.

Bobs answer all looks good. There’s no way (I think) to change the key without resetting and reincluding a device. The key exchange is only performed during that phase and I’m not aware of a way to change it in an operating network (at least with S0).

As above, you can’t do this without loosing devices that use the old key - they would need to be reset and included again.

Not to get a list, but if you look at the device properties, there should be a zwave_secure property if the device is using security.

OH uses the key stored in the OH config - not one stored on the stick.

If you change the key for testing, then I think that devices included with the new key will work ok, but then the old devices won’t work. Likewise when you change it back - the new devices using your test key won’t work, but the old devices using the original key should be fine (hopefully ).