String Items set using OnOffType ON will always appear to be OFF

Setup, Configuration and Use Scripts & Rules
1

I’m using the expire timer to auto-shutoff a fan after a period of time (triggered by UI) in OH 2.5.2. I have a “Selection” component in habPanel where the user picks a period of time (10, 30, or 60 minutes). For each of those times, there is a corresponding item with a corresponding expire. When someone changes the item linked to the Selection control, a rule turns the fan and the timer “ON”.

However, for reasons surpassing my understanding, it seems that whenever one of these timers is turned on, it’s state shows as off.

Consider this code I created just to validate:

rule "Trying to understand tripped timers"
when
    Member of ThermostatTimers received command
then
    Thread::sleep(1000) 
    logInfo("Thermostats", "** Reporting Thermostat: {}", triggeringItem.name)
    logInfo("Thermostats", "** Reported state: {}", receivedCommand)
    logInfo("Thermostats", "** Actual state: {}", triggeringItem.state.toString)
    ThermostatTimers
        .members
        .forEach[ i |
            logInfo("Thermostats", "** Timer: {}   State: {}", i.name, i.state.toString )
        ]
end

results in this:

** Reporting Thermostat: DownstairsThermostat_FanTimer_10
** Reported state: ON
** Actual state: OFF
** Timer: DownstairsThermostat_FanTimer_30   State: OFF
** Timer: DownstairsThermostat_FanTimer_60   State: OFF
** Timer: DownstairsThermostat_FanTimer_10   State: OFF

I’m baffled. Even more baffling, the fan does turn off at the expected time!

Anybody have thoughts on what I should be looking for?

Thanks!

2

openHAB commands are asynchronous. Your rule runs before it has taken effect.

Changed your rule trigger to received update to see the difference.
It takes a while to get your head round an event-driven system.

3

That was my first thought too but there is a second sleep in there. That should be plenty of time for the Item to update to the new state.

Look in events.log. What is the Item doing? Does it change to ON and then OFF right away or does it never turn OFF?

Do you have autoupdate=false configured on these Items? If so the Item will never update to ON in response to the command (useful when you get positive feedback from a device, not so useful for proxies or Expire timers like this).

4

Can you post your items?

5

Here’s the log immediately after I select “10 minutes” in the UI:

2020-04-21 12:15:20.275 thru 12:15:20.465
Item 'DownstairsThermostat_FanTimer_Control' received command 10
DownstairsThermostat_FanTimer_Control changed from OFF to 10
Item 'DownstairsThermostatFanMode' received command 1
DownstairsThermostatFanMode predicted to become 1
Item 'DownstairsThermostat_FanTimer_10' received command ON
DownstairsThermostatFanMode changed from 0 to 1
DownstairsThermostat_FanTimer_Status changed from  to Fan autoshutoff expected at 12:25.
DownstairsThermostatStatus changed from System: Idle.  Fan: Off.  Humidity: 46%.  Battery: 95%.   to System: Idle.  Fan: Off.  Humidity: 46%.  Battery: 95%.  Fan autoshutoff expected at 12:25.
DownstairsThermostatFanStateLiteral changed from Off to On
DownstairsThermostatFanState changed from 0 to 1

And here’s the items:

// MANUAL FAN TIMERS ----------------------------------------------------------------
// This item is expecting to receive a state of OFF, 10, 30, 60 or ON from a UI control.
String DownstairsThermostat_FanTimer_Control (TimedFanControls)
// These are the expiring items used to autoshutoff the fan.
String DownstairsThermostat_FanTimer_10 (ThermostatTimers) {expire="10m,command=OFF"}
String DownstairsThermostat_FanTimer_30 (ThermostatTimers) {expire="30m,command=OFF"}
String DownstairsThermostat_FanTimer_60 (ThermostatTimers) {expire="60m,command=OFF"}

String DownstairsThermostat_FanTimer_Status (DownstairsThermostat, ThermostatFanTimerStatus)

And if y’all are really willing to dig into it, here’s the relevant rules:


rule "Downstairs Thermostat Status String"
when
    Member of DownstairsThermostat changed
then
    var status = ""
    status += "System: "    + transform("MAP", "thermostatoperatingstate.map", DownstairsThermostatOperatingState.state.toString) + ".  "
    status += "Fan: "       + DownstairsThermostatFanStateLiteral.state + ".  "
    status += "Humidity: "  + DownstairsThermostatHumidity.state + "%.  "
    status += "Battery: "   + DownstairsThermostatBattery.state + "%.  "
    status += DownstairsThermostat_FanTimer_Status.state
    DownstairsThermostatStatus.postUpdate(status)
end

rule "ThermostatFanTimerStart"
when
    Member of TimedFanControls changed
