FGR-222 delays

  • Platform information:
    • Hardware: raspberry pi 3+
    • OS: Openhabian
    • openHAB version: latest version 2.4.0 Release build

Hello,

I use roller shutter FGR-222 for my roller blinds and the switch FGS-213 which is connected to a momentary switch to control the roller shutter (there is no wired connection between the roller shutter module and the switch possible, that’s why I use the scene functionality of the FGS…).

I created the items:

Rollershutter Gaestezimmer_Rollladen
    "Rollladen Gästezimmer [%d %%]"
    <rollershutter>
    (GF_GuestRoom)
    {channel="zwave:device:RaspberryPi3:node3:blinds_control"}

Number Sensor_Power
    "Sensor Power"
    <default>
    (GF_GuestRoom)
    {channel="zwave:device:RaspberryPi3:node3:sensor_power"}    

Number Gaestezimmer_Switch_SceneNumber              
    "Szenennummer"        
    { channel="zwave:device:RaspberryPi3:node4:scene_number" }

and the rules

rule	"Gaestezimmer runterfahren" //it means shut down roller blinds
when
	Item Gaestezimmer_Switch_SceneNumber received update 1.0
then
	if (Sensor_Power.state == 0) {
		sendCommand(Gaestezimmer_Rollladen, DOWN)
	}
	else if (Sensor_Power.state != 0) {
		sendCommand(Gaestezimmer_Rollladen, STOP)
	}

end

rule	"Gaestezimmer hochfahren" //it means roller blinds should go up
when
	Item Gaestezimmer_Switch_SceneNumber received update 2.0
then
	if (Sensor_Power.state == 0) {
		sendCommand(Gaestezimmer_Rollladen, UP)
        //Gaestezimmer_Rollladen.sendCommand(UP)
	}
	else if (Sensor_Power.state != 0) {
		sendCommand(Gaestezimmer_Rollladen, STOP)
	}

end

The rules work but there is a very long delay. For example if I press one of the up/down buttons to stop the moving roller blind, it takes sometimes two seconds or longer before the blind stops. The Rasberry is located right next to the devices.

As you can see the command is received immediately but it takes a few seconds before the command is processed:

2019-02-06 08:27:50.896 [INFO ] [odel.script.Szene_Gaestezimmer.rules] - Schalte 2.0

==> /var/log/openhab2/events.log <==

2019-02-06 08:27:50.906 [ome.event.ItemCommandEvent] - Item 'Gaestezimmer_Rollladen' received command STOP

2019-02-06 08:27:52.832 [vent.ItemStateChangedEvent] - Gaestezimmer_Rollladen changed from 70 to 44

2019-02-06 08:27:53.833 [vent.ItemStateChangedEvent] - Gaestezimmer_Rollladen changed from 44 to 43

2019-02-06 08:27:53.851 [vent.ItemStateChangedEvent] - Sensor_Power changed from 90.4 to 0

Does anyone have an idea what could be the rout cause?

Many thanks,
Matthias

Add logging to your Rules so you can compare when the Rule triggers to when the button press event comes in.

The delay could be in a number of places and we need to narrow it down before anyone will be able to help.

1 Like

Hello, I have just added the logging. First of all the rules:

rule	"Gaestezimmer runterfahren"
when
	Item Gaestezimmer_Switch_SceneNumber received update 1.0
then
	logInfo("Szene_Gaestezimmer.rules", "Scenenumber {} received", Gaestezimmer_Switch_SceneNumber.state.toString)
	if (Sensor_Power.state == 0) {logInfo("Szene_Gaestezimmer.rules", "Sensor Power is zero")
		sendCommand(Gaestezimmer_Rollladen, DOWN)
		logInfo("Szene_Gaestezimmer.rules", "Guest room command DOWN is sent")
	}
	else if (Sensor_Power.state != 0) {logInfo("Szene_Gaestezimmer.rules", "Sensor Power is not zero")
		sendCommand(Gaestezimmer_Rollladen, STOP)
		logInfo("Szene_Gaestezimmer.rules", "Guest room command STOP sent")
	}

end

rule	"Gaestezimmer hochfahren"
when
	Item Gaestezimmer_Switch_SceneNumber received update 2.0
