Rule fail to run after Item-State trigger

Hi, I have been running openhab:2.5.1-amd64-debian as a docker on my QNAP NAS for a long time with no issues whatsoever. I have many rules defined with delicate relationship and lots of checks and logs to make sure everything works as I want it. All of my rules are manually defined on individual files under DSL language and some rule files (but not all) might have 2-3 rules defined in them at the most.

I held myself off from upgrading for the last year or so, mainly because i didn’t have the time to make sure all of the rules were imported correctly and that they work as intended. Note that by the nature of running under a docker, I can just simply create a new docker with the desired version and still be able to run the my “stable” version 2.5.1!

So, I decided to finally cut the cord the migrate to the newest version, openhab:3.0.2-debian (still as a docker). As recommended, during the upgrade I changed some of my rules to use Zonetime (instead of Joda time) as well as updating the implicit variable “triggeringItemName” per the guidelines. IT was a breeze. After all of that, VS Code checks all rules, all good… the files are loaded into openhab and no complains on the logs!.

What I started noticing is that some of the rules were not running when certain triggers happened. To be more specific, I was able to determine that whenever an Item changes state (due to another rule, via BasicUI or via the Binding Sync) if there is a rule that was dependent on such item triggering, the rule did not start. I even placed a logging command at the very first line fo the rule to make sure it was not my rule logic that was flushing the rule… but my logs were clean. Simply the rule did not run.

However, whenever a channel change was sent, or a cron trigger was defined or even when the system started… all of those triggers were recognized by my rules and ran perfectly fine… it was only when and item state is changed.

As part of my debugging I tried updating the rule and see if i was doing anything wrong… and noticed that if I updated the rule file, say by added an empty line at the end of the rule, save it and let openhab reload it… then guess what? the rule started working!!! … at first I though, well maybe there is a format issue with my file and it got fixed now… but upon a docker re-start… the same behavior will occur and the rules will not trigger.

I did do a lot of searches in the forum and found a few threads were rules were not triggered correctly, but nothing related to OH 3.x and in the same way that i am experiencing… these thread seems to be similar, but I don’t think is the same:

and here:

Below are a few simple examples (real rule on my system) that are not working. The first is a simple rule that executes after a timer has expired. The timer is controlled via the EXPIRE binding and I can see in the logs when the timer turns off… but the rule fails to run.

rule "Master Bathroom 20M: When timer expires, Turn Off Fan/Heater"
when
    Item Master_Bathroom_Timer_20M changed from ON to OFF 
then    
    logInfo("TEST","THE TIMER RULE DID RUN.")
    var rule_name = "MyRules.Bathroom.20MTimer"
    if( Master_Bathroom_Heater.state == ON ) {
        Master_Bathroom_Heater.sendCommand(OFF)
        logInfo(rule_name, "Timer is up! Turning Master Bathroom Heater OFF")
    }
    if( Master_Bathroom_Fan.state == ON ) { 
        Master_Bathroom_Fan.sendCommand(OFF)
        logInfo(rule_name, "Timer is up! Turning Master Bathroom Fan OFF")
    }
end

Another examples is using the ASTRO binding to execute a rule when the Sun Phase changes:

rule "Define when Sun is up or down"
when
    Item Sun_Phase changed or 
    System started
then                                                                                                                            // Simple rule, no need for 1-2-3 approach nor logging
    logInfo("TEST","THE SUN UP RULE DID RUN.")
    switch Sun_Phase.state {
        case "CIVIL_DUSK", case "NAUTIC_DUSK", case "ASTRO_DUSK", case "CIVIL_DAWN", 
        case "NAUTIC_DAWN", case "ASTRO_DAWN", case "NIGHT": {
            if( Sundown.state != ON )    { Sundown.sendCommand(ON) }
        }
        case "SUN_RISE", case "DAYLIGHT", case "SUN_SET": {
            if( Sundown.state != OFF )   { Sundown.sendCommand(OFF) }
        }
        default: { }
    }
end

