[SOLVED] Rule doesn't trigger on change randomly?

Setup, Configuration and Use Scripts & Rules
1
  • Platform information:
    • Hardware: x86/2G ram /16GB ssd
    • OS: Lubuntu Xenial
    • Java Runtime Environment: openjdk 1.8
    • openHAB version: 2.3.0

Some times I find my rules don’t trigger when they should be.

I have a group for presence detection SA_gPresence with multiple items in it.

I also have 3 different rules for this item

rule "No presence detected"
when 
    Item SA_gPresence changed from ON to OFF
then
    logInfo("SA", "global presence changed to OFF, ie no someone home")
end

rule "Presence detected"
when 
    Item SA_gPresence changed from OFF to ON
then
    logInfo("SA", "global presence changed to ON, ie someone home ")
end

rule "debug status printout"
when
    Item SA_downstairs_occupancy        changed 
    or Item SA_girls_occupancy          changed 
    or Item SA_boys_occupancy           changed 
    or Item SA_parents_occupancy     changed
    or Item SA_gPresence                changed
then
        logInfo("SA", String::format("pres(%-3s)="
                + "Sen[D(%-3s)/P(%-3s)/G(%-3s)/B(%-3s)]"
                SA_gPresence.state, SA_downstairs_occupancy.state,SA_parents_occupancy.state,SA_girls_occupancy.state,SA_boys_occupancy.state))
end

Some times this works as is, but sometimes it only fires the debug print one and not the others.

Am I doing something wrong?

I did check the event log and that does report the change, but the output log only has the debug print out and not the Presence detection.

2018-06-08 10:57:06.966 [INFO ] [rg.eclipse.smarthome.model.script.SA] - pres(OFF)=Sen[D(OFF)/P(OFF)/G(OFF)/B(OFF)]
2018-06-08 10:57:06.972 [INFO ] [rg.eclipse.smarthome.model.script.SA] - global presence changed to OFF, ie no someone home
2018-06-08 18:13:15.398 [INFO ] [rg.eclipse.smarthome.model.script.SA] - pres(ON )=Sen[D(ON )/P(OFF)/G(OFF)/B(OFF)]
2018-06-08 18:13:15.402 [INFO ] [rg.eclipse.smarthome.model.script.SA] - pres(ON )=Sen[D(ON )/P(OFF)/G(OFF)/B(OFF)]
2018-06-08 18:16:15.828 [INFO ] [rg.eclipse.smarthome.model.script.SA] - pres(ON )=Sen[D(ON )/P(OFF)/G(ON )/B(OFF)]
2018-06-08 18:16:15.920 [INFO ] [rg.eclipse.smarthome.model.script.SA] - pres(ON )=Sen[D(ON )/P(ON )/G(ON )/B(OFF)]
2 
rule "Presence changed"
when 
    Item SA_gPresence changed
then
    if (previousState == NULL) return;
    var String presenceString = "global presence changed to " + gPresence.state.toString
    if (gPresence.state == ON) presenceString = presenceString + ", ie someone home"
    else  presenceString = presenceString + ", ie no one home"
    logInfo("SA", presenceString)
end

rule "debug status printout"
when
    Item SA_downstairs_occupancy        changed 
    or Item SA_girls_occupancy          changed 
    or Item SA_boys_occupancy           changed 
    or Item SA_parents_occupancy        changed
    or Item SA_gPresence                changed
then
    logInfo("SA", String::format("pres(%$1s)=Sen[D(%$2s)/P(%$3s)/G(%$4s)/B(%$5s)]"
        SA_gPresence.state, SA_downstairs_occupancy.state,SA_parents_occupancy.state,SA_girls_occupancy.state,SA_boys_occupancy.state))
end
3

Thanks I’ll try this out and see if it happens again.

But is there any reason you know why my implementation would have failed?

I’d like to know what I did wrong to ensure all my other rules work.

I’m assuming because I explicitly had the two rules trigger on a from - to that I wouldn’t need to account for null.

4

Your rules triggered, your logInfo was incorrect.

5

I’m still struggling to understand what was failing originally.

When I read the log it shows at 10:57 that presence was changed to OFF and “debug status printout” rule was triggered, then just after that the “No presence detected” triggered.

Then a few hours later at 18:13 only the “debug status printout” triggered and printed debug status.

