Hello,
Command 0 has no effect on my roller shutter. Every other value is fine.
Worked fine with openhab1.
Log when it works
2019-09-22 21:37:14.956 [ome.event.ItemCommandEvent] - Item 'VoletsSalon_ShutterPosition' received command 3
==> /var/log/openhab2/openhab.log <==
2019-09-22 21:37:14.982 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Command received zwave:device:350a292d:node2:blinds_shutter --> 3 [PercentType]
==> /var/log/openhab2/events.log <==
2019-09-22 21:37:14.980 [nt.ItemStatePredictedEvent] - VoletsSalon_ShutterPosition predicted to become 3
==> /var/log/openhab2/openhab.log <==
2019-09-22 21:37:14.991 [DEBUG] [nufacturerProprietaryFibaroFgrm222V1] - Creating command message FGRM222_SET version 1
==> /var/log/openhab2/events.log <==
2019-09-22 21:37:15.008 [vent.ItemStateChangedEvent] - VoletsSalon_ShutterPosition changed from 0 to 3
==> /var/log/openhab2/openhab.log <==
2019-09-22 21:37:15.016 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Adding to device queue
2019-09-22 21:37:15.022 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Added 586 to queue - size 2
2019-09-22 21:37:15.025 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-09-22 21:37:15.030 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0F 00 13 02 08 91 01 0F 26 01 02 03 00 25 0E 7B
2019-09-22 21:37:15.035 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 0F 00 13 02 08 91 01 0F 26 01 02 03 00 25 0E 7B
2019-09-22 21:37:15.040 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-09-22 21:37:15.041 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-09-22 21:37:15.042 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 586: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 14
2019-09-22 21:37:15.045 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-09-22 21:37:15.046 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Polling intialised at 1800 seconds - start in 1500 milliseconds.
2019-09-22 21:37:15.048 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-09-22 21:37:15.051 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 586: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 14
2019-09-22 21:37:15.052 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2019-09-22 21:37:15.053 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-09-22 21:37:15.055 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-09-22 21:37:15.057 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-09-22 21:37:15.060 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2019-09-22 21:37:15.064 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2019-09-22 21:37:15.066 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 586: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 14
2019-09-22 21:37:15.067 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 00 13 0E 00 E7
2019-09-22 21:37:15.068 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-09-22 21:37:15.071 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 586: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 14
2019-09-22 21:37:15.073 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2019-09-22 21:37:15.076 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: sentData successfully placed on stack.
2019-09-22 21:37:15.078 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 586: Advanced to WAIT_REQUEST
2019-09-22 21:37:15.080 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 586: Transaction not completed
2019-09-22 21:37:15.082 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-09-22 21:37:15.085 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-09-22 21:37:15.084 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=14, payload=0E 00
2019-09-22 21:37:15.089 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=14, payload=0E 00
2019-09-22 21:37:15.092 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 586: [WAIT_REQUEST] priority=Set, requiresResponse=true, callback: 14
2019-09-22 21:37:15.095 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-09-22 21:37:15.097 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 586: [WAIT_REQUEST] priority=Set, requiresResponse=true, callback: 14
2019-09-22 21:37:15.100 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 586: (Callback 14)
2019-09-22 21:37:15.103 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2019-09-22 21:37:15.105 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 586: callback 14
2019-09-22 21:37:15.107 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=14, payload=0E 00
2019-09-22 21:37:15.108 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: SendData Request. CallBack ID = 14, Status = Transmission complete and ACK received(0)
2019-09-22 21:37:15.110 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: resetResendCount initComplete=true isDead=false
2019-09-22 21:37:15.112 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 586: Transaction COMPLETED
2019-09-22 21:37:15.114 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Response processed after 71ms
2019-09-22 21:37:15.115 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 586: Transaction completed
2019-09-22 21:37:15.117 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: notifyTransactionResponse TID:586 DONE
2019-09-22 21:37:15.119 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2019-09-22 21:37:15.120 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-09-22 21:37:15.122 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-09-22 21:37:16.195 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 00 02 03 26 03 02 D4
2019-09-22 21:37:16.203 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=0, payload=00 02 03 26 03 02
2019-09-22 21:37:16.207 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=0, payload=00 02 03 26 03 02
2019-09-22 21:37:16.209 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-09-22 21:37:16.211 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Application Command Request (ALIVE:DONE)
2019-09-22 21:37:16.212 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: resetResendCount initComplete=true isDead=false
2019-09-22 21:37:16.214 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Incoming command class COMMAND_CLASS_SWITCH_MULTILEVEL, endpoint 0
2019-09-22 21:37:16.216 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: SECURITY not supported
2019-09-22 21:37:16.218 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Received COMMAND_CLASS_SWITCH_MULTILEVEL V3 SWITCH_MULTILEVEL_REPORT
2019-09-22 21:37:16.220 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 2: Switch Multi Level report, value = 2
2019-09-22 21:37:16.222 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2019-09-22 21:37:16.224 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got a value event from Z-Wave network, endpoint = 0, command class = COMMAND_CLASS_SWITCH_MULTILEVEL, value = 2
2019-09-22 21:37:16.226 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Updating channel state zwave:device:350a292d:node2:blinds_control to 2 [PercentType]
2019-09-22 21:37:16.229 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Commands processed 1.
2019-09-22 21:37:16.231 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1228407.
2019-09-22 21:37:16.233 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-09-22 21:37:16.235 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2019-09-22 21:37:16.237 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-09-22 21:37:16.239 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-09-22 21:37:16.548 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Polling...
2019-09-22 21:37:16.552 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Polling zwave:device:350a292d:node2:blinds_shutter
2019-09-22 21:37:16.553 [DEBUG] [nufacturerProprietaryFibaroFgrm222V1] - Creating command message FGRM222_GET version 1
2019-09-22 21:37:16.556 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Adding to device queue
2019-09-22 21:37:16.558 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Added 587 to queue - size 2
2019-09-22 21:37:16.561 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-09-22 21:37:16.565 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 02 02 91 02 25 0F 5C
2019-09-22 21:37:16.569 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 09 00 13 02 02 91 02 25 0F 5C
2019-09-22 21:37:16.573 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-09-22 21:37:16.576 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-09-22 21:37:16.577 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-09-22 21:37:16.577 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-09-22 21:37:16.578 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 587: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 15
2019-09-22 21:37:16.579 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-09-22 21:37:16.580 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2019-09-22 21:37:16.580 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-09-22 21:37:16.582 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-09-22 21:37:16.584 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-09-22 21:37:16.584 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2019-09-22 21:37:16.587 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2019-09-22 21:37:16.589 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 587: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 15
2019-09-22 21:37:16.590 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 00 13 0F 00 E6
2019-09-22 21:37:16.591 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-09-22 21:37:16.594 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 587: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 15
2019-09-22 21:37:16.596 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2019-09-22 21:37:16.597 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=15, payload=0F 00
2019-09-22 21:37:16.599 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: sentData successfully placed on stack.
2019-09-22 21:37:16.602 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 587: Advanced to WAIT_REQUEST
2019-09-22 21:37:16.603 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 587: Transaction not completed
2019-09-22 21:37:16.606 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=15, payload=0F 00
2019-09-22 21:37:16.608 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 587: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 15
2019-09-22 21:37:16.612 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-09-22 21:37:16.614 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 587: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 15
2019-09-22 21:37:16.616 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 587: (Callback 15)
2019-09-22 21:37:16.618 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2019-09-22 21:37:16.620 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 587: callback 15
2019-09-22 21:37:16.622 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=15, payload=0F 00
2019-09-22 21:37:16.624 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: SendData Request. CallBack ID = 15, Status = Transmission complete and ACK received(0)
2019-09-22 21:37:16.626 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: resetResendCount initComplete=true isDead=false
2019-09-22 21:37:16.628 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 587: Advanced to WAIT_DATA
2019-09-22 21:37:16.629 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 587: Transaction not completed
2019-09-22 21:37:16.631 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-09-22 21:37:16.635 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-09-22 21:37:21.629 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 2: TID 587: Timeout at state WAIT_DATA. 3 retries remaining.
2019-09-22 21:37:21.632 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 587: Transaction CANCELLED
2019-09-22 21:37:21.634 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2019-09-22 21:37:21.636 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: notifyTransactionResponse TID:587 CANCELLED
2019-09-22 21:37:21.639 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
Log when it does not work (nothing happens)
2019-09-22 21:37:52.756 [ome.event.ItemCommandEvent] - Item 'VoletsSalon_ShutterPosition' received command 0
2019-09-22 21:37:52.765 [nt.ItemStatePredictedEvent] - VoletsSalon_ShutterPosition predicted to become 0
2019-09-22 21:37:52.781 [vent.ItemStateChangedEvent] - VoletsSalon_ShutterPosition changed from 3 to 0
==> /var/log/openhab2/openhab.log <==
2019-09-22 21:37:52.777 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Command received zwave:device:350a292d:node2:blinds_shutter --> 0 [PercentType]
2019-09-22 21:37:52.790 [DEBUG] [nufacturerProprietaryFibaroFgrm222V1] - Creating command message FGRM222_SET version 1
2019-09-22 21:37:52.792 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Adding to device queue
2019-09-22 21:37:52.796 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Added 588 to queue - size 2
2019-09-22 21:37:52.798 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-09-22 21:37:52.803 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0F 00 13 02 08 91 01 0F 26 01 02 00 00 25 10 66
2019-09-22 21:37:52.807 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 0F 00 13 02 08 91 01 0F 26 01 02 00 00 25 10 66
2019-09-22 21:37:52.813 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-09-22 21:37:52.817 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-09-22 21:37:52.821 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2019-09-22 21:37:52.822 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-09-22 21:37:52.827 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-09-22 21:37:52.829 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-09-22 21:37:52.832 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-09-22 21:37:52.833 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-09-22 21:37:52.837 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 588: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 16
2019-09-22 21:37:52.840 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2019-09-22 21:37:52.840 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Polling intialised at 1800 seconds - start in 1500 milliseconds.
2019-09-22 21:37:52.844 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 00 13 10 00 F9
2019-09-22 21:37:52.840 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-09-22 21:37:52.849 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2019-09-22 21:37:52.851 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=16, payload=10 00
2019-09-22 21:37:52.853 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 588: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 16
2019-09-22 21:37:52.855 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-09-22 21:37:52.859 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 588: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 16
2019-09-22 21:37:52.863 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2019-09-22 21:37:52.866 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: sentData successfully placed on stack.
2019-09-22 21:37:52.868 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 588: Advanced to WAIT_REQUEST
2019-09-22 21:37:52.871 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 588: Transaction not completed
2019-09-22 21:37:52.873 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=16, payload=10 00
2019-09-22 21:37:52.876 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 588: [WAIT_REQUEST] priority=Set, requiresResponse=true, callback: 16
2019-09-22 21:37:52.879 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-09-22 21:37:52.883 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 588: [WAIT_REQUEST] priority=Set, requiresResponse=true, callback: 16
2019-09-22 21:37:52.885 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 588: (Callback 16)
2019-09-22 21:37:52.886 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2019-09-22 21:37:52.887 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 588: callback 16
2019-09-22 21:37:52.889 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=16, payload=10 00
2019-09-22 21:37:52.890 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: SendData Request. CallBack ID = 16, Status = Transmission complete and ACK received(0)
2019-09-22 21:37:52.893 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: resetResendCount initComplete=true isDead=false
2019-09-22 21:37:52.894 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 588: Transaction COMPLETED
2019-09-22 21:37:52.896 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Response processed after 60ms
2019-09-22 21:37:52.898 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 588: Transaction completed
2019-09-22 21:37:52.899 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: notifyTransactionResponse TID:588 DONE
2019-09-22 21:37:52.901 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2019-09-22 21:37:52.903 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-09-22 21:37:52.905 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
==> /var/log/openhab2/events.log <==
2019-09-22 21:37:53.163 [ome.event.ItemCommandEvent] - Item 'VoletsSalon_ShutterPosition' received command 0
2019-09-22 21:37:53.169 [nt.ItemStatePredictedEvent] - VoletsSalon_ShutterPosition predicted to become 0
==> /var/log/openhab2/openhab.log <==
2019-09-22 21:37:53.168 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Command received zwave:device:350a292d:node2:blinds_shutter --> 0 [PercentType]
2019-09-22 21:37:53.173 [DEBUG] [nufacturerProprietaryFibaroFgrm222V1] - Creating command message FGRM222_SET version 1
2019-09-22 21:37:53.175 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Adding to device queue
2019-09-22 21:37:53.177 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Added 589 to queue - size 2
2019-09-22 21:37:53.180 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-09-22 21:37:53.183 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 0F 00 13 02 08 91 01 0F 26 01 02 00 00 25 11 67
2019-09-22 21:37:53.187 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 0F 00 13 02 08 91 01 0F 26 01 02 00 00 25 11 67
2019-09-22 21:37:53.190 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-09-22 21:37:53.191 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-09-22 21:37:53.191 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-09-22 21:37:53.192 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 589: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 17
2019-09-22 21:37:53.193 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-09-22 21:37:53.194 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 589: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 17
2019-09-22 21:37:53.195 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2019-09-22 21:37:53.195 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-09-22 21:37:53.197 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Polling intialised at 1800 seconds - start in 1500 milliseconds.
2019-09-22 21:37:53.198 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2019-09-22 21:37:53.198 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-09-22 21:37:53.200 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-09-22 21:37:53.202 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2019-09-22 21:37:53.204 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 589: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 17
2019-09-22 21:37:53.205 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-09-22 21:37:53.208 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 00 13 11 00 F8
2019-09-22 21:37:53.208 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 589: [WAIT_RESPONSE] priority=Set, requiresResponse=true, callback: 17
2019-09-22 21:37:53.210 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2019-09-22 21:37:53.210 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=17, payload=11 00
2019-09-22 21:37:53.212 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: sentData successfully placed on stack.
2019-09-22 21:37:53.214 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 589: Advanced to WAIT_REQUEST
2019-09-22 21:37:53.215 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 589: Transaction not completed
2019-09-22 21:37:53.217 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=17, payload=11 00
2019-09-22 21:37:53.218 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 589: [WAIT_REQUEST] priority=Set, requiresResponse=true, callback: 17
2019-09-22 21:37:53.219 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-09-22 21:37:53.222 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 589: [WAIT_REQUEST] priority=Set, requiresResponse=true, callback: 17
2019-09-22 21:37:53.223 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 589: (Callback 17)
2019-09-22 21:37:53.225 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2019-09-22 21:37:53.227 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 589: callback 17
2019-09-22 21:37:53.228 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=17, payload=11 00
2019-09-22 21:37:53.230 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: SendData Request. CallBack ID = 17, Status = Transmission complete and ACK received(0)
2019-09-22 21:37:53.232 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: resetResendCount initComplete=true isDead=false
2019-09-22 21:37:53.233 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 589: Transaction COMPLETED
2019-09-22 21:37:53.236 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Response processed after 44ms
2019-09-22 21:37:53.237 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 589: Transaction completed
2019-09-22 21:37:53.239 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: notifyTransactionResponse TID:589 DONE
2019-09-22 21:37:53.240 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2019-09-22 21:37:53.242 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-09-22 21:37:53.244 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-09-22 21:37:54.694 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Polling...
2019-09-22 21:37:54.697 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Polling zwave:device:350a292d:node2:blinds_shutter
2019-09-22 21:37:54.702 [DEBUG] [nufacturerProprietaryFibaroFgrm222V1] - Creating command message FGRM222_GET version 1
2019-09-22 21:37:54.704 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Adding to device queue
2019-09-22 21:37:54.707 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Added 590 to queue - size 2
2019-09-22 21:37:54.709 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2019-09-22 21:37:54.713 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 02 02 91 02 25 12 41
2019-09-22 21:37:54.718 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 09 00 13 02 02 91 02 25 12 41
2019-09-22 21:37:54.722 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2019-09-22 21:37:54.724 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-09-22 21:37:54.726 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2019-09-22 21:37:54.728 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2019-09-22 21:37:54.728 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2019-09-22 21:37:54.730 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2019-09-22 21:37:54.732 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-09-22 21:37:54.742 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2019-09-22 21:37:54.744 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 590: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 18
2019-09-22 21:37:54.747 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-09-22 21:37:54.747 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2019-09-22 21:37:54.749 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2019-09-22 21:37:54.751 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 590: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 18
2019-09-22 21:37:54.751 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 00 13 12 00 FB
2019-09-22 21:37:54.753 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-09-22 21:37:54.755 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 590: [WAIT_RESPONSE] priority=Get, requiresResponse=true, callback: 18
2019-09-22 21:37:54.757 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01
2019-09-22 21:37:54.759 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: sentData successfully placed on stack.
2019-09-22 21:37:54.760 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=18, payload=12 00
2019-09-22 21:37:54.761 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 590: Advanced to WAIT_REQUEST
2019-09-22 21:37:54.762 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 590: Transaction not completed
2019-09-22 21:37:54.765 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=18, payload=12 00
2019-09-22 21:37:54.766 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 590: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 18
2019-09-22 21:37:54.768 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2019-09-22 21:37:54.770 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 590: [WAIT_REQUEST] priority=Get, requiresResponse=true, callback: 18
2019-09-22 21:37:54.771 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 590: (Callback 18)
2019-09-22 21:37:54.773 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2019-09-22 21:37:54.775 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 590: callback 18
2019-09-22 21:37:54.777 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=18, payload=12 00
2019-09-22 21:37:54.779 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: SendData Request. CallBack ID = 18, Status = Transmission complete and ACK received(0)
2019-09-22 21:37:54.781 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: resetResendCount initComplete=true isDead=false
2019-09-22 21:37:54.783 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 590: Advanced to WAIT_DATA
2019-09-22 21:37:54.786 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 590: Transaction not completed
2019-09-22 21:37:54.788 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2019-09-22 21:37:54.789 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2019-09-22 21:37:59.787 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 2: TID 590: Timeout at state WAIT_DATA. 3 retries remaining.
2019-09-22 21:37:59.792 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 590: Transaction CANCELLED
2019-09-22 21:37:59.794 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2019-09-22 21:37:59.797 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: notifyTransactionResponse TID:590 CANCELLED
2019-09-22 21:37:59.800 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
Does someone know how to solve this?
Thanks
Léo
