Scene takes forever using my rule (z-way, z-wave, hue)

Curtis · October 10, 2017, 6:29pm

Hi Everyone,

I’m having trouble with a rule that I have setup for a scene. I can operate all the devices singularly and within a second using virtual switches but when I combine them in a rule it can take a minute or more to for all devices to activate in my scene. I understand that there is bound to be some lag by sending all commands at once but I was not expecting it to be that much.

I have a couple of z-wave devices connected to Openhab via Razberry and the z-way binding, a hue lightstrip and a light switch via the lightwaverf binding.

I would really appreciate it if someone here could let me know if what I have done is correct or if have I gone about it the wrong way.

.sitemap

Switch item=Scene 
   mappings=["OFF"="Off", "ON"="On"]

.items

Switch Scene "Scene" ["Switchable"]

.rule

rule Scene_on

when 
	Item Scene received command ON
then
	Switch_BedMaster_Main.sendCommand(OFF)
	Switch_BedMaster_CurtLamp.sendCommand(OFF)
	Switch_BedMaster_SarahLamp.sendCommand(OFF)
	Dimmer_OnSuite.sendCommand(OFF)
	Hue_Bedroom.sendCommand("0,0,99")
end

rule Scene_off

when 
	Item Scene received command OFF
then
	Switch_BedMaster_Main.sendCommand(ON)
	Switch_BedMaster_CurtLamp.sendCommand(ON)
	Switch_BedMaster_SarahLamp.sendCommand(ON)
	Dimmer_OnSuite.sendCommand(ON)
	Hue_Bedroom.sendCommand("0,99,99")
end

Many thanks in advance

rlkoshak · October 10, 2017, 9:08pm

Please add log statements between the each of the commands in each rule.

Please post openhab.log after adding those log statements and you toggle the scene.

Please post events.log showing each of those devices changing state.

Please use code fences when you post the logs.

We are trying to narrow the problem down to the rules or the bindings and perhaps figure out which binding is causing the delay.

And this is just a stylistic thing but I would rewrite the above rule as:

Group:Switch:OR(ON,OFF) gScene1
Switch_BedMaster_Main ... (gScene1) ...
...

rule "Scene"
when
    Item Scene received command
then
    gScene1.sendCommand(if(receivedCommand == ON) OFF else ON)
    Hue_Bedroom.sendCommand(if(receivedCommand == OFF) "0,99,99" else "0,0,99")
end

Curtis · October 11, 2017, 8:32am

Hi Rich,

Many thanks for helping out. So in essence what you are saying is that although my rule is not neat and tidy it should work?

My Lightwaverf light always works quickly but my z-wave and Philips lightstrip take a while.

As this is my first rule and an introduction to the language I’m not sure I follow how your version of my rule works. To my unexperienced eye it looks like you are grouping in the top and using the lower section to combine my on and off code. If possible please can you add some comments to help me understand how it works. I would rather understand the right way from the beginning even if it is more difficult for me to understand at first.

Sorry but as I’m a beginner I don’t understand what you mean by:

“Please add log statements between the each of the commands in each rule.”

Thanks

rlkoshak · October 11, 2017, 1:33pm

Yes. My version is to just illustrate some of the ways one can make code simpler and easier to maintain.

The first thing I noticed is that your two rules do basically the same thing with the only difference being what commands get sent when Scene receives ON or OFF. So I combined the rules into one.

rule Scene_on

when 
	Item Scene received command ON
then
  if(receivedCommand == ON) {
    Switch_BedMaster_Main.sendCommand(OFF)
    Switch_BedMaster_CurtLamp.sendCommand(OFF)
	Switch_BedMaster_SarahLamp.sendCommand(OFF)
	Dimmer_OnSuite.sendCommand(OFF)
	Hue_Bedroom.sendCommand("0,0,99")
  }
  else {
	Switch_BedMaster_Main.sendCommand(ON)
	Switch_BedMaster_CurtLamp.sendCommand(ON)
	Switch_BedMaster_SarahLamp.sendCommand(ON)
	Dimmer_OnSuite.sendCommand(ON)
	Hue_Bedroom.sendCommand("0,99,99")
   }
end

Then I notice that you send the same command to all of your Switches and Dimmers based on what the receivedCommand is. So I can eliminate those from the if block and not have to repeat myself.

rule Scene_on

when 
	Item Scene received command ON
then
  var lightCmd = ON
  if(receivedCommand == ON) lightCmd = OFF

  Switch_BedMaster_Main.sendCommand(lightCmd)
  Switch_BedMaster_CurtLamp.sendCommand(Cmd)
  Switch_BedMaster_SarahLamp.sendCommand(Cmd)
  Dimmer_OnSuite.sendCommand(Cmd)

  if(receivedCommand == ON) {
	Hue_Bedroom.sendCommand("0,0,99")
  }
  else {
	Hue_Bedroom.sendCommand("0,99,99")
   }
end

If I were to put all the lights and Dimmers into a Group I would get the benefit of only needing one line in my Scene Rule and I can add or remove lights to the Scene just by modifying my .items file and will not have to mess with my Rule.

Group:Switch:OR(ON,OFF) gScene1
Switch Switch_BedMaster_Main ... (gScene1) ...
Switch Switch_BedMaster_CurtLamp ... (gScene1) ...
Switch Switch_BedMaster_SarahLamp ... (gScene1) ...
Dimmer Dimmer_OnSuite ... (gScene1) ...

rule Scene_on

when 
	Item Scene received command ON
then
  var lightCmd = ON
  if(receivedCommand == ON) lightCmd = OFF

  gScene1.sendCommand(lightCmd)

  if(receivedCommand == ON) {
	Hue_Bedroom.sendCommand("0,0,99")
  }
  else {
	Hue_Bedroom.sendCommand("0,99,99")
   }
end

I can further reduce the code by taking advantage of the fact that curly brackets are not required for if statements with only one statement in the body.

rule Scene_on

when 
	Item Scene received command ON
then
  var lightCmd = ON
  if(receivedCommand == ON) lightCmd = OFF

  gScene1.sendCommand(lightCmd)

  if(receivedCommand == ON) Hue_Bedroom.sendCommand("0,0,99")
  else Hue_Bedroom.sendCommand("0,99,99")

end

