triggeringItem.state bug?

[JimT (jimtng)]

• openHAB version: 2.5M1

.items file:

Group gAutomaticLights
Switch Front_Porch_Light_Automatic (gAutomaticLights) 

.rules file:

rule "Turn on porch light when dark"
when 
    Member of gAutomaticLights received command 
then
   logInfo("****TEST****", "**** 1 triggeringItem.state = " + triggeringItem.state + " receivedCommand = " + receivedCommand)
   logInfo("****TEST****", "**** 2 triggeringItem.state = " + triggeringItem.state + " receivedCommand = " + receivedCommand)
end

I opened two openhab console connections over two separate windows. One session is to send command (smarthome:send) and the other session is running log:tail

In the command session, I sent:

smarthome:send Front_Porch_Light_Automatic OFF
smarthome:send Front_Porch_Light_Automatic ON
smarthome:send Front_Porch_Light_Automatic OFF
smarthome:send Front_Porch_Light_Automatic ON
smarthome:send Front_Porch_Light_Automatic OFF
smarthome:send Front_Porch_Light_Automatic ON

In the log, I saw - excuse the long log - I’ve edited for clarity - stripping off unnecessary parts of the log

Item 'Front_Porch_Light_Automatic' received command OFF
Front_Porch_Light_Automatic changed from NULL to OFF
**** 1 triggeringItem.state = OFF receivedCommand = OFF
**** 2 triggeringItem.state = OFF receivedCommand = OFF
Item 'Front_Porch_Light_Automatic' received command ON
Front_Porch_Light_Automatic changed from OFF to ON
**** 1 triggeringItem.state = OFF receivedCommand = ON
**** 2 triggeringItem.state = **ON** receivedCommand = ON
Item 'Front_Porch_Light_Automatic' received command OFF
Front_Porch_Light_Automatic changed from ON to OFF
**** 1 triggeringItem.state = OFF receivedCommand = OFF
**** 2 triggeringItem.state = OFF receivedCommand = OFF
Item 'Front_Porch_Light_Automatic' received command ON
**** 1 triggeringItem.state = ON receivedCommand = ON
**** 2 triggeringItem.state = ON receivedCommand = ON
Front_Porch_Light_Automatic changed from OFF to ON
Item 'Front_Porch_Light_Automatic' received command OFF
**** 1 triggeringItem.state = ON receivedCommand = OFF
**** 2 triggeringItem.state = **OFF** receivedCommand = OFF
Front_Porch_Light_Automatic changed from ON to OFF
Item 'Front_Porch_Light_Automatic' received command ON
**** 1 triggeringItem.state = OFF receivedCommand = ON
**** 2 triggeringItem.state = **ON** receivedCommand = ON
Front_Porch_Light_Automatic changed from OFF to ON

I have enclosed the anomalous “ON/OFF” with two stars. Basically the two logs **** 1 and **** 2 should match for triggeringItem.state. However, sometimes they don’t. The first one is correct, but the second one is incorrect, as though the state got updated (it shouldn’t). This behaviour is also a bit intermittent, so if you’re trying it, try doing several on/off/on/off

So, is this a bug? If not, what can I do? It seems that the workaround is to save the triggeringItem.state at the top of the rule in a variable and use that variable in the rest of the rule.

Has anyone noticed this?

[rossko57]

@JimT

So, is this a bug?

No. This is how openHAB works.

You must draw a distinction between Item commands and Item states. Clearly they are not the same thing, because you can send command UP to a blind and get resulting state 99%

So commands go on openHABs event bus. They might trigger rules, and get seen by bindings that pass the command along to a real device. At some later time, the device might respond with a new status, and the binding will update the Item state (also via the event bus, so can be used to trigger rules etc.)

A rule triggered by received command should NOT expect to “see” the Item’s state from the result of the command. It hasn’t happened yet. It might happen in 10mS or 10 seconds. It might happen halfway through executing the rule.

In summary, it’s asynchronous.
You need to take care to avoid writing rules that fall into this trap - Items are not regular program variables.
If you are interested in the state, trigger your rule from state events changed or received update.

@JimT

Has anyone noticed this?

Oh yes

[SOLVED] Getting a deterministic item state from postUpdate (equivalent to "receivedCommand")

