ABUS Z-Wave Doorlock HomeTec Pro CFA3010

[stefan.hoehn (Stefan Höhn)]

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 (Bob Eckhoff)]

@stefan.hoehn

Anything that comes to your mind with this?

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 (Chris Jackson)]

@stefan.hoehn

has anything been changed in the last weeks regarding security or locks on the binding?

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 (Stefan Höhn)]

@apella12

Only question is your real security key 16 bytes?

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

@apella12

(the timeout at state WAIT DATA).

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 (Stefan Höhn)]

@chris

If this is repeatable (I guess so?) then I’d probably suggest to re install the lock.

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 (Bob Eckhoff)]

@stefan.hoehn

I am just wondering why as it sends inclusion info with the node number

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.

@stefan.hoehn

already “lost” another 4 zwave ids

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