I can still further reduce the code by taking advantage of the trinary operator which is like a one line if statement to initialze a variable or the like.

rule Scene_on

when 
	Item Scene received command ON
then
  val lightCmd = if(receivedCommand == ON) OFF else ON

  gScene1.sendCommand(lightCmd)

  if(receivedCommand == ON) Hue_Bedroom.sendCommand("0,0,99")
  else Hue_Bedroom.sendCommand("0,99,99")

end

And if I just use the trinary operator instead of a new variable I can get my version of the rule above.

rule "Scene"
when
    Item Scene received command
then
    gScene1.sendCommand(if(receivedCommand == ON) OFF else ON)
    Hue_Bedroom.sendCommand(if(receivedCommand == OFF) "0,99,99" else "0,0,99")
end

If you take your original rule:

rule Scene_on

when 
	Item Scene received command ON
then
    logInfo("Scene on", "Starting Scene ON")
	Switch_BedMaster_Main.sendCommand(OFF)
    logInfo("Scene on", "Sent OFF to Switch_BedMaster_Main")
	Switch_BedMaster_CurtLamp.sendCommand(OFF)
    logInfo("Scene on", "Send OFF to BedMaster_CurtLamp")
...

http://docs.openhab.org/administration/logging.html#create-log-entries-in-rules

Curtis · October 11, 2017, 3:41pm

Firstly thanks very much for your detailed response I really appreciate it! I feel I’m very close to understand but have a couple of questions.

Why the difference in the brackets from (lightCmd) to (Cmd)?

I assume this is to be put in the .items file but what does it mean?

event.log