Yes, that’s correct. As an Item received a command, it’s very likely that it may change its state. But that will happen asynchronous - either (autoupdate=“true”) because openHAB is setting the state according to the sent command - or (autoupdate=“false”) because openHAB receives a state update from elsewhere after sent command. So, you can’t predict when the state is updated or changed. When the trigger is received command, only use receivedCommand. triggeringItem is ok, but not triggeringIte…

[JimT (jimtng)]

@rossko57

A rule triggered by received command should NOT expect to “see” the Item’s state from the result of the command. It hasn’t happened yet.

I understand that part perfectly, I think. I was relying on triggeringItem.state to know what the item’s state was before / when received command was received. I was under the assumption that these sequence of events would happen synchronously:

• Item received a command - triggeringItem.state contains the state prior to receiving the command
• Rule “received command” fired - triggeringItem.state still contains the state prior to receiving the command
• Rule “received command” finished - triggeringItem.state still contains the state prior to receiving the command
• Item state now updated to the new value

So based on your explanation, my assumptions above are incorrect, and that I cannot rely on triggeringItem.state at all within my “received command” rule?

What I want to achieve, is to know the new value and the previous within my rule, so I can make a decision based on the two values/states.

[JimT (jimtng)]

Aha, I’ve just read the post you referred

On the other hand, when a rule was triggered by received update or changed , you may use previousState or triggeringItem.state , as it’s unlikely that the state may change a few millis after a change again.

Thanks, I’ll re-think my rule.

[rossko57]

@JimT

What I want to achieve, is to know the new value and the previous within my rule, so I can make a decision based on the two values/states.

You can achieve just that with state changed rule trigger and previousState implicit variable.
But that only works for changes, and will not trigger on updates to same value.

You can trigger off received update to catch those as well, but then the previousState implicit variable is not available. You would have to construct your own version using persistence to store and retrieve (and bear in mind it takes a little time to store updates, so there is room for ambiguity).

EDIT - thinks, there is if I recall a cheat here. Use both changed and received update triggers on the same rule. The existence of the changed trigger conjures previousState into existence, even if it was the updated trigger that fired. The disadvantage is the rule will run twice for an actual change (which is also an update of course)
MORE EDIT - I’m reminded now that previousState doesn’t get populated on any update rule run - so that cannot tell if a change happened or not. No use here.

Neither of these methods can tell what the command was, if that is important.
It’s actually quite involved to construct something that triggers from command and uses command results, without using arbitrary timers or delays.

[JimT (jimtng)]

@rossko57 thanks for your explanations above. They’ve helped me better understand some things.

After thinking a bit about this, I’ve changed my item to autoupdate=“false” and also saved the triggeringItem.state at the beginning of my rule. This solved my problem and my rule now works the way I intended using received command, pending further testing.

[JimT (jimtng)]

FWIW, this is what I’m really trying to achieve, perhaps there’s a better way:

I want to turn on the porch light for 10 minutes when I open my front door, after dark. So the _Automatic item uses the expire binding expire=“10m,command=OFF”. When the front light was off, I open door, it turns on and in 10 minutes turns off

However, if the porch light was already on before I opened the front door, do not turn it off in 10 minutes, and just leave the front light be, because it could’ve been turned on by some other timer or manually (which means it should stay on until it’s turned off).

So here’s my rule now:

rule "Turn on porch light when dark"
when 
    Member of gAutomaticLights received command 
then
    val currentState = triggeringItem.state
    val String realItemName = triggeringItem.name.split("_Automatic").get(0)
    val SwitchItem itemPower = ScriptServiceUtil.getItemRegistry.getItem(realItemName + "_Power")
    val DimmerItem itemDimmer = ScriptServiceUtil.getItemRegistry.getItem(realItemName + "_Dimmer")
    if (receivedCommand == ON) {
        // don't start an automatic item timer when the actual item was already on
        if (itemPower.state == ON && currentState != ON) {
            return
        }
        if (Sun_Elevation.state < 0) {
            itemPower.sendCommand(ON)
            if (itemDimmer !== null) {
                itemDimmer.sendCommand(new PercentType(100))
            }
            triggeringItem.postUpdate(ON)
        }
    } else {
        if (currentState == ON && itemPower.state == ON) {
            itemPower.sendCommand(OFF)
        }
        triggeringItem.postUpdate(OFF)
    }
end

rule "Front door open"
when
    Item FrontDoor_Contact changed to OPEN
then
    Front_Porch_Light_Automatic.sendCommand(ON) // reset the timer
end

.items:

Switch Front_Porch_Light_Power "Porch Light Power" <switch> (gOutsideLights, gTasmota) ["Switchable"] { autoupdate="false", channel="mqtt:topic:mosquitto:front_porch_light:power" }
Dimmer Front_Porch_Light_Dimmer "Porch Light Dimmer" <dimmer> ["Lighting"] { channel="mqtt:topic:mosquitto:front_porch_light:dimmer" }

Switch Front_Porch_Light_Automatic "Porch Light Turn on when dark" (gAutomaticLights) { autoupdate="false", expire="10m,command=OFF" }

[rossko57]

I use this (but have many lighting zones with different trigger needs)
Managed by always sending a time to run, but if already running a longer time, has no effect.

Design Pattern : Expire Binding based Countdown timer

Problem Statement Sometimes you need to run a timer, but want to able to inspect the remaining time. This is not directly possible with either createTimer() or the Expire binding. Example - I have lighting-on timers that run for different duration depending on the trigger source or time of day. It is useful to have the timer behave “intelligently” - do not apply a new 5-minute request where there is still seven minutes of a previous trigger to run. But do apply it if there is only two minu…

[rlkoshak (Rich Koshak)]

@JimT

In the log, I saw - excuse the long log - I’ve edited for clarity - stripping off unnecessary parts of the log

As long as you are using code fences, which you are, it’s better to leave log files unmodified. We are all used to looking at logs with the timestamps and everything and often the stuff you stripped off provides clues we would otherwise miss.

@JimT

So based on your explanation, my assumptions above are incorrect, and that I cannot rely on triggeringItem.state at all within my “received command” rule?

Correct. You would use the receivedCommand implicit variable to know what the command was that triggered the Rule but there is no reliable way to know the state of the Item prior to receiving the command.

@JimT

What I want to achieve, is to know the new value and the previous within my rule, so I can make a decision based on the two values/states.

Then you should be using the changed Rule trigger and you will have a previousState implicit variable that is the Item’s state before it changed.

@rossko57

Use both changed and received update triggers on the same rule.

I always just assumed this wouldn’t work. It doesn’t for triggeringItem and receivedEvent when you have a Rule that is triggered by both Item and Channel triggers. But I could see how what you describe could work.

@JimT

After thinking a bit about this, I’ve changed my item to autoupdate=“false” and also saved the triggeringItem.state at the beginning of my rule.

Keep in mind this is only working because of a trick of timing. If there is a hickup caused by Java garbage collection or something else going on when the Rule runs, it could delay execution of that line to save the state just enough that it get’s the new state instead of the old state.

@JimT

FWIW, this is what I’m really trying to achieve, perhaps there’s a better way:

I was about to post a link to the XY Problem article. I’m glad you added this.

This looks complicated to me. Why not check the current state of the actual light instead of relying on the previous state of the timer Item? Who cares what the previous state of the timer Item was, what you care about is whether the the light is already ON when the timer Item receives an ON command. If the actual light is ON you know it was manually turned ON so ignore the Timer.

I think this is a case where separating the Timer Item from the Proxy Item would result in a cleaner Rule. Let’s just use a Rule Timer. If you removed Expire binding from the Item the Rule could look like:

val Timer porchTimer = null

rule "Turn on porch light when dark"
when
    Member of gAutomaticLights received command