I thought according to my rules “Presence detected” should have also been triggered since according to the debug printout pres(OFF) changed to pres(ON)

6

So its still happening

Usually all the rules trigger and all of this works fine, but intermittently one does not.

In the log, after the following output I should see a line with "enter global presence changed" but I do not.

2018-07-16 09:54:57.312 [INFO ] [rg.eclipse.smarthome.model.script.SA] - pres(ON )=Sen[D(ON )/P(OFF)/G(OFF)/B(OFF)]
2018-07-16 09:57:57.831 [INFO ] [rg.eclipse.smarthome.model.script.SA] - pres(OFF)=Sen[D(OFF)/P(OFF)/G(OFF)/B(OFF)]
2018-07-16 09:57:57.845 [INFO ] [rg.eclipse.smarthome.model.script.SA] - pres(OFF)=Sen[D(OFF)/P(OFF)/G(OFF)/B(OFF)]

However in the events log I do see the following, so definitely my rule should have triggered:

2018-07-16 09:57:57.865 [GroupItemStateChangedEvent] - SA_gPresence changed from ON to OFF through SA_downstairs_occupancy

Can anyone answer why didn’t my rule trigger?

My Rules

rule "debug status printout"
when
    Item SA_downstairs_occupancy        changed 
    or Item SA_girls_occupancy          changed 
    or Item SA_boys_occupancy           changed 
    or Item SA_parents_occupancy        changed
    or Item SA_gPresence                changed
then
    logInfo("SA", String::format("pres(%$1s)=Sen[D(%$2s)/P(%$3s)/G(%$4s)/B(%$5s)]"
        SA_gPresence.state, SA_downstairs_occupancy.state,SA_parents_occupancy.state,SA_girls_occupancy.state,SA_boys_occupancy.state))
end

rule "Presence detected"
when 
    Item SA_gPresence changed
then
    logInfo("SA", "enter global presence changed")
    if (previousState == null)
    {
        logInfo("SA", "global presence was null, skip presence detection")
        return;
    }
    ...
end
7

My suggestion is to also try not to use changed from OFF to ON, and just use this:
Item SA_gPresence changed to ON

Specifying the from along with the to is a double constraint, but for binary switch (just two states) all you really care about is when the state is changed to something.

8

Does rule "Presence detected" triggers sometimes and sometimes not or does it never triggers?

If the first rule triggers when SA_gPresence changes then the second one should too.
The first rule has 5 triggers and the second one only one. What makes you think that SA_gPresence triggered the first rule in your log?

Change the first rule to this temporarily:

rule "debug status printout"
when
    Item SA_downstairs_occupancy        changed 
    or Item SA_girls_occupancy          changed 
    or Item SA_boys_occupancy           changed 
    or Item SA_parents_occupancy        changed
    or Item SA_gPresence                changed
then
    logInfo("SA", triggeringItem.name.toString)
    logInfo("SA", String::format("pres(%$1s)=Sen[D(%$2s)/P(%$3s)/G(%$4s)/B(%$5s)]"
        SA_gPresence.state, SA_downstairs_occupancy.state,SA_parents_occupancy.state,SA_girls_occupancy.state,SA_boys_occupancy.state))
end

To see which item triggered the rule

9

Since the original post i have switch to eliminating all constraints on the rule, the same issue occurs.

10

@vzorglub

All the rules as written work most of the time, however sometime it does not.

In the output there are two lines that are exactly the same (except the miliseconds), this is expected since the rule will be triggered twice when the very last item in the group changes.
This is because it will trigger once when the item in the group changes to OFF, then a second trigger when the group changes to OFF since all its children are OFF.

However, the group changing should also trigger the second rule and print “enter global presence changed” and it does not.

11

You didn’t post the items so I didn’t know which item belonged to which group.
If you trigger the group only through the rest api what happens?

12

Sorry about that

All the *_occupancy items are under the group SA_gPresence

I’m not home at the moment, I’ll see if i can test through the API

13

I don’t know whats going on
I tried the rest API and changed the state of SA_gPresence and only the “debug status printout” was printing

Then I commented out SA_gPresence from that rule, saved it and updated the state again and this time it printed from the rule “Presence detected”.

So undid my change, saved it and updated the state again and this time it printed out from both rules!

I’m guessing that the the rules as i have written them are fine, its just after some time OH gets into a state where it wont trigger both rules anymore until OH is reset or refreshed.