then
	logInfo("Szene_Gaestezimmer.rules", "Scenenumber {} received", Gaestezimmer_Switch_SceneNumber.state.toString)
	if (Sensor_Power.state == 0) {logInfo("Szene_Gaestezimmer.rules", "Sensor Power is zero")
		sendCommand(Gaestezimmer_Rollladen, UP)
		logInfo("Szene_Gaestezimmer.rules", "Guest room command UP is sent")
    
	}
	else if (Sensor_Power.state != 0) {logInfo("Szene_Gaestezimmer.rules", "Sensor Power is not zero")
		sendCommand(Gaestezimmer_Rollladen, STOP)
		logInfo("Szene_Gaestezimmer.rules", "Guest room command STOP is sent")
	}

end

…and now the log entries. I pushed the up and down button several times:

2019-02-06 21:56:49.973 [vent.ItemStateChangedEvent] - zwave_device_RaspberryPi3_node4_switch_binary2 changed from OFF to ON

2019-02-06 21:56:50.042 [vent.ItemStateChangedEvent] - Gaestezimmer_Switch_SceneNumber changed from 1.0 to 2.0

==> /var/log/openhab2/openhab.log <==

2019-02-06 21:56:50.727 [INFO ] [odel.script.Szene_Gaestezimmer.rules] - Scenenumber 2.0 received

2019-02-06 21:56:50.733 [INFO ] [odel.script.Szene_Gaestezimmer.rules] - Sensor Power is zero

2019-02-06 21:56:50.738 [INFO ] [odel.script.Szene_Gaestezimmer.rules] - Guest room command UP is sent

==> /var/log/openhab2/events.log <==

2019-02-06 21:56:50.738 [ome.event.ItemCommandEvent] - Item 'Gaestezimmer_Rollladen' received command UP

2019-02-06 21:56:50.744 [nt.ItemStatePredictedEvent] - Gaestezimmer_Rollladen predicted to become UP

2019-02-06 21:56:50.751 [vent.ItemStateChangedEvent] - Gaestezimmer_Rollladen changed from 100 to 0

2019-02-06 21:56:52.122 [vent.ItemStateChangedEvent] - Sensor_Power changed from 0 to 92.7

2019-02-06 21:56:52.310 [vent.ItemStateChangedEvent] - Gaestezimmer_Rollladen changed from 0 to 93

2019-02-06 21:56:55.762 [vent.ItemStateChangedEvent] - zwave_device_RaspberryPi3_node4_switch_binary1 changed from OFF to ON

2019-02-06 21:56:55.825 [vent.ItemStateChangedEvent] - Gaestezimmer_Switch_SceneNumber changed from 2.0 to 1.0

==> /var/log/openhab2/openhab.log <==

2019-02-06 21:56:55.840 [INFO ] [odel.script.Szene_Gaestezimmer.rules] - Scenenumber 1.0 received

2019-02-06 21:56:55.855 [INFO ] [odel.script.Szene_Gaestezimmer.rules] - Sensor Power is not zero

2019-02-06 21:56:55.865 [INFO ] [odel.script.Szene_Gaestezimmer.rules] - Guest room command STOP sent

==> /var/log/openhab2/events.log <==

2019-02-06 21:56:55.873 [ome.event.ItemCommandEvent] - Item 'Gaestezimmer_Rollladen' received command STOP

2019-02-06 21:56:57.477 [vent.ItemStateChangedEvent] - Gaestezimmer_Rollladen changed from 93 to 68

2019-02-06 21:56:58.476 [vent.ItemStateChangedEvent] - Gaestezimmer_Rollladen changed from 68 to 67

2019-02-06 21:56:58.505 [vent.ItemStateChangedEvent] - Sensor_Power changed from 92.7 to 0

2019-02-06 21:57:02.076 [vent.ItemStateChangedEvent] - zwave_device_RaspberryPi3_node4_switch_binary2 changed from ON to OFF

2019-02-06 21:57:02.138 [vent.ItemStateChangedEvent] - Gaestezimmer_Switch_SceneNumber changed from 1.0 to 2.0

==> /var/log/openhab2/openhab.log <==

2019-02-06 21:57:02.231 [INFO ] [odel.script.Szene_Gaestezimmer.rules] - Scenenumber 2.0 received

2019-02-06 21:57:02.244 [INFO ] [odel.script.Szene_Gaestezimmer.rules] - Sensor Power is zero

