22:54:04.659 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 9: Configuration update received 22:54:04.682 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 9: Configuration update set binding_cmdrepollperiod to 2000 (BigDecimal) [ was 1500 RB ] 22:54:04.707 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing 'zwave:device:dbe4518c:node9' has been updated. 22:54:04.722 [INFO ] [smarthome.event.ConfigStatusInfoEvent] - ConfigStatusInfo [configStatusMessages=[]] 22:54:17.827 [INFO ] [smarthome.event.ItemCommandEvent ] - Item 'MtrWinBed' received command 40 22:54:17.832 [INFO ] [arthome.event.ItemStatePredictedEvent] - MtrWinBed predicted to become 40 22:54:17.859 [INFO ] [smarthome.event.ItemStateChangedEvent] - MtrWinBed changed from 0 to 40 22:54:17.867 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 9: Command received zwave:device:dbe4518c:node9:blinds_control --> 40 [PercentType] 22:54:17.872 [DEBUG] [ass.ZWaveMultiLevelSwitchCommandClass] - NODE 9: Creating new message for command SWITCH_MULTILEVEL_SET 22:54:17.876 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 9: SECURITY not supported 22:54:17.879 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 9: Command Class COMMAND_CLASS_SWITCH_MULTILEVEL is NOT required to be secured 22:54:17.882 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 9: Adding to device queue 22:54:17.885 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 9: Added 968 to queue - size 2 22:54:17.888 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 22:54:17.895 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 09 03 26 01 28 25 C6 00 22:54:17.901 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 9: Sending REQUEST Message = 01 0A 00 13 09 03 26 01 28 25 C6 00 22:54:17.908 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 22:54:17.912 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 22:54:17.917 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 22:54:17.920 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null 22:54:17.923 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK 22:54:17.923 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 22:54:17.927 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 22:54:17.928 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT 22:54:17.933 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 968: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 198 22:54:17.934 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 22:54:17.937 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 9: Polling initialised at 86400 seconds - start in 2000 milliseconds. 22:54:17.937 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 22:54:17.945 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 22:54:17.948 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 968: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 198 22:54:17.953 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 22:54:17.958 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 968: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 198 22:54:17.963 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 C6 00 00 05 28 22:54:17.963 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 22:54:17.969 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 9: sentData successfully placed on stack. 22:54:17.973 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 968: Advanced to WAIT_REQUEST 22:54:17.976 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=198, payload=C6 00 00 05 22:54:17.978 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 9: TID 968: Transaction not completed 22:54:17.985 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=198, payload=C6 00 00 05 22:54:17.989 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 968: [WAIT_REQUEST] priority=Set, requiresResponse=true, callback: 198 22:54:17.993 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 22:54:17.996 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 968: [WAIT_REQUEST] priority=Set, requiresResponse=true, callback: 198 22:54:18.001 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking TID 968: (Callback 198) 22:54:18.004 [DEBUG] [l.serialmessage.ZWaveCommandProcessor] - Callback match! 22:54:18.009 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Correlated to TID 968: callback 198 22:54:18.013 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=198, payload=C6 00 00 05 22:54:18.018 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 9: SendData Request. CallBack ID = 198, Status = Transmission complete and ACK received(0) 22:54:18.021 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 9: resetResendCount initComplete=true isDead=false 22:54:18.026 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 968: Transaction COMPLETED 22:54:18.030 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 9: Response processed after 97ms 22:54:18.035 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 9: TID 968: Transaction completed 22:54:18.039 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 9: notifyTransactionResponse TID:968 DONE 22:54:18.044 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 9: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 22:54:18.049 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 22:54:18.051 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 22:54:19.937 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 9: Polling... 22:54:19.942 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 9: Polling zwave:device:dbe4518c:node9:blinds_control 22:54:19.947 [DEBUG] [verter.ZWaveMultiLevelSwitchConverter] - NODE 9: Generating poll message for COMMAND_CLASS_SWITCH_MULTILEVEL, endpoint 0 22:54:19.951 [DEBUG] [ass.ZWaveMultiLevelSwitchCommandClass] - NODE 9: Creating new message for command SWITCH_MULTILEVEL_GET 22:54:19.958 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 9: SECURITY not supported 22:54:19.961 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 9: Command Class COMMAND_CLASS_SWITCH_MULTILEVEL is NOT required to be secured 22:54:19.967 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 9: Polling skipped for zwave:device:dbe4518c:node9:blinds_control on COMMAND_CLASS_BASIC 22:54:19.971 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 9: Adding to device queue 22:54:19.976 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 9: Added 969 to queue - size 2 22:54:19.981 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 22:54:19.991 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 09 02 26 02 25 C7 28 22:54:19.999 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 9: Sending REQUEST Message = 01 09 00 13 09 02 26 02 25 C7 28 22:54:20.007 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 22:54:20.012 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 22:54:20.017 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 22:54:20.021 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null 22:54:20.022 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 22:54:20.024 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK 22:54:20.026 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 22:54:20.028 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT 22:54:20.034 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 969: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 199 22:54:20.036 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 22:54:20.040 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 22:54:20.045 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 22:54:20.051 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 969: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 199 22:54:20.054 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 22:54:20.059 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 969: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 199 22:54:20.063 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 22:54:20.068 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 9: sentData successfully placed on stack. 22:54:20.072 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 969: Advanced to WAIT_REQUEST 22:54:20.076 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 9: TID 969: Transaction not completed 22:54:20.079 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 22:54:20.082 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 22:54:20.140 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 C7 00 00 0D 21 22:54:20.169 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=199, payload=C7 00 00 0D 22:54:20.174 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=199, payload=C7 00 00 0D 22:54:20.177 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 969: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 199 22:54:20.180 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 22:54:20.184 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 969: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 199 22:54:20.187 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking TID 969: (Callback 199) 22:54:20.192 [DEBUG] [l.serialmessage.ZWaveCommandProcessor] - Callback match! 22:54:20.199 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 00 09 03 26 03 04 D9 22:54:20.200 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Correlated to TID 969: callback 199 22:54:20.204 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=199, payload=C7 00 00 0D 22:54:20.207 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 9: SendData Request. CallBack ID = 199, Status = Transmission complete and ACK received(0) 22:54:20.211 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 9: resetResendCount initComplete=true isDead=false 22:54:20.211 [INFO ] [smarthome.event.ItemStateChangedEvent] - BattNowSt changed from 65 to 64 22:54:20.213 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=9, callback=0, payload=00 09 03 26 03 04 22:54:20.213 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 969: Advanced to WAIT_DATA 22:54:20.216 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 9: TID 969: Transaction not completed 22:54:20.221 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=9, callback=0, payload=00 09 03 26 03 04 22:54:20.224 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null 22:54:20.227 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 9: Application Command Request (ALIVE:DONE) 22:54:20.234 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 9: resetResendCount initComplete=true isDead=false 22:54:20.237 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 9: Incoming command class COMMAND_CLASS_SWITCH_MULTILEVEL, endpoint 0 22:54:20.240 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 9: SECURITY not supported 22:54:20.243 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 9: Received COMMAND_CLASS_SWITCH_MULTILEVEL V3 SWITCH_MULTILEVEL_REPORT 22:54:20.252 [DEBUG] [ass.ZWaveMultiLevelSwitchCommandClass] - NODE 9: Switch Multi Level report, value = 4 22:54:20.255 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 9: Got an event from Z-Wave network: ZWaveCommandClassValueEvent 22:54:20.258 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 9: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_SWITCH_MULTILEVEL, value=4 22:54:20.259 [INFO ] [smarthome.event.ItemStateChangedEvent] - BattNow changed from 65 to 64 22:54:20.261 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 9: Updating channel state zwave:device:dbe4518c:node9:blinds_control to 4 [PercentType] 22:54:20.266 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 9: Commands processed 1. 22:54:20.268 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 9: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1ea001e. 22:54:20.271 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 9: Command verified org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1ea001e. 22:54:20.274 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 9: notifyTransactionResponse TID:969 DONE 22:54:20.280 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 9: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 22:54:20.283 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1 22:54:20.286 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 22:54:20.286 [INFO ] [smarthome.event.ItemStateChangedEvent] - BattChgNum changed from 65 to 64 22:54:20.288 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 22:54:20.291 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 22:54:20.298 [INFO ] [smarthome.event.ItemStateChangedEvent] - MtrWinBed changed from 40 to 4 22:54:20.514 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 10 09 03 26 03 04 C9 22:54:20.551 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=9, callback=16, payload=10 09 03 26 03 04 22:54:20.556 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=9, callback=16, payload=10 09 03 26 03 04 22:54:20.560 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null 22:54:20.562 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 9: Application Command Request (ALIVE:DONE) 22:54:20.566 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 9: resetResendCount initComplete=true isDead=false 22:54:20.569 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 9: Incoming command class COMMAND_CLASS_SWITCH_MULTILEVEL, endpoint 0 22:54:20.573 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 9: SECURITY not supported 22:54:20.576 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 9: Received COMMAND_CLASS_SWITCH_MULTILEVEL V3 SWITCH_MULTILEVEL_REPORT 22:54:20.580 [DEBUG] [ass.ZWaveMultiLevelSwitchCommandClass] - NODE 9: Switch Multi Level report, value = 4 22:54:20.583 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 9: Got an event from Z-Wave network: ZWaveCommandClassValueEvent 22:54:20.587 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 9: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_SWITCH_MULTILEVEL, value=4 22:54:20.591 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 9: Updating channel state zwave:device:dbe4518c:node9:blinds_control to 4 [PercentType] 22:54:20.597 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 9: Commands processed 1. 22:54:20.600 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 9: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@12fce6. 22:54:20.604 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 22:54:20.606 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 22:54:20.609 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 22:54:20.612 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2nd adjustment to poll period 22:57:57.940 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 9: Configuration update received 22:57:57.953 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 9: Configuration update set binding_cmdrepollperiod to 3000 (BigDecimal) 22:57:57.990 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing 'zwave:device:dbe4518c:node9' has been updated. 22:57:57.995 [INFO ] [smarthome.event.ConfigStatusInfoEvent] - ConfigStatusInfo [configStatusMessages=[]] 22:58:17.261 [INFO ] [smarthome.event.ItemCommandEvent ] - Item 'MtrWinBed' received command 10 22:58:17.267 [INFO ] [arthome.event.ItemStatePredictedEvent] - MtrWinBed predicted to become 10 22:58:17.296 [INFO ] [smarthome.event.ItemStateChangedEvent] - MtrWinBed changed from 4 to 10 22:58:17.315 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 9: Command received zwave:device:dbe4518c:node9:blinds_control --> 10 [PercentType] 22:58:17.318 [DEBUG] [ass.ZWaveMultiLevelSwitchCommandClass] - NODE 9: Creating new message for command SWITCH_MULTILEVEL_SET 22:58:17.321 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 9: SECURITY not supported 22:58:17.324 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 9: Command Class COMMAND_CLASS_SWITCH_MULTILEVEL is NOT required to be secured 22:58:17.327 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 9: Adding to device queue 22:58:17.330 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 9: Added 972 to queue - size 2 22:58:17.333 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 22:58:17.349 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0A 00 13 09 03 26 01 0A 25 CE 2A 22:58:17.355 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 9: Sending REQUEST Message = 01 0A 00 13 09 03 26 01 0A 25 CE 2A 22:58:17.361 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 22:58:17.364 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 22:58:17.367 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 22:58:17.370 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null 22:58:17.370 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 22:58:17.372 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK 22:58:17.375 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 22:58:17.388 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT 22:58:17.391 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 972: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 206 22:58:17.395 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 22:58:17.395 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 9: Polling initialised at 86400 seconds - start in 3000 milliseconds. 22:58:17.419 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 22:58:17.424 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 22:58:17.426 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 972: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 206 22:58:17.429 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 22:58:17.429 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 CE 00 00 05 20 22:58:17.432 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 972: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 206 22:58:17.435 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 22:58:17.439 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 9: sentData successfully placed on stack. 22:58:17.439 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=206, payload=CE 00 00 05 22:58:17.441 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 972: Advanced to WAIT_REQUEST 22:58:17.444 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 9: TID 972: Transaction not completed 22:58:17.454 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=206, payload=CE 00 00 05 22:58:17.461 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 972: [WAIT_REQUEST] priority=Set, requiresResponse=true, callback: 206 22:58:17.464 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 22:58:17.468 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 972: [WAIT_REQUEST] priority=Set, requiresResponse=true, callback: 206 22:58:17.471 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking TID 972: (Callback 206) 22:58:17.475 [DEBUG] [l.serialmessage.ZWaveCommandProcessor] - Callback match! 22:58:17.478 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Correlated to TID 972: callback 206 22:58:17.482 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=206, payload=CE 00 00 05 22:58:17.486 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 9: SendData Request. CallBack ID = 206, Status = Transmission complete and ACK received(0) 22:58:17.490 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 9: resetResendCount initComplete=true isDead=false 22:58:17.493 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 972: Transaction COMPLETED 22:58:17.497 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 9: Response processed after 105ms 22:58:17.500 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 9: TID 972: Transaction completed 22:58:17.503 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 9: notifyTransactionResponse TID:972 DONE 22:58:17.508 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 9: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 22:58:17.511 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 22:58:17.515 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 22:58:20.396 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 9: Polling... 22:58:20.400 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 9: Polling zwave:device:dbe4518c:node9:blinds_control 22:58:20.403 [DEBUG] [verter.ZWaveMultiLevelSwitchConverter] - NODE 9: Generating poll message for COMMAND_CLASS_SWITCH_MULTILEVEL, endpoint 0 22:58:20.407 [DEBUG] [ass.ZWaveMultiLevelSwitchCommandClass] - NODE 9: Creating new message for command SWITCH_MULTILEVEL_GET 22:58:20.410 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 9: SECURITY not supported 22:58:20.414 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 9: Command Class COMMAND_CLASS_SWITCH_MULTILEVEL is NOT required to be secured 22:58:20.417 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 9: Polling skipped for zwave:device:dbe4518c:node9:blinds_control on COMMAND_CLASS_BASIC 22:58:20.421 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 9: Adding to device queue 22:58:20.424 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 9: Added 973 to queue - size 2 22:58:20.428 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 22:58:20.434 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 09 02 26 02 25 CF 20 22:58:20.442 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 9: Sending REQUEST Message = 01 09 00 13 09 02 26 02 25 CF 20 22:58:20.448 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 22:58:20.452 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 22:58:20.456 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 22:58:20.458 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null 22:58:20.460 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 22:58:20.461 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg: ACK 22:58:20.464 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 22:58:20.468 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - Message SENT 22:58:20.471 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 973: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 207 22:58:20.473 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 22:58:20.476 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 22:58:20.480 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 22:58:20.484 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 973: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 207 22:58:20.487 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 22:58:20.490 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 973: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 207 22:58:20.493 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 22:58:20.496 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 9: sentData successfully placed on stack. 22:58:20.499 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 973: Advanced to WAIT_REQUEST 22:58:20.502 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 9: TID 973: Transaction not completed 22:58:20.504 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 22:58:20.508 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 22:58:20.609 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 CF 00 00 10 34 22:58:20.639 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=207, payload=CF 00 00 10 22:58:20.644 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=207, payload=CF 00 00 10 22:58:20.647 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction TID 973: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 207 22:58:20.650 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 22:58:20.653 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Last transaction: TID 973: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 207 22:58:20.656 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Checking TID 973: (Callback 207) 22:58:20.659 [DEBUG] [l.serialmessage.ZWaveCommandProcessor] - Callback match! 22:58:20.659 [DEBUG] [ZWaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 00 09 03 26 03 24 F9 22:58:20.662 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Correlated to TID 973: callback 207 22:58:20.669 [DEBUG] [ave.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=207, payload=CF 00 00 10 22:58:20.671 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=9, callback=0, payload=00 09 03 26 03 24 22:58:20.673 [DEBUG] [ol.serialmessage.SendDataMessageClass] - NODE 9: SendData Request. CallBack ID = 207, Status = Transmission complete and ACK received(0) 22:58:20.678 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 9: resetResendCount initComplete=true isDead=false 22:58:20.681 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - TID 973: Advanced to WAIT_DATA 22:58:20.685 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 9: TID 973: Transaction not completed 22:58:20.693 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=9, callback=0, payload=00 09 03 26 03 24 22:58:20.696 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - lastTransaction null 22:58:20.700 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 9: Application Command Request (ALIVE:DONE) 22:58:20.703 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 9: resetResendCount initComplete=true isDead=false 22:58:20.707 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 9: Incoming command class COMMAND_CLASS_SWITCH_MULTILEVEL, endpoint 0 22:58:20.710 [DEBUG] [ing.zwave.internal.protocol.ZWaveNode] - NODE 9: SECURITY not supported 22:58:20.713 [DEBUG] [otocol.commandclass.ZWaveCommandClass] - NODE 9: Received COMMAND_CLASS_SWITCH_MULTILEVEL V3 SWITCH_MULTILEVEL_REPORT 22:58:20.716 [DEBUG] [ass.ZWaveMultiLevelSwitchCommandClass] - NODE 9: Switch Multi Level report, value = 36 22:58:20.720 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 9: Got an event from Z-Wave network: ZWaveCommandClassValueEvent 22:58:20.723 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 9: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_SWITCH_MULTILEVEL, value=36 22:58:20.728 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 9: Updating channel state zwave:device:dbe4518c:node9:blinds_control to 36 [PercentType] 22:58:20.734 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 9: Commands processed 1. 22:58:20.741 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 9: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1e93749. 22:58:20.742 [INFO ] [smarthome.event.ItemStateChangedEvent] - MtrWinBed changed from 10 to 36 22:58:20.744 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 9: Command verified org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1e93749. 22:58:20.746 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 9: notifyTransactionResponse TID:973 DONE 22:58:20.756 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 9: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 22:58:20.759 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1 22:58:20.762 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 22:58:20.764 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 22:58:20.767 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.