Hello,
I am using a Fibaro Dimmer 2 to controll my main lights.
It is working perfect so far… there is only one problem: I don’t get an update if I use the physical switch connected to the device. It always stays in the most recent state known to openhab.
I am (now) using openHAB 2.5.0 Build #1502
Here are the Logs when triggering within openHAB:
2019-01-19 14:56:33.546 [ome.event.ItemCommandEvent] - Item 'LR_Light_Switch' received command ON
==> /var/log/openhab2/openhab.log <==
2019-01-19 14:56:33.552 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 4: Command received zwave:device:d5d05bd6:node4:switch_dimmer1 --> ON [OnOffType]
2019-01-19 14:56:33.555 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 4: Creating new message for command SWITCH_MULTILEVEL_SET
2019-01-19 14:56:33.558 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 4: Encapsulating message, instance / endpoint 1
2019-01-19 14:56:33.560 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 4: Creating new message for command MULTI_CHANNEL_ENCAP endpoint 1
2019-01-19 14:56:33.562 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 4: SECURITY NOT required on COMMAND_CLASS_MULTI_CHANNEL
2019-01-19 14:56:33.564 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 4: Command Class COMMAND_CLASS_MULTI_CHANNEL is NOT required to be secured
2019-01-19 14:56:33.567 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: Adding to device queue
2019-01-19 14:56:33.569 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: Added 44 to queue - size 1
2019-01-19 14:56:33.571 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-01-19 14:56:33.574 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0E 00 13 04 07 60 0D 01 01 26 01 FF 25 30 41
2019-01-19 14:56:33.577 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 4: Sending REQUEST Message = 01 0E 00 13 04 07 60 0D 01 01 26 01 FF 25 30 41
2019-01-19 14:56:33.580 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-01-19 14:56:33.582 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-01-19 14:56:33.582 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 44: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 48
2019-01-19 14:56:33.584 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-01-19 14:56:33.585 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 4: Polling intialised at 86400 seconds - start in 1500 milliseconds.
2019-01-19 14:56:33.586 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-01-19 14:56:33.589 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 44: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 48
2019-01-19 14:56:33.589 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2019-01-19 14:56:33.590 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-01-19 14:56:33.591 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2019-01-19 14:56:33.592 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-01-19 14:56:33.593 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-01-19 14:56:33.595 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2019-01-19 14:56:33.597 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 44: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 48
2019-01-19 14:56:33.599 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-01-19 14:56:33.600 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 44: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 48
2019-01-19 14:56:33.602 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2019-01-19 14:56:33.605 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 4: sentData successfully placed on stack.
2019-01-19 14:56:33.606 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 30 00 00 02 D9
2019-01-19 14:56:33.607 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 44: Advanced to WAIT_REQUEST
2019-01-19 14:56:33.609 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: TID 44: Transaction not completed
2019-01-19 14:56:33.609 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=48, payload=30 00 00 02
2019-01-19 14:56:33.610 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-01-19 14:56:33.612 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-01-19 14:56:33.614 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=48, payload=30 00 00 02
2019-01-19 14:56:33.616 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 44: [WAIT_REQUEST] priority=Set, requiresResponse=true, callback: 48
2019-01-19 14:56:33.618 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-01-19 14:56:33.620 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 44: [WAIT_REQUEST] priority=Set, requiresResponse=true, callback: 48
2019-01-19 14:56:33.621 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 44: (Callback 48)
2019-01-19 14:56:33.623 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2019-01-19 14:56:33.625 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 44: callback 48
2019-01-19 14:56:33.627 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=48, payload=30 00 00 02
2019-01-19 14:56:33.629 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 4: SendData Request. CallBack ID = 48, Status = Transmission complete and ACK received(0)
2019-01-19 14:56:33.631 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 4: resetResendCount initComplete=true isDead=false
2019-01-19 14:56:33.633 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 44: Transaction COMPLETED
2019-01-19 14:56:33.634 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: Response processed after 52ms
2019-01-19 14:56:33.635 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: TID 44: Transaction completed
2019-01-19 14:56:33.636 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: notifyTransactionResponse TID:44 DONE
2019-01-19 14:56:33.637 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 4: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2019-01-19 14:56:33.641 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-01-19 14:56:33.642 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
==> /var/log/openhab2/events.log <==
2019-01-19 14:56:34.895 [vent.ItemStateChangedEvent] - Gateway_AmbientLight changed from 622 to 504
==> /var/log/openhab2/openhab.log <==
2019-01-19 14:56:35.085 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 4: Polling...
2019-01-19 14:56:35.088 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 4: Polling zwave:device:d5d05bd6:node4:switch_dimmer1
2019-01-19 14:56:35.090 [DEBUG] [erter.ZWaveMultiLevelSwitchConverter] - NODE 4: Generating poll message for COMMAND_CLASS_SWITCH_MULTILEVEL, endpoint 1
2019-01-19 14:56:35.091 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 4: Creating new message for command SWITCH_MULTILEVEL_GET
2019-01-19 14:56:35.093 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 4: Encapsulating message, instance / endpoint 1
2019-01-19 14:56:35.095 [DEBUG] [class.ZWaveMultiInstanceCommandClass] - NODE 4: Creating new message for command MULTI_CHANNEL_ENCAP endpoint 1
2019-01-19 14:56:35.097 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 4: SECURITY NOT required on COMMAND_CLASS_MULTI_CHANNEL
2019-01-19 14:56:35.099 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 4: Command Class COMMAND_CLASS_MULTI_CHANNEL is NOT required to be secured
2019-01-19 14:56:35.101 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 4: Polling skipped for zwave:device:d5d05bd6:node4:switch_dimmer1 on COMMAND_CLASS_BASIC
2019-01-19 14:56:35.103 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: Adding to device queue
2019-01-19 14:56:35.105 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: Added 45 to queue - size 1
2019-01-19 14:56:35.107 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-01-19 14:56:35.110 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0D 00 13 04 06 60 0D 01 01 26 02 25 31 BE
2019-01-19 14:56:35.115 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 4: Sending REQUEST Message = 01 0D 00 13 04 06 60 0D 01 01 26 02 25 31 BE
2019-01-19 14:56:35.117 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-01-19 14:56:35.120 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-01-19 14:56:35.119 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 45: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 49
2019-01-19 14:56:35.122 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-01-19 14:56:35.124 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-01-19 14:56:35.125 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 45: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 49
2019-01-19 14:56:35.127 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2019-01-19 14:56:35.127 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-01-19 14:56:35.129 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-01-19 14:56:35.130 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-01-19 14:56:35.130 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2019-01-19 14:56:35.133 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2019-01-19 14:56:35.135 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 45: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 49
2019-01-19 14:56:35.136 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-01-19 14:56:35.138 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 45: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 49
2019-01-19 14:56:35.140 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2019-01-19 14:56:35.142 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 4: sentData successfully placed on stack.
2019-01-19 14:56:35.144 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 31 00 00 02 D8
2019-01-19 14:56:35.144 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 45: Advanced to WAIT_REQUEST
2019-01-19 14:56:35.146 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: TID 45: Transaction not completed
2019-01-19 14:56:35.148 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-01-19 14:56:35.148 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=49, payload=31 00 00 02
2019-01-19 14:56:35.149 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-01-19 14:56:35.153 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=49, payload=31 00 00 02
2019-01-19 14:56:35.155 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 45: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 49
2019-01-19 14:56:35.156 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-01-19 14:56:35.156 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0D 00 04 00 04 07 60 0D 01 01 26 03 63 DE
2019-01-19 14:56:35.158 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 45: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 49
2019-01-19 14:56:35.160 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 45: (Callback 49)
2019-01-19 14:56:35.161 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=4, callback=0, payload=00 04 07 60 0D 01 01 26 03 63
2019-01-19 14:56:35.162 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2019-01-19 14:56:35.164 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 45: callback 49
2019-01-19 14:56:35.166 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=49, payload=31 00 00 02
2019-01-19 14:56:35.168 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 4: SendData Request. CallBack ID = 49, Status = Transmission complete and ACK received(0)
2019-01-19 14:56:35.170 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 4: resetResendCount initComplete=true isDead=false
2019-01-19 14:56:35.172 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 45: Advanced to WAIT_DATA
2019-01-19 14:56:35.173 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: TID 45: Transaction not completed
2019-01-19 14:56:35.176 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=4, callback=0, payload=00 04 07 60 0D 01 01 26 03 63
2019-01-19 14:56:35.177 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-01-19 14:56:35.179 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: Application Command Request (ALIVE:DONE)
2019-01-19 14:56:35.181 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 4: resetResendCount initComplete=true isDead=false
2019-01-19 14:56:35.183 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 4: Decapsulating COMMAND_CLASS_MULTI_CHANNEL
2019-01-19 14:56:35.185 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 4: Incoming command class COMMAND_CLASS_SWITCH_MULTILEVEL, endpoint 1
2019-01-19 14:56:35.187 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 4: SECURITY NOT required on COMMAND_CLASS_SWITCH_MULTILEVEL
2019-01-19 14:56:35.188 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 4: Received COMMAND_CLASS_SWITCH_MULTILEVEL V3 SWITCH_MULTILEVEL_REPORT
2019-01-19 14:56:35.190 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 4: Switch Multi Level report, value = 99
2019-01-19 14:56:35.193 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 4: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2019-01-19 14:56:35.195 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 4: Got a value event from Z-Wave network, endpoint = 1, command class = COMMAND_CLASS_SWITCH_MULTILEVEL, value = 99
2019-01-19 14:56:35.197 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 4: Updating channel state zwave:device:d5d05bd6:node4:switch_dimmer1 to 100 [PercentType]
2019-01-19 14:56:35.201 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: Commands processed 1.
==> /var/log/openhab2/events.log <==
2019-01-19 14:56:35.211 [vent.ItemStateChangedEvent] - LR_Light_Switch changed from OFF to ON
==> /var/log/openhab2/openhab.log <==
2019-01-19 14:56:35.211 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@4f6872.
2019-01-19 14:56:35.214 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: Command verified org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@4f6872.
2019-01-19 14:56:35.216 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: notifyTransactionResponse TID:45 DONE
==> /var/log/openhab2/events.log <==
2019-01-19 14:56:35.221 [GroupItemStateChangedEvent] - gMainLighting changed from OFF to ON through LR_Light_Switch
==> /var/log/openhab2/openhab.log <==
2019-01-19 14:56:35.226 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 4: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
==> /var/log/openhab2/events.log <==
2019-01-19 14:56:35.228 [vent.ItemStateChangedEvent] - LR_Dimmer_Brightness changed from 0 to 100
2019-01-19 14:56:35.235 [GroupItemStateChangedEvent] - gLighting changed from OFF to ON through gMainLighting
==> /var/log/openhab2/openhab.log <==
2019-01-19 14:56:35.238 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2019-01-19 14:56:35.239 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-01-19 14:56:35.241 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-01-19 14:56:35.242 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-01-19 14:56:48.677 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: ZWaveCommandClassTransactionPayload - send to node
2019-01-19 14:56:48.680 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: SECURITY not supported
2019-01-19 14:56:48.682 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: Command Class COMMAND_CLASS_NO_OPERATION is NOT required to be secured
2019-01-19 14:56:48.684 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: sendTransaction org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@d53c73
2019-01-19 14:56:48.686 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Adding to device queue
2019-01-19 14:56:48.690 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Added 46 to queue - size 1
2019-01-19 14:56:48.693 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-01-19 14:56:48.696 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 08 00 13 03 01 00 25 32 F1
2019-01-19 14:56:48.699 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 3: Sending REQUEST Message = 01 08 00 13 03 01 00 25 32 F1
2019-01-19 14:56:48.702 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-01-19 14:56:48.705 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-01-19 14:56:48.706 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-01-19 14:56:48.708 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-01-19 14:56:48.708 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 46: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 50
2019-01-19 14:56:48.710 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-01-19 14:56:48.711 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-01-19 14:56:48.712 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-01-19 14:56:48.714 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-01-19 14:56:48.714 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2019-01-19 14:56:48.717 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2019-01-19 14:56:48.720 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2019-01-19 14:56:48.723 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 46: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 50
2019-01-19 14:56:48.725 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-01-19 14:56:48.728 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 46: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 50
2019-01-19 14:56:48.730 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2019-01-19 14:56:48.733 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: sentData successfully placed on stack.
2019-01-19 14:56:48.735 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 46: Advanced to WAIT_REQUEST
2019-01-19 14:56:48.738 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: TID 46: Transaction not completed
2019-01-19 14:56:48.740 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-01-19 14:56:48.743 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-01-19 14:56:48.846 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 32 01 00 0E D6
2019-01-19 14:56:48.848 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=1, callback=50, payload=32 01 00 0E
2019-01-19 14:56:48.850 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=1, callback=50, payload=32 01 00 0E
2019-01-19 14:56:48.851 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 46: [WAIT_REQUEST] priority=Poll, requiresResponse=true, callback: 50
2019-01-19 14:56:48.852 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-01-19 14:56:48.854 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 46: [WAIT_REQUEST] priority=Poll, requiresResponse=true, callback: 50
2019-01-19 14:56:48.855 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 46: (Callback 50)
2019-01-19 14:56:48.857 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2019-01-19 14:56:48.857 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 46: callback 50
2019-01-19 14:56:48.859 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=1, callback=50, payload=32 01 00 0E
2019-01-19 14:56:48.860 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: SendData Request. CallBack ID = 50, Status = Transmission complete, no ACK received(1)
2019-01-19 14:56:48.862 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 46: Transaction CANCELLED
2019-01-19 14:56:48.863 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: CANCEL while sending message. Requeueing - 2 attempts left!
2019-01-19 14:56:48.864 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 46: Transaction RESET with 2 retries remaining.
2019-01-19 14:56:48.865 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Adding to device queue
2019-01-19 14:56:48.867 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Added 46 to queue - size 1
2019-01-19 14:56:48.868 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-01-19 14:56:48.870 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 08 00 13 03 01 00 25 33 F0
2019-01-19 14:56:48.871 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 3: Sending REQUEST Message = 01 08 00 13 03 01 00 25 33 F0
2019-01-19 14:56:48.873 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-01-19 14:56:48.874 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 46: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 51
2019-01-19 14:56:48.875 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-01-19 14:56:48.876 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: TID 46: Transaction not completed
2019-01-19 14:56:48.876 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-01-19 14:56:48.877 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-01-19 14:56:48.879 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-01-19 14:56:48.880 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-01-19 14:56:48.881 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 46: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 51
2019-01-19 14:56:48.882 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-01-19 14:56:48.884 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-01-19 14:56:48.884 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2019-01-19 14:56:48.885 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-01-19 14:56:48.888 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2019-01-19 14:56:48.889 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2019-01-19 14:56:48.890 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 46: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 51
2019-01-19 14:56:48.892 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-01-19 14:56:48.893 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 46: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 51
2019-01-19 14:56:48.894 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2019-01-19 14:56:48.896 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: sentData successfully placed on stack.
2019-01-19 14:56:48.897 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 46: Advanced to WAIT_REQUEST
2019-01-19 14:56:48.898 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: TID 46: Transaction not completed
2019-01-19 14:56:48.899 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-01-19 14:56:48.900 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-01-19 14:56:49.017 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 33 01 00 0E D7
2019-01-19 14:56:49.019 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=1, callback=51, payload=33 01 00 0E
2019-01-19 14:56:49.020 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=1, callback=51, payload=33 01 00 0E
2019-01-19 14:56:49.022 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 46: [WAIT_REQUEST] priority=Poll, requiresResponse=true, callback: 51
2019-01-19 14:56:49.023 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-01-19 14:56:49.024 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 46: [WAIT_REQUEST] priority=Poll, requiresResponse=true, callback: 51
2019-01-19 14:56:49.025 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 46: (Callback 51)
2019-01-19 14:56:49.027 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2019-01-19 14:56:49.028 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 46: callback 51
2019-01-19 14:56:49.030 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=1, callback=51, payload=33 01 00 0E
2019-01-19 14:56:49.031 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: SendData Request. CallBack ID = 51, Status = Transmission complete, no ACK received(1)
2019-01-19 14:56:49.032 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 46: Transaction CANCELLED
2019-01-19 14:56:49.033 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: CANCEL while sending message. Requeueing - 1 attempts left!
2019-01-19 14:56:49.035 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 46: Transaction RESET with 1 retries remaining.
2019-01-19 14:56:49.036 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Adding to device queue
2019-01-19 14:56:49.037 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Added 46 to queue - size 1
2019-01-19 14:56:49.038 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-01-19 14:56:49.040 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 08 00 13 03 01 00 25 34 F7
2019-01-19 14:56:49.042 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 3: Sending REQUEST Message = 01 08 00 13 03 01 00 25 34 F7
2019-01-19 14:56:49.043 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-01-19 14:56:49.045 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-01-19 14:56:49.046 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-01-19 14:56:49.044 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 46: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 52
2019-01-19 14:56:49.048 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: TID 46: Transaction not completed
2019-01-19 14:56:49.050 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-01-19 14:56:49.051 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 46: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 52
2019-01-19 14:56:49.052 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-01-19 14:56:49.053 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-01-19 14:56:49.055 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2019-01-19 14:56:49.055 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-01-19 14:56:49.056 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2019-01-19 14:56:49.058 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2019-01-19 14:56:49.059 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 46: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 52
2019-01-19 14:56:49.060 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-01-19 14:56:49.062 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 46: [WAIT_RESPONSE] priority=Poll, requiresResponse=true, callback: 52
2019-01-19 14:56:49.063 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2019-01-19 14:56:49.064 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: sentData successfully placed on stack.
2019-01-19 14:56:49.065 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 46: Advanced to WAIT_REQUEST
2019-01-19 14:56:49.067 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: TID 46: Transaction not completed
2019-01-19 14:56:49.068 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-01-19 14:56:49.069 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-01-19 14:56:49.172 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 34 01 00 0D D3
2019-01-19 14:56:49.174 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=1, callback=52, payload=34 01 00 0D
2019-01-19 14:56:49.175 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=1, callback=52, payload=34 01 00 0D
2019-01-19 14:56:49.177 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 46: [WAIT_REQUEST] priority=Poll, requiresResponse=true, callback: 52
2019-01-19 14:56:49.178 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-01-19 14:56:49.179 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 46: [WAIT_REQUEST] priority=Poll, requiresResponse=true, callback: 52
2019-01-19 14:56:49.180 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 46: (Callback 52)
2019-01-19 14:56:49.182 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2019-01-19 14:56:49.183 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 46: callback 52
2019-01-19 14:56:49.184 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=1, callback=52, payload=34 01 00 0D
2019-01-19 14:56:49.186 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 3: SendData Request. CallBack ID = 52, Status = Transmission complete, no ACK received(1)
2019-01-19 14:56:49.187 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 46: Transaction CANCELLED
2019-01-19 14:56:49.188 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Retry count exceeded. Discarding message: TID 46: [CANCELLED] priority=Poll, requiresResponse=true, callback: 52
2019-01-19 14:56:49.190 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: TID 46: Transaction completed
2019-01-19 14:56:49.191 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: notifyTransactionResponse TID:46 CANCELLED
2019-01-19 14:56:49.193 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-01-19 14:56:49.193 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 46: Transaction event listener: DONE: CANCELLED ->
2019-01-19 14:56:49.194 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-01-19 14:56:49.198 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 3: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@1255036
Anyone got an idea what I am doing wrong?
Thanks in advance
Joe