First, a question; am I really running your binding? Listing the installed bundles shows
209 | Active | 80 | 2.1.0.201702061819 | ZWave Binding
Second, Iāve noticed delays in reacting to commands; it seems that the first command to a device will work immediately, but a subsequent one wonāt. Hereās a chunk of logs between when I sent the command (to NODE 51) and when the node actually reacted:
2017-02-07 21:58:19.426 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 51: Command received zwave:device:69d7d64d:node51:switch_dimmer --> ON
2017-02-07 21:58:19.426 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 51: Creating new message for command SWITCH_MULTILEVEL_SET
2017-02-07 21:58:19.427 [DEBUG] [ommandClassTransactionPayloadBuilder] - At build null
2017-02-07 21:58:19.427 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 51: Encapsulating message, endpoint 0
2017-02-07 21:58:19.427 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 51: SECURITY not supported
2017-02-07 21:58:19.427 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 51: Command Class COMMAND_CLASS_SWITCH_MULTILEVEL is NOT required to be secured
2017-02-07 21:58:19.427 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 51: Adding to device queue
2017-02-07 21:58:19.427 [DEBUG] [e.internal.protocol.ZWaveTransaction] - >>>>> transaction node Id is different
2017-02-07 21:58:19.427 [DEBUG] [e.internal.protocol.ZWaveTransaction] - >>>>> transaction node Id is different
2017-02-07 21:58:19.427 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 51: Added to queue - size 27
2017-02-07 21:58:19.428 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start
2017-02-07 21:58:19.428 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction lastTransaction outstanding...
2017-02-07 21:58:19.428 [DEBUG] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
2017-02-07 21:58:19.428 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Tue Feb 07 21:58:35 CST 2017 - 15579ms
2017-02-07 21:58:26.060 [DEBUG] [rialmessage.IsFailedNodeMessageClass] - NODE 25: Requesting IsFailedNode status from controller.
2017-02-07 21:58:26.060 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@6e575513
2017-02-07 21:58:26.060 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Adding to controller queue
2017-02-07 21:58:26.061 [DEBUG] [e.internal.protocol.ZWaveTransaction] - >>>>> transaction payload is NOT the same
2017-02-07 21:58:26.061 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added to queue - size 28
2017-02-07 21:58:26.061 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start
2017-02-07 21:58:26.061 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction lastTransaction outstanding...
2017-02-07 21:58:26.061 [DEBUG] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
2017-02-07 21:58:26.061 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Tue Feb 07 21:58:35 CST 2017 - 8946ms
2017-02-07 21:58:35.007 [DEBUG] [sactionManager$ZWaveTransactionTimer] - XXXXXXXXX Timeout.......... 1 outstanding transactions
2017-02-07 21:58:35.008 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 65: XXXXXXX Timeout at state WAIT_DATA. 3 retries remaining.
2017-02-07 21:58:35.008 [DEBUG] [sactionManager$ZWaveTransactionTimer] - Transaction is current transaction, so clearing!!!!!
2017-02-07 21:58:35.008 [DEBUG] [e.internal.protocol.ZWaveTransaction] - Transaction 265 CANCELLED
2017-02-07 21:58:35.008 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
2017-02-07 21:58:35.008 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 65: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2017-02-07 21:58:35.008 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 65: notifyTransactionResponse 265
2017-02-07 21:58:35.009 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start
2017-02-07 21:58:35.009 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ********* Transaction event listener 9 -- 265
2017-02-07 21:58:35.009 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ********* Transaction event listener 10 -- 265
2017-02-07 21:58:35.009 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ********* Transaction event listener 11 -- 265
2017-02-07 21:58:35.009 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 51: listening == true, frequentlyListening == false, awake == false
2017-02-07 21:58:35.009 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ********* Transaction event listener 12 -- 265
2017-02-07 21:58:35.009 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ********* Transaction event listener 13 -- 265
2017-02-07 21:58:35.009 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ********* Transaction event listener 14 -- 265
2017-02-07 21:58:35.009 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ********* Transaction event listener 15 -- 265
2017-02-07 21:58:35.009 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ********* Transaction event listener 16 -- 265
2017-02-07 21:58:35.009 [DEBUG] [e.internal.protocol.ZWaveTransaction] - >>>>> transaction payload is the same [[38, 1, -1]] == [[38, 1, -1]]
2017-02-07 21:58:35.009 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ********* Transaction event listener 17 -- 265
2017-02-07 21:58:35.009 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction from sendQueue
2017-02-07 21:58:35.009 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ********* Transaction event listener 18 -- 265
2017-02-07 21:58:35.009 [DEBUG] [nal.protocol.ZWaveTransactionManager] - getTransactionToSend 6
2017-02-07 21:58:35.009 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ********* Transaction event listener 19 -- 265
2017-02-07 21:58:35.010 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ********* Transaction event listener 20 -- 265
2017-02-07 21:58:35.010 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ********* Transaction event listener 21 -- 265
2017-02-07 21:58:35.010 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ********* Transaction event listener 22 -- 265
2017-02-07 21:58:35.010 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ********* Transaction event listener 23 -- 265
2017-02-07 21:58:35.010 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 33 03 26 01 FF 25 B1 9A
2017-02-07 21:58:35.010 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ********* Transaction event listener 24 -- 265
2017-02-07 21:58:35.010 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ********* Transaction event listener 25 -- 265
2017-02-07 21:58:35.010 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 51: Sending REQUEST Message = 01 0A 00 13 33 03 26 01 FF 25 B1 9A
2017-02-07 21:58:35.010 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ********* Transaction event listener 26 -- 265
2017-02-07 21:58:35.010 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ********* Transaction event listener 36 -- 265
2017-02-07 21:58:35.010 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ********* Transaction event listener 37 -- 265
2017-02-07 21:58:35.010 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ********* Transaction event listener 38 -- 265
2017-02-07 21:58:35.010 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ********* Transaction event listener 39 -- 265
2017-02-07 21:58:35.010 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ********* Transaction event listener 40 -- 265
2017-02-07 21:58:35.010 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ********* Transaction event listener 41 -- 265
2017-02-07 21:58:35.010 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ********* Transaction event listener 42 -- 265
2017-02-07 21:58:35.010 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ********* Transaction event listener 264 -- 265
2017-02-07 21:58:35.011 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ********* Transaction event listener 265 -- 265
2017-02-07 21:58:35.011 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ********* Transaction event listener 265 -- DONE -- CANCELLED WAIT_DATA
2017-02-07 21:58:35.011 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 65: -- To notify -- TIMEOUT_WAITING_FOR_DATA
2017-02-07 21:58:35.011 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ********* Transaction event listener 266 -- 265
2017-02-07 21:58:35.011 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ********* Transaction event listener 267 -- 265
2017-02-07 21:58:35.011 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ********* Transaction event listener 268 -- 265
2017-02-07 21:58:35.011 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ********* Transaction event listener 270 -- 265
2017-02-07 21:58:35.011 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2017-02-07 21:58:35.011 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ********* Transaction Response Complete 265 --
2017-02-07 21:58:35.011 [DEBUG] [e.internal.protocol.ZWaveTransaction] - transactionStart type SendData
2017-02-07 21:58:35.011 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID:269 [WAIT_RESPONSE] callback: 177
2017-02-07 21:58:35.011 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 65: Node Init response (0) TIMEOUT_WAITING_FOR_DATA
2017-02-07 21:58:35.012 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd class: null
2017-02-07 21:58:35.012 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 65: No data from device, but it was ACK'd. Possibly not supported? (Try 0)
2017-02-07 21:58:35.012 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd: 0
2017-02-07 21:58:35.012 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage Transactions outstanding: 1
2017-02-07 21:58:35.012 [DEBUG] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
2017-02-07 21:58:35.012 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Tue Feb 07 21:58:37 CST 2017 - 2000ms
2017-02-07 21:58:35.012 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage lastTransaction: TID:269 [WAIT_RESPONSE] callback: 177
2017-02-07 21:58:35.012 [DEBUG] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
2017-02-07 21:58:35.012 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Tue Feb 07 21:58:37 CST 2017 - 2000ms
2017-02-07 21:58:35.012 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2017-02-07 21:58:35.012 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage inputMessage: class=null[0x00], type=ACK[0x02], dest=255, callback=0, payload=
2017-02-07 21:58:35.012 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lockMessage: class=null[0x00], type=ACK[0x02], dest=255, callback=0, payload=
2017-02-07 21:58:35.018 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2017-02-07 21:58:35.018 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT 6
2017-02-07 21:58:35.019 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage inputMessage: class=SendData[0x13], type=Response[0x01], dest=255, callback=0, payload=01
2017-02-07 21:58:35.019 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lockMessage: class=SendData[0x13], type=Response[0x01], dest=255, callback=0, payload=01
2017-02-07 21:58:35.036 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 B1 00 00 03 59
2017-02-07 21:58:35.038 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT 6
2017-02-07 21:58:35.038 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage inputMessage: class=SendData[0x13], type=Request[0x00], dest=0, callback=177, payload=B1 00 00 03
2017-02-07 21:58:35.038 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lockMessage: class=SendData[0x13], type=Request[0x00], dest=0, callback=177, payload=B1 00 00 03
2017-02-07 21:58:36.347 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 65: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@6ec2b270
2017-02-07 21:58:36.347 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 65: Adding to device queue
2017-02-07 21:58:36.348 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 65: Added to queue - size 28
2017-02-07 21:58:36.348 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start
2017-02-07 21:58:36.348 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction lastTransaction outstanding...
2017-02-07 21:58:36.348 [DEBUG] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
2017-02-07 21:58:36.348 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Tue Feb 07 21:58:37 CST 2017 - 664ms
2017-02-07 21:58:37.012 [DEBUG] [sactionManager$ZWaveTransactionTimer] - XXXXXXXXX Timeout.......... 1 outstanding transactions
2017-02-07 21:58:37.013 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 51: XXXXXXX Timeout at state WAIT_RESPONSE. 3 retries remaining.
2017-02-07 21:58:37.013 [DEBUG] [sactionManager$ZWaveTransactionTimer] - Aborting Transaction!
2017-02-07 21:58:37.013 [DEBUG] [e.internal.protocol.ZWaveTransaction] - Transaction 269 ABORTED
2017-02-07 21:58:37.013 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 16 EA
2017-02-07 21:58:37.013 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 16 EA
2017-02-07 21:58:37.014 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2017-02-07 21:58:37.015 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start
2017-02-07 21:58:37.015 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction lastTransaction outstanding...
2017-02-07 21:58:37.015 [DEBUG] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
2017-02-07 21:58:37.015 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2017-02-07 21:58:37.016 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage inputMessage: class=null[0x00], type=ACK[0x02], dest=255, callback=0, payload=
2017-02-07 21:58:37.016 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Tue Feb 07 21:58:49 CST 2017 - 11998ms
2017-02-07 21:58:37.016 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lockMessage: class=null[0x00], type=ACK[0x02], dest=255, callback=0, payload=
^C
Third, I have three Kwikset locks which have worked with OpenHAB 1.8, but arenāt doing well with OpenHAB 2.x. Iāve tried repairing them, with limited successā¦ help?