2019-02-06 21:57:02.255 [INFO ] [odel.script.Szene_Gaestezimmer.rules] - Guest room command UP is sent

==> /var/log/openhab2/events.log <==

2019-02-06 21:57:02.267 [ome.event.ItemCommandEvent] - Item 'Gaestezimmer_Rollladen' received command UP

2019-02-06 21:57:02.278 [nt.ItemStatePredictedEvent] - Gaestezimmer_Rollladen predicted to become UP

2019-02-06 21:57:02.282 [vent.ItemStateChangedEvent] - Gaestezimmer_Rollladen changed from 67 to 0

2019-02-06 21:57:03.840 [vent.ItemStateChangedEvent] - Gaestezimmer_Rollladen changed from 0 to 67

2019-02-06 21:57:03.928 [vent.ItemStateChangedEvent] - Sensor_Power changed from 0 to 92.8

2019-02-06 21:57:05.831 [vent.ItemStateChangedEvent] - zwave_device_RaspberryPi3_node4_switch_binary2 changed from OFF to ON

==> /var/log/openhab2/openhab.log <==

2019-02-06 21:57:05.944 [INFO ] [odel.script.Szene_Gaestezimmer.rules] - Scenenumber 2.0 received

2019-02-06 21:57:05.959 [INFO ] [odel.script.Szene_Gaestezimmer.rules] - Sensor Power is not zero

2019-02-06 21:57:05.969 [INFO ] [odel.script.Szene_Gaestezimmer.rules] - Guest room command STOP is sent

==> /var/log/openhab2/events.log <==

2019-02-06 21:57:05.978 [ome.event.ItemCommandEvent] - Item 'Gaestezimmer_Rollladen' received command STOP

2019-02-06 21:57:09.050 [vent.ItemStateChangedEvent] - Gaestezimmer_Rollladen changed from 67 to 41

2019-02-06 21:57:09.957 [vent.ItemStateChangedEvent] - Azimut changed from 300.77170485252657 to 302.12359759240906

2019-02-06 21:57:09.969 [vent.ItemStateChangedEvent] - Sonnenhoehe changed from -43.495526800748465 to -44.20176994175195

2019-02-06 21:57:10.024 [vent.ItemStateChangedEvent] - Gaestezimmer_Rollladen changed from 41 to 36

2019-02-06 21:57:10.043 [vent.ItemStateChangedEvent] - Sensor_Power changed from 92.8 to 0

2019-02-06 21:57:17.888 [vent.ItemStateChangedEvent] - zwave_device_RaspberryPi3_node4_switch_binary2 changed from ON to OFF

==> /var/log/openhab2/openhab.log <==

2019-02-06 21:57:17.963 [INFO ] [odel.script.Szene_Gaestezimmer.rules] - Scenenumber 2.0 received

2019-02-06 21:57:17.972 [INFO ] [odel.script.Szene_Gaestezimmer.rules] - Sensor Power is zero

2019-02-06 21:57:17.980 [INFO ] [odel.script.Szene_Gaestezimmer.rules] - Guest room command UP is sent

==> /var/log/openhab2/events.log <==

2019-02-06 21:57:17.984 [ome.event.ItemCommandEvent] - Item 'Gaestezimmer_Rollladen' received command UP

2019-02-06 21:57:17.991 [nt.ItemStatePredictedEvent] - Gaestezimmer_Rollladen predicted to become UP

2019-02-06 21:57:18.002 [vent.ItemStateChangedEvent] - Gaestezimmer_Rollladen changed from 36 to 0

2019-02-06 21:57:19.547 [vent.ItemStateChangedEvent] - Gaestezimmer_Rollladen changed from 0 to 36

2019-02-06 21:57:19.621 [vent.ItemStateChangedEvent] - Sensor_Power changed from 0 to 92.7

2019-02-06 21:57:26.757 [vent.ItemStateChangedEvent] - Sensor_Power changed from 92.7 to 0

2019-02-06 21:57:28.214 [vent.ItemStateChangedEvent] - Gaestezimmer_Rollladen changed from 36 to 0

Just let me know in case you need further information.

Thanks a lot!!

Matthias

By the way - perhaps it is important: I see a similar behaviour if I use the up/down/stop button in the Paper UI control environment. The initial command up/down command works perfectly but if I try to stop, it takes time…