then
    val thermostatName = triggeringItem.name.split("_").get(0)
    val fan = ThermostatFans.members.findFirst[ l | l.name == thermostatName + "FanMode" ]
    val time = triggeringItem.state

    if (fan === null){
        logInfo("Thermostats", "Attempt to start a timed fan cycled failed. No fan item found for {}", thermostatName)
        return;
    }

    var statusItem = ThermostatFanTimerStatus.members.findFirst[ l | l.name == thermostatName + "_FanTimer_Status" ]

    if (time == "OFF"){
        logInfo("Thermostats", "Turning off fan for {}.", thermostatName)
        fan.sendCommand(0);
        // clear the timer status string
        if (statusItem === null){
            logInfo("Thermostats", "Status item not found: {}{}", thermostatName, "_FanTimer_Status")
        } else {
            statusItem.postUpdate("")
        }
    } else if (time == "ON"){
        logInfo("Thermostats", "Turning on fan for {}.", thermostatName)
        fan.sendCommand(1);
        // clear the timer status string
        if (statusItem === null){
            logInfo("Thermostats", "Status item not found: {}{}", thermostatName, "_FanTimer_Status")
        } else {
            statusItem.postUpdate("")
        }
    } else {
        val timer = ThermostatTimers.members.findFirst[ l | l.name == thermostatName + "_FanTimer_" +  time]
        if (timer === null){
            logInfo("Thermostats", "Attempt to start a timed fan cycle failed. No {} minute timer found for {}", time, thermostatName)
            return;
        }
        logInfo("Thermostats", "Turning on {} (timed).", fan.name)
        fan.sendCommand(1);
        logInfo("Thermostats", "Tripping timer {}.", timer.name)
        timer.sendCommand(ON);

        ThermostatTimers
            .members
            .filter[i | i.name.contains(thermostatName) && ! i.name.contains(time.toString)]
            .forEach[ timerItem |
                if (timerItem.state.toString == "ON"){
                    logInfo("Thermostats", "Cancelling timer on {}", timerItem.name )
                    timerItem.sendCommand("OFF")
                } else {
                    logInfo("Thermostats", "Not cancelling timer on {} because it is {}", timerItem.name, timerItem.state.toString )
                }
            ]
    }
end

rule "ThermostatFanTimerTripped"
when
    Member of ThermostatTimers received command
then
    //logInfo("Thermostats", "ThermostatTimer {} received command {} and its state is {}", triggeringItem.name, receivedCommand.toString, triggeringItem.state.toString)
    if (receivedCommand.toString != "ON"){ return; }
    val minuteDelay = Integer.parseInt(triggeringItem.name.split("_").get(2))
    var shutoffTime = now.plusMinutes(minuteDelay)
    
    val thermostatName = triggeringItem.name.split("_").get(0)
    var statusItem = ThermostatFanTimerStatus.members.findFirst[ l | l.name == thermostatName + "_FanTimer_Status" ]
    logInfo("Thermostats", thermostatName + " fan autoshutoff expected at " + shutoffTime.toString("HH:mm"))
    statusItem.postUpdate("Fan autoshutoff expected at " + shutoffTime.toString("HH:mm") + ".")
end

rule "Trying to understand tripped timers"
when
    Member of ThermostatTimers received command
then
    Thread::sleep(1000) 
    logInfo("Thermostats", "** Reporting Thermostat: {}", triggeringItem.name)
    logInfo("Thermostats", "** Reported state: {}", receivedCommand)
    logInfo("Thermostats", "** Actual state: {}", triggeringItem.state.toString)
    ThermostatTimers
        .members
        .forEach[ i |
            logInfo("Thermostats", "** Timer: {}   State: {}", i.name, i.state.toString )
        ]
end

rule "ThermostatFanTimerElapsed"
when
    Member of ThermostatTimers received command OFF
then
    logInfo("Thermostats", "Fan timer {} elapsed.", triggeringItem.name)
    val thermostatName = triggeringItem.name.split("_").get(0)
    //val timerDuration = triggeringItem.name.split("_").get(2)
    val fan = ThermostatFans.members.findFirst[ l | l.name == thermostatName + "FanMode" ]
    if (fan === null){
        logInfo("Thermostats", "Fan timer elapsed, but fan not found for {}", thermostatName)
        return;
    }

    //logInfo("Thermostats", "{} fan timer elapsed after {} minutes.", thermostatName, timerDuration)
    fan.sendCommand(0);

    // Update the proxy control item so UI will look right
    val control = TimedFanControls.members.findFirst[ l | l.name == thermostatName + "_FanTimer_Control" ]
    if (control === null){
        logInfo("Thermostats", "Fan timer elapsed, but UI control not found for {}", thermostatName)
    } else {
        control.postUpdate("OFF");
    }
end
6