2017-10-11 16:23:19.773 [ItemStateChangedEvent     ] - Scene changed from NULL to OFF
2017-10-11 16:23:19.814 [ItemCommandEvent          ] - Item 'Scene' received command OFF
2017-10-11 16:23:21.771 [ItemCommandEvent          ] - Item 'Switch_BedMaster_Main' received command ON
2017-10-11 16:23:21.775 [ItemStateChangedEvent     ] - Switch_BedMaster_Main changed from NULL to ON
2017-10-11 16:23:22.371 [ItemStateChangedEvent     ] - Switch_BedMaster_CurtLamp changed from OFF to ON
2017-10-11 16:23:22.420 [ItemCommandEvent          ] - Item 'Switch_BedMaster_CurtLamp' received command ON
2017-10-11 16:23:22.912 [ItemStateChangedEvent     ] - Switch_BedMaster_SarahLamp changed from OFF to ON
2017-10-11 16:23:22.954 [ItemCommandEvent          ] - Item 'Switch_BedMaster_SarahLamp' received command ON
2017-10-11 16:23:23.421 [ItemStateChangedEvent     ] - Dimmer_OnSuite changed from 0 to 100
2017-10-11 16:23:23.456 [ItemCommandEvent          ] - Item 'Dimmer_OnSuite' received command ON
2017-10-11 16:23:23.473 [ItemStateChangedEvent     ] - Hue_Bedroom changed from 155,85,0 to 0,99,99
2017-10-11 16:23:23.524 [ItemCommandEvent          ] - Item 'Hue_Bedroom' received command 0,99,99
2017-10-11 16:23:23.773 [ItemStateChangedEvent     ] - Switch_BedMaster_Main changed from ON to UNDEF
2017-10-11 16:23:29.237 [ItemStateChangedEvent     ] - zway_zwayDevice_192_168_0_222_20_switchPowerOutlet_ZWayVDev_zway_20_0_37 changed from OFF to ON
2017-10-11 16:23:29.911 [ItemStateChangedEvent     ] - hue_0210_001788234103_8_color changed from 155,85,0 to 0,98,98
2017-10-11 16:23:29.915 [ItemStateChangedEvent     ] - Hue_Bedroom changed from 0,99,99 to 0,98,98
2017-10-11 16:24:27.240 [ItemCommandEvent          ] - Item 'Scene' received command ON
2017-10-11 16:24:27.552 [ItemCommandEvent          ] - Item 'Scene' received command ON
2017-10-11 16:24:27.557 [ItemStateChangedEvent     ] - Dimmer_OnSuite changed from 100 to 99
2017-10-11 16:24:27.561 [ItemStateChangedEvent     ] - zway_zwayDevice_192_168_0_222_11_switchPowerOutlet_ZWayVDev_zway_11_0_37 changed from OFF to ON
2017-10-11 16:24:27.580 [ItemStateChangedEvent     ] - Scene changed from OFF to ON
2017-10-11 16:24:27.781 [ItemCommandEvent          ] - Item 'Switch_BedMaster_Main' received command OFF
2017-10-11 16:24:27.784 [ItemCommandEvent          ] - Item 'Switch_BedMaster_Main' received command OFF
2017-10-11 16:24:28.499 [ItemCommandEvent          ] - Item 'Switch_BedMaster_CurtLamp' received command OFF
2017-10-11 16:24:28.549 [ItemCommandEvent          ] - Item 'Switch_BedMaster_CurtLamp' received command OFF
2017-10-11 16:24:29.205 [ItemCommandEvent          ] - Item 'Switch_BedMaster_SarahLamp' received command OFF
2017-10-11 16:24:29.250 [ItemCommandEvent          ] - Item 'Switch_BedMaster_SarahLamp' received command OFF
2017-10-11 16:24:29.875 [ItemCommandEvent          ] - Item 'Dimmer_OnSuite' received command OFF
2017-10-11 16:24:29.893 [ItemCommandEvent          ] - Item 'Hue_Bedroom' received command 0,0,99
2017-10-11 16:24:29.920 [ItemCommandEvent          ] - Item 'Dimmer_OnSuite' received command OFF
2017-10-11 16:24:29.937 [ItemCommandEvent          ] - Item 'Hue_Bedroom' received command 0,0,99
2017-10-11 16:24:30.051 [ItemStateChangedEvent     ] - Dimmer_OnSuite changed from 99 to 0
2017-10-11 16:24:30.064 [ItemStateChangedEvent     ] - Hue_Bedroom changed from 0,98,98 to 0,0,99
2017-10-11 16:24:40.482 [ItemStateChangedEvent     ] - Switch_BedMaster_Main changed from UNDEF to OFF
2017-10-11 16:24:40.492 [ItemStateChangedEvent     ] - Switch_BedMaster_CurtLamp changed from ON to OFF
2017-10-11 16:24:40.498 [ItemStateChangedEvent     ] - Switch_BedMaster_SarahLamp changed from ON to OFF
2017-10-11 16:24:40.511 [ItemStateChangedEvent     ] - zway_zwayDevice_192_168_0_222_20_switchPowerOutlet_ZWayVDev_zway_20_0_37 changed from ON to OFF
2017-10-11 16:24:40.515 [ItemStateChangedEvent     ] - Switch_BedMaster_Main changed from OFF to UNDEF
2017-10-11 16:24:51.418 [ItemCommandEvent          ] - Item 'Scene' received command OFF
2017-10-11 16:24:51.439 [ItemStateChangedEvent     ] - hue_0210_001788234103_8_color changed from 0,98,98 to 0,0,98
2017-10-11 16:24:51.444 [ItemStateChangedEvent     ] - Scene changed from ON to OFF
2017-10-11 16:24:51.449 [ItemStateChangedEvent     ] - Hue_Bedroom changed from 0,0,99 to 0,0,98
2017-10-11 16:24:51.453 [ItemCommandEvent          ] - Item 'Switch_BedMaster_Main' received command ON
2017-10-11 16:24:51.530 [ItemStateChangedEvent     ] - Switch_BedMaster_Main changed from UNDEF to ON
2017-10-11 16:24:51.939 [ItemStateChangedEvent     ] - Switch_BedMaster_CurtLamp changed from OFF to ON
2017-10-11 16:24:51.975 [ItemCommandEvent          ] - Item 'Switch_BedMaster_CurtLamp' received command ON
2017-10-11 16:24:52.369 [ItemStateChangedEvent     ] - Switch_BedMaster_SarahLamp changed from OFF to ON
2017-10-11 16:24:52.427 [ItemCommandEvent          ] - Item 'Switch_BedMaster_SarahLamp' received command ON
2017-10-11 16:24:52.549 [ItemStateChangedEvent     ] - Dimmer_OnSuite changed from 0 to 100
2017-10-11 16:24:52.793 [ItemStateChangedEvent     ] - Switch_BedMaster_Main changed from ON to UNDEF
2017-10-11 16:24:52.923 [ItemCommandEvent          ] - Item 'Dimmer_OnSuite' received command ON
2017-10-11 16:24:52.936 [ItemStateChangedEvent     ] - Hue_Bedroom changed from 0,0,98 to 0,99,99
2017-10-11 16:24:52.944 [ItemCommandEvent          ] - Item 'Hue_Bedroom' received command 0,99,99
2017-10-11 16:25:40.659 [hingStatusInfoChangedEvent] - 'hue:0210:001788234103:8' changed from ONLINE to OFFLINE: Bridge reports light as not reachable
2017-10-11 16:25:40.689 [ItemStateChangedEvent     ] - zway_zwayDevice_192_168_0_222_20_switchPowerOutlet_ZWayVDev_zway_20_0_37 changed from OFF to ON
2017-10-11 16:25:40.696 [ItemStateChangedEvent     ] - hue_0210_001788234103_8_color changed from 0,0,98 to 0,98,98
2017-10-11 16:25:40.701 [ItemStateChangedEvent     ] - Hue_Bedroom changed from 0,99,99 to 0,98,98
2017-10-11 16:25:41.081 [ItemStateChangedEvent     ] - Dimmer_OnSuite changed from 100 to 99
2017-10-11 16:25:49.881 [hingStatusInfoChangedEvent] - 'hue:0210:001788234103:8' changed from OFFLINE: Bridge reports light as not reachable to ONLINE
2017-10-11 16:25:49.892 [ItemStateChangedEvent     ] - hue_0210_001788234103_8_color changed from 0,98,98 to 0,0,98
2017-10-11 16:25:49.910 [ItemStateChangedEvent     ] - Hue_Bedroom changed from 0,98,98 to 0,0,98
2017-10-11 16:25:49.915 [ItemStateChangedEvent     ] - hue_0210_001788234103_8_color_temperature changed from 0 to 27
2017-10-11 16:26:29.893 [hingStatusInfoChangedEvent] - 'hue:0210:001788234103:8' changed from ONLINE to OFFLINE: Bridge reports light as not reachable
2017-10-11 16:26:52.624 [ItemCommandEvent          ] - Item 'Scene' received command ON
2017-10-11 16:26:52.630 [ItemStateChangedEvent     ] - Scene changed from OFF to ON
2017-10-11 16:26:52.656 [ItemCommandEvent          ] - Item 'Switch_BedMaster_Main' received command OFF
2017-10-11 16:26:52.681 [ItemStateChangedEvent     ] - Switch_BedMaster_Main changed from UNDEF to OFF
2017-10-11 16:26:53.092 [ItemCommandEvent          ] - Item 'Switch_BedMaster_CurtLamp' received command OFF
2017-10-11 16:26:53.592 [ItemStateChangedEvent     ] - Switch_BedMaster_CurtLamp changed from ON to OFF
2017-10-11 16:26:53.596 [ItemStateChangedEvent     ] - Switch_BedMaster_SarahLamp changed from ON to OFF
2017-10-11 16:26:53.633 [ItemCommandEvent          ] - Item 'Switch_BedMaster_SarahLamp' received command OFF
2017-10-11 16:26:54.077 [ItemStateChangedEvent     ] - Dimmer_OnSuite changed from 99 to 0
2017-10-11 16:26:55.889 [ItemCommandEvent          ] - Item 'Dimmer_OnSuite' received command OFF
2017-10-11 16:26:55.914 [ItemCommandEvent          ] - Item 'Hue_Bedroom' received command 0,0,99
2017-10-11 16:26:59.098 [ItemStateChangedEvent     ] - Switch_BedMaster_Main changed from OFF to UNDEF
2017-10-11 16:26:59.117 [ItemStateChangedEvent     ] - Hue_Bedroom changed from 0,0,98 to 0,0,99
2017-10-11 16:27:00.933 [ItemStateChangedEvent     ] - zway_zwayDevice_192_168_0_222_20_switchPowerOutlet_ZWayVDev_zway_20_0_37 changed from ON to OFF
2017-10-11 16:27:29.049 [ItemCommandEvent          ] - Item 'Hue_Bedroom' received command 0.000000,0.000000,99.000001
2017-10-11 16:27:29.183 [hingStatusInfoChangedEvent] - 'hue:0210:001788234103:8' changed from OFFLINE: Bridge reports light as not reachable to ONLINE
2017-10-11 16:27:29.213 [ItemStateChangedEvent     ] - zway_zwayDevice_192_168_0_222_11_switchPowerOutlet_ZWayVDev_zway_11_0_37 changed from ON to OFF
2017-10-11 16:27:29.244 [ItemCommandEvent          ] - Item 'Hue_Bedroom' received command 118.477148,84.052944,99.000001
2017-10-11 16:27:29.449 [ItemStateChangedEvent     ] - Hue_Bedroom changed from 0,0,99 to 0,0,98
2017-10-11 16:27:29.477 [ItemStateChangedEvent     ] - Hue_Bedroom changed from 0,0,98 to 0.000000,0.000000,99.000001
2017-10-11 16:27:29.492 [ItemStateChangedEvent     ] - Hue_Bedroom changed from 0.000000,0.000000,99.000001 to 118.477148,84.052944,99.000001
2017-10-11 16:27:29.926 [ItemStateChangedEvent     ] - hue_0210_001788234103_8_color changed from 0,0,98 to 118,83,98
2017-10-11 16:27:29.932 [ItemStateChangedEvent     ] - Hue_Bedroom changed from 118.477148,84.052944,99.000001 to 118,83,98
2017-10-11 16:27:31.691 [ItemStateChangedEvent     ] - Hue_Bedroom changed from 118,83,98 to 118.477148,84.052944,93.993234
2017-10-11 16:27:31.695 [ItemCommandEvent          ] - Item 'Hue_Bedroom' received command 118.477148,84.052944,93.993234
2017-10-11 16:27:32.248 [ItemStateChangedEvent     ] - Hue_Bedroom changed from 118.477148,84.052944,93.993234 to 118.477148,84.052944,89.678514
2017-10-11 16:27:32.269 [ItemCommandEvent          ] - Item 'Hue_Bedroom' received command 118.477148,84.052944,89.678514
2017-10-11 16:27:32.282 [ItemCommandEvent          ] - Item 'Hue_Bedroom' received command 118.477148,84.052944,92.554993
2017-10-11 16:27:32.300 [ItemCommandEvent          ] - Item 'Hue_Bedroom' received command 118.477148,84.052944,96.785113
2017-10-11 16:27:32.302 [ItemStateChangedEvent     ] - Hue_Bedroom changed from 118.477148,84.052944,89.678514 to 118.477148,84.052944,92.554993
2017-10-11 16:27:32.315 [ItemStateChangedEvent     ] - Hue_Bedroom changed from 118.477148,84.052944,92.554993 to 118.477148,84.052944,96.785113
2017-10-11 16:27:35.546 [ItemStateChangedEvent     ] - Hue_Bedroom changed from 118.477148,84.052944,96.785113 to 118.477148,84.052944,92.385787
2017-10-11 16:27:35.565 [ItemCommandEvent          ] - Item 'Hue_Bedroom' received command 118.477148,84.052944,92.385787
2017-10-11 16:27:35.582 [ItemCommandEvent          ] - Item 'Hue_Bedroom' received command 118.477148,84.052944,93.485620
2017-10-11 16:27:35.588 [ItemStateChangedEvent     ] - Hue_Bedroom changed from 118.477148,84.052944,92.385787 to 118.477148,84.052944,93.485620
2017-10-11 16:27:35.604 [ItemStateChangedEvent     ] - Hue_Bedroom changed from 118.477148,84.052944,93.485620 to 118.477148,84.052944,95.939086
2017-10-11 16:27:35.609 [ItemCommandEvent          ] - Item 'Hue_Bedroom' received command 118.477148,84.052944,95.939086
2017-10-11 16:27:35.642 [ItemStateChangedEvent     ] - Hue_Bedroom changed from 118.477148,84.052944,95.939086 to 118.477148,84.052944,97.123521
2017-10-11 16:27:35.648 [ItemCommandEvent          ] - Item 'Hue_Bedroom' received command 118.477148,84.052944,97.123521
2017-10-11 16:27:39.895 [hingStatusInfoChangedEvent] - 'hue:0210:001788234103:8' changed from ONLINE to OFFLINE: Bridge reports light as not reachable
2017-10-11 16:27:39.914 [ItemStateChangedEvent     ] - hue_0210_001788234103_8_color changed from 118,83,98 to 118,83,97
2017-10-11 16:27:39.928 [ItemStateChangedEvent     ] - Hue_Bedroom changed from 118.477148,84.052944,97.123521 to 118,83,97
2017-10-11 16:27:40.827 [ItemStateChangedEvent     ] - Hue_Bedroom changed from 118,83,97 to 118,83,0
2017-10-11 16:27:40.849 [ItemCommandEvent          ] - Item 'Hue_Bedroom' received command OFF
2017-10-11 16:27:42.281 [ItemStateChangedEvent     ] - Hue_Bedroom changed from 118,83,0 to 118,83,100
2017-10-11 16:27:42.290 [ItemCommandEvent          ] - Item 'Hue_Bedroom' received command ON
2017-10-11 16:27:59.895 [hingStatusInfoChangedEvent] - 'hue:0210:001788234103:8' changed from OFFLINE: Bridge reports light as not reachable to ONLINE
2017-10-11 16:27:59.917 [ItemStateChangedEvent     ] - hue_0210_001788234103_8_color changed from 118,83,97 to 118,83,98
2017-10-11 16:27:59.930 [ItemStateChangedEvent     ] - Hue_Bedroom changed from 118,83,100 to 118,83,98
2017-10-11 16:28:19.924 [ItemStateChangedEvent     ] - hue_0210_001788234103_4_color changed from 199,79,0 to 199,79,53
2017-10-11 16:28:19.941 [ItemStateChangedEvent     ] - Hue_Kitchen changed from 199,79,0 to 199,79,53
2017-10-11 16:28:19.951 [ItemStateChangedEvent     ] - Hue_Microwave changed from 199,79,0 to 199,79,53
2017-10-11 16:28:19.970 [ItemStateChangedEvent     ] - hue_0210_001788234103_5_color changed from 228,100,0 to 228,100,53
2017-10-11 16:28:19.982 [ItemStateChangedEvent     ] - Hue_Kitchen changed from 199,79,53 to 228,100,53
2017-10-11 16:28:19.990 [ItemStateChangedEvent     ] - Hue_Sink changed from 228,100,0 to 228,100,53
2017-10-11 16:28:20.004 [ItemStateChangedEvent     ] - hue_0210_001788234103_6_color changed from 0,0,0 to 0,0,53
2017-10-11 16:28:20.015 [ItemStateChangedEvent     ] - Hue_Kitchen changed from 228,100,53 to 0,0,53
2017-10-11 16:28:20.020 [ItemStateChangedEvent     ] - Hue_Cocktail changed from 0,0,0 to 0,0,53
2017-10-11 16:28:20.040 [ItemStateChangedEvent     ] - hue_0210_001788234103_7_color changed from 230,93,0 to 230,93,53
2017-10-11 16:28:20.050 [ItemStateChangedEvent     ] - Hue_Sofa changed from 230,93,0 to 230,93,53
2017-10-11 16:28:20.056 [hingStatusInfoChangedEvent] - 'hue:0210:001788234103:8' changed from ONLINE to OFFLINE: Bridge reports light as not reachable
2017-10-11 16:28:25.579 [ItemStateChangedEvent     ] - NestTStat_last_connection changed from 2017-10-11T16:10:15.136+0100 to 2017-10-11T16:27:31.428+0100
2017-10-11 16:28:25.619 [ItemCommandEvent          ] - Item 'Hue_Bedroom' received command 117.999998,82.999998,98.000002
2017-10-11 16:28:25.632 [ItemStateChangedEvent     ] - Hue_Bedroom changed from 118,83,98 to 117.999998,82.999998,98.000002
2017-10-11 16:28:27.431 [ItemStateChangedEvent     ] - Hue_Bedroom changed from 117.999998,82.999998,98.000002 to 245.786802,90.863531,98.000002
2017-10-11 16:28:27.436 [ItemCommandEvent          ] - Item 'Hue_Bedroom' received command 245.786802,90.863531,98.000002
2017-10-11 16:28:29.904 [ItemStateChangedEvent     ] - hue_0210_001788234103_8_color changed from 118,83,98 to 245,90,98
2017-10-11 16:28:29.943 [ItemStateChangedEvent     ] - Hue_Bedroom changed from 245.786802,90.863531,98.000002 to 245,90,98
2017-10-11 16:28:39.901 [hingStatusInfoChangedEvent] - 'hue:0210:001788234103:8' changed from OFFLINE: Bridge reports light as not reachable to ONLINE
2017-10-11 16:28:59.913 [ItemStateChangedEvent     ] - hue_0210_001788234103_8_color changed from 245,90,98 to 0,0,98
2017-10-11 16:28:59.927 [ItemStateChangedEvent     ] - Hue_Bedroom changed from 245,90,98 to 0,0,98