In both instances the item is getting changed (I see it in the logs) but the rule fails to run. As I said above, if I modify the file, say add an empty line… it loads and it is recognized and it works as intended, but upon restart the same behavior occurs.

At this point I have reverted back to version 2.5.1 (one of the benefit of running under a docker) with everything working as intended… and I have stopped the 3.0.1 instance. I am not sure if the issue is with my rules or something on the docker install or something else… I will like to get to the bottom of this, and fix it… so any help or ideas are greatly appreciated.

Thanks.

1 Like

Does this issue fit? (I.e. are you editing Items)

Interesting… I never tried to see what happens to the rule if I modify the items files (which i have manually created for all of my bindings)… mainly because i was focused on updating the rules to work with OH3.

I will fire up my OH3 docker and run a few tests to see if i get the same behavior… but what is interesting is that we are both using Docker under Qnap.

Also, i did not do a count of how many rules i have vs what OH3 reports (on the new UI) but will do so.

I will report back (it might take a day or two between work and family life :sweat_smile: )

Ok, ran some tests and I can definitely say that I see the same exact issue when changing items. Here is a run down of what I was able to see:

  • Upon system start, the UI rule tab shows 13 rules that are “loaded/available”, when in reality i have 37 rules spread across 18 files.

  • Using my ASTRO binding/item/rule from above, as reported, the rule is not firing when the item state changes… but if I add a line or any type of modification to the file, the rule gets recognized and it shows on the UI rule tab.

  • Changed the name (label) of the item “Sun_State” and the rule was still working, since I did the file manipulation workaround from the previous state (manually changed the item state and the rule did fire up).

  • Changed the name of the variable to “Sun_State_1” and then the rule was all of a sudden missing from the UI rule tab, and upon a manual change of the item state, the rule did not run.

This is for sure an interesting behavior… and reading the issue post linked above, this is reported as a bug, but it is not clear to me if this has been marked for a fix or if further info/debugging is needed… how do we go abut this so that it is noticed and prioritized for the next release (if indeed a bug)? should I post on that open issue and refer to this post?

Thanks

So, that’s nothing to do with editing Items?

Might possibly have similar root cause, say there’s a timing race with rules loading and Items “ready”. Or something else altogether.

With 3 1 now on general release you should re-evaluate there. There were changes related to DSL rules performance.

You are right, I guess I should re-state: I can replicate the issue you described (rules not triggering when the item is changed on the file)… but the issue that I have is still there, which is that the rules do not load upon system start, and for them to do so…I have to manually edit the rule file for it to be recognized and loaded.

Perhaps they are related… who knows!

I will give 3.1 a try, and report back… just want to make sure this is on the developers radar and hopefully a root cause can be found and fixed :slight_smile:

Tried OH Docker 3.1.0-Debian, did a partial import of most of my rules, things and items and re-ran the same scenarios described above.

I am happy to say in every instance the rule did work/fire up as intended. No longer I had to “manually” modify a rule to get OH to load it and run it… I also played with changing the items file (changed the item name of one variable as described above) and still, OH worked as intended and no issues that i could see were encountered.

I will take more time to fully migrate my database and files, and run the same scenarios to be 100% sure… but fingers crossed and knock on wood, I think we I am on a good path here and it seems 3.1.0 fixed something under the hood to get rid of the issue I had…

Stay tuned.

1 Like

Just a quick report out. After running with 3.1.0 for almost two weeks, I have not had any issues with rules not triggering, and all of my rules properly appear on the UI. So, apparently this issue was fix on the 3.1.0 version and I am marking this as solved.

Thanks.

1 Like

I have exactly the same behaviour as funky28 described but with OpenHAB 3.2.0 running bare-metal on a RaspberryPi 4 with Ubuntu 20.04.4 (using stable channel on openhab.jfrog.io). Any suggestions?

Show us some more detail, it works for others. Rule trigger conditions, how you know the rule runs, events.log of “missed” events, etc.

I wasn’t able to reproduce it for a while. But now I found the problem. It was an exception which corrupted a timer.