I should also mention that I have dummy items in my habpanel for the timer items, and they always say “OFF”.

7

Please don’t strip timestamps out of your log snippets.

You’ve not shown your Group Items, but let’s assume they are defined.

Okay, that should not be long enough to get any output from the rule in the first post.

Don’t know why that happened. Are you stripping out autoupdate predictions as well? Let’s guess so.

Meantime. DownstairsThermostat_FanTimer_Control is a member of TimedFanControls, so the rule “ThermostatFanTimerStart” runs due to the change.

That rule seeks Item DownstairsThermostat_FanMode
(I don’t like the use of a variable called time, that looks like a reserved word perhaps.)
That eventually gets commanded ‘1’

It also seeks an Item DownstairsThermostat_FanTimer_Status
and an ItemDownstairsThermostat_FanTimer_10
and that gets commanded ON.
Technically that’s an error, because it is a String type Item and you should command with a string “ON”, not an OnOffType ON.

Is that where we came in, DownstairsThermostat_FanTimer_10 gets a command which starts expire timing, but it’s not a valid command so it doesn’t get reflected in state?

8

It really is quite helpful to see the actual timestamps on the log statements, especially if timing issues are one of the suspected causes for the bad behavior. It’s not only to see what events follow which events, but how long between the individual events.

In short, never redact stuff. We’d rather see more stuff than we need than less that we need.

It’s interesting that these are String Items. Any reason you are not using a Switch? You appear to be using it like a Switch.

Why do you have dummy Items for the timers?

Honestly this smells a whole lot like an XY Problem. What are you really trying to achieve? This seems way more complex than necessary. As best as I can tell, this would probably be better implemented using a Rule Timer and a single Number Item. Send 10, 30, or 60 to the one Number Item which triggers a Rule to set a Timer for that amount of time.

1 Like
9

Point taken on the logs … I was trying to reduce clutter. Here’s another set of log entries, unredacted.

2020-04-21 13:41:33.655 [ome.event.ItemCommandEvent] - Item 'DownstairsThermostat_FanTimer_Control' received command 10
2020-04-21 13:41:33.657 [vent.ItemStateChangedEvent] - DownstairsThermostat_FanTimer_Control changed from OFF to 10
2020-04-21 13:41:33.671 [ome.event.ItemCommandEvent] - Item 'DownstairsThermostatFanMode' received command 1
2020-04-21 13:41:33.671 [nt.ItemStatePredictedEvent] - DownstairsThermostatFanMode predicted to become 1
2020-04-21 13:41:33.673 [ome.event.ItemCommandEvent] - Item 'DownstairsThermostat_FanTimer_10' received command ON
2020-04-21 13:41:33.679 [vent.ItemStateChangedEvent] - DownstairsThermostatFanMode changed from 0 to 1
2020-04-21 13:41:33.681 [vent.ItemStateChangedEvent] - DownstairsThermostat_FanTimer_Status changed from  to Fan autoshutoff expected at 13:51.
2020-04-21 13:41:33.685 [vent.ItemStateChangedEvent] - DownstairsThermostatStatus changed from System: Idle.  Fan: Off.  Humidity: 46%.  Battery: 95%.   to System: Idle.  Fan: Off.  Humidity: 46%.  Battery: 95%.  Fan autoshutoff expected at 13:51.
2020-04-21 13:41:33.821 [vent.ItemStateChangedEvent] - DownstairsThermostatFanStateLiteral changed from Off to On
2020-04-21 13:41:33.821 [vent.ItemStateChangedEvent] - DownstairsThermostatFanState changed from 0 to 1
2020-04-21 13:41:33.826 [vent.ItemStateChangedEvent] - DownstairsThermostatStatus changed from System: Idle.  Fan: Off.  Humidity: 46%.  Battery: 95%.  Fan autoshutoff expected at 13:51. to System: Idle.  Fan: On.  Humidity: 46%.  Battery: 95%.  Fan autoshutoff expected at 13:51.

No, the only thing I redacted was the time and source from the log entries. What do you mean by “autoupdate predictions”? The entries that say predicted to become...? I never really understood that.

Intended. This “Control” is a proxy for a user interface item. This is the rule that turns the fan on or off, and sets the autoshutoff timer if needed (along with some housekeeping like creating status strings, and “cancelling” any other timer that might be running).

Yes, the Honeywell thermostat uses a number of the fan mode: 0=Auto, 1=On, 2=Circulate (a predefined timed fan cycle). Agreed on the bad variable name.

and

I didn’t need to use Strings here; a Switch would have done. I patterned after a different use case where I needed to differentiate between a “rule” ON and a “device” ON, so I had rules posting a RESET to it which in turn tripped a rule to turn it on. Not as elegant as @rlkoshak’s design pattern for that purpose, which I use extensively (and extended to include motion sensors and manage autoshutoff).

