[SOLVED] Ultimate guide to debugging rules?

Hello.

I have a simple rule that I don’t understand why it isn’t working. I have read posts up and posts down on how to debug the standard rules engine, but I am currently at a loss!

Here is my simple rule:

rule “Oppvask”
when
Item OppvaskProgramStatus changed
then
logDebug(“Oppvask”,“Rule running!”)
if (OppvaskProgramStatus is “Off”) {
KjokkenPanel.postUpdate(“Huset”)
logDebug(“Oppvask”,“HUSET chosen”)
}
else {
KjokkenPanel.postupdate(“HusOppvask”)
logDebug(“Oppvask”,“Oppvask chosen”)
}
end

Both “KjokkenPanel” and “OppvaskProgramStatus” are string items. OppvaskProgramStatus is a string item being set by MQTT, while KjokkenPanel is a dummy string item being used to switch HabPanel dashboard when my dishwasher is running. I have tried different variants of adding or omitting “.state”, and with “==” and “is”.

-But what is the best way to actually debug this? I tried to specify “DEBUG” for org.eclipse.smarthome.model.script, org.eclipse.smarthome.model.script.Oppvask, org.eclipse.smarthome.model.rule, but when I do “log:tail”, I don’t see any messages from the rule engine. However, triggering another rule, I see a message from “runtime.internal.engine.RuleEngineImpl”.

So, I guess my basic question is: Is there any way to debug how the rules files are read, validated, and which rules are currently registered? I may still have a syntax error somewhere, but how can I know, except asking everyone here?

1 Like

Ok,

First of all, please use the code fences when publishing code

You rules is:

rule "Oppvask"
when
Item OppvaskProgramStatus changed
then
logDebug("Oppvask","Rule running!")
if (OppvaskProgramStatus is "Off") {
KjokkenPanel.postUpdate("Huset")
logDebug("Oppvask","HUSET chosen")
}
else {
KjokkenPanel.postupdate("HusOppvask")
logDebug("Oppvask","Oppvask chosen")
}
end

Which is untidy, use indents:
To see message in the log use logInfo if your logging is not set to debug.
Use ==, is is NOT a keywork.
Put a space after commas, it makes the code easier to read.
The state of an item can be obtained with .state. Putting just the name of the item refers to the item object itself.
Add a logInfo line to check the value of OppvaskProgramStatus.
Add a check if the value is NULL and do nothing in that case.

rule "Oppvask"
when
    Item OppvaskProgramStatus changed
then
    logInfo("Oppvask", "Rule running!")
    logInfo("Oppvask", "Status is: " + OppvaskProgramStatus.state.toString)
    if (OppvaskProgramStatus.state == NULL) return; //Do nothing if changed to NULL
    if (OppvaskProgramStatus.state == "Off") {
        KjokkenPanel.postUpdate("Huset")
        logInfo("Oppvask", "HUSET chosen")
    }
    else {
        KjokkenPanel.postUpdate("HusOppvask")
        logInfo("Oppvask", "Oppvask chosen")
    }
end
2 Likes

Thank you very much!

Sorry, didn’t realize the “fencing” part. My indents and spacing disappeared in cut/paste, I promise it looks a lot better IRL :slight_smile:

As mentioned, I tried all different variants of using “.state” and not (and using “==” or “is”). Some sample rules in the documentation / posts actually use “is”, which made me think it should work.

I used logInfo in the beginning, but I never saw any of it in the logs, so I tried changing to logDebug. As mentioned,

Seems like your changes was all it took. -So I can not have tested the combination of “==” and “.state” at the same time. Checking for NULL is also a very good suggestion, although the value should in theory never be NULL (but always best to be sure).

-But. Can someone tell me exactly which modules to set to “Debug” in order to actually be able to debug these things myself? I write code in different languages all the time, but feel completely blind when working with this! As mentioned, I set “org.eclipse.smarthome.model.script.Oppvask” to DEBUG, but I still didn’t get any info in the log.

That was a good idea! But this feature from the karaf console is to set the log level of the bindings. I don’t think it works with rules/scripts.

The value changes to NULL on restart for example which can trigger the rule depending if it has loaded yet or not during the start-up process.

Ok, thanks a lot for your help! It works very well now. I saw that I had a type in the last “postupdate”, which should have a capital “U”, but now it all works. -And grep’ing for “Oppvask” in openhab.log tells me what is happening.

Still, I am curious as to whether there is any kind of debugging possible, in the form of syntax-related error messages and similar. I believe in my first iterations, I had errors that prevented OpenHAB from loading the rule in the first place, and these situations seem very hard to debug.

If you look at the “logging” section of the documentation, extracting specific logging to separate files seems to be documented only for a previous release. (All statements in the sample say “log4j…”, while in the actual configuration file, all statements are “log4j2…” with somewhat different parameters.) -And with my admittedly limited efforts to separate rule logging into a separate file, I was unable to achieve that.

1 Like

You need to use VScode to edit your files
That will enable syntax checks etc…

Please tell us where because any code in docs that uses “is” is wrong and needs to be corrected.

Notice logInfo has two parameters.

What logs were you looking in because you should have been seeing errors in openhab.log every time OH loaded your .rules file with the line number and indication of what was wrong for many of the corrections Vincent suggested.

It might be worth while to look at the JSR223 add-on that will let you write Rules in Jython, JavaScript, or Groovy. There is less support here on the forum but lots of users are a lot happier not being constrained by the purposefully added limitations in the Rules DSL.

Beyond that, Rules | openHAB, Xtend - Expressions, and Topics tagged designpattern will be your primary resources for the Rules DSL. Logging is documented at Logging | openHAB and an example for configuring logging levels is at Log4j2 Sample Config. working in the Karaf console is documented at The Console | openHAB.

Setting org.eclipse.smarthome.model.script.Oppvask to DEBUG via Karaf console is the perfectly right way to get that self-generated output (logRules lines) logged, see also official docs on this. For more information, you can also enable debug on org.eclipse.smarthome.model to get a log line every time OH calls a rule.

Thanks, everyone. I still struggle a bit with this debugging, but at least now I know I am applying the correct technique. I probably just need to hone things a bit.

I searched for the (probably forum post) where I found the “if (xxx IS xxx)”, but couldn’t find it again. I also briefly opened VSCode, but didn’t immediately find any syntax checker there, so went back to Notepad++, which, with the addition of “NPPFTP” plugin is perfect for editing scripts on a Linux box from Windows or Mac (using Winebottler).

Give VS another try. There is no client-side only syntax checker but it needs to be able to talk LSP protocol to the OH server. That you probably didn’t enable and gave up too early. Search the official docs and forum how to get VS code extensions running.

I agree with Markus. Give VSCode another chance. It requires some configuration but it will save a ton of time in the long run.

and

Have the instructions for getting it set up. IIRC it is as simple as installing the extension and setting the hostname/IP address where OH is running.

Unless it has been fixed, the only problem with it I know of is the live updated view of the sitemap panel isn’t working. Everything else works like a champ. I can’t imagine how frustrated I would be trying to write Rules DSL without VSCode.