openhab.log

2017-10-11 16:23:21.744 [INFO ] [pse.smarthome.model.script.Scene off] - Starting Scene OFF
2017-10-11 16:23:21.762 [INFO ] [pse.smarthome.model.script.Scene off] - Sent ON to Switch_BedMaster_Main
2017-10-11 16:23:21.769 [INFO ] [pse.smarthome.model.script.Scene off] - Sent ON to Switch_BedMaster_CurtLamp
2017-10-11 16:23:21.775 [INFO ] [pse.smarthome.model.script.Scene off] - Sent ON to Switch_BedMaster_SarahLamp
2017-10-11 16:23:21.782 [INFO ] [pse.smarthome.model.script.Scene off] - Sent ON to Dimmer_OnSuite
2017-10-11 16:23:21.790 [INFO ] [pse.smarthome.model.script.Scene off] - Sent RED to Hue_Bedroom
2017-10-11 16:23:21.879 [ERROR] [twaverf.internal.LightwaveRfWifiLink] - Error converting message: *!{"trans":57794,"mac":"20:30:18","time":1507739001,"pkt":"433T","fn":"on","room":5,"dev":1}
2017-10-11 16:23:21.894 [ERROR] [twaverf.internal.LightwaveRfWifiLink] - Error converting message: *!{"trans":57794,"mac":"20:30:18","time":1507739001,"pkt":"433T","fn":"on","room":5,"dev":1}
2017-10-11 16:23:21.911 [INFO ] [erf.internal.LightwaveRFSenderThread] - Ok message received for 200,!R5D1F1

