Z-Wave node not responding correctly

Add-ons Bindings
,
1

Hi all,
I am having a strange behaviour in my system.
I am running latest 2.2 stable and I have few ZWave units.

If I control the Zwave switches one by one in the sitemap they work correctly and react immediately.

But if create a scene in a rule then the behaviour is weird.
Sometimes the zwave devices do not respond, sometimes they respond with a lot of delay.

Attached is a debug and event log case where the zwave responded with several seconds of delay after selecting SceneNumber = 2.
The most delayed one is node3 that is a FIBARO FGS-222.

Here is the scene:

import org.openhab.core.library.types
import org.openhab.model.script.actions

rule "Movie Scene Selector" 
when
	Item nMovieScene received command

then
  
	if (nMovieScene.state == 0) { 
	//all OFF
		zsRGBW_AllSwitch.sendCommand(OFF) 
		Thread::sleep(100)
		zsLedNord.sendCommand(OFF) 
		Thread::sleep(100)
		zsLedSud.sendCommand(OFF) 
		Thread::sleep(100)
		zsDimmer1.sendCommand(OFF) 
		Thread::sleep(100)
		sX10A13.sendCommand(OFF) 
	} else if (nMovieScene.state == 1) { 
	//led blue at 3%
		zdRGBW_R.sendCommand(1)
		Thread::sleep(100)
		zdRGBW_G.sendCommand(3)
		Thread::sleep(100)
		zdRGBW_B.sendCommand(3)
		Thread::sleep(100)
		zdRGBW_W.sendCommand(0)
		Thread::sleep(100)
		zsLedNord.sendCommand(OFF) 
		Thread::sleep(100)
		zsLedSud.sendCommand(OFF) 
		Thread::sleep(100)
		zsDimmer1.sendCommand(OFF) 
		Thread::sleep(100)
		sX10A13.sendCommand(OFF) 
		Thread::sleep(100)
	} else if (nMovieScene.state == 2) { 
	//led blue at 7%
		zdRGBW_R.sendCommand(2)
		Thread::sleep(100)
		zdRGBW_G.sendCommand(7)
		Thread::sleep(100)
		zdRGBW_B.sendCommand(7)
		Thread::sleep(100)
		zdRGBW_W.sendCommand(0)
		Thread::sleep(100)
		zsLedNord.sendCommand(OFF) 
		Thread::sleep(100)
		zsLedSud.sendCommand(OFF) 
		Thread::sleep(100)
		zsDimmer1.sendCommand(OFF) 
		Thread::sleep(100)
		sX10A13.sendCommand(OFF) 
	} else if (nMovieScene.state == 3) { 
	//led blue at 100% + white at 50%
		zdRGBW_R.sendCommand(28)
		Thread::sleep(100)
		zdRGBW_G.sendCommand(100)
		Thread::sleep(100)
		zdRGBW_B.sendCommand(100)
		Thread::sleep(100)
		zdRGBW_W.sendCommand(50)
		Thread::sleep(100)
		zsLedNord.sendCommand(OFF) 
		Thread::sleep(100)
		zsLedSud.sendCommand(OFF) 
		Thread::sleep(100)
		zsDimmer1.sendCommand(OFF) 
		Thread::sleep(100)
		sX10A13.sendCommand(OFF) 
	} else if (nMovieScene.state == 4) { 
	//led white at 50%
		zdRGBW_R.sendCommand(0)
		Thread::sleep(100)
		zdRGBW_G.sendCommand(0)
		Thread::sleep(100)
		zdRGBW_B.sendCommand(0)
		Thread::sleep(100)
		zdRGBW_W.sendCommand(75)
		Thread::sleep(100)
		zsLedNord.sendCommand(OFF) 
		Thread::sleep(100)
		zsLedSud.sendCommand(OFF) 
		Thread::sleep(100)
		zsDimmer1.sendCommand(OFF) 
	} else if (nMovieScene.state == 5) { 
	//led spot ON
		zsRGBW_AllSwitch.sendCommand(OFF) 
		Thread::sleep(100)
		zsLedNord.sendCommand(ON) 
		Thread::sleep(100)
		zsLedSud.sendCommand(ON) 
		Thread::sleep(100)
		zsDimmer1.sendCommand(OFF) 
	} else if (nMovieScene.state == 6) { 
	//all OFF
		zsRGBW_AllSwitch.sendCommand(OFF) 
		Thread::sleep(100)
		zsLedNord.sendCommand(OFF) 
		Thread::sleep(100)
		zsLedSud.sendCommand(OFF) 
		Thread::sleep(100)
		zsDimmer1.sendCommand(OFF) 
	} 