I don’t know enough about how all of this works to begin to tell you anything useful. What sets Sensor_Power’s state?

Try putting the binding into debug logging and see if you can see the events going and coming to the device.

Ok, Thank you, I see tomorrow :slight_smile: The rollershutters’ power sensor measures the energy transmitted in real time. My idea behind it is: I wanted to use the up/down button to stop the blinds in case they are in movement. For me (as a beginner :wink: it was the only possibility to identify this status.

You can also try to use direct associations. This will send a direct command from the switch to the roller shutter, without any delay. But because it’ll bypass openhab, you can’t use rules for any other thing you wanna do with it.

Associations

1 Like

Hello Rich,

I used the z-wave log viewer but don’t know how to share the nice view here. Let me know if I can improve the view.

First of all the blinds went down to around 50%, then I stopped and afterwards I moved them down to 100%. This is the logging:

     07:44:12.437	4	
    RX REQ ApplicationCommandHandler MULTI_CHANNEL_CMD_ENCAP EP-1 -> EP-1 SWITCH_BINARY_REPORT OFF 0 /128
    07:44:12.479	4	
    STATE UPDATE zwave:device:RaspberryPi3:node4:switch_binary1 OFF [OnOffType]
    07:44:12.485	4	
    STATE UPDATE zwave:device:RaspberryPi3:node4:switch_binary1 OFF [OnOffType]
    07:44:12.506	4	
    RX REQ ApplicationCommandHandler CENTRAL_SCENE_NOTIFICATION SEQ=64 SCENE=1 ATTR=Key Pressed 0 /128
    07:44:12.545	4	
    STATE UPDATE zwave:device:RaspberryPi3:node4:scene_number 1.0 [DecimalType]
    07:44:12.565	4	
    RX REQ ApplicationCommandHandler MULTI_CHANNEL_CMD_ENCAP EP-1 -> EP-1 BASIC_SET 0 /128
    07:44:12.582	4	
    RX REQ ApplicationCommandHandler MULTI_CHANNEL_CMD_ENCAP EP-1 -> EP-1 BASIC_SET 0 /128
    07:44:12.608	4	
    STATE UPDATE zwave:device:RaspberryPi3:node4:switch_binary1 OFF [OnOffType]
    07:44:12.611	4	
    STATE UPDATE zwave:device:RaspberryPi3:node4:switch_binary1 OFF [OnOffType]
    07:44:12.604	3	
    COMMAND RECEIVED zwave:device:RaspberryPi3:node3:blinds_control DOWN [UpDownType]
    07:44:12.640	3	
    TX REQ SendData 160 SWITCH_MULTILEVEL_START_LEVEL_CHANGE  ACK AUTO_ROUTE EXPLORE
    07:44:12.646		
    RX ACK 0 /128
    07:44:12.653	3	
    RX RES SendData 160 ACCEPTED BY CONTROLLER 1 /128
    07:44:12.658	4	
    STATE UPDATE zwave:device:RaspberryPi3:node4:switch_binary1 OFF [OnOffType]
    07:44:12.661	4	
    STATE UPDATE zwave:device:RaspberryPi3:node4:switch_binary1 OFF [OnOffType]
    07:44:12.674	3	
    RX REQ SendData 160 ACK RECEIVED from device in 34ms 0 /128
    07:44:13.164	4	
    RX REQ ApplicationCommandHandler MULTI_CHANNEL_CMD_ENCAP EP-1 -> EP-1 METER_REPORT ELECTRIC_W 0 /128
    07:44:13.188	4	
    STATE UPDATE zwave:device:RaspberryPi3:node4:meter_watts1 0 [DecimalType]
    07:44:13.193	4	
    STATE UPDATE zwave:device:RaspberryPi3:node4:meter_watts1 0 [DecimalType]
    07:44:14.001	3	
    RX REQ ApplicationCommandHandler SENSOR_MULTI_LEVEL_REPORT POWER=34 0 /128
    07:44:14.040	3	
    STATE UPDATE zwave:device:RaspberryPi3:node3:sensor_power 87.1 [DecimalType]
    07:44:14.218	3	
    TX REQ SendData 161 SWITCH_MULTILEVEL_GET  ACK AUTO_ROUTE EXPLORE
    07:44:14.223		
    RX ACK 0 /128
    07:44:14.230	3	
    RX RES SendData 161 ACCEPTED BY CONTROLLER 0 /128
    07:44:14.248	3	
    RX REQ SendData 161 ACK RECEIVED from device in 30ms 0 /128
    07:44:14.265	3	
    RX REQ ApplicationCommandHandler SWITCH_MULTILEVEL_REPORT 7% 0 /128
    07:44:14.298	3	
    STATE UPDATE zwave:device:RaspberryPi3:node3:blinds_control 7 [PercentType]
    07:44:14.321	3	
    TX REQ SendData 162 SENSOR_MULTI_LEVEL_GET  ACK AUTO_ROUTE EXPLORE
    07:44:14.324		
    RX ACK 0 /128
    07:44:14.332	3	
    RX RES SendData 162 ACCEPTED BY CONTROLLER 0 /128
    07:44:14.350	3	
    RX REQ SendData 162 ACK RECEIVED from device in 29ms 0 /128
    07:44:14.368	3	
    RX REQ ApplicationCommandHandler SENSOR_MULTI_LEVEL_REPORT POWER=34 0 /128
    07:44:14.398	3	
    STATE UPDATE zwave:device:RaspberryPi3:node3:sensor_power 87.1 [DecimalType]
    07:44:14.416	3	
    TX REQ SendData 163 METER_GET ELECTRIC_W  ACK AUTO_ROUTE EXPLORE
    07:44:14.419		
    RX ACK 0 /128
    07:44:14.427	3	
    RX RES SendData 163 ACCEPTED BY CONTROLLER 0 /128
    07:44:14.446	3	
    RX REQ SendData 163 ACK RECEIVED from device in 30ms 0 /128
    07:44:14.465	3	
    RX REQ ApplicationCommandHandler METER_REPORT ELECTRIC_W 0 /128
    07:44:14.489	3	
    STATE UPDATE zwave:device:RaspberryPi3:node3:meter_watts 87.1 [DecimalType]
    07:44:14.514	3	
    TX REQ SendData 164 METER_GET ELECTRIC_KWH  ACK AUTO_ROUTE EXPLORE
    07:44:14.518		
    RX ACK 0 /128
    07:44:14.525	3	
    RX RES SendData 164 ACCEPTED BY CONTROLLER 0 /128
    07:44:14.543	3	
    RX REQ SendData 164 ACK RECEIVED from device in 29ms 0 /128
    07:44:14.561	3	
    RX REQ ApplicationCommandHandler METER_REPORT ELECTRIC_KWH 0 /128
    07:44:14.579	3	
    STATE UPDATE zwave:device:RaspberryPi3:node3:meter_kwh 0.29 [DecimalType]
    07:44:14.596	3	
    TX REQ SendData 165 MANUFACTURER_PROPRIETARY 02  ACK AUTO_ROUTE EXPLORE
    07:44:14.599		
    RX ACK 0 /128
    07:44:14.606	3	
    RX RES SendData 165 ACCEPTED BY CONTROLLER 0 /128
    07:44:14.624	3	
    RX REQ SendData 165 ACK RECEIVED from device in 28ms 0 /128
    07:44:17.926	4	
    RX REQ ApplicationCommandHandler MULTI_CHANNEL_CMD_ENCAP EP-1 -> EP-1 SWITCH_BINARY_REPORT ON 0 /128
    07:44:17.958	4	
    STATE UPDATE zwave:device:RaspberryPi3:node4:switch_binary1 ON [OnOffType]
    07:44:17.962	4	
    STATE UPDATE zwave:device:RaspberryPi3:node4:switch_binary1 ON [OnOffType]
    07:44:17.994	4	
    RX REQ ApplicationCommandHandler CENTRAL_SCENE_NOTIFICATION SEQ=65 SCENE=1 ATTR=Key Pressed 0 /128
    07:44:18.016	4	
    STATE UPDATE zwave:device:RaspberryPi3:node4:scene_number 1.0 [DecimalType]
    07:44:18.052	3	
    COMMAND RECEIVED zwave:device:RaspberryPi3:node3:blinds_control STOP [StopMoveType]
    07:44:18.054	4	
    RX REQ ApplicationCommandHandler MULTI_CHANNEL_CMD_ENCAP EP-1 -> EP-1 BASIC_SET 0 /128
    07:44:18.078	4	
    RX REQ ApplicationCommandHandler MULTI_CHANNEL_CMD_ENCAP EP-1 -> EP-1 BASIC_SET 0 /128
    07:44:18.087	4	
    STATE UPDATE zwave:device:RaspberryPi3:node4:switch_binary1 ON [OnOffType]
    07:44:18.092	4	
    STATE UPDATE zwave:device:RaspberryPi3:node4:switch_binary1 ON [OnOffType]
    07:44:18.123	4	
    STATE UPDATE zwave:device:RaspberryPi3:node4:switch_binary1 ON [OnOffType]
    07:44:18.127	4	
    STATE UPDATE zwave:device:RaspberryPi3:node4:switch_binary1 ON [OnOffType]
    07:44:19.664	3	
    TX REQ SendData 166 SWITCH_MULTILEVEL_STOP_LEVEL_CHANGE  ACK AUTO_ROUTE EXPLORE
    07:44:19.667		
    RX ACK 0 /128
    07:44:19.677	3	
    RX RES SendData 166 ACCEPTED BY CONTROLLER 0 /128
    07:44:19.693	3	
    RX REQ SendData 166 ACK RECEIVED from device in 29ms 0 /128
    07:44:19.735	3	
    TX REQ SendData 167 SWITCH_MULTILEVEL_GET  ACK AUTO_ROUTE EXPLORE
    07:44:19.738		
    RX ACK 0 /128
    07:44:19.745	3	
    RX RES SendData 167 ACCEPTED BY CONTROLLER 0 /128
    07:44:19.764	3	
    RX REQ SendData 167 ACK RECEIVED from device in 29ms 0 /128
    07:44:19.781	3	
    RX REQ ApplicationCommandHandler SWITCH_MULTILEVEL_REPORT 33% 0 /128
    07:44:19.803	3	
    STATE UPDATE zwave:device:RaspberryPi3:node3:blinds_control 33 [PercentType]
    07:44:19.824	3	
    TX REQ SendData 168 SENSOR_MULTI_LEVEL_GET  ACK AUTO_ROUTE EXPLORE
    07:44:19.828		
    RX ACK 0 /128
    07:44:19.835	3	
    RX RES SendData 168 ACCEPTED BY CONTROLLER 0 /128
    07:44:19.855	3	
    RX REQ SendData 168 ACK RECEIVED from device in 31ms 0 /128
    07:44:19.872	3	
    RX REQ ApplicationCommandHandler SENSOR_MULTI_LEVEL_REPORT POWER=34 0 /128
    07:44:19.897	3	
    STATE UPDATE zwave:device:RaspberryPi3:node3:sensor_power 86.7 [DecimalType]
    07:44:19.916	3	
    TX REQ SendData 169 METER_GET ELECTRIC_W  ACK AUTO_ROUTE EXPLORE
    07:44:19.921		
    RX ACK 0 /128
    07:44:19.926	3	
    RX RES SendData 169 ACCEPTED BY CONTROLLER 0 /128
    07:44:19.945	3	
    RX REQ SendData 169 ACK RECEIVED from device in 29ms 0 /128
    07:44:19.963	3	
    RX REQ ApplicationCommandHandler METER_REPORT ELECTRIC_W 0 /128
    07:44:19.987	3	
    STATE UPDATE zwave:device:RaspberryPi3:node3:meter_watts 86.7 [DecimalType]
    07:44:20.006	3	
    TX REQ SendData 170 METER_GET ELECTRIC_KWH  ACK AUTO_ROUTE EXPLORE
    07:44:20.012		
    RX ACK 0 /128
    07:44:20.017	3	
    RX RES SendData 170 ACCEPTED BY CONTROLLER 0 /128
    07:44:20.035	3	
    RX REQ SendData 170 ACK RECEIVED from device in 29ms 0 /128
    07:44:20.055	3	
    RX REQ ApplicationCommandHandler METER_REPORT ELECTRIC_KWH 0 /128
    07:44:20.079	3	
    STATE UPDATE zwave:device:RaspberryPi3:node3:meter_kwh 0.29 [DecimalType]
    07:44:20.097	3	
    TX REQ SendData 171 MANUFACTURER_PROPRIETARY 02  ACK AUTO_ROUTE EXPLORE
    07:44:20.100		
    RX ACK 0 /128
    07:44:20.107	3	
    RX RES SendData 171 ACCEPTED BY CONTROLLER 0 /128
    07:44:20.126	3	
    RX REQ SendData 171 ACK RECEIVED from device in 29ms 0 /128
    07:44:20.164	4	
    RX REQ ApplicationCommandHandler MULTI_CHANNEL_CMD_ENCAP EP-1 -> EP-1 METER_REPORT ELECTRIC_W 0 /128
    07:44:20.186	4	
    STATE UPDATE zwave:device:RaspberryPi3:node4:meter_watts1 0 [DecimalType]
    07:44:20.189	4	
    STATE UPDATE zwave:device:RaspberryPi3:node4:meter_watts1 0 [DecimalType]
    07:44:20.736	3	
    RX REQ ApplicationCommandHandler SWITCH_MULTILEVEL_REPORT 37% 0 /128
    07:44:20.755	3	
    RX REQ ApplicationCommandHandler SENSOR_MULTI_LEVEL_REPORT POWER=34 0 /128
    07:44:20.754	3	
    STATE UPDATE zwave:device:RaspberryPi3:node3:blinds_control 37 [PercentType]
    07:44:20.788	3	
    STATE UPDATE zwave:device:RaspberryPi3:node3:sensor_power 0 [DecimalType]
    07:44:22.167	4	
    RX REQ ApplicationCommandHandler MULTI_CHANNEL_CMD_ENCAP EP-1 -> EP-1 SWITCH_BINARY_REPORT OFF 0 /128
    07:44:22.207	4	
    STATE UPDATE zwave:device:RaspberryPi3:node4:switch_binary1 OFF [OnOffType]
    07:44:22.211	4	
    STATE UPDATE zwave:device:RaspberryPi3:node4:switch_binary1 OFF [OnOffType]
    07:44:22.236	4	
    RX REQ ApplicationCommandHandler CENTRAL_SCENE_NOTIFICATION SEQ=66 SCENE=1 ATTR=Key Pressed 0 /128
    07:44:22.266	4	
    STATE UPDATE zwave:device:RaspberryPi3:node4:scene_number 1.0 [DecimalType]
    07:44:22.296	4	
    RX REQ ApplicationCommandHandler MULTI_CHANNEL_CMD_ENCAP EP-1 -> EP-1 BASIC_SET 0 /128
    07:44:22.319	4	
    RX REQ ApplicationCommandHandler MULTI_CHANNEL_CMD_ENCAP EP-1 -> EP-1 BASIC_SET 0 /128
    07:44:22.340	4	
    STATE UPDATE zwave:device:RaspberryPi3:node4:switch_binary1 OFF [OnOffType]
    07:44:22.340	3	
    COMMAND RECEIVED zwave:device:RaspberryPi3:node3:blinds_control DOWN [UpDownType]
    07:44:22.344	4	
    STATE UPDATE zwave:device:RaspberryPi3:node4:switch_binary1 OFF [OnOffType]
    07:44:22.392	4	
    STATE UPDATE zwave:device:RaspberryPi3:node4:switch_binary1 OFF [OnOffType]
    07:44:22.394	4	
    STATE UPDATE zwave:device:RaspberryPi3:node4:switch_binary1 OFF [OnOffType]
    07:44:23.166	4	
    RX REQ ApplicationCommandHandler MULTI_CHANNEL_CMD_ENCAP EP-1 -> EP-1 METER_REPORT ELECTRIC_W 0 /128
    07:44:23.198	4	
    STATE UPDATE zwave:device:RaspberryPi3:node4:meter_watts1 0 [DecimalType]
    07:44:23.202	4	
    STATE UPDATE zwave:device:RaspberryPi3:node4:meter_watts1 0 [DecimalType]
    07:44:25.165	3	
    TX REQ SendData 172 SWITCH_MULTILEVEL_START_LEVEL_CHANGE  ACK AUTO_ROUTE EXPLORE
    07:44:25.171		
    RX ACK 0 /128
    07:44:25.181	3	
    RX RES SendData 172 ACCEPTED BY CONTROLLER 0 /128
    07:44:25.199	3	
    RX REQ SendData 172 ACK RECEIVED from device in 34ms 0 /128
    07:44:25.270	3	
    TX REQ SendData 173 SWITCH_MULTILEVEL_GET  ACK AUTO_ROUTE EXPLORE
    07:44:25.274		
    RX ACK 0 /128
    07:44:25.281	3	
    RX RES SendData 173 ACCEPTED BY CONTROLLER 0 /128
    07:44:25.300	3	
    RX REQ SendData 173 ACK RECEIVED from device in 30ms 0 /128
    07:44:25.317	3	
    RX REQ ApplicationCommandHandler SWITCH_MULTILEVEL_REPORT 37% 0 /128
    07:44:25.341	3	
    STATE UPDATE zwave:device:RaspberryPi3:node3:blinds_control 37 [PercentType]
    07:44:25.361	3	
    TX REQ SendData 174 SENSOR_MULTI_LEVEL_GET  ACK AUTO_ROUTE EXPLORE
    07:44:25.365		
    RX ACK 0 /128
    07:44:25.371	3	
    RX RES SendData 174 ACCEPTED BY CONTROLLER 0 /128
    07:44:25.391	3	
    RX REQ SendData 174 ACK RECEIVED from device in 30ms 0 /128
    07:44:25.409	3	
    RX REQ ApplicationCommandHandler SENSOR_MULTI_LEVEL_REPORT POWER=34 0 /128
    07:44:25.435	3	
    STATE UPDATE zwave:device:RaspberryPi3:node3:sensor_power 0 [DecimalType]
    07:44:25.454	3	
    TX REQ SendData 175 METER_GET ELECTRIC_W  ACK AUTO_ROUTE EXPLORE
    07:44:25.458		
    RX ACK 0 /128
    07:44:25.464	3	
    RX RES SendData 175 ACCEPTED BY CONTROLLER 0 /128
    07:44:25.484	3	
    RX REQ SendData 175 ACK RECEIVED from device in 30ms 0 /128
    07:44:25.501	3	
    RX REQ ApplicationCommandHandler METER_REPORT ELECTRIC_W 0 /128
    07:44:25.527	3	
    STATE UPDATE zwave:device:RaspberryPi3:node3:meter_watts 0 [DecimalType]
    07:44:25.547	3	
    TX REQ SendData 176 METER_GET ELECTRIC_KWH  ACK AUTO_ROUTE EXPLORE
    07:44:25.551		
    RX ACK 0 /128
    07:44:25.558	3	
    RX RES SendData 176 ACCEPTED BY CONTROLLER 0 /128
    07:44:25.577	3	
    RX REQ SendData 176 ACK RECEIVED from device in 30ms 0 /128
    07:44:25.593	3	
    RX REQ ApplicationCommandHandler METER_REPORT ELECTRIC_KWH 0 /128
    07:44:25.616	3	
    STATE UPDATE zwave:device:RaspberryPi3:node3:meter_kwh 0.29 [DecimalType]
    07:44:25.640	3	
    TX REQ SendData 177 MANUFACTURER_PROPRIETARY 02  ACK AUTO_ROUTE EXPLORE
    07:44:25.645		
    RX ACK 0 /128
    07:44:25.650	3	
    RX RES SendData 177 ACCEPTED BY CONTROLLER 0 /128
    07:44:25.669	3	
    RX REQ SendData 177 ACK RECEIVED from device in 29ms 0 /128
    07:44:26.505	3	
    RX REQ ApplicationCommandHandler SENSOR_MULTI_LEVEL_REPORT POWER=34 0 /128
    07:44:26.547	3	
    STATE UPDATE zwave:device:RaspberryPi3:node3:sensor_power 86.9 [DecimalType]
    07:44:39.742	3	
    RX REQ ApplicationCommandHandler SWITCH_MULTILEVEL_REPORT 99% 0 /128
    07:44:39.763	3	
    RX REQ ApplicationCommandHandler SENSOR_MULTI_LEVEL_REPORT POWER=34 0 /128
    07:44:39.782	3	
    STATE UPDATE zwave:device:RaspberryPi3:node3:blinds_control 100 [PercentType]
    07:44:39.845	3	
    STATE UPDATE zwave:device:RaspberryPi3:node3:sensor_power 0 [DecimalType]
     

I personally don’t really know how to read zwave logs but what you need to do is look for log statements from the devices based on node number, and compare the timestamps with the log statements in events.log and openhab.log. If the time stamps correspond you know the problem isn’t zwave. If the timestamps are two seconds after events.log send the command then you know the problem is in the binding.