2017-10-11 16:23:29.256 [INFO ] [thome.io.rest.core.item.ItemResource] - Received HTTP PUT request at 'items/zway_zwayDevice_192_168_0_222_14_switchMultilevel_ZWayVDev_zway_14_0_38/state' for the unknown item 'zway_zwayDevice_192_168_0_222_14_switchMultilevel_ZWayVDev_zway_14_0_38'.
2017-10-11 16:23:34.290 [WARN ] [ore.internal.events.OSGiEventManager] - Dispatching event to subscriber 'org.eclipse.smarthome.core.thing.internal.ThingManager@1e4c35d' takes more than 5000ms.
2017-10-11 16:23:36.169 [WARN ] [ore.internal.events.OSGiEventManager] - Dispatching event to subscriber 'org.eclipse.smarthome.core.thing.internal.ThingManager@1e4c35d' takes more than 5000ms.
2017-10-11 16:23:38.671 [INFO ] [thome.io.rest.core.item.ItemResource] - Received HTTP PUT request at 'items/zway_zwayDevice_192_168_0_222_11_sensorMeterW_ZWayVDev_zway_11_0_50_2/state' for the unknown item 'zway_zwayDevice_192_168_0_222_11_sensorMeterW_ZWayVDev_zway_11_0_50_2'.
2017-10-11 16:23:39.305 [WARN ] [ore.internal.events.OSGiEventManager] - Dispatching event to subscriber 'org.eclipse.smarthome.core.thing.internal.ThingManager@1e4c35d' takes more than 5000ms.
2017-10-11 16:23:39.638 [INFO ] [thome.io.rest.core.item.ItemResource] - Received HTTP PUT request at 'items/zway_zwayDevice_192_168_0_222_14_switchMultilevel_ZWayVDev_zway_14_0_38/state' for the unknown item 'zway_zwayDevice_192_168_0_222_14_switchMultilevel_ZWayVDev_zway_14_0_38'.
2017-10-11 16:23:47.686 [WARN ] [ore.internal.events.OSGiEventManager] - Dispatching event to subscriber 'org.eclipse.smarthome.core.thing.internal.ThingManager@1e4c35d' takes more than 5000ms.
2017-10-11 16:24:17.657 [INFO ] [thome.io.rest.core.item.ItemResource] - Received HTTP PUT request at 'items/zway_zwayDevice_192_168_0_222_11_sensorMeterW_ZWayVDev_zway_11_0_50_2/state' for the unknown item 'zway_zwayDevice_192_168_0_222_11_sensorMeterW_ZWayVDev_zway_11_0_50_2'.
2017-10-11 16:24:19.442 [INFO ] [thome.io.rest.core.item.ItemResource] - Received HTTP PUT request at 'items/zway_zwayDevice_192_168_0_222_11_sensorMeterW_ZWayVDev_zway_11_0_50_2/state' for the unknown item 'zway_zwayDevice_192_168_0_222_11_sensorMeterW_ZWayVDev_zway_11_0_50_2'.
2017-10-11 16:24:27.259 [INFO ] [ipse.smarthome.model.script.Scene on] - Starting Scene ON
2017-10-11 16:24:27.266 [INFO ] [ipse.smarthome.model.script.Scene on] - Sent OFF to Switch_BedMaster_Main
2017-10-11 16:24:27.273 [INFO ] [ipse.smarthome.model.script.Scene on] - Send OFF to BedMaster_CurtLamp
2017-10-11 16:24:27.280 [INFO ] [ipse.smarthome.model.script.Scene on] - Send OFF to BedMaster_CurtLamp
2017-10-11 16:24:27.286 [INFO ] [ipse.smarthome.model.script.Scene on] - Send OFF to Dimmer_OnSuite
2017-10-11 16:24:27.298 [INFO ] [ipse.smarthome.model.script.Scene on] - Send White to Hue_Bedroom
2017-10-11 16:24:27.566 [INFO ] [ipse.smarthome.model.script.Scene on] - Starting Scene ON
2017-10-11 16:24:27.576 [INFO ] [ipse.smarthome.model.script.Scene on] - Sent OFF to Switch_BedMaster_Main
2017-10-11 16:24:27.585 [INFO ] [ipse.smarthome.model.script.Scene on] - Send OFF to BedMaster_CurtLamp
2017-10-11 16:24:27.598 [INFO ] [ipse.smarthome.model.script.Scene on] - Send OFF to BedMaster_CurtLamp
2017-10-11 16:24:27.605 [INFO ] [ipse.smarthome.model.script.Scene on] - Send OFF to Dimmer_OnSuite
2017-10-11 16:24:27.613 [INFO ] [ipse.smarthome.model.script.Scene on] - Send White to Hue_Bedroom
2017-10-11 16:24:29.971 [ERROR] [twaverf.internal.LightwaveRfWifiLink] - Error converting message: *!{"trans":57795,"mac":"20:30:18","time":1507739069,"pkt":"433T","fn":"off","room":5,"dev":1}
2017-10-11 16:24:29.984 [ERROR] [twaverf.internal.LightwaveRfWifiLink] - Error converting message: *!{"trans":57795,"mac":"20:30:18","time":1507739069,"pkt":"433T","fn":"off","room":5,"dev":1}
2017-10-11 16:24:30.067 [INFO ] [erf.internal.LightwaveRFSenderThread] - Ok message received for 201,!R5D1F0

