More logs
The device is NODE 10.
It seems to wake up when I am pressing the button 3 times and it is blinking twice.
I can see exchanges.
13:27:50.427 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking TID 125: (Callback 179)
13:27:50.428 [DEBUG] [l.serialmessage.ZWaveCommandProcessor] - Callback match!
13:27:50.430 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Correlated to TID 125: callback 179
13:27:50.432 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=1, callback=179, payload=B3 01
13:27:50.435 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 10: SendData Request. CallBack ID = 179, Status = Transmission complete, no ACK received(1)
13:27:50.437 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 125: Transaction CANCELLED
13:27:50.439 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 10: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
13:27:50.442 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 10: Transaction failed waiting for REQUEST, assume sleeping device.
13:27:50.444 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 10: CANCEL while sending message. Requeueing - 2 attempts left!
13:27:50.446 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 125: Transaction RESET with 2 retries remaining.
13:27:50.448 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 10: Adding to device queue
13:27:50.450 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 10: Added 125 to queue - size 6
13:27:50.452 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
13:27:50.456 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 10: TID 125: Transaction not completed
13:27:50.458 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
13:27:50.460 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
13:27:53.988 [INFO ] [smarthome.event.ItemStateChangedEvent] - zwave_serial_zstick_0696af2c_serial_sof changed from 285 to 286
13:27:53.990 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 17 00 49 84 0A 11 04 21 01 5E 85 8E 59 55 86 72 5A 73 80 9F 84 6C 31 58
13:27:54.002 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationUpdate[73], type=Request[0], dest=10, callback=132, payload=84 0A 11 04 21 01 5E 85 8E 59 55 86 72 5A 73 80 9F 84 6C 31
13:27:54.007 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationUpdate[73], type=Request[0], dest=10, callback=132, payload=84 0A 11 04 21 01 5E 85 8E 59 55 86 72 5A 73 80 9F 84 6C 31
13:27:54.010 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null
13:27:54.012 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 0
13:27:54.015 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: null
13:27:54.019 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=ApplicationUpdate[73], type=Request[0], dest=10, callback=132, payload=84 0A 11 04 21 01 5E 85 8E 59 55 86 72 5A 73 80 9F 84 6C 31
13:27:54.022 [DEBUG] [message.ApplicationUpdateMessageClass] - NODE 10: Application update request. Node information received. Transaction null
13:27:54.024 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 10: Unsupported command class COMMAND_CLASS_TRANSPORT_SERVICE
13:27:54.026 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 10: Unsupported command class COMMAND_CLASS_SECURITY_2
13:27:54.028 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 10: Unsupported command class COMMAND_CLASS_SUPERVISION
13:27:54.030 [DEBUG] [message.ApplicationUpdateMessageClass] - NODE 10: Application update - no transaction.
13:27:54.032 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
13:27:54.035 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
13:27:54.283 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 10: Is awake with 2 messages in the queue
13:27:54.286 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 10: Start sleep timer at 5000ms
13:27:54.288 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 10: Got an event from Z-Wave network: ZWaveNodeStatusEvent
13:27:54.314 [DEBUG] [ave.internal.protocol.ZWaveController] - NODE 10: Node Status event - Node is AWAKE
13:27:54.329 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing 'zwave:device:0696af2c:node10' has been updated.
13:28:34.007 [INFO ] [smarthome.event.ItemStateChangedEvent] - zwave_serial_zstick_0696af2c_serial_sof changed from 286 to 287
13:28:34.013 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 17 00 49 84 0A 11 04 21 01 5E 85 8E 59 55 86 72 5A 73 80 9F 84 6C 31 58
13:28:34.046 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationUpdate[73], type=Request[0], dest=10, callback=132, payload=84 0A 11 04 21 01 5E 85 8E 59 55 86 72 5A 73 80 9F 84 6C 31
13:28:34.054 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationUpdate[73], type=Request[0], dest=10, callback=132, payload=84 0A 11 04 21 01 5E 85 8E 59 55 86 72 5A 73 80 9F 84 6C 31
13:28:34.060 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null
13:28:34.061 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 0
13:28:34.063 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: null
13:28:34.068 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=ApplicationUpdate[73], type=Request[0], dest=10, callback=132, payload=84 0A 11 04 21 01 5E 85 8E 59 55 86 72 5A 73 80 9F 84 6C 31
13:28:34.070 [DEBUG] [message.ApplicationUpdateMessageClass] - NODE 10: Application update request. Node information received. Transaction null
13:28:34.072 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 10: Unsupported command class COMMAND_CLASS_TRANSPORT_SERVICE
13:28:34.073 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 10: Unsupported command class COMMAND_CLASS_SECURITY_2
13:28:34.075 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 10: Unsupported command class COMMAND_CLASS_SUPERVISION
13:28:34.076 [DEBUG] [message.ApplicationUpdateMessageClass] - NODE 10: Application update - no transaction.
13:28:34.078 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
13:28:34.080 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
13:28:34.084 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 0A 03 86 13 98 25 B4 73
13:28:34.088 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 10: Sending REQUEST Message = 01 0A 00 13 0A 03 86 13 98 25 B4 73
13:28:34.090 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT
13:28:34.092 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 125: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 180
13:28:34.101 [INFO ] [smarthome.event.ItemStateChangedEvent] - zwave_serial_zstick_0696af2c_serial_ack changed from 208 to 209
13:28:34.094 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
13:28:34.107 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
13:28:34.109 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
13:28:34.111 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 125: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 180
13:28:34.113 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK
13:28:34.115 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
13:28:34.117 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
13:28:34.117 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
13:28:34.119 [INFO ] [smarthome.event.ItemStateChangedEvent] - zwave_serial_zstick_0696af2c_serial_sof changed from 287 to 288
13:28:34.123 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
13:28:34.128 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
13:28:34.130 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 125: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 180
13:28:34.132 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
13:28:34.134 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 125: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 180
13:28:34.135 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 00 13 B4 00 5D
13:28:34.136 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
13:28:34.138 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 10: sentData successfully placed on stack.
13:28:34.138 [INFO ] [smarthome.event.ItemStateChangedEvent] - zwave_serial_zstick_0696af2c_serial_sof changed from 288 to 289
13:28:34.140 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 125: Advanced to WAIT_REQUEST
13:28:34.143 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 10: TID 125: Transaction not completed
13:28:34.143 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=180, payload=B4 00
13:28:34.145 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
13:28:34.147 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
13:28:34.154 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=180, payload=B4 00
13:28:34.156 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0A 00 04 00 0A 04 86 14 98 00 F5
13:28:34.156 [INFO ] [smarthome.event.ItemStateChangedEvent] - zwave_serial_zstick_0696af2c_serial_sof changed from 289 to 290
13:28:34.160 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 125: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 180
13:28:34.163 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
13:28:34.166 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 125: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 180
13:28:34.169 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 04 86 14 98 00
13:28:34.170 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking TID 125: (Callback 180)
13:28:34.173 [DEBUG] [l.serialmessage.ZWaveCommandProcessor] - Callback match!
13:28:34.175 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Correlated to TID 125: callback 180
13:28:34.179 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=180, payload=B4 00
13:28:34.182 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 10: SendData Request. CallBack ID = 180, Status = Transmission complete and ACK received(0)
13:28:34.185 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 125: Advanced to WAIT_DATA
13:28:34.188 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 10: TID 125: Transaction not completed
13:28:34.193 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 04 86 14 98 00
13:28:34.195 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null
13:28:34.198 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 10: Application Command Request (ALIVE:VERSION)
13:28:34.200 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 10: Incoming command class COMMAND_CLASS_VERSION, endpoint 0
13:28:34.203 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 10: SECURITY NOT required on COMMAND_CLASS_VERSION
13:28:34.206 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 10: Received COMMAND_CLASS_VERSION V0 VERSION_COMMAND_CLASS_REPORT
13:28:34.208 [DEBUG] [commandclass.ZWaveVersionCommandClass] - NODE 10: Process Version Command Class Report
13:28:34.210 [DEBUG] [commandclass.ZWaveVersionCommandClass] - NODE 10: Requested Command Class = COMMAND_CLASS_SECURITY, Version = 0
13:28:34.212 [INFO ] [commandclass.ZWaveVersionCommandClass] - NODE 10: Command Class COMMAND_CLASS_SECURITY has version 0!
13:28:34.214 [DEBUG] [commandclass.ZWaveVersionCommandClass] - NODE 10: Removed Command Class COMMAND_CLASS_SECURITY
13:28:34.216 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 10: Commands processed 1.
13:28:34.218 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 10: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1de8601.
13:28:34.221 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 10: Command verified org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1de8601.
13:28:34.223 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 10: notifyTransactionResponse TID:125 DONE
13:28:34.226 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 125: Transaction event listener: DONE: DONE ->
13:28:34.226 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 10: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
13:28:34.229 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
13:28:34.229 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 10: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@14266d0
13:28:34.231 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 10: Node Init transaction completed with response COMPLETE
13:28:34.232 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
13:28:34.232 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer: VERSION - checking COMMAND_CLASS_POWERLEVEL, version is 0
13:28:34.233 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
13:28:34.234 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer: VERSION - queued COMMAND_CLASS_POWERLEVEL
13:28:34.234 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
13:28:34.235 [DEBUG] [commandclass.ZWaveVersionCommandClass] - NODE 10: Creating new message for application command VERSION_COMMAND_CLASS_GET command class COMMAND_CLASS_POWERLEVEL
13:28:34.237 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 10: ZWaveCommandClassTransactionPayload - send to node
13:28:34.238 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 0A 02 84 08 25 B5 F1
13:28:34.238 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 10: SECURITY not supported
13:28:34.239 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 10: Command Class COMMAND_CLASS_VERSION is NOT required to be secured
13:28:34.241 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 10: Sending REQUEST Message = 01 09 00 13 0A 02 84 08 25 B5 F1
13:28:34.241 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 10: sendTransaction org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@8ea029
13:28:34.243 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 10: Bump transaction 127 priority from Config to Immediate
13:28:34.245 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT
13:28:34.249 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
13:28:34.248 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 126: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 181
13:28:34.254 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
13:28:34.255 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 10: Adding to device queue
13:28:34.255 [INFO ] [smarthome.event.ItemStateChangedEvent] - zwave_serial_zstick_0696af2c_serial_ack changed from 209 to 210
13:28:34.257 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 10: Added 127 to queue - size 5
13:28:34.259 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
13:28:34.263 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
13:28:34.265 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
13:28:34.266 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 126: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 181
13:28:34.268 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK
13:28:34.269 [INFO ] [smarthome.event.ItemStateChangedEvent] - zwave_serial_zstick_0696af2c_serial_sof changed from 290 to 291
13:28:34.270 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
13:28:34.272 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
13:28:34.272 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
13:28:34.276 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
13:28:34.278 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 126: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 181
13:28:34.281 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
13:28:34.283 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 126: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 181
13:28:34.285 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
13:28:34.288 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 10: sentData successfully placed on stack.
13:28:34.290 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 126: Advanced to WAIT_REQUEST
13:28:34.292 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 10: TID 126: Transaction not completed
13:28:34.294 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
13:28:34.295 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
13:28:34.335 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 00 13 B5 00 5C
13:28:34.339 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=181, payload=B5 00
13:28:34.342 [INFO ] [smarthome.event.ItemStateChangedEvent] - zwave_serial_zstick_0696af2c_serial_sof changed from 291 to 292
13:28:34.342 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=181, payload=B5 00
13:28:34.344 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 126: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 181
13:28:34.346 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
13:28:34.348 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 126: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 181
13:28:34.350 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking TID 126: (Callback 181)
13:28:34.352 [DEBUG] [l.serialmessage.ZWaveCommandProcessor] - Callback match!
13:28:34.354 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Correlated to TID 126: callback 181
13:28:34.356 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=181, payload=B5 00
13:28:34.359 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 10: SendData Request. CallBack ID = 181, Status = Transmission complete and ACK received(0)
13:28:34.361 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 126: Transaction COMPLETED
13:28:34.363 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 10: Response processed after 115ms
13:28:34.365 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 10: TID 126: Transaction completed
13:28:34.367 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 10: notifyTransactionResponse TID:126 DONE
13:28:34.369 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 126: Transaction event listener: DONE: DONE ->
13:28:34.369 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 10: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
13:28:34.371 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
13:28:34.372 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 10: Went to sleep COMPLETE
13:28:34.373 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
13:29:13.496 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 17 00 49 84 0A 11 04 21 01 5E 85 8E 59 55 86 72 5A 73 80 9F 84 6C 31 58
13:29:13.496 [INFO ] [smarthome.event.ItemStateChangedEvent] - zwave_serial_zstick_0696af2c_serial_sof changed from 292 to 293
13:29:13.514 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationUpdate[73], type=Request[0], dest=10, callback=132, payload=84 0A 11 04 21 01 5E 85 8E 59 55 86 72 5A 73 80 9F 84 6C 31
13:29:13.520 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationUpdate[73], type=Request[0], dest=10, callback=132, payload=84 0A 11 04 21 01 5E 85 8E 59 55 86 72 5A 73 80 9F 84 6C 31
13:29:13.530 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null
13:29:13.532 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 0
13:29:13.535 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: null
13:29:13.541 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=ApplicationUpdate[73], type=Request[0], dest=10, callback=132, payload=84 0A 11 04 21 01 5E 85 8E 59 55 86 72 5A 73 80 9F 84 6C 31
13:29:13.546 [DEBUG] [message.ApplicationUpdateMessageClass] - NODE 10: Application update request. Node information received. Transaction null
13:29:13.548 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 10: Unsupported command class COMMAND_CLASS_TRANSPORT_SERVICE
13:29:13.551 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 10: Unsupported command class COMMAND_CLASS_SECURITY_2
13:29:13.554 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 10: Unsupported command class COMMAND_CLASS_SUPERVISION
13:29:13.558 [DEBUG] [message.ApplicationUpdateMessageClass] - NODE 10: Application update - no transaction.
13:29:13.561 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
13:29:13.564 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
13:29:13.811 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 10: Is awake with 1 messages in the queue
13:29:13.813 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 10: Start sleep timer at 5000ms
13:29:13.815 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 10: Got an event from Z-Wave network: ZWaveNodeStatusEvent
13:29:13.835 [DEBUG] [ave.internal.protocol.ZWaveController] - NODE 10: Node Status event - Node is AWAKE
13:29:13.843 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing 'zwave:device:0696af2c:node10' has been updated.
13:29:16.316 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 10: WakeupTimerTask 1 Messages waiting, state VERSION
13:29:18.816 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 10: WakeupTimerTask 1 Messages waiting, state VERSION
13:29:18.820 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 10: No more messages, go back to sleep
13:29:18.826 [DEBUG] [.commandclass.ZWaveWakeUpCommandClass] - NODE 10: Creating new message for application command WAKE_UP_NO_MORE_INFORMATION
13:29:18.830 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 10: SECURITY not supported
13:29:18.833 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 10: Command Class COMMAND_CLASS_WAKE_UP is NOT required to be secured
13:29:18.837 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 10: sendTransaction org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@11c4612
13:29:18.840 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 10: Bump transaction 128 priority from Immediate to Immediate
13:29:18.848 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 10: Adding to device queue
13:29:18.852 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 10: Added 128 to queue - size 6
13:29:18.856 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
13:29:18.861 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 0A 03 86 13 73 25 B6 9A
13:29:18.868 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 10: Sending REQUEST Message = 01 0A 00 13 0A 03 86 13 73 25 B6 9A
13:29:18.872 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT
13:29:18.875 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
13:29:18.878 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
13:29:18.883 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
13:29:18.884 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
13:29:18.887 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
13:29:18.890 [INFO ] [smarthome.event.ItemStateChangedEvent] - zwave_serial_zstick_0696af2c_serial_ack changed from 210 to 211
13:29:18.891 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null
13:29:18.892 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK
13:29:18.884 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 127: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 182
13:29:18.900 [INFO ] [smarthome.event.ItemStateChangedEvent] - zwave_serial_zstick_0696af2c_serial_sof changed from 293 to 294
13:29:18.896 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
13:29:18.908 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 127: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 182
13:29:18.915 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
13:29:18.922 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 127: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 182
13:29:18.931 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
13:29:18.938 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 10: sentData successfully placed on stack.
13:29:18.945 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 127: Advanced to WAIT_REQUEST
13:29:18.948 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 10: TID 127: Transaction not completed
13:29:18.952 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
13:29:18.955 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
13:29:22.998 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 00 13 B6 01 5E
13:29:23.004 [INFO ] [smarthome.event.ItemStateChangedEvent] - zwave_serial_zstick_0696af2c_serial_sof changed from 294 to 295
13:29:23.005 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=1, callback=182, payload=B6 01
13:29:23.007 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=1, callback=182, payload=B6 01
13:29:23.019 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 127: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 182
13:29:23.022 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
13:29:23.025 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 127: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 182
13:29:23.027 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking TID 127: (Callback 182)
13:29:23.030 [DEBUG] [l.serialmessage.ZWaveCommandProcessor] - Callback match!
13:29:23.032 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Correlated to TID 127: callback 182
13:29:23.036 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=1, callback=182, payload=B6 01
13:29:23.039 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 10: SendData Request. CallBack ID = 182, Status = Transmission complete, no ACK received(1)
13:29:23.042 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 127: Transaction CANCELLED
13:29:23.045 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 10: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
13:29:23.048 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 10: Transaction failed waiting for REQUEST, assume sleeping device.
13:29:23.050 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 10: CANCEL while sending message. Requeueing - 2 attempts left!
13:29:23.052 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 127: Transaction RESET with 2 retries remaining.
13:29:23.054 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 10: Adding to device queue
13:29:23.056 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 10: Added 127 to queue - size 6
13:29:23.058 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
13:29:23.061 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 10: TID 127: Transaction not completed
13:29:23.063 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
13:29:23.066 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
13:30:00.320 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 17 00 49 84 0A 11 04 21 01 5E 85 8E 59 55 86 72 5A 73 80 9F 84 6C 31 58
13:30:00.320 [INFO ] [smarthome.event.ItemStateChangedEvent] - zwave_serial_zstick_0696af2c_serial_sof changed from 295 to 296
13:30:00.340 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationUpdate[73], type=Request[0], dest=10, callback=132, payload=84 0A 11 04 21 01 5E 85 8E 59 55 86 72 5A 73 80 9F 84 6C 31
13:30:00.357 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationUpdate[73], type=Request[0], dest=10, callback=132, payload=84 0A 11 04 21 01 5E 85 8E 59 55 86 72 5A 73 80 9F 84 6C 31
13:30:00.367 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null
13:30:00.370 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 0
13:30:00.375 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: null
13:30:00.382 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=ApplicationUpdate[73], type=Request[0], dest=10, callback=132, payload=84 0A 11 04 21 01 5E 85 8E 59 55 86 72 5A 73 80 9F 84 6C 31
13:30:00.387 [DEBUG] [message.ApplicationUpdateMessageClass] - NODE 10: Application update request. Node information received. Transaction null
13:30:00.389 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 10: Unsupported command class COMMAND_CLASS_TRANSPORT_SERVICE
13:30:00.393 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 10: Unsupported command class COMMAND_CLASS_SECURITY_2
13:30:00.395 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 10: Unsupported command class COMMAND_CLASS_SUPERVISION
13:30:00.399 [DEBUG] [message.ApplicationUpdateMessageClass] - NODE 10: Application update - no transaction.
13:30:00.401 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
13:30:00.405 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
13:30:00.652 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 10: Is awake with 2 messages in the queue
13:30:00.654 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 10: Start sleep timer at 5000ms
13:30:00.657 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 10: Got an event from Z-Wave network: ZWaveNodeStatusEvent
13:30:00.675 [DEBUG] [ave.internal.protocol.ZWaveController] - NODE 10: Node Status event - Node is AWAKE
13:30:00.679 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing 'zwave:device:0696af2c:node10' has been updated.
13:30:04.826 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 17 00 49 84 0A 11 04 21 01 5E 85 8E 59 55 86 72 5A 73 80 9F 84 6C 31 58
13:30:04.826 [INFO ] [smarthome.event.ItemStateChangedEvent] - zwave_serial_zstick_0696af2c_serial_sof changed from 296 to 297
13:30:04.844 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationUpdate[73], type=Request[0], dest=10, callback=132, payload=84 0A 11 04 21 01 5E 85 8E 59 55 86 72 5A 73 80 9F 84 6C 31
13:30:04.853 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationUpdate[73], type=Request[0], dest=10, callback=132, payload=84 0A 11 04 21 01 5E 85 8E 59 55 86 72 5A 73 80 9F 84 6C 31
13:30:04.856 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null
13:30:04.859 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 0
13:30:04.861 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: null
13:30:04.867 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=ApplicationUpdate[73], type=Request[0], dest=10, callback=132, payload=84 0A 11 04 21 01 5E 85 8E 59 55 86 72 5A 73 80 9F 84 6C 31
13:30:04.871 [DEBUG] [message.ApplicationUpdateMessageClass] - NODE 10: Application update request. Node information received. Transaction null
13:30:04.874 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 10: Unsupported command class COMMAND_CLASS_TRANSPORT_SERVICE
13:30:04.877 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 10: Unsupported command class COMMAND_CLASS_SECURITY_2
13:30:04.880 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 10: Unsupported command class COMMAND_CLASS_SUPERVISION
13:30:04.883 [DEBUG] [message.ApplicationUpdateMessageClass] - NODE 10: Application update - no transaction.
13:30:04.887 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
13:30:04.892 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
13:30:04.898 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 0A 03 86 13 73 25 B7 9B
13:30:04.903 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 10: Sending REQUEST Message = 01 0A 00 13 0A 03 86 13 73 25 B7 9B
13:30:04.906 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT
13:30:04.909 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
13:30:04.911 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 127: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 183
13:30:04.912 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
13:30:04.916 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
13:30:04.918 [INFO ] [smarthome.event.ItemStateChangedEvent] - zwave_serial_zstick_0696af2c_serial_ack changed from 211 to 212
13:30:04.920 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 127: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 183
13:30:04.921 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
13:30:04.923 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK
13:30:04.927 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
13:30:04.927 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
13:30:04.932 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
13:30:04.937 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
13:30:04.938 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 00 13 B7 00 5E
13:30:04.940 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 127: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 183
13:30:04.944 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
13:30:04.947 [INFO ] [smarthome.event.ItemStateChangedEvent] - zwave_serial_zstick_0696af2c_serial_sof changed from 297 to 298
13:30:04.948 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 127: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 183
13:30:04.951 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
13:30:04.951 [INFO ] [smarthome.event.ItemStateChangedEvent] - zwave_serial_zstick_0696af2c_serial_sof changed from 298 to 299
13:30:04.954 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=183, payload=B7 00
13:30:04.955 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 10: sentData successfully placed on stack.
13:30:04.959 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 127: Advanced to WAIT_REQUEST
13:30:04.963 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0A 00 04 00 0A 04 86 14 73 01 1F
13:30:04.964 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 10: TID 127: Transaction not completed
13:30:04.967 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=183, payload=B7 00
13:30:04.968 [INFO ] [smarthome.event.ItemStateChangedEvent] - zwave_serial_zstick_0696af2c_serial_sof changed from 299 to 300
13:30:04.972 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 127: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 183
13:30:04.973 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 04 86 14 73 01
13:30:04.976 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
13:30:04.980 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 127: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 183
13:30:04.982 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking TID 127: (Callback 183)
13:30:04.986 [DEBUG] [l.serialmessage.ZWaveCommandProcessor] - Callback match!
13:30:04.989 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Correlated to TID 127: callback 183
13:30:04.993 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=183, payload=B7 00
13:30:04.996 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 10: SendData Request. CallBack ID = 183, Status = Transmission complete and ACK received(0)
13:30:05.001 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 127: Advanced to WAIT_DATA
13:30:05.004 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 10: TID 127: Transaction not completed
13:30:05.008 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 04 86 14 73 01
13:30:05.011 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null
13:30:05.014 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 10: Application Command Request (ALIVE:VERSION)
13:30:05.018 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 10: Incoming command class COMMAND_CLASS_VERSION, endpoint 0
13:30:05.020 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 10: SECURITY not supported
13:30:05.023 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 10: Received COMMAND_CLASS_VERSION V0 VERSION_COMMAND_CLASS_REPORT
13:30:05.026 [DEBUG] [commandclass.ZWaveVersionCommandClass] - NODE 10: Process Version Command Class Report
13:30:05.029 [DEBUG] [commandclass.ZWaveVersionCommandClass] - NODE 10: Requested Command Class = COMMAND_CLASS_POWERLEVEL, Version = 1
13:30:05.031 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 10: Version = 1, version set. Enabling extra functionality.
13:30:05.035 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 10: Commands processed 1.
13:30:05.037 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 10: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1ac9a20.
13:30:05.041 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 10: Command verified org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1ac9a20.
13:30:05.043 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 10: notifyTransactionResponse TID:127 DONE
13:30:05.047 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 127: Transaction event listener: DONE: DONE ->
13:30:05.047 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 10: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
13:30:05.050 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
13:30:05.051 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 10: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@6cdbd9
13:30:05.053 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 10: Node Init transaction completed with response COMPLETE
13:30:05.054 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
13:30:05.056 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
13:30:05.056 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer: VERSION - checking COMMAND_CLASS_ASSOCIATION, version is 0
13:30:05.059 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
13:30:05.059 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 10: Node advancer: VERSION - queued COMMAND_CLASS_ASSOCIATION
13:30:05.062 [DEBUG] [commandclass.ZWaveVersionCommandClass] - NODE 10: Creating new message for application command VERSION_COMMAND_CLASS_GET command class COMMAND_CLASS_ASSOCIATION
13:30:05.064 [DEBUG] [ialization.ZWaveNodeInitStageAdvancer] - NODE 10: ZWaveCommandClassTransactionPayload - send to node
13:30:05.065 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 0A 02 84 08 25 B8 FC
13:30:05.067 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 10: SECURITY not supported
13:30:05.069 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 10: Sending REQUEST Message = 01 09 00 13 0A 02 84 08 25 B8 FC
13:30:05.069 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 10: Command Class COMMAND_CLASS_VERSION is NOT required to be secured
13:30:05.072 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 10: sendTransaction org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@10c96d6
13:30:05.074 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT
13:30:05.075 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 10: Bump transaction 129 priority from Config to Immediate
13:30:05.076 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 128: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 184
13:30:05.077 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
13:30:05.081 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
13:30:05.084 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 10: Adding to device queue
13:30:05.086 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
13:30:05.088 [INFO ] [smarthome.event.ItemStateChangedEvent] - zwave_serial_zstick_0696af2c_serial_ack changed from 212 to 213
13:30:05.089 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 128: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 184
13:30:05.092 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 10: Added 129 to queue - size 5
13:30:05.094 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK
13:30:05.095 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
13:30:05.099 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty