Reliability Javascript Rules OH4.0.2

Setup, Configuration and Use Scripts & Rules
1

Hi,
since 4.0.2 i dont understand something about reliability of javascript. For finding out more I entered a little very simple Testscript for showing this:

console.loggerName = 'org.openhab.automation.rules.test';
osgi.getService('org.apache.karaf.log.core.LogService').setLevel(console.loggerName, 'DEBUG');

function myFunction(p1, p2) {
  return p1 * p2;
}


console.debug("START");
var x=myFunction(2,5)
console.debug(x);
console.debug("END");

Result:

2023-09-01 10:41:35.994 [DEBUG] [org.openhab.automation.rules.test   ] - START
2023-09-01 10:41:36.014 [DEBUG] [org.openhab.automation.rules.test   ] - 10
2023-09-01 10:41:36.015 [DEBUG] [org.openhab.automation.rules.test   ] - END
2023-09-01 10:41:37.553 [DEBUG] [org.openhab.automation.rules.test   ] - START
2023-09-01 10:41:41.016 [DEBUG] [org.openhab.automation.rules.test   ] - START
2023-09-01 10:41:41.055 [DEBUG] [org.openhab.automation.rules.test   ] - 10
2023-09-01 10:41:41.057 [DEBUG] [org.openhab.automation.rules.test   ] - END

In Words: Not each Rulestart seems to starts the script. Some Rulestarts only generating a START, some nothing.

What can i do to find out why?

2

I just copied your script and it does the same thing.
I am using OH 4.0.2. Interesting.
If I just run something simple:
console.log(items.getItem(“Door_bedroom_lastupdate”).state)
It works every time.

3

The call to the logger service actually takes a non- negligible amount of time. However the script is still exciting because it is not waiting for a return value. So sometimes, the logger has correctly finished setting the level to debug by the time the first console call is made and sometimes it has not.

The good news is that you don’t need to use the logger service call ever rule run. Once the level is set, it stays that way until a new level is set. So, you can just comment out that line 99% if the time and only re-enable it when you actually need to set a new logger level.

1 Like
4

HI @JustinG
I tested to comment out the first two lines. But then The script does not know any more to which loggername it belongs.
If im Doing a log:get on console it shows the former set loggernames assigned to the DEBUG-Level but Script is logging no more to this loggername.
A newly added console.log("LOGEND"); gives output to log but a console.debug("END"); does not.

5

Only comment out the one line that sets the logger level. You need to keep the line that sets the logger name.

1 Like
6

oh, you are right. It works now and also its no more suppressing logoutputs :wink: Thanks!

7

There’s also what I’ll call a bug but it probably is better considered a limitation.

Every time you change a logging setting in karaf, the rest API, or a rule, the log4j2.xml fine gets updated with that new setting.

If you are unlucky and one role runs and tries to change it’s logging level whole another rule is already trying to change it’s own logging level, the log4j2.xml file gets destroyed and replaced with a zero length file.

So it’s a bad idea to always change the loggibg level every time the rule runs. Only include that line when you want to change the level, then comment it out.

1 Like