2017-10-11 16:24:32.079 [ERROR] [twaverf.internal.LightwaveRfWifiLink] - Error converting message: *!{"trans":57796,"mac":"20:30:18","time":1507739071,"pkt":"433T","fn":"off","room":5,"dev":1}
2017-10-11 16:24:32.091 [ERROR] [twaverf.internal.LightwaveRfWifiLink] - Error converting message: *!{"trans":57796,"mac":"20:30:18","time":1507739071,"pkt":"433T","fn":"off","room":5,"dev":1}
2017-10-11 16:24:32.175 [INFO ] [erf.internal.LightwaveRFSenderThread] - Ok message received for 202,!R5D1F0

2017-10-11 16:24:35.396 [WARN ] [ore.internal.events.OSGiEventManager] - Dispatching event to subscriber 'org.eclipse.smarthome.core.thing.internal.ThingManager@1e4c35d' takes more than 5000ms.
2017-10-11 16:24:36.594 [WARN ] [ore.internal.events.OSGiEventManager] - Dispatching event to subscriber 'org.eclipse.smarthome.core.thing.internal.ThingManager@1e4c35d' takes more than 5000ms.
2017-10-11 16:24:37.261 [INFO ] [thome.io.rest.core.item.ItemResource] - Received HTTP PUT request at 'items/zway_zwayDevice_192_168_0_222_14_switchMultilevel_ZWayVDev_zway_14_0_38/state' for the unknown item 'zway_zwayDevice_192_168_0_222_14_switchMultilevel_ZWayVDev_zway_14_0_38'.
2017-10-11 16:24:37.456 [INFO ] [thome.io.rest.core.item.ItemResource] - Received HTTP PUT request at 'items/zway_zwayDevice_192_168_0_222_14_switchMultilevel_ZWayVDev_zway_14_0_38/state' for the unknown item 'zway_zwayDevice_192_168_0_222_14_switchMultilevel_ZWayVDev_zway_14_0_38'.
2017-10-11 16:24:38.447 [INFO ] [thome.io.rest.core.item.ItemResource] - Received HTTP PUT request at 'items/zway_zwayDevice_192_168_0_222_11_sensorMeterW_ZWayVDev_zway_11_0_50_2/state' for the unknown item 'zway_zwayDevice_192_168_0_222_11_sensorMeterW_ZWayVDev_zway_11_0_50_2'.
2017-10-11 16:24:40.410 [WARN ] [ore.internal.events.OSGiEventManager] - Dispatching event to subscriber 'org.eclipse.smarthome.core.thing.internal.ThingManager@1e4c35d' takes more than 5000ms.
2017-10-11 16:24:45.521 [WARN ] [ore.internal.events.OSGiEventManager] - Dispatching event to subscriber 'org.eclipse.smarthome.core.thing.internal.ThingManager@1e4c35d' takes more than 5000ms.
2017-10-11 16:24:49.305 [WARN ] [ore.internal.events.OSGiEventManager] - Dispatching event to subscriber 'org.eclipse.smarthome.core.thing.internal.ThingManager@1e4c35d' takes more than 5000ms.
2017-10-11 16:24:51.315 [INFO ] [pse.smarthome.model.script.Scene off] - Starting Scene OFF
2017-10-11 16:24:51.324 [INFO ] [pse.smarthome.model.script.Scene off] - Sent ON to Switch_BedMaster_Main
2017-10-11 16:24:51.334 [INFO ] [pse.smarthome.model.script.Scene off] - Sent ON to Switch_BedMaster_CurtLamp
2017-10-11 16:24:51.344 [INFO ] [pse.smarthome.model.script.Scene off] - Sent ON to Switch_BedMaster_SarahLamp
2017-10-11 16:24:51.356 [INFO ] [pse.smarthome.model.script.Scene off] - Sent ON to Dimmer_OnSuite
2017-10-11 16:24:51.363 [INFO ] [pse.smarthome.model.script.Scene off] - Sent RED to Hue_Bedroom
2017-10-11 16:24:51.544 [ERROR] [twaverf.internal.LightwaveRfWifiLink] - Error converting message: *!{"trans":57797,"mac":"20:30:18","time":1507739090,"pkt":"433T","fn":"on","room":5,"dev":1}
2017-10-11 16:24:51.563 [ERROR] [twaverf.internal.LightwaveRfWifiLink] - Error converting message: *!{"trans":57797,"mac":"20:30:18","time":1507739090,"pkt":"433T","fn":"on","room":5,"dev":1}
2017-10-11 16:24:51.640 [INFO ] [erf.internal.LightwaveRFSenderThread] - Ok message received for 203,!R5D1F1