end

Here are the z-wave items:

// Fibaro 2x1.5kW (node=3; ID=fibaro_fgs222_00_000)
Switch zsLedNord "Led Nord" <switch> (gSalotto,gZwave)  {channel="zwave:device:controller:node3:switch_binary"} 
Switch zsLedSud  "Led Sud"  <switch> (gSalotto,gZwave)  {channel="zwave:device:controller:node3:switch_binary2"}

// Fibaro 2x1.5kW 2 (node=5; ID=fibaro_fgs222_00_000)
Switch  zsSwitch1     "Switch1"    <switch> (gSalotto,gZwave)  {channel="zwave:device:controller:node5:switch_binary"}
Switch  zsSwitch2     "Switch2"    <switch> (gSalotto,gZwave)  {channel="zwave:device:controller:node5:switch_binary2"}

// FIBARO DIMMER (node=8; ID=fibaro_fgd211_02_001)
Switch zsDimmer1 "Switch Alogena" <switch> (gSalotto,gZwave)  {channel="zwave:device:controller:node8:switch_dimmer"}
Dimmer zdDimmer1 "Dimmer Alogena" <slider> (gSalotto,gZwave)  {channel="zwave:device:controller:node8:switch_dimmer"}

// Fibaro RGBW (node=7; ID=fibaro_fgrgbw_00_000)
Color   zcRGBW      "RGBW ColorPicker"    <slider> (gSalotto,gZwave,gzRGBW)  {channel="zwave:device:controller:node7:color_color"}
Dimmer  zdRGBW_All  "RGBW All"    <slider> (gSalotto,gZwave,gzRGBW)  {channel="zwave:device:controller:node7:switch_dimmer"}
Dimmer  zdRGBW_R    "RGBW Red [%d %%]"    <slider> (gSalotto,gZwave,gzRGBW)  {channel="zwave:device:controller:node7:switch_dimmer2"}  
Dimmer  zdRGBW_G    "RGBW Green [%d %%]"  <slider> (gSalotto,gZwave,gzRGBW)  {channel="zwave:device:controller:node7:switch_dimmer3"} 
Dimmer  zdRGBW_B    "RGBW Blue [%d %%]"   <slider> (gSalotto,gZwave,gzRGBW)  {channel="zwave:device:controller:node7:switch_dimmer4"} 
Dimmer  zdRGBW_W    "RGBW White"  <slider> (gSalotto,gZwave,gzRGBW)  {channel="zwave:device:controller:node7:switch_dimmer5"}

Switch  zsRGBW_AllSwitch "RGBW SwitchAll"      <switch>    (gSalotto,gZwave,gzRGBW)  {channel="zwave:device:controller:node7:switch_dimmer"}
Switch  zsRGBW_RSwitch 	 "RGBW SwitchRed"      <switch>    (gSalotto,gZwave,gzRGBW)  {channel="zwave:device:controller:node7:switch_dimmer2"}
Switch  zsRGBW_GSwitch 	 "RGBW SwitchGreen"    <switch>    (gSalotto,gZwave,gzRGBW)  {channel="zwave:device:controller:node7:switch_dimmer3"}
Switch  zsRGBW_BSwitch 	 "RGBW SwitchBlue"     <switch>    (gSalotto,gZwave,gzRGBW)  {channel="zwave:device:controller:node7:switch_dimmer4"}
Switch  zsRGBW_WSwitch 	 "RGBW SwitchWhite"    <switch>    (gSalotto,gZwave,gzRGBW)  {channel="zwave:device:controller:node7:switch_dimmer5"}

Number  znRGBW_Power     "RGBW Potenza [%.1f W]"   <energy>  (gSalotto,gZwave,gzRGBW)   {channel="zwave:device:controller:node7:meter_watts"}
Number  znRGBW_Energy    "RGBW Energia [%.2f KWh]" <energy>  (gSalotto,gZwave,gzRGBW)   {channel="zwave:device:controller:node7:meter_kwh"}

Number  znRGBW_Programs  "RGBW Programs"           <switch>  (gSalotto,gZwave,gzRGBW)   {channel="zwave:device:controller:node7:scene_number_param72"}
String  zsRGBW_ProgName  "RGBW Program Name: [%s]"  <switch>  (gSalotto,gZwave,gzRGBW)   //valore calcolato nelle RULES


// TEST
Color   zcRGBWtest      "RGBW TEST ColorPicker"    <slider> (gSalotto,gZwave,gzRGBW) 

// VIRTUAL
Number  nMovieScene "MovieScene" <switch>  (gSalotto,gZwave,gzRGBW)   //valore calcolato nelle RULES

The debug log is attached (had to change the name to .xml to be able to upload)
openhab.xml (50.7 KB)

and the event.log

2017-12-26 17:01:18.626 [ome.event.ItemCommandEvent] - Item 'nMovieScene' received command 2
2017-12-26 17:01:18.630 [vent.ItemStateChangedEvent] - nMovieScene changed from 0 to 2
2017-12-26 17:01:18.648 [ome.event.ItemCommandEvent] - Item 'zdRGBW_R' received command 2
2017-12-26 17:01:18.662 [vent.ItemStateChangedEvent] - zdRGBW_R changed from 0 to 2
2017-12-26 17:01:18.752 [ome.event.ItemCommandEvent] - Item 'zdRGBW_G' received command 7
2017-12-26 17:01:18.758 [vent.ItemStateChangedEvent] - zdRGBW_G changed from 0 to 7
2017-12-26 17:01:18.856 [ome.event.ItemCommandEvent] - Item 'zdRGBW_B' received command 7
2017-12-26 17:01:18.872 [vent.ItemStateChangedEvent] - zdRGBW_B changed from 0 to 7
2017-12-26 17:01:18.874 [vent.ItemStateChangedEvent] - zsRGBW_RSwitch changed from OFF to ON
2017-12-26 17:01:18.896 [vent.ItemStateChangedEvent] - zsRGBW_AllSwitch changed from OFF to ON
2017-12-26 17:01:18.912 [vent.ItemStateChangedEvent] - zdRGBW_All changed from 0 to 2
2017-12-26 17:01:18.914 [vent.ItemStateChangedEvent] - zcRGBW changed from 0,0,0 to 0,0,2
2017-12-26 17:01:18.962 [ome.event.ItemCommandEvent] - Item 'zdRGBW_W' received command 0
2017-12-26 17:01:19.062 [ome.event.ItemCommandEvent] - Item 'zsLedNord' received command OFF
2017-12-26 17:01:19.072 [vent.ItemStateChangedEvent] - zsLedNord changed from ON to OFF
2017-12-26 17:01:19.166 [ome.event.ItemCommandEvent] - Item 'zsLedSud' received command OFF
2017-12-26 17:01:19.174 [vent.ItemStateChangedEvent] - zsLedSud changed from ON to OFF
2017-12-26 17:01:19.214 [vent.ItemStateChangedEvent] - zsRGBW_GSwitch changed from OFF to ON
2017-12-26 17:01:19.249 [vent.ItemStateChangedEvent] - zsRGBW_BSwitch changed from OFF to ON
2017-12-26 17:01:19.262 [vent.ItemStateChangedEvent] - zdRGBW_All changed from 2 to 7
2017-12-26 17:01:19.264 [vent.ItemStateChangedEvent] - zcRGBW changed from 0,0,2 to 0,0,7
2017-12-26 17:01:19.270 [ome.event.ItemCommandEvent] - Item 'zsDimmer1' received command OFF
2017-12-26 17:01:19.373 [ome.event.ItemCommandEvent] - Item 'sX10A13' received command OFF
2

anyone?

3

It looks like the transmission to node 3 is timing out for some reason. That is what’s introducing the delay.

capture
capture.jpg1830×1058 443 KB

4

Hi @mhilbush the delay happens only in the rule.
If I switch the item directly from the sitemap it doesn’t delay.

Is there any way to determine what is generating the delay? The unit? The rule? OH? The binding?

thanks

P.S. can you explain me what you did to modify my log in the coloured way above?

EDIT: in the rule execution order, the first node that is called is node7 (RGBW) then node3.
But also node7 is executed with delay, so the problem is not only with node3.

5

In the log above, the OFF transmit goes out to node 3 at 17:01:19.181 and there’s an abort (almost) exactly 5 seconds later at 17:01:24.184, followed by a retransmission of the OFF command at 17:01:24.188. I don’t see where this has anything to do with the rule.

It appears to be a transmission failure in the z-wave network. The transmission timeout is 5 seconds. How far away is node 3 from the controller?

@chris made this handy log viewer tool. I’d be lost without it. :smile:
http://www.cd-jackson.com/index.php/openhab/zwave-log-viewer