Why is my rule triggering twice? (And not telling me what triggered it either.)

Setup, Configuration and Use Scripts & Rules
1

Hi,

I am using openHAB 3.0.0 and am trying to do some integration with a Lutron Pico keypad. As I was debugging it, I noticed that my ruled seemed triggered a lot more than I expected. Here is the simplest version of the rule (ignore the spurious variables, they’re used in the longer rule):

rule "Kitchen scene All Bright"
when
  Item KitchenLights_Pico_Button1 received update OFF
then
  val log = "KitchenSceneAllBright"
  val item = KitchenLights_Pico_Button1
  logInfo(log, "Item '{}' triggered rule", item.name)
end

Below are the logs. I see a single ItemStateChangedEvent from ON to OFF, which is what should trigger the rule, right? But the rule fires twice. Any ideas why? Shouldn’t the rule only fire once with the received update OFF trigger?

Also, I tried to log the implicit variables triggeringItem, previousState, newState and they are all null which doesn’t seem to match the documentation?

==> /opt/openhab/userdata/logs/events.log <==
2020-10-25 01:27:29.958 [ome.event.RuleRemovedEvent] - Rule 'double_taps-2' has been removed.
2020-10-25 01:27:29.965 [ome.event.RuleRemovedEvent] - Rule 'double_taps-1' has been removed.
2020-10-25 01:27:30.002 [thome.event.RuleAddedEvent] - Rule 'double_taps-1' has been added.
2020-10-25 01:27:30.004 [.event.RuleStatusInfoEvent] - double_taps-1 updated: UNINITIALIZED
2020-10-25 01:27:30.008 [.event.RuleStatusInfoEvent] - double_taps-1 updated: INITIALIZING
2020-10-25 01:27:30.021 [.event.RuleStatusInfoEvent] - double_taps-1 updated: IDLE
2020-10-25 01:27:30.024 [thome.event.RuleAddedEvent] - Rule 'double_taps-2' has been added.
2020-10-25 01:27:30.040 [.event.RuleStatusInfoEvent] - double_taps-2 updated: UNINITIALIZED
2020-10-25 01:27:30.049 [.event.RuleStatusInfoEvent] - double_taps-2 updated: INITIALIZING
2020-10-25 01:27:30.054 [.event.RuleStatusInfoEvent] - double_taps-2 updated: IDLE
2020-10-25 01:27:31.055 [vent.ItemStateChangedEvent] - Item 'KitchenLights_Pico_Button1' changed from OFF to ON
2020-10-25 01:27:31.059 [vent.ItemStateChangedEvent] - Item 'KitchenLights_Pico_Button1' changed from ON to OFF
2020-10-25 01:27:31.062 [.event.RuleStatusInfoEvent] - double_taps-1 updated: RUNNING

==> /opt/openhab/userdata/logs/openhab.log <==
2020-10-25 01:27:32.001 [INFO ] [e.model.script.KitchenSceneAllBright] - Item 'KitchenLights_Pico_Button1' triggered rule

==> /opt/openhab/userdata/logs/events.log <==
2020-10-25 01:27:32.011 [.event.RuleStatusInfoEvent] - double_taps-1 updated: IDLE
2020-10-25 01:27:32.014 [.event.RuleStatusInfoEvent] - double_taps-1 updated: RUNNING

==> /opt/openhab/userdata/logs/openhab.log <==
2020-10-25 01:27:32.016 [INFO ] [e.model.script.KitchenSceneAllBright] - Item 'KitchenLights_Pico_Button1' triggered rule

==> /opt/openhab/userdata/logs/events.log <==
2020-10-25 01:27:32.022 [.event.RuleStatusInfoEvent] - double_taps-1 updated: IDLE```
2

No.
You asked for
Item KitchenLights_Pico_Button1 received update OFF

Multiple updates which happen to be to the same state are perfectly acceptable in openHAB.
Updates to same state are not generally logged.

This is why there are choices of rules triggers.

If you want trigger on change, do so.
Item KitchenLights_Pico_Button1 changed to OFF
but you might not want to if pressing the same button twice doesn’t change anything. I’ve no idea what the behavior of that device is.

You messed up somewhere with triggeringItem, that will be available on received update triggers.
Remember that is an Item, maybe you wanted to log out its name
triggeringItem.name

But yes, previousState and newState will not exist if there is no change, as per the documentation. They will not actually be null, they simply do not exist.

As to why multiple updates may appear, that depends on your Item configuration and what you are doing to it.

3

Thanks for the changed to OFF tip, that took care of the double trigger.

You messed up somewhere with triggeringItem , that will be available on received update triggers.

I don’t think so. It is null. I added this log for it on in script, just under the previous log call:

logInfo(log, "Trigger was Item '{}'", triggeringItem.name)

and the log showing it’s null when trying to execute it. BTW, is there no way to get line numbers with those errors? They make debugging so painful in general.

2020-10-25 01:23:36.322 [ERROR] [internal.handler.ScriptActionHandler] - Script execution failed: cannot invoke method public abstract java.lang.String org.openhab.core.items.Item.getName() on null in double_taps

But yes, previousState and newState will not exist if there is no change, as per the documentation. They will not actually be null, they simply do not exist.

Actually, newState does exist and is correct. Sorry about the assumption that I could get previousState too. You’re correct about the documentation actually being correct there.

4

It is possible this is a deficiency in the OH3 DSL interpreter. Be surprising if no-one has run into it before, usage is common where Groups are involved.