2017-10-11 16:25:01.323 [WARN ] [ore.internal.events.OSGiEventManager] - Dispatching event to subscriber 'org.eclipse.smarthome.core.thing.internal.ThingManager@1e4c35d' takes more than 5000ms.
2017-10-11 16:25:04.443 [WARN ] [ore.internal.events.OSGiEventManager] - Dispatching event to subscriber 'org.eclipse.smarthome.core.thing.internal.ThingManager@1e4c35d' takes more than 5000ms.
2017-10-11 16:25:04.506 [INFO ] [thome.io.rest.core.item.ItemResource] - Received HTTP PUT request at 'items/zway_zwayDevice_192_168_0_222_14_switchMultilevel_ZWayVDev_zway_14_0_38/state' for the unknown item 'zway_zwayDevice_192_168_0_222_14_switchMultilevel_ZWayVDev_zway_14_0_38'.
2017-10-11 16:25:04.583 [INFO ] [thome.io.rest.core.item.ItemResource] - Received HTTP PUT request at 'items/zway_zwayDevice_192_168_0_222_14_switchMultilevel_ZWayVDev_zway_14_0_38/state' for the unknown item 'zway_zwayDevice_192_168_0_222_14_switchMultilevel_ZWayVDev_zway_14_0_38'.
2017-10-11 16:25:06.338 [WARN ] [ore.internal.events.OSGiEventManager] - Dispatching event to subscriber 'org.eclipse.smarthome.core.thing.internal.ThingManager@1e4c35d' takes more than 5000ms.
2017-10-11 16:25:15.696 [WARN ] [ore.internal.events.OSGiEventManager] - Dispatching event to subscriber 'org.eclipse.smarthome.core.thing.internal.ThingManager@1e4c35d' takes more than 5000ms.
2017-10-11 16:26:28.278 [INFO ] [thome.io.rest.core.item.ItemResource] - Received HTTP PUT request at 'items/zway_zwayDevice_192_168_0_222_11_sensorMeterW_ZWayVDev_zway_11_0_50_2/state' for the unknown item 'zway_zwayDevice_192_168_0_222_11_sensorMeterW_ZWayVDev_zway_11_0_50_2'.
2017-10-11 16:26:52.641 [INFO ] [ipse.smarthome.model.script.Scene on] - Starting Scene ON
2017-10-11 16:26:52.652 [INFO ] [ipse.smarthome.model.script.Scene on] - Sent OFF to Switch_BedMaster_Main
2017-10-11 16:26:52.662 [INFO ] [ipse.smarthome.model.script.Scene on] - Send OFF to BedMaster_CurtLamp
2017-10-11 16:26:52.673 [INFO ] [ipse.smarthome.model.script.Scene on] - Send OFF to BedMaster_CurtLamp
2017-10-11 16:26:52.695 [ERROR] [twaverf.internal.LightwaveRfWifiLink] - Error converting message: *!{"trans":57798,"mac":"20:30:18","time":1507739211,"pkt":"433T","fn":"off","room":5,"dev":1}
2017-10-11 16:26:52.699 [INFO ] [ipse.smarthome.model.script.Scene on] - Send OFF to Dimmer_OnSuite
2017-10-11 16:26:52.719 [ERROR] [twaverf.internal.LightwaveRfWifiLink] - Error converting message: *!{"trans":57798,"mac":"20:30:18","time":1507739211,"pkt":"433T","fn":"off","room":5,"dev":1}
2017-10-11 16:26:52.724 [INFO ] [ipse.smarthome.model.script.Scene on] - Send White to Hue_Bedroom
2017-10-11 16:26:52.790 [INFO ] [erf.internal.LightwaveRFSenderThread] - Ok message received for 204,!R5D1F0

