openhab2 (2.5.0~S1614-1) 225 │ Active │ 80 │ 2.5.0.201906151852 │ openHAB Add-ons :: Bundles :: ZWave Binding this log contains all after: - fresh update fresh restart of the system - deleted a thing in habmin - set the binding to inclusion (true binding did nothing, just let it end) - deleted an old wrong discovery (security issue) - set the controller in exclusion (true the binding)and excluded the wrong thing 2019-06-16 14:21:34.693 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 18: Polling... ==> /var/log/openhab2/events.log <== 2019-06-16 14:22:14.613 [ome.event.ItemCommandEvent] - Item 'TimerOFF_5min_1' received command OFF 2019-06-16 14:22:14.699 [vent.ItemStateChangedEvent] - TimerOFF_5min_1 changed from ON to OFF 2019-06-16 14:22:15.447 [ome.event.ItemCommandEvent] - Item 'SwitchLichtGang' received command OFF 2019-06-16 14:22:15.468 [nt.ItemStatePredictedEvent] - SwitchLichtGang predicted to become OFF ==> /var/log/openhab2/openhab.log <== 2019-06-16 14:22:15.482 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 11: Command received zwave:device:16b56bde664:node11:switch_binary1 --> OFF [OnOffType] 2019-06-16 14:22:15.485 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 11: Creating new message for application command SWITCH_BINARY_SET 2019-06-16 14:22:15.488 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 11: Encapsulating message, instance / endpoint 1 2019-06-16 14:22:15.491 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 11: Creating new message for command MULTI_CHANNEL_ENCAP endpoint 1 2019-06-16 14:22:15.493 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 11: SECURITY NOT required on COMMAND_CLASS_MULTI_CHANNEL 2019-06-16 14:22:15.496 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 11: Command Class COMMAND_CLASS_MULTI_CHANNEL is NOT required to be secured 2019-06-16 14:22:15.498 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: Adding to device queue 2019-06-16 14:22:15.501 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: Added 155 to queue - size 3 2019-06-16 14:22:15.503 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-06-16 14:22:15.508 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0E 00 13 0B 07 60 0D 01 01 25 01 00 25 74 F6 2019-06-16 14:22:15.513 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 11: Sending REQUEST Message = 01 0E 00 13 0B 07 60 0D 01 01 25 01 00 25 74 F6 ==> /var/log/openhab2/events.log <== 2019-06-16 14:22:15.517 [vent.ItemStateChangedEvent] - SwitchLichtGang changed from ON to OFF ==> /var/log/openhab2/openhab.log <== 2019-06-16 14:22:15.517 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2019-06-16 14:22:15.521 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 155: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 116 2019-06-16 14:22:15.521 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2019-06-16 14:22:15.525 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 11: Polling intialised at 86400 seconds - start in 1500 milliseconds. 2019-06-16 14:22:15.528 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-06-16 14:22:15.531 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-06-16 14:22:15.532 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 2019-06-16 14:22:15.533 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 155: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 116 2019-06-16 14:22:15.536 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2019-06-16 14:22:15.538 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2019-06-16 14:22:15.539 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2019-06-16 14:22:15.542 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2019-06-16 14:22:15.545 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2019-06-16 14:22:15.547 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 155: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 116 2019-06-16 14:22:15.549 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2019-06-16 14:22:15.552 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 155: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 116 2019-06-16 14:22:15.554 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2019-06-16 14:22:15.557 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 11: sentData successfully placed on stack. 2019-06-16 14:22:15.559 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 155: Advanced to WAIT_REQUEST 2019-06-16 14:22:15.562 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: TID 155: Transaction not completed 2019-06-16 14:22:15.564 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2019-06-16 14:22:15.567 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2019-06-16 14:22:15.569 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 74 00 00 05 9A 2019-06-16 14:22:15.572 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=116, payload=74 00 00 05 2019-06-16 14:22:15.574 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=116, payload=74 00 00 05 2019-06-16 14:22:15.576 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 155: [WAIT_REQUEST] priority=Set, requiresResponse=true, callback: 116 2019-06-16 14:22:15.578 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2019-06-16 14:22:15.579 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 155: [WAIT_REQUEST] priority=Set, requiresResponse=true, callback: 116 2019-06-16 14:22:15.581 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 155: (Callback 116) 2019-06-16 14:22:15.583 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match! 2019-06-16 14:22:15.585 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 155: callback 116 2019-06-16 14:22:15.586 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=116, payload=74 00 00 05 2019-06-16 14:22:15.588 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 11: SendData Request. CallBack ID = 116, Status = Transmission complete and ACK received(0) 2019-06-16 14:22:15.590 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 11: resetResendCount initComplete=true isDead=false 2019-06-16 14:22:15.591 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 155: Transaction COMPLETED 2019-06-16 14:22:15.593 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: Response processed after 73ms 2019-06-16 14:22:15.595 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: TID 155: Transaction completed 2019-06-16 14:22:15.596 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: notifyTransactionResponse TID:155 DONE 2019-06-16 14:22:15.598 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 11: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 2019-06-16 14:22:15.600 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2019-06-16 14:22:15.602 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-06-16 14:22:15.647 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0D 00 04 00 0B 07 60 0D 01 01 25 03 00 B1 2019-06-16 14:22:15.651 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=11, callback=0, payload=00 0B 07 60 0D 01 01 25 03 00 2019-06-16 14:22:15.654 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=11, callback=0, payload=00 0B 07 60 0D 01 01 25 03 00 2019-06-16 14:22:15.655 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2019-06-16 14:22:15.657 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: Application Command Request (ALIVE:DONE) 2019-06-16 14:22:15.658 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 11: resetResendCount initComplete=true isDead=false 2019-06-16 14:22:15.660 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 11: Decapsulating COMMAND_CLASS_MULTI_CHANNEL 2019-06-16 14:22:15.662 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 11: Incoming command class COMMAND_CLASS_SWITCH_BINARY, endpoint 1 2019-06-16 14:22:15.663 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 11: SECURITY NOT required on COMMAND_CLASS_SWITCH_BINARY 2019-06-16 14:22:15.665 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 11: Received COMMAND_CLASS_SWITCH_BINARY V1 SWITCH_BINARY_REPORT 2019-06-16 14:22:15.666 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 11: Switch Binary report, value = 0 2019-06-16 14:22:15.668 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 11: Got an event from Z-Wave network: ZWaveCommandClassValueEvent 2019-06-16 14:22:15.670 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 11: Got a value event from Z-Wave network, endpoint=1, command class=COMMAND_CLASS_SWITCH_BINARY, value=0 2019-06-16 14:22:15.672 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 11: Updating channel state zwave:device:16b56bde664:node11:switch_binary1 to OFF [OnOffType] 2019-06-16 14:22:15.677 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: Commands processed 1. 2019-06-16 14:22:15.679 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@84537a. 2019-06-16 14:22:15.682 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2019-06-16 14:22:15.685 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2019-06-16 14:22:15.686 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2019-06-16 14:22:15.688 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-06-16 14:22:16.180 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 12 00 04 00 0B 0C 60 0D 01 01 32 02 21 32 00 00 00 00 A0 2019-06-16 14:22:16.191 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=11, callback=0, payload=00 0B 0C 60 0D 01 01 32 02 21 32 00 00 00 00 2019-06-16 14:22:16.195 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=11, callback=0, payload=00 0B 0C 60 0D 01 01 32 02 21 32 00 00 00 00 2019-06-16 14:22:16.198 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2019-06-16 14:22:16.202 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: Application Command Request (ALIVE:DONE) 2019-06-16 14:22:16.206 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 11: resetResendCount initComplete=true isDead=false 2019-06-16 14:22:16.209 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 11: Decapsulating COMMAND_CLASS_MULTI_CHANNEL 2019-06-16 14:22:16.213 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 11: Incoming command class COMMAND_CLASS_METER, endpoint 1 2019-06-16 14:22:16.216 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 11: SECURITY NOT required on COMMAND_CLASS_METER 2019-06-16 14:22:16.220 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 11: Received COMMAND_CLASS_METER V3 METER_REPORT 2019-06-16 14:22:16.224 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 11: Meter: Type=Electric(1), Scale=W(2), Value=0E+1 2019-06-16 14:22:16.228 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 11: Got an event from Z-Wave network: ZWaveMeterValueEvent 2019-06-16 14:22:16.231 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 11: Got a value event from Z-Wave network, endpoint=1, command class=COMMAND_CLASS_METER, value=0E+1 2019-06-16 14:22:16.236 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 11: Updating channel state zwave:device:16b56bde664:node11:meter_watts1 to 0 [DecimalType] 2019-06-16 14:22:16.240 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: Commands processed 1. 2019-06-16 14:22:16.243 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@b18b62. 2019-06-16 14:22:16.246 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2019-06-16 14:22:16.250 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2019-06-16 14:22:16.253 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2019-06-16 14:22:16.256 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-06-16 14:22:17.027 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 11: Polling... 2019-06-16 14:22:17.032 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 11: Polling zwave:device:16b56bde664:node11:switch_binary1 2019-06-16 14:22:17.036 [DEBUG] [converter.ZWaveBinarySwitchConverter] - NODE 11: Generating poll message for COMMAND_CLASS_SWITCH_BINARY, endpoint 1 2019-06-16 14:22:17.039 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 11: Creating new message for application command SWITCH_BINARY_GET 2019-06-16 14:22:17.043 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 11: Encapsulating message, instance / endpoint 1 2019-06-16 14:22:17.047 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 11: Creating new message for command MULTI_CHANNEL_ENCAP endpoint 1 2019-06-16 14:22:17.051 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 11: SECURITY NOT required on COMMAND_CLASS_MULTI_CHANNEL 2019-06-16 14:22:17.055 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 11: Command Class COMMAND_CLASS_MULTI_CHANNEL is NOT required to be secured 2019-06-16 14:22:17.059 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 11: Polling skipped for zwave:device:16b56bde664:node11:switch_binary1 on COMMAND_CLASS_BASIC 2019-06-16 14:22:17.063 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: Adding to device queue 2019-06-16 14:22:17.066 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: Added 156 to queue - size 3 2019-06-16 14:22:17.069 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-06-16 14:22:17.075 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0D 00 13 0B 06 60 0D 01 01 25 02 25 75 F6 2019-06-16 14:22:17.081 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 11: Sending REQUEST Message = 01 0D 00 13 0B 06 60 0D 01 01 25 02 25 75 F6 2019-06-16 14:22:17.086 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2019-06-16 14:22:17.089 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2019-06-16 14:22:17.088 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 156: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 117 2019-06-16 14:22:17.093 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-06-16 14:22:17.096 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-06-16 14:22:17.099 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 156: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 117 2019-06-16 14:22:17.099 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 2019-06-16 14:22:17.101 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2019-06-16 14:22:17.105 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2019-06-16 14:22:17.107 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2019-06-16 14:22:17.111 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2019-06-16 14:22:17.117 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2019-06-16 14:22:17.121 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 156: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 117 2019-06-16 14:22:17.124 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2019-06-16 14:22:17.128 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 156: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 117 2019-06-16 14:22:17.139 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 75 00 00 05 9B 2019-06-16 14:22:17.143 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=117, payload=75 00 00 05 2019-06-16 14:22:17.148 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2019-06-16 14:22:17.151 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 11: sentData successfully placed on stack. 2019-06-16 14:22:17.153 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 156: Advanced to WAIT_REQUEST 2019-06-16 14:22:17.156 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: TID 156: Transaction not completed 2019-06-16 14:22:17.159 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=117, payload=75 00 00 05 2019-06-16 14:22:17.162 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 156: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 117 2019-06-16 14:22:17.164 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2019-06-16 14:22:17.167 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 156: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 117 2019-06-16 14:22:17.169 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 156: (Callback 117) 2019-06-16 14:22:17.172 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match! 2019-06-16 14:22:17.175 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 156: callback 117 2019-06-16 14:22:17.178 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=117, payload=75 00 00 05 2019-06-16 14:22:17.181 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 11: SendData Request. CallBack ID = 117, Status = Transmission complete and ACK received(0) 2019-06-16 14:22:17.184 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 11: resetResendCount initComplete=true isDead=false 2019-06-16 14:22:17.186 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 156: Advanced to WAIT_DATA 2019-06-16 14:22:17.189 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: TID 156: Transaction not completed 2019-06-16 14:22:17.191 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2019-06-16 14:22:17.194 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2019-06-16 14:22:17.217 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0D 00 04 00 0B 07 60 0D 01 01 25 03 00 B1 2019-06-16 14:22:17.223 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=11, callback=0, payload=00 0B 07 60 0D 01 01 25 03 00 2019-06-16 14:22:17.226 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=11, callback=0, payload=00 0B 07 60 0D 01 01 25 03 00 2019-06-16 14:22:17.229 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2019-06-16 14:22:17.231 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: Application Command Request (ALIVE:DONE) 2019-06-16 14:22:17.240 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 11: resetResendCount initComplete=true isDead=false 2019-06-16 14:22:17.242 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 11: Decapsulating COMMAND_CLASS_MULTI_CHANNEL 2019-06-16 14:22:17.245 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 11: Incoming command class COMMAND_CLASS_SWITCH_BINARY, endpoint 1 2019-06-16 14:22:17.247 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 11: SECURITY NOT required on COMMAND_CLASS_SWITCH_BINARY 2019-06-16 14:22:17.249 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 11: Received COMMAND_CLASS_SWITCH_BINARY V1 SWITCH_BINARY_REPORT 2019-06-16 14:22:17.251 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 11: Switch Binary report, value = 0 2019-06-16 14:22:17.254 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 11: Got an event from Z-Wave network: ZWaveCommandClassValueEvent 2019-06-16 14:22:17.256 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 11: Got a value event from Z-Wave network, endpoint=1, command class=COMMAND_CLASS_SWITCH_BINARY, value=0 2019-06-16 14:22:17.259 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 11: Updating channel state zwave:device:16b56bde664:node11:switch_binary1 to OFF [OnOffType] 2019-06-16 14:22:17.263 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: Commands processed 1. 2019-06-16 14:22:17.265 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1fadb4e. 2019-06-16 14:22:17.268 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: Command verified org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1fadb4e. 2019-06-16 14:22:17.271 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: notifyTransactionResponse TID:156 DONE 2019-06-16 14:22:17.274 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 11: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 2019-06-16 14:22:17.276 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1 2019-06-16 14:22:17.279 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2019-06-16 14:22:17.281 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2019-06-16 14:22:17.283 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. ==> /var/log/openhab2/events.log <== 2019-06-16 14:22:21.894 [hingStatusInfoChangedEvent] - 'zwave:device:16b56bde664:node18' changed from ONLINE to UNINITIALIZED ==> /var/log/openhab2/openhab.log <== 2019-06-16 14:22:21.898 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 18: Handler disposed. Unregistering listener. 2019-06-16 14:22:21.956 [DEBUG] [l.initialization.ZWaveNodeSerializer] - NODE 18: Serializing to file /var/lib/openhab2/zwave/network_ebae5036__node_18.xml 2019-06-16 14:22:22.006 [DEBUG] [org.openhab.binding.zwave ] - ServiceEvent UNREGISTERING - {org.eclipse.smarthome.config.core.status.ConfigStatusProvider}={service.id=418, service.bundleid=225, service.scope=singleton} - org.openhab.binding.zwave ==> /var/log/openhab2/events.log <== 2019-06-16 14:22:22.035 [hingStatusInfoChangedEvent] - 'zwave:device:16b56bde664:node18' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR) ==> /var/log/openhab2/openhab.log <== 2019-06-16 14:24:17.981 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 12 00 04 00 04 0C 60 0D 01 01 32 02 21 32 00 00 00 00 AF 2019-06-16 14:24:17.990 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=4, callback=0, payload=00 04 0C 60 0D 01 01 32 02 21 32 00 00 00 00 2019-06-16 14:24:17.994 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=4, callback=0, payload=00 04 0C 60 0D 01 01 32 02 21 32 00 00 00 00 2019-06-16 14:24:17.998 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2019-06-16 14:24:18.001 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: Application Command Request (ALIVE:DONE) 2019-06-16 14:24:18.005 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 4: resetResendCount initComplete=true isDead=false 2019-06-16 14:24:18.008 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 4: Decapsulating COMMAND_CLASS_MULTI_CHANNEL 2019-06-16 14:24:18.011 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 4: Incoming command class COMMAND_CLASS_METER, endpoint 1 2019-06-16 14:24:18.015 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 4: SECURITY NOT required on COMMAND_CLASS_METER 2019-06-16 14:24:18.017 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 4: Received COMMAND_CLASS_METER V3 METER_REPORT 2019-06-16 14:24:18.020 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 4: Meter: Type=Electric(1), Scale=W(2), Value=0E+1 2019-06-16 14:24:18.023 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 4: Got an event from Z-Wave network: ZWaveMeterValueEvent 2019-06-16 14:24:18.025 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 4: Got a value event from Z-Wave network, endpoint=1, command class=COMMAND_CLASS_METER, value=0E+1 2019-06-16 14:24:18.028 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 4: Updating channel state zwave:device:16b56bde664:node4:meter_watts1 to 0 [DecimalType] 2019-06-16 14:24:18.032 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: Commands processed 1. 2019-06-16 14:24:18.034 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@2aef14. 2019-06-16 14:24:18.036 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2019-06-16 14:24:18.038 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2019-06-16 14:24:18.040 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2019-06-16 14:24:18.042 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-06-16 14:25:44.781 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0F 00 04 00 0A 09 71 05 00 00 00 FF 07 08 00 73 2019-06-16 14:25:44.790 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 09 71 05 00 00 00 FF 07 08 00 2019-06-16 14:25:44.794 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 09 71 05 00 00 00 FF 07 08 00 2019-06-16 14:25:44.797 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2019-06-16 14:25:44.799 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Application Command Request (ALIVE:REQUEST_NIF) 2019-06-16 14:25:44.802 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: Incoming command class COMMAND_CLASS_ALARM, endpoint 0 2019-06-16 14:25:44.804 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: SECURITY NOT required on COMMAND_CLASS_ALARM 2019-06-16 14:25:44.807 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Received COMMAND_CLASS_ALARM V5 NOTIFICATION_REPORT 2019-06-16 14:25:44.810 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 10: NOTIFICATION report - 0 = 0, event=8, status=255, plen=0 2019-06-16 14:25:44.812 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 10: Alarm Type = BURGLAR (0) 2019-06-16 14:25:44.815 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got an event from Z-Wave network: ZWaveAlarmValueEvent 2019-06-16 14:25:44.817 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_ALARM, value=255 2019-06-16 14:25:44.820 [DEBUG] [ternal.converter.ZWaveAlarmConverter] - NODE 10: Alarm converter processing NOTIFICATION 2019-06-16 14:25:44.822 [DEBUG] [ternal.converter.ZWaveAlarmConverter] - NODE 10: Alarm converter NOTIFICATION event is 8, type OnOffType 2019-06-16 14:25:44.825 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Updating channel state zwave:device:16b56bde664:node10:alarm_motion to ON [OnOffType] 2019-06-16 14:25:44.830 [DEBUG] [ternal.converter.ZWaveAlarmConverter] - NODE 10: Alarm converter processing NOTIFICATION 2019-06-16 14:25:44.833 [DEBUG] [ternal.converter.ZWaveAlarmConverter] - NODE 10: Alarm converter NOTIFICATION event is 8, type OnOffType 2019-06-16 14:25:44.836 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Commands processed 1. 2019-06-16 14:25:44.838 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@a569a8. 2019-06-16 14:25:44.841 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2019-06-16 14:25:44.843 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2019-06-16 14:25:44.845 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2019-06-16 14:25:44.848 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. ==> /var/log/openhab2/events.log <== 2019-06-16 14:25:44.907 [vent.ItemStateChangedEvent] - SwitchSensorMotion_1 changed from OFF to ON 2019-06-16 14:25:45.780 [ome.event.ItemCommandEvent] - Item 'SwitchLichtGang' received command ON 2019-06-16 14:25:45.812 [ome.event.ItemCommandEvent] - Item 'TimerOFF_5min_1' received command ON ==> /var/log/openhab2/openhab.log <== 2019-06-16 14:25:45.819 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 11: Command received zwave:device:16b56bde664:node11:switch_binary1 --> ON [OnOffType] 2019-06-16 14:25:45.823 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 11: Creating new message for application command SWITCH_BINARY_SET 2019-06-16 14:25:45.826 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 11: Encapsulating message, instance / endpoint 1 2019-06-16 14:25:45.829 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 11: Creating new message for command MULTI_CHANNEL_ENCAP endpoint 1 2019-06-16 14:25:45.832 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 11: SECURITY NOT required on COMMAND_CLASS_MULTI_CHANNEL 2019-06-16 14:25:45.836 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 11: Command Class COMMAND_CLASS_MULTI_CHANNEL is NOT required to be secured ==> /var/log/openhab2/events.log <== 2019-06-16 14:25:45.837 [nt.ItemStatePredictedEvent] - SwitchLichtGang predicted to become ON ==> /var/log/openhab2/openhab.log <== 2019-06-16 14:25:45.841 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: Adding to device queue 2019-06-16 14:25:45.842 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: Added 157 to queue - size 3 2019-06-16 14:25:45.845 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-06-16 14:25:45.848 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0E 00 13 0B 07 60 0D 01 01 25 01 FF 25 76 0B 2019-06-16 14:25:45.852 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 11: Sending REQUEST Message = 01 0E 00 13 0B 07 60 0D 01 01 25 01 FF 25 76 0B 2019-06-16 14:25:45.854 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2019-06-16 14:25:45.857 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2019-06-16 14:25:45.858 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-06-16 14:25:45.860 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-06-16 14:25:45.862 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2019-06-16 14:25:45.864 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2019-06-16 14:25:45.864 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 2019-06-16 14:25:45.865 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2019-06-16 14:25:45.865 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 157: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 118 2019-06-16 14:25:45.869 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2019-06-16 14:25:45.870 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2019-06-16 14:25:45.872 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2019-06-16 14:25:45.876 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 11: Polling intialised at 86400 seconds - start in 1500 milliseconds. 2019-06-16 14:25:45.880 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 157: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 118 2019-06-16 14:25:45.885 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2019-06-16 14:25:45.887 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 157: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 118 2019-06-16 14:25:45.889 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2019-06-16 14:25:45.891 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 11: sentData successfully placed on stack. 2019-06-16 14:25:45.892 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 157: Advanced to WAIT_REQUEST 2019-06-16 14:25:45.894 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: TID 157: Transaction not completed 2019-06-16 14:25:45.896 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2019-06-16 14:25:45.898 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2019-06-16 14:25:45.906 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 76 00 00 05 98 2019-06-16 14:25:45.909 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=118, payload=76 00 00 05 2019-06-16 14:25:45.913 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=118, payload=76 00 00 05 2019-06-16 14:25:45.915 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 157: [WAIT_REQUEST] priority=Set, requiresResponse=true, callback: 118 2019-06-16 14:25:45.916 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2019-06-16 14:25:45.919 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 157: [WAIT_REQUEST] priority=Set, requiresResponse=true, callback: 118 2019-06-16 14:25:45.921 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 157: (Callback 118) 2019-06-16 14:25:45.923 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match! 2019-06-16 14:25:45.925 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 157: callback 118 ==> /var/log/openhab2/events.log <== 2019-06-16 14:25:45.926 [vent.ItemStateChangedEvent] - SwitchLichtGang changed from OFF to ON ==> /var/log/openhab2/openhab.log <== 2019-06-16 14:25:45.928 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=118, payload=76 00 00 05 2019-06-16 14:25:45.930 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 11: SendData Request. CallBack ID = 118, Status = Transmission complete and ACK received(0) 2019-06-16 14:25:45.933 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 11: resetResendCount initComplete=true isDead=false 2019-06-16 14:25:45.934 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 157: Transaction COMPLETED 2019-06-16 14:25:45.937 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: Response processed after 72ms 2019-06-16 14:25:45.939 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: TID 157: Transaction completed 2019-06-16 14:25:45.941 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: notifyTransactionResponse TID:157 DONE 2019-06-16 14:25:45.943 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 11: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 2019-06-16 14:25:45.945 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2019-06-16 14:25:45.947 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. ==> /var/log/openhab2/events.log <== 2019-06-16 14:25:45.948 [ome.event.ItemCommandEvent] - Item 'TimerOFF_5min_1' received command ON 2019-06-16 14:25:45.968 [vent.ItemStateChangedEvent] - TimerOFF_5min_1 changed from OFF to ON ==> /var/log/openhab2/openhab.log <== 2019-06-16 14:25:45.977 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0D 00 04 00 0B 07 60 0D 01 01 25 03 FF 4E 2019-06-16 14:25:45.983 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=11, callback=0, payload=00 0B 07 60 0D 01 01 25 03 FF 2019-06-16 14:25:45.987 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=11, callback=0, payload=00 0B 07 60 0D 01 01 25 03 FF 2019-06-16 14:25:45.988 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2019-06-16 14:25:45.990 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: Application Command Request (ALIVE:DONE) 2019-06-16 14:25:45.992 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 11: resetResendCount initComplete=true isDead=false 2019-06-16 14:25:45.994 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 11: Decapsulating COMMAND_CLASS_MULTI_CHANNEL 2019-06-16 14:25:45.996 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 11: Incoming command class COMMAND_CLASS_SWITCH_BINARY, endpoint 1 2019-06-16 14:25:45.998 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 11: SECURITY NOT required on COMMAND_CLASS_SWITCH_BINARY 2019-06-16 14:25:46.000 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 11: Received COMMAND_CLASS_SWITCH_BINARY V1 SWITCH_BINARY_REPORT 2019-06-16 14:25:46.002 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 11: Switch Binary report, value = 255 2019-06-16 14:25:46.004 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 11: Got an event from Z-Wave network: ZWaveCommandClassValueEvent 2019-06-16 14:25:46.005 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 11: Got a value event from Z-Wave network, endpoint=1, command class=COMMAND_CLASS_SWITCH_BINARY, value=255 2019-06-16 14:25:46.008 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 11: Updating channel state zwave:device:16b56bde664:node11:switch_binary1 to ON [OnOffType] 2019-06-16 14:25:46.010 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: Commands processed 1. 2019-06-16 14:25:46.012 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@b1005. 2019-06-16 14:25:46.014 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2019-06-16 14:25:46.015 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2019-06-16 14:25:46.017 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2019-06-16 14:25:46.019 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-06-16 14:25:47.377 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 11: Polling... 2019-06-16 14:25:47.381 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 11: Polling zwave:device:16b56bde664:node11:switch_binary1 2019-06-16 14:25:47.385 [DEBUG] [converter.ZWaveBinarySwitchConverter] - NODE 11: Generating poll message for COMMAND_CLASS_SWITCH_BINARY, endpoint 1 2019-06-16 14:25:47.389 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 11: Creating new message for application command SWITCH_BINARY_GET 2019-06-16 14:25:47.393 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 11: Encapsulating message, instance / endpoint 1 2019-06-16 14:25:47.407 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 11: Creating new message for command MULTI_CHANNEL_ENCAP endpoint 1 2019-06-16 14:25:47.411 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 11: SECURITY NOT required on COMMAND_CLASS_MULTI_CHANNEL 2019-06-16 14:25:47.415 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 11: Command Class COMMAND_CLASS_MULTI_CHANNEL is NOT required to be secured 2019-06-16 14:25:47.431 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 11: Polling skipped for zwave:device:16b56bde664:node11:switch_binary1 on COMMAND_CLASS_BASIC 2019-06-16 14:25:47.435 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: Adding to device queue 2019-06-16 14:25:47.439 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: Added 158 to queue - size 3 2019-06-16 14:25:47.444 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-06-16 14:25:47.450 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0D 00 13 0B 06 60 0D 01 01 25 02 25 77 F4 2019-06-16 14:25:47.457 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 11: Sending REQUEST Message = 01 0D 00 13 0B 06 60 0D 01 01 25 02 25 77 F4 2019-06-16 14:25:47.459 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2019-06-16 14:25:47.462 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2019-06-16 14:25:47.462 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 158: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 119 2019-06-16 14:25:47.464 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-06-16 14:25:47.467 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-06-16 14:25:47.468 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 158: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 119 2019-06-16 14:25:47.470 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2019-06-16 14:25:47.469 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 2019-06-16 14:25:47.472 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2019-06-16 14:25:47.473 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2019-06-16 14:25:47.473 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2019-06-16 14:25:47.475 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2019-06-16 14:25:47.477 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 158: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 119 2019-06-16 14:25:47.478 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2019-06-16 14:25:47.480 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 158: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 119 2019-06-16 14:25:47.481 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2019-06-16 14:25:47.483 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 11: sentData successfully placed on stack. 2019-06-16 14:25:47.484 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 158: Advanced to WAIT_REQUEST 2019-06-16 14:25:47.486 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: TID 158: Transaction not completed 2019-06-16 14:25:47.487 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2019-06-16 14:25:47.489 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2019-06-16 14:25:47.513 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 77 00 00 05 99 2019-06-16 14:25:47.516 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=119, payload=77 00 00 05 2019-06-16 14:25:47.518 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=119, payload=77 00 00 05 2019-06-16 14:25:47.520 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 158: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 119 2019-06-16 14:25:47.521 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2019-06-16 14:25:47.523 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 158: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 119 2019-06-16 14:25:47.524 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 158: (Callback 119) 2019-06-16 14:25:47.526 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match! 2019-06-16 14:25:47.527 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 158: callback 119 2019-06-16 14:25:47.530 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=119, payload=77 00 00 05 2019-06-16 14:25:47.531 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 11: SendData Request. CallBack ID = 119, Status = Transmission complete and ACK received(0) 2019-06-16 14:25:47.533 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 11: resetResendCount initComplete=true isDead=false 2019-06-16 14:25:47.534 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 158: Advanced to WAIT_DATA 2019-06-16 14:25:47.536 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: TID 158: Transaction not completed 2019-06-16 14:25:47.537 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2019-06-16 14:25:47.539 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2019-06-16 14:25:47.586 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0D 00 04 00 0B 07 60 0D 01 01 25 03 FF 4E 2019-06-16 14:25:47.590 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=11, callback=0, payload=00 0B 07 60 0D 01 01 25 03 FF 2019-06-16 14:25:47.593 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=11, callback=0, payload=00 0B 07 60 0D 01 01 25 03 FF 2019-06-16 14:25:47.594 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2019-06-16 14:25:47.596 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: Application Command Request (ALIVE:DONE) 2019-06-16 14:25:47.597 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 11: resetResendCount initComplete=true isDead=false 2019-06-16 14:25:47.599 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 11: Decapsulating COMMAND_CLASS_MULTI_CHANNEL 2019-06-16 14:25:47.601 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 11: Incoming command class COMMAND_CLASS_SWITCH_BINARY, endpoint 1 2019-06-16 14:25:47.602 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 11: SECURITY NOT required on COMMAND_CLASS_SWITCH_BINARY 2019-06-16 14:25:47.604 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 11: Received COMMAND_CLASS_SWITCH_BINARY V1 SWITCH_BINARY_REPORT 2019-06-16 14:25:47.605 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 11: Switch Binary report, value = 255 2019-06-16 14:25:47.607 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 11: Got an event from Z-Wave network: ZWaveCommandClassValueEvent 2019-06-16 14:25:47.608 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 11: Got a value event from Z-Wave network, endpoint=1, command class=COMMAND_CLASS_SWITCH_BINARY, value=255 2019-06-16 14:25:47.611 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 11: Updating channel state zwave:device:16b56bde664:node11:switch_binary1 to ON [OnOffType] 2019-06-16 14:25:47.613 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: Commands processed 1. 2019-06-16 14:25:47.615 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1a09b21. 2019-06-16 14:25:47.617 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: Command verified org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1a09b21. 2019-06-16 14:25:47.618 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: notifyTransactionResponse TID:158 DONE 2019-06-16 14:25:47.621 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 11: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 2019-06-16 14:25:47.622 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1 2019-06-16 14:25:47.624 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2019-06-16 14:25:47.626 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2019-06-16 14:25:47.627 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-06-16 14:25:48.179 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 12 00 04 00 0B 0C 60 0D 01 01 32 02 21 32 01 0C 00 00 AD 2019-06-16 14:25:48.186 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=11, callback=0, payload=00 0B 0C 60 0D 01 01 32 02 21 32 01 0C 00 00 2019-06-16 14:25:48.191 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=11, callback=0, payload=00 0B 0C 60 0D 01 01 32 02 21 32 01 0C 00 00 2019-06-16 14:25:48.195 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2019-06-16 14:25:48.198 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: Application Command Request (ALIVE:DONE) 2019-06-16 14:25:48.201 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 11: resetResendCount initComplete=true isDead=false 2019-06-16 14:25:48.205 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 11: Decapsulating COMMAND_CLASS_MULTI_CHANNEL 2019-06-16 14:25:48.208 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 11: Incoming command class COMMAND_CLASS_METER, endpoint 1 2019-06-16 14:25:48.210 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 11: SECURITY NOT required on COMMAND_CLASS_METER 2019-06-16 14:25:48.213 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 11: Received COMMAND_CLASS_METER V3 METER_REPORT 2019-06-16 14:25:48.215 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 11: Meter: Type=Electric(1), Scale=W(2), Value=26.8 2019-06-16 14:25:48.218 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 11: Got an event from Z-Wave network: ZWaveMeterValueEvent 2019-06-16 14:25:48.220 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 11: Got a value event from Z-Wave network, endpoint=1, command class=COMMAND_CLASS_METER, value=26.8 2019-06-16 14:25:48.223 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 11: Updating channel state zwave:device:16b56bde664:node11:meter_watts1 to 26.8 [DecimalType] 2019-06-16 14:25:48.226 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: Commands processed 1. 2019-06-16 14:25:48.228 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@7797ce. 2019-06-16 14:25:48.231 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2019-06-16 14:25:48.233 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2019-06-16 14:25:48.235 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2019-06-16 14:25:48.237 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-06-16 14:26:43.696 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0F 00 04 00 09 09 71 05 00 00 00 FF 06 17 00 6E 2019-06-16 14:26:43.704 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=9, callback=0, payload=00 09 09 71 05 00 00 00 FF 06 17 00 2019-06-16 14:26:43.707 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=9, callback=0, payload=00 09 09 71 05 00 00 00 FF 06 17 00 2019-06-16 14:26:43.710 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2019-06-16 14:26:43.712 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: Application Command Request (ALIVE:REQUEST_NIF) 2019-06-16 14:26:43.715 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 9: Incoming command class COMMAND_CLASS_ALARM, endpoint 0 2019-06-16 14:26:43.717 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 9: SECURITY not supported 2019-06-16 14:26:43.719 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 9: Received COMMAND_CLASS_ALARM V5 NOTIFICATION_REPORT 2019-06-16 14:26:43.721 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 9: NOTIFICATION report - 0 = 0, event=23, status=255, plen=0 2019-06-16 14:26:43.724 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 9: Alarm Type = ACCESS_CONTROL (0) 2019-06-16 14:26:43.726 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Got an event from Z-Wave network: ZWaveAlarmValueEvent 2019-06-16 14:26:43.729 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_ALARM, value=255 2019-06-16 14:26:43.732 [DEBUG] [ternal.converter.ZWaveAlarmConverter] - NODE 9: Alarm converter processing NOTIFICATION 2019-06-16 14:26:43.734 [DEBUG] [ternal.converter.ZWaveAlarmConverter] - NODE 9: Alarm converter NOTIFICATION event is 23, type OnOffType 2019-06-16 14:26:43.737 [DEBUG] [ternal.converter.ZWaveAlarmConverter] - NODE 9: Alarm converter processing NOTIFICATION 2019-06-16 14:26:43.739 [DEBUG] [ternal.converter.ZWaveAlarmConverter] - NODE 9: Alarm converter NOTIFICATION event is 23, type OpenClosedType 2019-06-16 14:26:43.742 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 9: Updating channel state zwave:device:16b56bde664:node9:sensor_door to CLOSED [OpenClosedType] 2019-06-16 14:26:43.744 [DEBUG] [ternal.converter.ZWaveAlarmConverter] - NODE 9: Alarm converter processing NOTIFICATION 2019-06-16 14:26:43.747 [DEBUG] [ternal.converter.ZWaveAlarmConverter] - NODE 9: Alarm converter NOTIFICATION event is 23, type OnOffType 2019-06-16 14:26:43.749 [DEBUG] [ternal.converter.ZWaveAlarmConverter] - NODE 9: Alarm converter processing NOTIFICATION 2019-06-16 14:26:43.751 [DEBUG] [ternal.converter.ZWaveAlarmConverter] - NODE 9: Alarm converter NOTIFICATION event is 23, type OnOffType 2019-06-16 14:26:43.754 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: Commands processed 1. 2019-06-16 14:26:43.756 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 9: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1f65741. 2019-06-16 14:26:43.758 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2019-06-16 14:26:43.760 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2019-06-16 14:26:43.761 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2019-06-16 14:26:43.763 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-06-16 14:26:59.503 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0C 00 04 00 0F 06 31 05 04 22 00 00 EC 2019-06-16 14:26:59.508 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=15, callback=0, payload=00 0F 06 31 05 04 22 00 00 2019-06-16 14:26:59.511 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=15, callback=0, payload=00 0F 06 31 05 04 22 00 00 2019-06-16 14:26:59.513 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2019-06-16 14:26:59.516 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Application Command Request (ALIVE:DONE) 2019-06-16 14:26:59.518 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: resetResendCount initComplete=true isDead=false 2019-06-16 14:26:59.520 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: Incoming command class COMMAND_CLASS_SENSOR_MULTILEVEL, endpoint 0 2019-06-16 14:26:59.523 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: SECURITY NOT required on COMMAND_CLASS_SENSOR_MULTILEVEL 2019-06-16 14:26:59.525 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 15: Received COMMAND_CLASS_SENSOR_MULTILEVEL V5 SENSOR_MULTILEVEL_REPORT 2019-06-16 14:26:59.527 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 15: Sensor Type = Power(4), Scale = 0 2019-06-16 14:26:59.529 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 15: Sensor Value = 0E+1 2019-06-16 14:26:59.532 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Got an event from Z-Wave network: ZWaveMultiLevelSensorValueEvent 2019-06-16 14:26:59.534 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_SENSOR_MULTILEVEL, value=0E+1 2019-06-16 14:26:59.537 [DEBUG] [erter.ZWaveMultiLevelSensorConverter] - NODE 15: Sensor conversion not performed for POWER. 2019-06-16 14:26:59.540 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 15: Updating channel state zwave:device:16b56bde664:node15:sensor_power to 0 [DecimalType] 2019-06-16 14:26:59.543 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Commands processed 1. 2019-06-16 14:26:59.545 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@123e842. 2019-06-16 14:26:59.547 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2019-06-16 14:26:59.549 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2019-06-16 14:26:59.551 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2019-06-16 14:26:59.553 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-06-16 14:27:02.458 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 10 00 04 00 0A 0A 71 05 00 00 00 FF 07 00 01 08 6E 2019-06-16 14:27:02.464 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 0A 71 05 00 00 00 FF 07 00 01 08 2019-06-16 14:27:02.467 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=10, callback=0, payload=00 0A 0A 71 05 00 00 00 FF 07 00 01 08 2019-06-16 14:27:02.470 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null 2019-06-16 14:27:02.472 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Application Command Request (ALIVE:REQUEST_NIF) 2019-06-16 14:27:02.475 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: Incoming command class COMMAND_CLASS_ALARM, endpoint 0 2019-06-16 14:27:02.477 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: SECURITY NOT required on COMMAND_CLASS_ALARM 2019-06-16 14:27:02.480 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 10: Received COMMAND_CLASS_ALARM V5 NOTIFICATION_REPORT 2019-06-16 14:27:02.482 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 10: NOTIFICATION report - 0 = 0, event=0, status=255, plen=1 2019-06-16 14:27:02.485 [DEBUG] [.commandclass.ZWaveAlarmCommandClass] - NODE 10: Alarm Type = BURGLAR (0) 2019-06-16 14:27:02.487 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got an event from Z-Wave network: ZWaveAlarmValueEvent 2019-06-16 14:27:02.490 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Got a value event from Z-Wave network, endpoint=0, command class=COMMAND_CLASS_ALARM, value=255 2019-06-16 14:27:02.493 [DEBUG] [ternal.converter.ZWaveAlarmConverter] - NODE 10: Alarm converter processing NOTIFICATION 2019-06-16 14:27:02.496 [DEBUG] [ternal.converter.ZWaveAlarmConverter] - NODE 10: Alarm converter NOTIFICATION event is 0, type OnOffType 2019-06-16 14:27:02.499 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Updating channel state zwave:device:16b56bde664:node10:alarm_motion to OFF [OnOffType] 2019-06-16 14:27:02.503 [DEBUG] [ternal.converter.ZWaveAlarmConverter] - NODE 10: Alarm converter processing NOTIFICATION 2019-06-16 14:27:02.509 [DEBUG] [ternal.converter.ZWaveAlarmConverter] - NODE 10: Alarm converter NOTIFICATION event is 0, type OnOffType 2019-06-16 14:27:02.512 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 10: Updating channel state zwave:device:16b56bde664:node10:alarm_tamper to OFF [OnOffType] 2019-06-16 14:27:02.515 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Commands processed 1. 2019-06-16 14:27:02.517 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 10: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@d30514. 2019-06-16 14:27:02.520 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2019-06-16 14:27:02.522 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0 2019-06-16 14:27:02.525 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2019-06-16 14:27:02.527 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. ==> /var/log/openhab2/events.log <== 2019-06-16 14:27:02.565 [vent.ItemStateChangedEvent] - SwitchSensorMotion_1 changed from ON to OFF ==> /var/log/openhab2/openhab.log <== 2019-06-16 14:27:12.985 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:16b56bde664 2019-06-16 14:27:12.991 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave inclusion process not running - nothing to do 2019-06-16 14:27:13.001 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Start zwave:serial_zstick:16b56bde664 2019-06-16 14:27:13.006 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave controller start inclusion - mode 2 2019-06-16 14:27:13.013 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added. 2019-06-16 14:27:13.017 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller start inclusion 2019-06-16 14:27:13.025 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Setting controller into INCLUSION mode, highPower:true networkWide:true. 2019-06-16 14:27:13.029 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 159 to queue - size 1 2019-06-16 14:27:13.032 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-06-16 14:27:13.037 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A C1 78 09 2019-06-16 14:27:13.041 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A C1 78 09 2019-06-16 14:27:13.045 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2019-06-16 14:27:13.048 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2019-06-16 14:27:13.049 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 159: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 120 2019-06-16 14:27:13.053 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-06-16 14:27:13.056 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-06-16 14:27:13.059 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 159: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 120 2019-06-16 14:27:13.059 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 78 01 00 00 CB 2019-06-16 14:27:13.062 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK 2019-06-16 14:27:13.064 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=120, payload=78 01 00 00 2019-06-16 14:27:13.066 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty 2019-06-16 14:27:13.070 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2019-06-16 14:27:13.074 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=120, payload=78 01 00 00 2019-06-16 14:27:13.078 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 159: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 120 2019-06-16 14:27:13.081 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1 2019-06-16 14:27:13.096 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 159: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 120 2019-06-16 14:27:13.098 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 159: (Callback 120) 2019-06-16 14:27:13.100 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match! 2019-06-16 14:27:13.101 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 159: callback 120 2019-06-16 14:27:13.103 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=AddNodeToNetwork[74], type=Request[0], dest=1, callback=120, payload=78 01 00 00 2019-06-16 14:27:13.105 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: Learn ready. 2019-06-16 14:27:13.109 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Sending user event @text/zwave.event.inclusion_started 2019-06-16 14:27:15.058 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 2: Device discovery completed 2019-06-16 14:27:15.123 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 2: Device discovery resolved to thingType zwave:fibaro_fgs213_00_000 2019-06-16 14:27:15.134 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 3: Device discovery completed 2019-06-16 14:27:15.157 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 3: Device discovery resolved to thingType zwave:fibaro_fgs213_00_000 2019-06-16 14:27:15.170 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 4: Device discovery completed 2019-06-16 14:27:15.179 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 4: Device discovery resolved to thingType zwave:fibaro_fgs213_00_000 2019-06-16 14:27:15.189 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 5: Device discovery completed 2019-06-16 14:27:15.193 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 5: Device discovery resolved to thingType zwave:fibaro_fgd212_03_005 2019-06-16 14:27:15.204 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 6: Device discovery completed 2019-06-16 14:27:15.208 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 6: Device discovery resolved to thingType zwave:fibaro_fgs222_00_000 2019-06-16 14:27:15.217 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 7: Device discovery completed 2019-06-16 14:27:15.221 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 7: Device discovery resolved to thingType zwave:fibaro_fgwp102_03_002 2019-06-16 14:27:15.231 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 8: Device discovery completed 2019-06-16 14:27:15.236 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 8: Device discovery resolved to thingType zwave:fibaro_fgs213_00_000 2019-06-16 14:27:15.246 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 9: Device discovery completed 2019-06-16 14:27:15.250 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 9: Device discovery resolved to thingType zwave:fibaro_fgdw002_00_000 2019-06-16 14:27:15.258 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 10: Device discovery completed 2019-06-16 14:27:15.263 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 10: Device discovery resolved to thingType zwave:fibaro_fgms001_03_002 2019-06-16 14:27:15.273 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 11: Device discovery completed 2019-06-16 14:27:15.278 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 11: Device discovery resolved to thingType zwave:fibaro_fgs213_00_000 2019-06-16 14:27:15.289 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 12: Device discovery completed 2019-06-16 14:27:15.293 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 12: Device discovery resolved to thingType zwave:fibaro_fgwp102_03_002 2019-06-16 14:27:15.303 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 13: Device discovery completed 2019-06-16 14:27:15.308 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 13: Device discovery resolved to thingType zwave:fibaro_fgd212_03_005 2019-06-16 14:27:15.319 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 14: Device discovery completed 2019-06-16 14:27:15.323 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 14: Device discovery resolved to thingType zwave:fibaro_fgd212_03_005 2019-06-16 14:27:15.334 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 15: Device discovery completed 2019-06-16 14:27:15.338 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 15: Device discovery resolved to thingType zwave:fibaro_fgwp102_03_002 2019-06-16 14:27:15.348 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 17: Device discovery completed 2019-06-16 14:27:15.353 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 17: Device discovery resolved to thingType zwave:fibaro_fgbs001_00_000 2019-06-16 14:27:15.362 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 18: Device discovery completed 2019-06-16 14:27:15.365 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - NODE 18: Device discovery resolved to thingType zwave:polycontrol_umv3btze_00_000 2019-06-16 14:27:15.371 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'zwave:device:16b56bde664:node18' to inbox. ==> /var/log/openhab2/events.log <== 2019-06-16 14:27:15.377 [home.event.InboxAddedEvent] - Discovery Result with UID 'zwave:device:16b56bde664:node18' has been added. ==> /var/log/openhab2/openhab.log <== 2019-06-16 14:27:18.055 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 159: Timeout at state WAIT_REQUEST. 3 retries remaining. 2019-06-16 14:27:18.060 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 159: Transaction is current transaction, so clearing!!!!! 2019-06-16 14:27:18.064 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 159: Transaction CANCELLED 2019-06-16 14:27:18.069 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:159 CANCELLED 2019-06-16 14:27:18.074 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-06-16 14:27:43.000 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:16b56bde664 2019-06-16 14:27:43.006 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave controller stopping inclusion at IncludeSent 2019-06-16 14:27:43.010 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode. 2019-06-16 14:27:43.015 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added 160 to queue - size 1 2019-06-16 14:27:43.018 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-06-16 14:27:43.024 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 79 CC 2019-06-16 14:27:43.028 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 79 CC 2019-06-16 14:27:43.033 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2019-06-16 14:27:43.036 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2019-06-16 14:27:43.041 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-06-16 14:27:43.037 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 160: [WAIT_REQUEST] priority=Controller, requiresResponse=true, callback: 121 2019-06-16 14:27:43.087 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 79 06 09 00 C4 2019-06-16 14:27:43.092 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 1<>127 : Message: class=AddNodeToNetwork[74], type=Request[0], dest=6, callback=121, payload=79 06 09 00 2019-06-16 14:27:48.045 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 255: TID 160: Timeout at state WAIT_REQUEST. 3 retries remaining. 2019-06-16 14:27:48.047 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 160: Transaction is current transaction, so clearing!!!!! 2019-06-16 14:27:48.050 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 160: Transaction CANCELLED 2019-06-16 14:27:48.055 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:160 CANCELLED 2019-06-16 14:27:48.059 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-06-16 14:27:58.053 [DEBUG] [al.protocol.ZWaveInclusionController] - Inclusion timer at IncludeDone ==> /var/log/openhab2/events.log <== 2019-06-16 14:28:57.163 [me.event.InboxRemovedEvent] - Discovery Result with UID 'zwave:device:16b56bde664:node18' has been removed. ==> /var/log/openhab2/openhab.log <== 2019-06-16 14:30:06.175 [DEBUG] [g.zwave.internal.ZWaveConfigProvider] - No bridgeUID found in getConfigDescription thing:zwave:serial_zstick:16b56bde664 2019-06-16 14:30:11.541 [DEBUG] [g.zwave.internal.ZWaveConfigProvider] - No bridgeUID found in getConfigDescription thing:zwave:serial_zstick:16b56bde664 2019-06-16 14:30:11.592 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update received 2019-06-16 14:30:11.619 [DEBUG] [zwave.handler.ZWaveControllerHandler] - Controller Configuration update controller_exclude to true 2019-06-16 14:30:11.621 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave inclusion process already running - aborted ==> /var/log/openhab2/events.log <== 2019-06-16 14:30:11.645 [me.event.ThingUpdatedEvent] - Thing 'zwave:serial_zstick:16b56bde664' has been updated. ==> /var/log/openhab2/openhab.log <== 2019-06-16 14:30:21.434 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0F 00 49 84 12 09 04 40 03 5E 98 9F 55 72 8A 95 2019-06-16 14:30:21.444 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 2<>126 : Message: class=ApplicationUpdate[73], type=Request[0], dest=18, callback=132, payload=84 12 09 04 40 03 5E 98 9F 55 72 8A 2019-06-16 14:30:21.501 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0F 00 49 84 12 09 04 40 03 5E 98 9F 55 72 8A 95 2019-06-16 14:30:21.509 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 3<>125 : Message: class=ApplicationUpdate[73], type=Request[0], dest=18, callback=132, payload=84 12 09 04 40 03 5E 98 9F 55 72 8A ==> /var/log/openhab2/events.log <== 2019-06-16 14:30:46.712 [ome.event.ItemCommandEvent] - Item 'TimerOFF_5min_1' received command OFF 2019-06-16 14:30:46.810 [ome.event.ItemCommandEvent] - Item 'SwitchLichtGang' received command OFF 2019-06-16 14:30:46.833 [vent.ItemStateChangedEvent] - TimerOFF_5min_1 changed from ON to OFF 2019-06-16 14:30:46.843 [nt.ItemStatePredictedEvent] - SwitchLichtGang predicted to become OFF ==> /var/log/openhab2/openhab.log <== 2019-06-16 14:30:46.849 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 11: Command received zwave:device:16b56bde664:node11:switch_binary1 --> OFF [OnOffType] 2019-06-16 14:30:46.852 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 11: Creating new message for application command SWITCH_BINARY_SET 2019-06-16 14:30:46.854 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 11: Encapsulating message, instance / endpoint 1 2019-06-16 14:30:46.856 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 11: Creating new message for command MULTI_CHANNEL_ENCAP endpoint 1 2019-06-16 14:30:46.858 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 11: SECURITY NOT required on COMMAND_CLASS_MULTI_CHANNEL 2019-06-16 14:30:46.861 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 11: Command Class COMMAND_CLASS_MULTI_CHANNEL is NOT required to be secured 2019-06-16 14:30:46.862 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: Adding to device queue 2019-06-16 14:30:46.865 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: Added 161 to queue - size 3 2019-06-16 14:30:46.867 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-06-16 14:30:46.871 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0E 00 13 0B 07 60 0D 01 01 25 01 00 25 7A F8 2019-06-16 14:30:46.876 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 11: Sending REQUEST Message = 01 0E 00 13 0B 07 60 0D 01 01 25 01 00 25 7A F8 2019-06-16 14:30:46.878 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2019-06-16 14:30:46.880 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2019-06-16 14:30:46.880 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 161: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 122 2019-06-16 14:30:46.882 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 4<>124 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-06-16 14:30:46.886 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 11: Polling intialised at 86400 seconds - start in 1500 milliseconds. 2019-06-16 14:30:46.887 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 2019-06-16 14:30:46.891 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 5<>123 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 ==> /var/log/openhab2/events.log <== 2019-06-16 14:30:46.901 [vent.ItemStateChangedEvent] - SwitchLichtGang changed from ON to OFF ==> /var/log/openhab2/openhab.log <== 2019-06-16 14:30:46.930 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 7A 00 00 04 95 2019-06-16 14:30:46.934 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 6<>122 : Message: class=SendData[19], type=Request[0], dest=0, callback=122, payload=7A 00 00 04 2019-06-16 14:30:47.009 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0D 00 04 00 0B 07 60 0D 01 01 25 03 00 B1 2019-06-16 14:30:47.014 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 7<>121 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=11, callback=0, payload=00 0B 07 60 0D 01 01 25 03 00 2019-06-16 14:30:47.178 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 12 00 04 00 0B 0C 60 0D 01 01 32 02 21 32 00 00 00 00 A0 2019-06-16 14:30:47.184 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 8<>120 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=11, callback=0, payload=00 0B 0C 60 0D 01 01 32 02 21 32 00 00 00 00 2019-06-16 14:30:48.389 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 11: Polling... 2019-06-16 14:30:48.395 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 11: Polling zwave:device:16b56bde664:node11:switch_binary1 2019-06-16 14:30:48.398 [DEBUG] [converter.ZWaveBinarySwitchConverter] - NODE 11: Generating poll message for COMMAND_CLASS_SWITCH_BINARY, endpoint 1 2019-06-16 14:30:48.401 [DEBUG] [dclass.ZWaveBinarySwitchCommandClass] - NODE 11: Creating new message for application command SWITCH_BINARY_GET 2019-06-16 14:30:48.405 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 11: Encapsulating message, instance / endpoint 1 2019-06-16 14:30:48.408 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 11: Creating new message for command MULTI_CHANNEL_ENCAP endpoint 1 2019-06-16 14:30:48.412 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 11: SECURITY NOT required on COMMAND_CLASS_MULTI_CHANNEL 2019-06-16 14:30:48.415 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 11: Command Class COMMAND_CLASS_MULTI_CHANNEL is NOT required to be secured 2019-06-16 14:30:48.419 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 11: Polling skipped for zwave:device:16b56bde664:node11:switch_binary1 on COMMAND_CLASS_BASIC 2019-06-16 14:30:48.425 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: Adding to device queue 2019-06-16 14:30:48.428 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: Added 162 to queue - size 3 2019-06-16 14:30:48.431 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2019-06-16 14:30:48.883 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 11: TID 161: Timeout at state WAIT_RESPONSE. 3 retries remaining. 2019-06-16 14:30:48.887 [DEBUG] [sactionManager$ZWaveTransactionTimer] - Aborting Transaction! 2019-06-16 14:30:48.890 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 161: Transaction ABORTED 2019-06-16 14:30:48.895 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 16 EA 2019-06-16 14:30:48.901 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 16 EA 2019-06-16 14:30:48.907 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2019-06-16 14:30:48.905 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2019-06-16 14:30:48.911 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 9<>119 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-06-16 14:30:48.912 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2019-06-16 14:31:00.894 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 11: TID 161: Timeout at state ABORTED. 3 retries remaining. 2019-06-16 14:31:00.897 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 161: Transaction is current transaction, so clearing!!!!! 2019-06-16 14:31:00.899 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 161: Transaction CANCELLED 2019-06-16 14:31:00.902 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 11: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 2019-06-16 14:31:00.904 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: notifyTransactionResponse TID:161 CANCELLED 2019-06-16 14:31:00.907 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false. 2019-06-16 14:31:00.913 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0D 00 13 0B 06 60 0D 01 01 25 02 25 7B F8 2019-06-16 14:31:00.918 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 11: Sending REQUEST Message = 01 0D 00 13 0B 06 60 0D 01 01 25 02 25 7B F8 2019-06-16 14:31:00.921 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2019-06-16 14:31:00.924 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2019-06-16 14:31:00.924 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 162: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 123 2019-06-16 14:31:00.928 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 10<>118 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-06-16 14:31:00.934 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 2019-06-16 14:31:00.939 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 11<>117 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 2019-06-16 14:31:00.976 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 7B 00 00 05 95 2019-06-16 14:31:00.984 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 12<>116 : Message: class=SendData[19], type=Request[0], dest=0, callback=123, payload=7B 00 00 05 2019-06-16 14:31:01.050 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0D 00 04 00 0B 07 60 0D 01 01 25 03 00 B1 2019-06-16 14:31:01.061 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 13<>115 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=11, callback=0, payload=00 0B 07 60 0D 01 01 25 03 00 2019-06-16 14:31:02.925 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 11: TID 162: Timeout at state WAIT_RESPONSE. 3 retries remaining. 2019-06-16 14:31:02.928 [DEBUG] [sactionManager$ZWaveTransactionTimer] - Aborting Transaction! 2019-06-16 14:31:02.931 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 162: Transaction ABORTED 2019-06-16 14:31:02.935 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 03 00 16 EA 2019-06-16 14:31:02.938 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 03 00 16 EA 2019-06-16 14:31:02.943 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06 2019-06-16 14:31:02.946 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 14<>114 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload= 2019-06-16 14:31:02.941 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT 2019-06-16 14:31:02.951 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false. 2019-06-16 14:31:14.934 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 11: TID 162: Timeout at state ABORTED. 3 retries remaining. 2019-06-16 14:31:14.937 [DEBUG] [sactionManager$ZWaveTransactionTimer] - TID 162: Transaction is current transaction, so clearing!!!!! 2019-06-16 14:31:14.940 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 162: Transaction CANCELLED 2019-06-16 14:31:14.943 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 11: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent 2019-06-16 14:31:14.946 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 11: notifyTransactionResponse TID:162 CANCELLED 2019-06-16 14:31:14.949 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.