then
    val lightName = triggeringItem.name.split("_Automatic").get(0)
    val lightPower = ScriptServiceUtil.getItemRegistry.getItem(realItemName + "_Power")
    val lightDimmer = ScriptServiceUtil.getItemRegistry.getItem(realItemName + "_Dimmer")

    if(receivedCommand == ON && lightPower.state == OFF && Sun_Elevation.state < 0) {
        lightPower.sendCommand(ON)
        lightDimmer.sendCommand(100)
        lightTimer?.cancel
        lightTimer = createTimer(now.plusMinutes(10), [ | 
            lightPower.sendCommand(OFF) 
            triggeringItem.postUpdate(OFF)  // synchronize the proxy item
        ]
    }
    // in all other cases the light was controlled manually so we don't want to mess with a timer
end

I love Expire based Timers, but there are some cases where they cause more problems than they solve.

Python version

from core.rules import rule
from core.triggers import when
from core.actions import ScriptExecution
from org.joda.time import DateTime

timer = None

def turn_off(proxyName, powerName):
    """ Called by the Timer, turns off the light and resets the proxy """
    events.sendCommand(powerName, "OFF")
    events.postUpdate(proxyName, "OFF")

@rule("Porch light when dark", description="turns on the porch light after dark for 10 minutes unless it's already on", tags=["lights"])
@when("Member of gAutomaticLights received command")
def porch_light(event):
    lightName = event.itemName.replace("_Automatic", "")
    lightPower = lightNamne+"_Power"
    lightDimmer - lightName+"_Dimmer"
    if event.itemCommand == ON and items[lightPower] == ON and items["Sun_Elevation"] < DecimalType(0):
        events.sendCommand(lightPower, "ON")
        events.sendCommand(lightDimmer, "100")
        if timer and not timer.hasTerminated(): timer.cancel() # I'm not 100% this syntax is correct
        timer = ScriptExecution.createTimer(DateTime.now().plusMinutes(10), lambda: turn_off(event.itemName, lightPower))

[rossko57]

@rlkoshak

I always just assumed this wouldn’t work.

Off topic - I marvelled at this discovery, that the mere existence of a type of rule trigger calls into existence the appropriate implicit variable in the rule block. It might have no useful content though i.e. null

Rule which iterates through group(s) of similar items

I must say I didn’t fully realise that either. VSCode editor is smart enough to realize that it won’t work in rules with command or updated triggers - and complains vaguely. "Invalid number of arguments. The method previousState(Item) is not applicable without arguments" OpenHAB fails with a runtime error if you do try it anyway in a rule, and that’s the source of the obscure error message seen earlier - Rule 'testing': An error occurred during the script execution: index=0, size=0 So you …

[rlkoshak (Rich Koshak)]

@rossko57

Off topic - I marvelled at this discovery, that the mere existence of a type of rule trigger calls into existence the appropriate implicit variable in the rule block. It might have no useful content though i.e. null

But that’s is useful content. If previousState === null you know the Rule wasn’t triggered by a change.

[rossko57]

@rlkoshak

If previousState === null you know the Rule wasn’t triggered by a change.

The difficulty is that the rule will also be triggered by the received update trigger when there is a change.
This run of the rule (there will be two runs, order indeterminate) will also have previousState = null because the update trigger doesn’t populate it even if a change happened. It is not possible to determine changed or not on this run of the rule.

Having refreshed the memory, I cannot think of any practical use for this quirk that is not covered by individual rules and triggers.

[JimT (jimtng)]

@rlkoshak thanks for the explanation and idea. I have rewritten my rule to use a timer instead of the expire binding.

I’ll move the timer durations into items next.

import java.util.Map
val Map<String, Timer> timers = newHashMap
val timerSecs = 10*60 // 10 minutes

rule "Turn on porch light when dark"
when 
    Member of gLightTimers received command 
then
    val String baseName = triggeringItem.name.split("_Timer").get(0)
    val timer = timers.get(baseName)


    val SwitchItem itemPower = ScriptServiceUtil.getItemRegistry.getItem(baseName + "_Power")
    val DimmerItem itemDimmer = ScriptServiceUtil.getItemRegistry.getItem(baseName + "_Dimmer")

    if (receivedCommand == ON) {
        if (timer !== null) {
            timer.reschedule(now.plusSeconds(timerSecs))
            return
        }

        // don't start an automatic item timer when the actual item was already on
        if (itemPower.state != ON && Sun_Elevation.state < 0) {
            itemPower.sendCommand(ON)
            if (itemDimmer !== null) {
                itemDimmer.sendCommand(new PercentType(100))
            }
            triggeringItem.postUpdate(ON)

            timers.put(baseName, createTimer(now.plusSeconds(timerSecs), [
                if (itemPower.state == ON) {
                    itemPower.sendCommand(OFF)
                }
                timers.put(baseName, null)
            ]))
        }
    } else {
        if (timer !== null && itemPower.state == ON) {
            timer.cancel
            timers.put(baseName, null)
            itemPower.sendCommand(OFF)
        }
        triggeringItem.postUpdate(OFF)
    }
end