Alarm item not updated with Zwave Binding 2.2.0 for Kwikset lock / paperUI / openhabian / latestversion / TRACE logs

Hello

I use the latest version of the zwave binding to use with my Kwikset. I see the alarm getting reported in the logs but I don’t see the item being updated in PaperUI.

Is that a bug?

  • Platform information:

    • Hardware: Rasberry Pi 3
    • OS: Rasbian
    • openHAB version: 2.1.0
  • If logs where generated please post these here using code fences:

    2017-11-29 10:37:25.028 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Received SOF
    2017-11-29 10:37:25.031 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 04 00 04 02 98 40 2D 
    2017-11-29 10:37:25.036 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Message is valid, sending ACK
    2017-11-29 10:37:25.037 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT 6
    2017-11-29 10:37:25.039 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=4, callback=0, payload=00 04 02 98 40 
    2017-11-29 10:37:25.041 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lock Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=4, callback=0, payload=00 04 02 98 40 
    2017-11-29 10:37:25.042 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=4, callback=0, payload=00 04 02 98 40 
    2017-11-29 10:37:25.043 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
    2017-11-29 10:37:25.044 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: Application Command Request (ALIVE:DONE)
    2017-11-29 10:37:25.045 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 4: resetResendCount initComplete=true isDead=false
    2017-11-29 10:37:25.046 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 4: Incoming command class COMMAND_CLASS_SECURITY, endpoint 0
    2017-11-29 10:37:25.048 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 4: SECURITY check internal
    2017-11-29 10:37:25.048 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 4: Received COMMAND_CLASS_SECURITY V1 SECURITY_NONCE_GET
    2017-11-29 10:37:25.051 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: Added to secure queue - size 1
    2017-11-29 10:37:25.052 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: Commands processed 1.
    2017-11-29 10:37:25.053 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1e8ad9f.
    2017-11-29 10:37:25.054 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
    2017-11-29 10:37:25.055 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
    2017-11-29 10:37:25.056 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
    2017-11-29 10:37:25.057 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start
    2017-11-29 10:37:25.058 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction from secureQueue
    2017-11-29 10:37:25.059 [DEBUG] [nal.protocol.ZWaveTransactionManager] - getTransactionToSend 6
    2017-11-29 10:37:25.065 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 4: Sending REQUEST Message = 01 11 00 13 04 0A 98 80 4E 01 68 1A D3 7D 93 8A 25 E5 A1 
    2017-11-29 10:37:25.067 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
    2017-11-29 10:37:25.068 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 5076: Transaction Start type SendData 
    2017-11-29 10:37:25.070 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 5076: [WAIT_RESPONSE] requiresResponse=true callback: 229
    2017-11-29 10:37:25.071 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
    2017-11-29 10:37:25.071 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd class: null
    2017-11-29 10:37:25.073 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd: 0
    2017-11-29 10:37:25.075 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage Transactions outstanding: 1
    2017-11-29 10:37:25.075 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0x00], type=ACK[0x02], dest=255, callback=0, payload=
    2017-11-29 10:37:25.076 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lock Message: class=null[0x00], type=ACK[0x02], dest=255, callback=0, payload=
    2017-11-29 10:37:25.077 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Received SOF
    2017-11-29 10:37:25.082 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
    2017-11-29 10:37:25.077 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Nov 29 10:37:27 EST 2017 - 2000ms
    2017-11-29 10:37:25.087 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Message is valid, sending ACK
    2017-11-29 10:37:25.085 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage lastTransaction: TID 5076: [WAIT_RESPONSE] requiresResponse=true callback: 229
    2017-11-29 10:37:25.088 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT 6
    2017-11-29 10:37:25.089 [DEBUG] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
    2017-11-29 10:37:25.090 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 1<>127 : Message: class=SendData[0x13], type=Response[0x01], dest=255, callback=0, payload=01 
    2017-11-29 10:37:25.091 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lock Message: class=SendData[0x13], type=Response[0x01], dest=255, callback=0, payload=01 
    2017-11-29 10:37:25.092 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Wed Nov 29 10:37:27 EST 2017 - 1985ms
    2017-11-29 10:37:25.093 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (1): Message: class=null[0x00], type=ACK[0x02], dest=255, callback=0, payload=
    2017-11-29 10:37:25.093 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Received SOF
    2017-11-29 10:37:25.094 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 5076: [WAIT_RESPONSE] requiresResponse=true callback: 229
    2017-11-29 10:37:25.095 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
    2017-11-29 10:37:25.096 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[0x13], type=Response[0x01], dest=255, callback=0, payload=01 
    2017-11-29 10:37:25.096 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 5076: [WAIT_RESPONSE] requiresResponse=true callback: 229
    2017-11-29 10:37:25.097 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
    2017-11-29 10:37:25.098 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 5076: [WAIT_RESPONSE] requiresResponse=true callback: 229
    2017-11-29 10:37:25.098 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 E5 00 00 03 0D 
    2017-11-29 10:37:25.099 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[0x13], type=Response[0x01], dest=255, callback=0, payload=01 
    2017-11-29 10:37:25.100 [TRACE] [ve.internal.protocol.ZWaveController] - Incoming Message type = RESPONSE
    2017-11-29 10:37:25.105 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Message is valid, sending ACK
    2017-11-29 10:37:25.105 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT 6
    2017-11-29 10:37:25.107 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[0x13], type=Request[0x00], dest=0, callback=229, payload=E5 00 00 03 
    2017-11-29 10:37:25.108 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 5076: TransactionAdvance ST: WAIT_RESPONSE
    2017-11-29 10:37:25.109 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 5076: TransactionAdvance WT: null {}
    2017-11-29 10:37:25.110 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lock Message: class=SendData[0x13], type=Request[0x00], dest=0, callback=229, payload=E5 00 00 03 
    2017-11-29 10:37:25.110 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 5076: TransactionAdvance RX: Message: class=SendData[0x13], type=Response[0x01], dest=255, callback=0, payload=01 
    2017-11-29 10:37:25.111 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 5076: TransactionAdvance TO: WAIT_REQUEST
    2017-11-29 10:37:25.112 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 5076: Advanced to WAIT_REQUEST
    2017-11-29 10:37:25.112 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: TID 5076: Transaction not completed
    2017-11-29 10:37:25.114 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[0x13], type=Request[0x00], dest=0, callback=229, payload=E5 00 00 03 
    2017-11-29 10:37:25.114 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 5076: [WAIT_REQUEST] requiresResponse=true callback: 229
    2017-11-29 10:37:25.115 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
    2017-11-29 10:37:25.116 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 5076: [WAIT_REQUEST] requiresResponse=true callback: 229
    2017-11-29 10:37:25.116 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 5076: (Callback 229)
    2017-11-29 10:37:25.117 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
    2017-11-29 10:37:25.118 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Received SOF
    2017-11-29 10:37:25.118 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 5076: callback 229
    2017-11-29 10:37:25.119 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[0x13], type=Request[0x00], dest=0, callback=229, payload=E5 00 00 03 
    2017-11-29 10:37:25.120 [TRACE] [ve.internal.protocol.ZWaveController] - Incoming Message type = REQUEST
    2017-11-29 10:37:25.123 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 4: resetResendCount initComplete=true isDead=false
    2017-11-29 10:37:25.124 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 5076: Transaction COMPLETED
    2017-11-29 10:37:25.124 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 5076: TransactionAdvance ST: DONE
    2017-11-29 10:37:25.125 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 5076: TransactionAdvance WT: null {}
    2017-11-29 10:37:25.126 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 1E 00 04 00 04 18 98 81 8D 10 4B 36 3A 8C 3E 3A 08 BB CB 9A F1 4E EB 99 60 C3 B4 5E FB 1A 35 
    2017-11-29 10:37:25.126 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 5076: TransactionAdvance RX: Message: class=SendData[0x13], type=Request[0x00], dest=0, callback=229, payload=E5 00 00 03 
    2017-11-29 10:37:25.127 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 5076: TransactionAdvance TO: DONE
    2017-11-29 10:37:25.128 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: Response processed after 60ms
    2017-11-29 10:37:25.128 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: TID 5076: Transaction completed
    2017-11-29 10:37:25.129 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: notifyTransactionResponse TID:5076 DONE
    2017-11-29 10:37:25.133 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
    2017-11-29 10:37:25.134 [TRACE] [WaveSerialHandler$ZWaveReceiveThread] - Message is valid, sending ACK
    2017-11-29 10:37:25.134 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
    2017-11-29 10:37:25.135 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start
    2017-11-29 10:37:25.135 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT 6
    2017-11-29 10:37:25.135 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction from controllerQueue
    2017-11-29 10:37:25.136 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage nothing
    2017-11-29 10:37:25.136 [DEBUG] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
    2017-11-29 10:37:25.138 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=4, callback=0, payload=00 04 18 98 81 8D 10 4B 36 3A 8C 3E 3A 08 BB CB 9A F1 4E EB 99 60 C3 B4 5E FB 1A 
    2017-11-29 10:37:25.140 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lock Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=4, callback=0, payload=00 04 18 98 81 8D 10 4B 36 3A 8C 3E 3A 08 BB CB 9A F1 4E EB 99 60 C3 B4 5E FB 1A 
    2017-11-29 10:37:25.142 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=4, callback=0, payload=00 04 18 98 81 8D 10 4B 36 3A 8C 3E 3A 08 BB CB 9A F1 4E EB 99 60 C3 B4 5E FB 1A 
    2017-11-29 10:37:25.142 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
    2017-11-29 10:37:25.142 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: Application Command Request (ALIVE:DONE)
    2017-11-29 10:37:25.143 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 4: resetResendCount initComplete=true isDead=false
    2017-11-29 10:37:25.144 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 4: Decapsulating COMMAND_CLASS_SECURITY
    2017-11-29 10:37:25.152 [DEBUG] [mmandclass.ZWaveSecurityCommandClass] - NODE 4: SECURITY_RXD 71 05 13 01 
    2017-11-29 10:37:25.153 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 4: Incoming command class COMMAND_CLASS_ALARM, endpoint 0
    2017-11-29 10:37:25.154 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 4: Received COMMAND_CLASS_ALARM V1 NOTIFICATION_REPORT
    2017-11-29 10:37:25.155 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 4: ALARM report - 19 = 1
    2017-11-29 10:37:25.156 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 4: Alarm Type = null (19)
    2017-11-29 10:37:25.157 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveAlarmValueEvent
    2017-11-29 10:37:25.158 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: Commands processed 1.
    2017-11-29 10:37:25.159 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@100d0e4.
    2017-11-29 10:37:25.160 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
    2017-11-29 10:37:25.161 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
    2017-11-29 10:37:25.162 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
    2017-11-29 10:37:25.163 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start
    2017-11-29 10:37:25.164 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction from controllerQueue
    2017-11-29 10:37:25.165 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage nothing

By latest binding I assume you mean the development branch of the binding found here? The version of the Binding that comes with OH does not yet support locks.

And you missed the “post these here using code fences”

```
code and logs go here
```

My bad, thank you sir.

And yes, that’s what I was talking about.

Actually, I just tried to bundle:stop/start on the Zwave binding and I rebooted the controller and now it works.

It was in a weird state where, not only the alarms, but also the inclusion wasn’t working.

Thank you very much.