2017-10-11 16:26:59.090 [WARN ] [ore.internal.events.OSGiEventManager] - Dispatching event to subscriber 'org.eclipse.smarthome.core.thing.internal.ThingManager@1e4c35d' takes more than 5000ms.
2017-10-11 16:27:00.926 [WARN ] [ore.internal.events.OSGiEventManager] - Dispatching event to subscriber 'org.eclipse.smarthome.core.thing.internal.ThingManager@1e4c35d' takes more than 5000ms.
2017-10-11 16:27:04.281 [INFO ] [thome.io.rest.core.item.ItemResource] - Received HTTP PUT request at 'items/zway_zwayDevice_192_168_0_222_14_switchMultilevel_ZWayVDev_zway_14_0_38/state' for the unknown item 'zway_zwayDevice_192_168_0_222_14_switchMultilevel_ZWayVDev_zway_14_0_38'.
2017-10-11 16:27:04.321 [INFO ] [thome.io.rest.core.item.ItemResource] - Received HTTP PUT request at 'items/zway_zwayDevice_192_168_0_222_14_switchMultilevel_ZWayVDev_zway_14_0_38/state' for the unknown item 'zway_zwayDevice_192_168_0_222_14_switchMultilevel_ZWayVDev_zway_14_0_38'.
2017-10-11 16:27:07.033 [WARN ] [ore.internal.events.OSGiEventManager] - Dispatching event to subscriber 'org.eclipse.smarthome.core.thing.internal.ThingManager@1e4c35d' takes more than 5000ms.
2017-10-11 16:27:09.152 [WARN ] [ore.internal.events.OSGiEventManager] - Dispatching event to subscriber 'org.eclipse.smarthome.core.thing.internal.ThingManager@1e4c35d' takes more than 5000ms.
2017-10-11 16:27:11.884 [WARN ] [ui.internal.items.ItemUIRegistryImpl] - Cannot retrieve color item NestSmoke_state for widget
2017-10-11 16:27:11.888 [WARN ] [ui.internal.items.ItemUIRegistryImpl] - Cannot retrieve color item NestSmoke_state for widget
2017-10-11 16:27:21.033 [WARN ] [ore.internal.events.OSGiEventManager] - Dispatching event to subscriber 'org.eclipse.smarthome.core.thing.internal.ThingManager@1e4c35d' takes more than 5000ms.
2017-10-11 16:27:42.332 [WARN ] [ui.internal.items.ItemUIRegistryImpl] - Cannot retrieve color item NestSmoke_state for widget
2017-10-11 16:27:42.337 [WARN ] [ui.internal.items.ItemUIRegistryImpl] - Cannot retrieve color item NestSmoke_state for widget
2017-10-11 16:27:59.774 [INFO ] [thome.io.rest.core.item.ItemResource] - Received HTTP PUT request at 'items/zway_zwayDevice_192_168_0_222_19_sensorMultilevel_ZWayVDev_zway_19_0_50_0/state' for the unknown item 'zway_zwayDevice_192_168_0_222_19_sensorMultilevel_ZWayVDev_zway_19_0_50_0'.

My hue light was giving me some issues this time but it does that sometimes. I can always control using the Philips Hue app but sometimes its struggles through OH. I think I need more bulbs to make a better connection. Hopefully this is not what is causing the delay. I cannot pin the issue down as each time I toggle my scene something different happens.

rlkoshak · October 11, 2017, 4:14pm

Typo. It should be lightCmd for all of them.

See the Groups section of the Items Config docs.

In English the line means:

Group Define a Group which is a special type of Item that contains other Items as members
Switch The Item type of the Group is Switch so you can treat the Group as if it were a SwitchItem (e.g. gScene1.sendCommand(ON))
OR(ON,OFF) This is the function used to calculate the state of gScene1 based on the states of all of its member Items. It basically means "If any one of the members of the Group are ON, gScene1’s state will be ON. If all members are OFF then the state gScene1 will be OFF.

It is possible to put gScene1 on your sitemap as a Switch and turn ON or OFF all the members of the Group and see if any member of the Group is ON.

OK, looking at events.log it does appear to be taking longer than I would expect for the Items to receive their commands. What RPi are you running on? If it is a RPi 1 or RPi Zero than the problem may be your host is not powerful enough.

The LightwaveRF error gives me pause but is probably unrelated to these Items since they are all zwave and Hue, correct?

The ThingManager warnings I’m sure are related to the problem and again could be caused by an underpowered host. Though that is not a guarantee.

I see you are using the ZWay binding. Is the network connection between the ZWay server and OH pretty solid? I don’t want to assume they are on the same host since they don’t have to be.

The Rule is running exactly like I would expect so there are no problems there.

At this point all I can surmise is that either the connections between OH and the ZWay server and/or Hue Hub is flakey, you are running on an underpowered RPi (you should be running on at least a RPi 2), or there is something messed up with the Things.

If you are sure of your network and are running on at least a RPi 2 then the first thing I would do is eliminate the lightwave error.

Then let’s see if those warnings have something to do with your missing zway_zwayDevice_192_168_0_222_1* Items. Something is trying to update these Items through the REST API (ZWay server?) and those Items do not exist.

Curtis · October 11, 2017, 4:50pm

I’m using a Pi3. Fully updated also with the latest RaZberry/ZWay software

Just done a test using htop and I’m only using 300mb ram and once my rule is toggled the CPU goes from 7 - 25% briefly.

Switch_BedMaster_Main is controlled using lightwaveRF. However this is the most responsive item in my group. it switches on and off instantly. Then 3 z-wave and 1 hue item.

Yes my network is wired and solid. ZWay & OpenHab run on the same Pi

OK I will remove the Lightwave item from my rule and test.

I had an idea, something strange keeps happening inside ZWay with the openHAB connector App that’s used to connect to OpenHab. I keep getting loads of errors from devices that have not existed for quite some time.

17:06 | "Observer not notified - openHAB item: zway_zwayDevice_192_168_0_222_3_sensorEnergy_ZWayVDev_zway_3_1_49_4 (HTTP Status: 404 - Not Found - Item zway_zwayDevice_192_168_0_222_3_sensorEnergy_ZWayVDev_zway_3_1_49_4 does not exist!). Failed request: http://localhost:8080/rest/items/zway_zwayDevice_192_168_0_222_3_sensorEnergy_ZWayVDev_zway_3_1_49_4/state with body: 0"

I’ve just remove all openHAB observers from the table (located in link below). It was full of errors from items that don’t exist http://192.168.0.222:8083/smarthome/#/elements

And for now at least my rule seams to work loads better! Don’t want to celebrate yet though as it can be hit and miss.

rlkoshak · October 11, 2017, 4:52pm

Plenty powerful enough. That isn’t your problem.

Glad to hear that seemed to improve things. Hope it solves your problem.

Curtis · October 11, 2017, 4:54pm

Thanks very much, I’ve learn’t a lot with your help!