I have several rules which seem to crash everytime they are called with the same error, but I do not know why and the error message is to general (for my knowledge of Xtext/Xtend).
The error log:
09:57:55.273 [INFO ] [marthome.event.ItemStateChangedEvent] - window_STATE changed from CLOSED to OPEN
09:57:55.291 [INFO ] [pse.smarthome.model.script.smarthome] - balcony state check imminent (open)
09:57:55.315 [ERROR] [.script.engine.ScriptExecutionThread] - Rule 'balcony_window_switch_on_night': An error occured during the script execution: Unhandled parameter types: [null, org.eclipse.xtext.xbase.interpreter.impl.DefaultEvaluationContext@101dac9, org.eclipse.xtext.util.CancelIndicator$1@abce98]
The script in question is the following. Note that it seems to crash somewhere after the first log message and before the handling of the switchBalconyLightOff timer (found out through commenting-out-debugging). Following that, I cannot understand why it would crash when checking a simple state (because this seems to work everywhere else except these few rules).
import org.openhab.model.script.actions.Timer
var Timer switchBalconyLightOn = null
var Timer switchBalconyLightOff = null
rule balcony_window_switch_on_night
when
Item window_STATE changed from CLOSED to OPEN
then
logInfo("smarthome", "balcony state check imminent (open)")
if (weather_is_soon_night.state == OFF && weather_is_night.state == OFF) {
return
}
if (user_force_off.state == ON) {
logInfo("smarthome", "balcony has been opened, but force off is in effect")
return
}
// -- rule seems to crash above this line --
if (switchBalconyLightOff != null && !switchBalconyLightOff.hasTerminated()) {
switchBalconyLightOff.cancel()
switchBalconyLightOff = null
}
logInfo("smarthome", "scheduling balcony check timer (on)")
if (switchBalconyLightOn != null && !switchBalconyLightOn.hasTerminated()) {
logDebug("smarthome", "canceling old check timer (off)")
switchBalconyLightOn.cancel()
}
switchBalconyLightOn = createTimer(now.plusSeconds(70)) [|
if (weather_is_soon_night.state == OFF && weather_is_night.state == OFF) {
return
}
if (user_force_off.state == ON) {
return
}
if (window_STATE.state == OPEN) {
sendCommand(socket_balcony, ON)
}
]
end
The error is coming from one of the switchBalconyLightX.cancel() lines I’m almost positive.
I’m not certain why that line would be causing an error though.
Add some additional logging to see if you can narrow it down to which one is causing the problem then log out the states of the timer to see if you can figure out what might be working as expected.
You are right, the .cancel() call of the timer was the issue!
Hence this finding, I thought I add two log lines to the function (right below the first one) to print the content of the timer variables (I presumed it will be NULL). The method body start looks like this now:
logInfo("smarthome", "balcony state check imminent (open)")
logInfo("on timer is = " + switchBalconyLightOn)
logInfo("off timer is = " + switchBalconyLightOff)
Strange enough, OpenHAB does not seem to like this and writes this error to its log:
Rule 'balcony_window_switch_on_night': An error occured during the script execution: index=1, size=1
I have a second rule (the switch-off counterpart of the posted rule) that yields the exact same error.
logInfo requires two arguments, a log name and the log statement. In your first example you have these two arguments (“smarthome” is the log name you are using there) but the second two lines are missing this argument.
Okay, after having log output about the timer variables, this seems a bit odd to me: The error seems to occur if the timer variables are null, but there is a null-check in the if before calling cancel… strange!
So i replaced it with a null-safe call for now like this and that seems to do the trick for the moment:
if (!switchBalconyLightOn?.hasTerminated()) {
switchBalconyLightOn?.cancel()
}
But I guess this should not happen in the first place?
Well, you would have to check the timing but it is possible that you have a timing issue where the timer goes off and sets it’s var to null after your if check whether it is null has run but before you call cancel. This is commonly referred to as a TOCTU (Time of Check Time of Use) problem.
Actually, I now got a rule without any timers at all and the same error message:
10:43:00.033 [INFO ] [marthome.event.ItemStateChangedEvent] - weather_is_morning changed from ON to OFF
10:43:00.058 [INFO ] [pse.smarthome.model.script.smarthome] - morning end for lights has toggled, but force off is in effect
10:43:00.074 [ERROR] [.script.engine.ScriptExecutionThread] - Rule 'fluter_switch_off_morning_end': An error occured during the script execution: Unhandled parameter types: [null, org.eclipse.xtext.xbase.interpreter.impl.DefaultEvaluationContext@2719ec, org.eclipse.xtext.util.CancelIndicator$1@d496e9]
And the rule:
rule fluter_switch_off_morning_end
when
Item weather_is_morning changed from ON to OFF
then
if (user_force_off.state == ON) {
logInfo("smarthome", "morning end for lights has toggled, but force off is in effect")
return
}
logInfo("smarthome", "morning end, should switch off corner lights, conditions = " + weather_outside_conditions.state)
var specialDay = today_is_weekend.state == ON || today_is_public_holiday.state == ON || today_is_holiday.state == ON
var sunnyConditions = weather_outside_conditions.state == "sunny"
if (specialDay && !sunnyConditions && (current_season.state == "AUTUMN" || current_season.state == "WINTER")) {
logInfo("smarthome", "it is a special day and autumn or winter, morning lights are not switched off")
sendCommand(fluter_couch_COLOR, HUE_READING_COLOR)
sendCommand(fluter_esstisch_COLOR, HUE_READING_COLOR)
return
}
sendCommand(fluter_couch_STATE, OFF)
sendCommand(fluter_esstisch_STATE, OFF)
end
The first log message of the rule is triggered (then the rule is ended in the if with return). So I really do not understand what is going on here, definitely no TOCTU… There must be some easy way to debug something like this… does anybody know something?
Add logging statement every other lint until you know exactly what line is failing. Print the state of all the relevant vars and Items at that point.
The problem might be the returns. I’ve not used return statements in rules before. I know in the past when I’ve tried to use break statements it kills the whole rule rather than just breaking out of the loop I was in.Given that behavior you might try replacing the returns with breaks and see if that makes a difference. Or restructure the rule to not use/need the returns.
That is what I have in most of my rules. I was rather thinking of something like “An error occured during the script execution […] at line X in file Y” or a stack trace to ease development.
Nevertheless, I changed the rule in question (and another one crashing with the same pattern) and both do not use return statements anymore. And you know what? It works now, without any problems!
That would be great. Unfortunately the underlying library that implements the Rule’s DSL doesn’t support that. Kai is working on a new Rules engine (if you enable Experimental you can install it too). Perhaps this rewrite will include that capability.
That certainly points to return being the problem. Thanks for reporting back.
Hi,
if anyone wants to use a return because it makes the rule simpler to write/ understand, then to stop the error, I have found that using a return 0 is accepted by the rules engine, even though the Designer IDE flags it up as a syntax issue. I haven’t seen any side-effects of using return 0 to get out of rule early.