I’m thinking I need to open a bug for this

14

Ehmm, just a wild guess: Are your items and the group defined in two different files? I did have the case that when I did this, the group claimed to get updates in the log as it should, but any rule trigger that should have fired happily ignored it. Restarting oh solved the issue, but some (not all) edits in the item definition files could bring it back.

15

Hmm, looks like all in one file.
Although I have multiple files with item definitions, all the the items that are in the group SA_gPresence are defined in the same file as the group itself.

But I’ll keep that in mind though thanks

16

Another thought is to use Zulu instead of openjdk 1.8. If you have not tried it yet, stop OpenHAB, uninstall openjdk, and install Zulu.

Installation Prerequisites say “Zulu is currently the recommended Java platform for openHAB.”.

17

Unfortunately Zulu isn’t available for x86 32bit.

18

I tried to simplify this and remove one of the rules and I still have the same problem.

I removed the debug printing rule from printing when the group changes so there is only one rule in question now.

Again this rules seems to work for a day or two then stops working at all.
Note, my assumption is regardless of anything else in the rule I should have the first log line print on any change to SA_gPresence, and it is not.

In my events log I get

2018-08-02 12:53:17.418 [GroupItemStateChangedEvent] - SA_gPresence changed from ON to OFF through SA_parents_occupancy

But I don’t get “enter global presence changed” in my log (once this issue rears its head)

Now I only the following rule where SA_gPresence is a group with several switch items in it

rule "Presence detected"
when 
    Item SA_gPresence changed
then
    logInfo("SA", "enter global presence changed")
    if (previousState == null)
    {
        logInfo("SA", "global presence was null, skip presence detection")
        return;
    }
    
    logInfo("SA", "global presence changed to " + SA_gPresence.state.toString)
    if (SA_delaySmartAwayTimer !== null)
    {
        logInfo("SA", "\tcancelling SA_delaySmartAwayTimer")
    
        SA_delaySmartAwayTimer.cancel()
        SA_delaySmartAwayTimer = null
    }
    if (SA_gPresence.state == ON)
    {
        if (firstEvent_climate.state == SA_SmartAwayClimateRef)
        {
            logInfo("SA", "\tWe were in our smart away climate")
            if (SI_DEBUG.state == OFF)
            {
                sendMail("myfake@email.com", "SmartAway", "Someone home, resuming schedule")
                logInfo("SA", "\tcalling ecobeeResumeProgram(" + ecobeeID +", true)")
                ecobeeResumeProgram(ecobeeID, true)
            }
        }
    }
    else if (SA_gPresence.state == OFF)
    {
        SA_delaySmartAwayTimer = createTimer(now.plusMinutes(SA_dismissMinuets), [|

                logInfo("SA", "Timer up, no occupancy for X min")
                if (SI_DEBUG.state == OFF)
                {
                    sendMail("myfake@email.com", "SmartAway", "No one home for 60 min, Holding on smart away climate")
                    logInfo("SA", "\tcalling ecobeeSetHold("+ecobeeID+", null, null, " + SA_SmartAwayClimateRef + ", null, null, 'holdHours', " + SA_holdHours +")") 
                    ecobeeSetHold(ecobeeID, null, null, SA_SmartAwayClimateRef, null, null, 'holdHours', SA_holdHours) 
                }
                SA_delaySmartAwayTimer = null
            ])
    }
end

Can anyone see why this rule would just stop working over time? is my timer causing the function to get stuck or something?

19

Are you running the rule with SI_DEBUG off? If so, it is possibly the sendMail or ecobee actions that are hanging the rule. I would put a log at the end and check the log the next time it hangs to see if you ever got the last completion log. This would prove that it is this rule that is hanging. What is SA_dismissMinuets set for, and is that a typo in your post or rule? In your ecobee log entry and action, are you using items for ecobeeID, SA_SmartAwayClimateRef, etc.? If so, it looks like you are missing the .state.

Also, previousState may be NULL (an UnDefType), but it will never be null (undefined). And please post your item definitions.

20

Thanks for the replay @5iver

  1. Yes SI_DEBUG is off
  2. I added some exit logging to determine where it fails. Hopefully I can figure it out now.
  3. Those are val or var defined in the rules file, sorry i never included those in the post
  4. When I tried to use NULL instead of null i got Cannot reference the field 'NULL' before it is defined