Rule Occasionally Misfires

Setup, Configuration and Use Scripts & Rules
1

Hi All,

Need help with a rule. The rule below dictates the state of the house. Problem is that occasionally when I press the ‘Wake Up’ command openhab sends the ‘Go to Bed’ command. This has happened using the mobile app and Habpanel. The strange thing is that this rule works 90% of the time. The problem only happens once every 2-3 weeks. Not a big deal except when it happens to people other than myself.

You can see in the events.log file that the scene received the command 3 (wakeup), but in the openhab.log file we see the log info showing that the the number 2 (gotobed) was triggered. A few minutes later I pressed the wakeup command again and it went through normally.

Does anyone have any idea on why this misfires?

Thanks

Using:
openhab 2.3 on Raspberry Pi 3
java: Zulu Embedded 8.25.0.76

Items

Number	Scene_TV	"State: [MAP(scenes.map):%s]" <sofa>

Sitemap

Frame label="Activity" {
		Switch item=Scene_TV label="." mappings=[1="TV", 2="Bed", 3="WakeUp"]
		}

From events.log

2018-08-02 05:47:29.489 [ome.event.ItemCommandEvent] - Item 'Scene_TV' received command 3
2018-08-02 05:47:29.543 [vent.ItemStateChangedEvent] - Scene_TV changed from 2 to 3
2018-08-02 05:50:25.987 [ome.event.ItemCommandEvent] - Item 'Scene_TV' received command 3

From openhab.log

2018-08-02 05:47:29.532 [INFO ] [.smarthome.model.script.Going to bed] - Have a good night
2018-08-02 05:47:29.542 [INFO ] [.smarthome.model.script.Stars are on] - Turning on Stars
2018-08-02 05:50:26.018 [INFO ] [model.script.Scene_TV set to wake up] - Rise and shine!

Rule

rule "House Scene Activity"
when Item Scene_TV received command
then
var Timer bedTimer = null
var Timer morningTimer = null
switch Scene_TV
{
	case Scene_TV.state==1 : //watching tv
	{
		logInfo("Setting house scene to tv", "We're watching tv")
		sendCommand(LR_Lamp_Color, "0,0,10")
		sendCommand(Stairs1_Dimmer, 25)
		sendCommand(Kitchen_Lightstrip_Counter_Color, "253,100,50")
		sendCommand(Kitchen_Lightstrip_Top_Color, "123,100,50")
		sendCommand(Kitchen_Sink_Color, "253,100,50")
		
		if (TV_Lightstrip.state!=ON)
		{
			logInfo("turning on tv light", "turning on tv light")
			sendCommand(TV_Lightstrip, ON)
		}
		gWatchTV.members.forEach(s | if (s.state == ON) { 
		gWatchTV.sendCommand(OFF) })
		Harmony_Current_Activity.sendCommand("Xbox")
	}
	
	case Scene_TV.state==2 : //going to bed
	{
		logInfo("Going to bed", "Have a good night")
		Harmony_Current_Activity.sendCommand("PowerOff")
		sendCommand(LR_Lamp_Color, "0,0,100")
		Entryway.sendCommand(ON)
		Stairs1_Dimmer.sendCommand(30)
		Thermo_HeatSetPoint.sendCommand(60)		
		bedTimer = createTimer(now.plusMinutes(5))[|
		gBed.members.forEach(s | if (s.state==ON) {
			s.sendCommand(OFF)
			})
			]
	
	}
	case Scene_TV.state==3 : //wakeup
	{
		logInfo("Scene_TV set to wake up", "Rise and shine!")		
		sendCommand(LR_Lamp_Color, "0,0,100")
	 	gWakeup.members.forEach(s | if (s.state==OFF)
			{
				s.sendCommand(ON)
			}
		)
		gSKitchen.members.forEach(i | if (i.state==ON) {
			i.sendCommand(OFF)
			})
		Scene_Kitchen.postUpdate(3)
		Harmony_Current_Activity.sendCommand("TV")
		morningTimer = createTimer(now.plusMinutes(5))[|
		Down_Bath.sendCommand(OFF)
		]
		
	}
}
end
2 
rule "House Scene Activity"
    when Item Scene_TV changed
