My first steps with OpenHab

I removed the custom logger and still got nothing from the logInfo entries in my rules. Basically, my rules don’t appear to be running at all, not even the ones that aren’t giving errors.

It is. You have to fill in all three, but null is OK for the second if you don’t want to specify a state - at least this banishes the error.

triggers: 
    [ 
      ItemStateUpdateTrigger("Test1", null, "Test1")
    ],

Which log entries might indicate that the rule engine is doing something? After the “Loading script” entries, I see nothing. No rules appear to be running.

Hey guys, sorry I’m so late to the party, I have not had much time to spend on the forum lately.

The JS branch is maybe 60% complete and in terms of the most used features for writing rules I would say it’s 85% functional. The rule syntax has changed to line up as close as I could get to the Jython syntax. An example rule is included in my first post in the Ivan’s Helper Libraries thread.

Being a work in progress you will need to look through the code to see what’s available and how to use it. I have not updated any of the documentation yet, that will usually come last in the development cycle.

2 Likes

I hadn’t seen that thread. Is that the only example of the new-style JS rules? I’m afraid I don’t entirely follow it, or understand how it would apply to, say, timers.

Doesn’t anybody else use JS rules in OH3?

Edit: OK, so I just have to look at Jython examples. Let’s see.

I’m struggling to make sense of the Python examples. Would a timer rule look like this?

function every_minute(event) 
{
}
when("Time cron 0 0/1 * * * ?")(every_minute);
rule
(
    "Every Minute Timer",
    "Does stuff"
)(every_minute);
1 Like

I think I have to make my question even more specific: Doesn’t anybody else use JS rules using .js files in OH3?

On the one hand, it feels like it would be a good idea to go away for six months whilst the JS situation stabilises, but on the other, I feel like Zipato could collapse any day now, so I really want to get on with getting my system operational.

In the meantime, the ventilation goes back to manual programming :roll_eyes:

Yes, you’re example “every minute” rules correct. I’m assuming you skipped the load statements for brevity but they are in the file.

And yes, I should have mentioned that the Jython docs can be used as a reference. I have not ported everything over but what I have works 98% the same as Jython. I would suggest checking the JS function in the source after reading the Jython docs on it just to make sure it is there and uses the same parameters. I’ve done my best but there are differences between the languages that occasionally required me to do something a little different in JS.

You mean the load statement to load the helper libraries?

Why does triggers.js contain what look like the old-style triggers if they’re not used in this new syntax?

The rule is loaded OK, but then I get this error every minute:

Failed to execute rule '19495b7c-380b-43a3-8422-8b960ff9c111': Fail to execute action: 1

I consider this a kind of progress. At least something is trying to happen.

I’ve set logging for org.openhab.core.automation to DEBUG and restarted. I don’t know if it will tell me any more. Literally this only thing the rule does is this:

logInfo(“All-new radical minute-timer”);

So I’m not sure that’s the cause - unless logInfo has been replaced by something else?

I get this with DEBUG logging:

Failed to execute rule '6c6e1967-3801-4937-9cbc-dee217c5f977': Fail to execute action: 1
2021-07-23 12:53:00.807 [DEBUG] [e.automation.internal.RuleEngineImpl] - 
java.lang.RuntimeException: Fail to execute action: 1
	at org.openhab.core.automation.internal.RuleEngineImpl.executeActions(RuleEngineImpl.java:1191) ~[bundleFile:?]
	at org.openhab.core.automation.internal.RuleEngineImpl.runRule(RuleEngineImpl.java:991) [bundleFile:?]
	at org.openhab.core.automation.internal.TriggerHandlerCallbackImpl$TriggerData.run(TriggerHandlerCallbackImpl.java:90) [bundleFile:?]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) [?:?]
	at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304) [?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
	at java.lang.Thread.run(Thread.java:829) [?:?]
Caused by: jdk.nashorn.internal.runtime.ECMAException: Error: An error occured while running rule Every Minute Timer(see the stack trace for details)
	at jdk.nashorn.internal.objects.NativeError.initException(NativeError.java:135) ~[jdk.scripting.nashorn:?]
	at jdk.nashorn.internal.objects.NativeError.<init>(NativeError.java:101) ~[jdk.scripting.nashorn:?]
	at jdk.nashorn.internal.objects.NativeError.<init>(NativeError.java:105) ~[jdk.scripting.nashorn:?]
	at jdk.nashorn.internal.objects.NativeError.<init>(NativeError.java:109) ~[jdk.scripting.nashorn:?]
	at jdk.nashorn.internal.objects.NativeError.constructor(NativeError.java:128) ~[jdk.scripting.nashorn:?]
	at jdk.nashorn.internal.scripts.Script$Recompilation$8175$1270AA$rules.L:11#function_rule#rule_execute(/etc/openhab/automation/lib/javascript/core/rules.js:45) ~[?:?]
	at jdk.nashorn.javaadapters.org_openhab_core_automation_module_script_rulesupport_shared_simple_SimpleRule.execute(Unknown Source) ~[?:?]
	at org.openhab.core.automation.module.script.rulesupport.shared.simple.SimpleRuleActionHandlerDelegate.execute(SimpleRuleActionHandlerDelegate.java:34) ~[?:?]
	at org.openhab.core.automation.module.script.rulesupport.internal.delegates.SimpleActionHandlerDelegate.execute(SimpleActionHandlerDelegate.java:59) ~[?:?]
	at org.openhab.core.automation.internal.RuleEngineImpl.executeActions(RuleEngineImpl.java:1183) ~[bundleFile:?]
	... 8 more

That seems to indicate the rule itself is triggering an exception:

           try {
                    callback.apply(callback, [inputs.event]);
                } catch (e) {
                    callback.log.error(
                        get_stacktrace(e, "rule: " + (name || callback.name), -1, 1)
                    );
                    throw Error(
                        "An error occured while running rule " + (name || callback.name)
                        + "(see the stack trace for details)"
                    );
                }

since the error originates in the throw here in rules.js.

So I’m commenting out my logInfo line to see what happens.

Yep, now it “works” (it doesn’t actually do anything):

The trigger 'Time_cron_0_0_1_1d4ca4a7-a321-41e0-967a-12923498de7df7d6ba32-bb44-4261-bd0a-16bfa544b063' of rule '310ee782-8f8e-42aa-beb6-1661aab0c9f7' is triggered.
2021-07-23 13:11:01.117 [DEBUG] [e.automation.internal.RuleEngineImpl] - The rule '310ee782-8f8e-42aa-beb6-1661aab0c9f7' is executed.

So, what’s the new way of writing to the log?

I see the core .js use getLogger, but I’m not sure how that would translate to my rules.

You skimmed a little too quick through that file, you went right past the answer.

Line 31 has the getLogger definition, you get an slf4j logger instance. Docs can be found on Google for that library, but it is essentially the same implementation as the Python logger from the perspective of writing rules. Instead of logInfo() use it like log.info() after assigning var log = getLogger();.

Also you can find that stack trace in a different logger, see lines 17-22 for where that ended up. If you have a config file then the log path will be in there, otherwise it will be in the default.

What I can’t work out is that you seem to be specifying a certain log file. How do I just write to the log file that automation output is directed to?

I’m remoting to my 4K PC on an HD screen - definitely doesn’t help with skimming :roll_eyes:

You could, but you’d have to specify that as the log path in configuration.js

OK, wait, let’s see if I understand this.

var LOG = getLogger(LOG_PREFIX + ".core.rules");

equates to

var LOG = getLogger("jsr223.javascript.core.rules");

That would go to my JSR223.log as it stands. The output from “org.openhab.model.script” is what I’ve directed to rules.log, so if I just do:

var log = getLogger("org.openhab.model.script");
log.info("Hello");

I get what I want, correct? I could then define a logInfo function and avoid having to find/replace all my log entries.

createTimer is an Action so the library to load will be actions.js. createTimer lives in the ScriptExecution class.

Almost all the interactions with openHAB itself (calling actions, working with Items, etc.) is achieve through the same Java Classes and Objects no matter what language you are using. So for the most part, with a little practice, you should be able to look at a jython block of code and convert it to JavaScript without too much trouble. Rules after all are mainly about interacting with openHAB and the rest of the rule is either proforma or stringing together those interactions.

So using the Helper Library you’d create a Timer

var logger = Java.type("org.slf4j.LoggerFactory").getLogger("org.openhab.model.script.Test");
var ZDT = Java.type("java.time.ZonedDateTime");

var OPENHAB_CONF = java.lang.System.getenv("OPENHAB_CONF");
load(OPENHAB_CONF + "/automation/lib/javascript/core/actions.js");

var runme = function(){ 
  logger.info("Timer expired...");'
  // timer code goes here
}
var timer = ScriptExecution.createTimer(ZDT.now().plusSeconds(1), runme);

But you’re not asking about a Timer there but a cron triggered rule. As I only use UI created rules with JavaScript I don’t know what it should look like in .js files.

As with createTimer, logInfo is one of the core openHAB Actions. In this case it’s on the Log class. @CrazyIvan359, the Helper Library seems to be trying to import the wrong class for the logger Actions, using org.openhab.core.model.script.actions.LogAction which is what is was before OH 3. I thought someone submitted a PR for that. I can do so if you like. Only the first block need to be updated I think. However that will make it not work for OH 2.5 so I don’t know how you are handling that.

@LordLiverpool, this appears to be one of the places in that 20% not yet done. So you can either create the logger directly like I showed in the createTimer example above, or import the Log class manually.

var Log = Java.type("org.openhab.core.model.script.actions.Log");
Log.logError("Experiments", "This is an OH error log");
Log.logWarn("Experiments", "This is an OH warn log");
Log.logInfo("Experiments", "This is an OH info log");
Log.logDebug("Experiments", "This is an OH debug log");
// There is no trace

Not a file, but a logger name. The logger names are hierarchical. By default, there are configs in log3jk2.xml to log out everything under org.openhab.model.script to openhab.log. You’ve added some customizations to move those to another file. The openHAB Log actions create new loggers under that path. If you use slf4j directly instead, you have to specify the full path.

@rlkoshak I can’t remember if I did JS but the Jython libs are fully OH2/3 agnostic. You can use either Log or LogAction in both version and you’ll get the available object.