As far as ON vs "ON" issue, I realize I’ve been inconsistent. In my head, things like ON and OFF are just enumerations representing strings. My c# thinking, there, and apparently wrong in this context.

And we have a winner! That’s at least part of my problem … changing all the ON/OFF to "ON"/"OFF" is having an effect! I need to clean up some other stuff, but that was very helpful!

Just while troubleshooting, so I could see the state of those timer items.

Yes, this become more complex than I expected. I’ve had problems using timers in other rules. Not really understanding the scope or threading of those timers, I wound up with all kinds of unexpected results when I tried “resetting” them, or turning them “off”. After reading and using the “Proxy Item” approach in your Manual Trigger Detection design pattern, I became enamored of the approach of allowing a proliferation of items to overcome complex rules code. I asked myself why I couldn’t do that for this use case, but I wound up with complex rules code anyway. I guess I need to sharpen my understanding of timers and refactor this.

Thanks to you both for the thoughtful responses!

10

If you’re sticking with DSL rules for now, you may be interested in -

11

Subtle. I went into this using the Rules DSL because

  1. I saw more examples out there using the DSL than python, and I’m a Google-dependent developer, and
  2. I suck at python.

The latter problem being borne of the same laziness that makes me a Googler. I’ve learned many, many languages to greater or lesser degrees over the decades since I started with COBOL. Right now, my highest proficiency language is .net core c#, and to a lesser degree, the rest of a .net world web development stack. Maybe I need to move along here and get my head around this newfangled python stuff :slight_smile:.

Thanks for the link … I’ll read it.

12

Now I recall that autoupdate does not log it’s predictions unless the Item concerned has a binding linked, so that’s sorted.

This might help

13

There is a feature of OH called autoupdate. This is a sort of pseudo-binding that, when configured as true on an Item (the default) will take any command sent to that Item and attempt to predict what state the Item will become in response to the command. It has to predict because not all commands become a state. For example, consider a Dimmer. You might sendCommand(INCREASE) and autoupdate may predict the new state will become 75. autoupdate is required when you have devices that do not report back when you’ve commanded them to do something. For Expire based bindings, you would want to keep autoupdate set to true because I think it’s the update that causes the Expire binding timer to kick off. Sending a command with autoupdate set to false means the Item never receives and update.

The lack of the “autoupdate predicts” log statements would indicate that autoupdate=false, though that doesn’t appear to be the case given your Item definitions.

When you call createTimer, a “handle” on the Timer is returned. You can store that as a global variable and thus access a Timer created in another Rule or a previous run of the same Rule. Then you can use the variable to cancel or reschedule the Timer. If you have generic Rules, you can use a Map<String, Timer> to store the Timers in a HashMap and therefore access a timer based on triggeringItem.name, for example.

As for threading, Timers do not consume any threads while waiting to run. When they trigger, they consume a thread while the code is executing from the Quartz Timer thread pool. There are 10 threads in this pool so you can have up to ten Timer actively running at the same time.

I converted that to a Python library as well. See Initial submission of a Countdown Timer implementation by rkoshak · Pull Request #237 · openhab-scripters/openhab-helper-libraries · GitHub. It doesn’t use Expire binding but it does all the timer management for you anyway so that doesn’t really matter. Just call the function with the amount of time, the Item you want to get updated as it counts down, and the lambda to call when the timer goes off.

How are you with JavaScript or Groovy? Both of those are also supported as well. Though you don’t have to be a Python coder to write Python OH Rules. Very rarely do we need to go that deep into specifics of the language. And I believe I’ve written Python examples for all of the Design Patterns, at least those that are applicable.

I didn’t know that. That’s good information to know. But the Expire binding is linked, right?

14

I’ve been told my javascript looks like it was written like this: https://gifer.com/embed/DwzE

Can you point me to an example where you’ve used that from openHab? You may be assuming too much about my familiarity with all this.

Again, thanks!
Andy

15

You have to install Python and then copy the code at that link to $OH_CONF/. Then look at the test code which shows how to use it.

16

I’ve re-discovered the suppressed autoupdate prediction messages at least three times now and forgotten until the next time …

In this case, the Item was DownstairsThermostat_FanTimer_Control which is not linked to expire, or anything else.
I am not entirely sure if autoupdate recognises v1.x links for this suppression purpose though.

1 Like
17

Thank! found documentation page references Jython 2.7.0. Should I do that first? I’d like to get into this to have a better devex for OH, but I’m afraid I’m out over my skis.

Note that I’m on OH 2.5.2 on Windoze…

Thanks.

18

You are better off starting with the link I posted above in post 15. Following those instructions will install Jython and the helper libraries that makes writing OH Rules much simpler.

19

Good to hear … thanks!