then
    Thread::sleep(x)
    ...

test what is the necessary time on you system.

1 Like
3

Is it this issue? Mysterious delay in items being updated

If so, you can fix it with a Thread::sleep(500) at the start of the rule

1 Like
4

I will. Thanks.

5

This issue occurs because you are checking the state of Scene_TV BEFORE it has actually updated after receiving a command. It can take a few milliseconds and by that time your rule is already running.

Change the case statements with the implicit variable receivedCommand should get rid of the problem without resorting to Thread::sleep which should be avoided if possible:

rule "House Scene Activity"
when Item Scene_TV received command
then
var Timer bedTimer = null
var Timer morningTimer = null
var sceneNumber = receivedCommand as Number
switch Scene_TV
{
	case sceneNumber==1 : //watching tv
	{
		logInfo("Setting house scene to tv", "We're watching tv")
		sendCommand(LR_Lamp_Color, "0,0,10")
		sendCommand(Stairs1_Dimmer, 25)
		sendCommand(Kitchen_Lightstrip_Counter_Color, "253,100,50")
		sendCommand(Kitchen_Lightstrip_Top_Color, "123,100,50")
		sendCommand(Kitchen_Sink_Color, "253,100,50")
		
		if (TV_Lightstrip.state!=ON)
		{
			logInfo("turning on tv light", "turning on tv light")
			sendCommand(TV_Lightstrip, ON)
		}
		gWatchTV.members.forEach(s | if (s.state == ON) { 
		gWatchTV.sendCommand(OFF) })
		Harmony_Current_Activity.sendCommand("Xbox")
	}
	
	case sceneNumber==2 : //going to bed
	{
		logInfo("Going to bed", "Have a good night")
		Harmony_Current_Activity.sendCommand("PowerOff")
		sendCommand(LR_Lamp_Color, "0,0,100")
		Entryway.sendCommand(ON)
		Stairs1_Dimmer.sendCommand(30)
		Thermo_HeatSetPoint.sendCommand(60)		
		bedTimer = createTimer(now.plusMinutes(5))[|
		gBed.members.forEach(s | if (s.state==ON) {
			s.sendCommand(OFF)
			})
			]
	
	}
	case sceneNumber==3 : //wakeup
	{
		logInfo("Scene_TV set to wake up", "Rise and shine!")		
		sendCommand(LR_Lamp_Color, "0,0,100")
	 	gWakeup.members.forEach(s | if (s.state==OFF)
			{
				s.sendCommand(ON)
			}
		)
		gSKitchen.members.forEach(i | if (i.state==ON) {
			i.sendCommand(OFF)
			})
		Scene_Kitchen.postUpdate(3)
		Harmony_Current_Activity.sendCommand("TV")
		morningTimer = createTimer(now.plusMinutes(5))[|
		Down_Bath.sendCommand(OFF)
		]
		
	}
}
end
3 Likes
6

I will give this a try. Thanks for your help.

7

Didn’t know that - thank you

8

@vzorglub, I got a question here, should it not be:

switch sceneNumber  // instead of Scene_TV
{
	case 1 : //watching tv
...
	case 2 : //going to bed
// ... and so on ...

since you said that Scene_TV might take some time to update?

9

Yes, you are right
I replied too quickly.
The important bit is the delay between the command received and item being updated. Did you understant that and does it make sense.
It’s important because it can cause unpredictable behaviour (As in your case) and therefore you need to choose carefully what trigger to choose to use for your rules and learn about the implicit variables:

1 Like
10

Thanks @vzorglub for the clarification! I think I do understand; I see the “implicit” as a the “variable” that is passed on to the rule being called (and then start executing), while in a parallel process (asynchronous to the rule execution) the item is updated. Since this is asynchronous, the item update can “fall behind” and the two therefore won’t be identical at the time when the check happens within the rule execution…

1 Like