changedSince and so on does not work...have to use timers instead

Hello evryone,

as the topic says i cant use the persistance extensions.
For example i want a reminder if i forget to turn off my Sonos.

rule "Sonos Betriebsmeldung"
when
Time cron "0 */1 * * * ?"
then
if(!sonosOben_phy_State.changedSince(now.minusMinutes(5)) && sonosOben_phy_State.state != “STOPPED”) {
sendTelegram(“wf_prio_bot”, “ChangedSince funktioniert eh!” + sonosOben_phy_State.lastUpdate)
}
end

This does not work.
I already get a telegram at THE FIRST full minute and after that every minute when sonos is playing (or transitioning). And instead of a timestamp i get just “null” when i add sonosOben_phy_State.lastUpdate to the telegram.
Maybe i have to import something? I use OH2

Did you install persistence services? Did you setup a default persistence service? If using a persistence service other than the default one, you have to use

sonosOben_phy_State.changedSince(now.minusMinutes(5),"<name-of-persistence-service>")
1 Like

Hello Udo and thank you for your help.

I am using rrd4j for an chart (and for the sonos-tries i wrote about above) and mapdb for storing setting-values, which i need to get saved and restored after startup.
Both got installed using paperUI and for both a *.persist file exist:

rrd4j.persist:
Strategies {
everyMinute : "0 * * * * ?"
everyHour : "0 0 * * * ?"
everyDay : "0 0 0 * * ?"
default = everyChange
}

Items {
persistrr_minute* : strategy = everyMinute, restoreOnStartup
persistrr_change* : strategy = everyChange, restoreOnStartup

}

mapdb.persist:
Strategies {
everyMinute : "0 * * * * ?"
everyHour : "0 0 * * * ?"
everyDay : "0 0 0 * * ?"
default = everyChange
}

Items {
mapdb_change* : strategy = everyChange, restoreOnStartup
}

As you see i do not store every item/state, because i want to hold write access on the raspberry-SD down to a minimum and hope so to increase the SDs lifetime.

There also exists a main.items file which declares the persist-groups you see above.
And the sonos-item from the example was in the persistrr_change group.

The line handling the default service is disabled within runtime.cfg

That brings me to the question, if every persistance service allows to work with changedSince and so on?
Is there a recommended service for that use case?

Thanks

I just came across this thread as I cant get the changedSince to work either. But to answer asdfasf’s question first.
mapdb does not store historical values but only the last value. In order to use changeSince you have to use a persistance method that stores historical values (e.g. rrd4j or mysql).

Now the error description I came across today when debugging the changedSince function:

  • running OH 1.8.3

  • created a test_switch

  • configured rrd4j persistance for everyChange & everyMinute

  • cross checked that persistance is working by checking the graph on: http://openhab:8080/chart?items=test_switch&period=h&h=600&w=1000

  • wrote a small rule:

    rule "test changedSince in rule"
    when
    Item test_switch changed
    then
    Thread::sleep(500) // give persistence time to populate
    if(!test_switch.changedSince(now.minusSeconds(60), “rrd4j”)){
    logInfo(“test_switch”, “Last change GREATER 60 seconds”)
    } else {
    logInfo(“test_switch”, “last change SMALLER 60 seconds”)
    }
    end

ran tail on events.log & openhab.log which gave me the following output:

tail -f events.log openhab.log |grep test_switch
2016-12-29 13:56:19 - test_switch state updated to ON
2016-12-29 13:56:30 - test_switch state updated to OFF
2016-12-29 13:56:31.221 [INFO ] [enhab.model.script.test_switch] - last change SMALLER 60 seconds
2016-12-29 13:57:46 - test_switch state updated to ON
2016-12-29 13:57:46.613 [INFO ] [enhab.model.script.test_switch] - last change SMALLER 60 seconds
2016-12-29 14:05:12 - test_switch state updated to OFF
2016-12-29 14:05:12.794 [INFO ] [enhab.model.script.test_switch] - last change SMALLER 60 seconds

Same when sending commands instead of updates:

2016-12-29 14:16:51 - test_switch received command ON
2016-12-29 14:16:52.137 [INFO ] [enhab.model.script.test_switch] - last change SMALLER 60 seconds
2016-12-29 14:17:02 - test_switch received command OFF
2016-12-29 14:17:03.144 [INFO ] [enhab.model.script.test_switch] - last change SMALLER 60 seconds
2016-12-29 14:19:21 - test_switch received command ON
2016-12-29 14:19:22.007 [INFO ] [enhab.model.script.test_switch] - last change SMALLER 60 seconds

As logfile clearly states my rule always access the else condition while timestamps of events.log clearly state it should enter the other case.
Any idea or input how to get this working is appreciated.

Thanks much
Sebastian

Just re-tested the same on my OH2 setup with exactly the same behavior. I cant imagine that this is a bug. Must be something I’ve done wrong in my setup. Anyone any thought on what might be the issue?
Thanks much.

Me again. I’ve updated the rule to do some more debug output and changedSince somehow always exits with true no matter how long the real changedSince time is.
Here’s the rule I’m running right now:

rule "test changedSince in rule"
    when
        Item test_switch changed
    then
        Thread::sleep(500) // give persistence time to populate
        logInfo("test_switch", "changedSince returns  : " + test_switch.changedSince(now.minusMinutes(1), "rrd4j"))
        logInfo("test_switch", "historicState returns : " + test_switch.historicState(now.minusMinutes(1), "rrd4j"))
        logInfo("test_switch", "lastUpdate returns    : " + test_switch.lastUpdate)
        if(test_switch.changedSince(now.minusMinutes(1), "rrd4j")){
            logInfo("test_switch", "Function returns "  + test_switch.changedSince(now.minusMinutes(1), "rrd4j") + " thus last change SMALLER 60 seconds")
        } else {
            logInfo("test_switch", "Function returns "  + test_switch.changedSince(now.minusMinutes(1), "rrd4j") + " thus last change GREATER 60 seconds")
        }
    end

and the corresponding log entries when tailing events.log & openhab.log.

2017-01-03 13:32:49 - test_switch state updated to ON
2017-01-03 13:32:50.336 [INFO ] [enhab.model.script.test_switch] - changedSince returns  : true
2017-01-03 13:32:50.474 [INFO ] [enhab.model.script.test_switch] - historicState returns : 03.01.2017 13:31:50: test_switch -> OFF
2017-01-03 13:32:50.570 [INFO ] [enhab.model.script.test_switch] - lastUpdate returns    : Tue Jan 03 13:32:49 CET 2017
2017-01-03 13:32:50.777 [INFO ] [enhab.model.script.test_switch] - Function returns true thus last change SMALLER 60 seconds
2017-01-03 13:33:00 - test_switch state updated to OFF
2017-01-03 13:33:01.492 [INFO ] [enhab.model.script.test_switch] - changedSince returns  : true
2017-01-03 13:33:01.496 [INFO ] [enhab.model.script.test_switch] - historicState returns : 03.01.2017 13:32:01: test_switch -> OFF
2017-01-03 13:33:01.498 [INFO ] [enhab.model.script.test_switch] - lastUpdate returns    : Tue Jan 03 13:33:00 CET 2017
2017-01-03 13:33:01.508 [INFO ] [enhab.model.script.test_switch] - Function returns true thus last change SMALLER 60 seconds
2017-01-03 13:34:06 - test_switch state updated to ON
2017-01-03 13:34:07.066 [INFO ] [enhab.model.script.test_switch] - changedSince returns  : true
2017-01-03 13:34:07.070 [INFO ] [enhab.model.script.test_switch] - historicState returns : 03.01.2017 13:33:07: test_switch -> OFF
2017-01-03 13:34:07.072 [INFO ] [enhab.model.script.test_switch] - lastUpdate returns    : Tue Jan 03 13:34:06 CET 2017
2017-01-03 13:34:07.082 [INFO ] [enhab.model.script.test_switch] - Function returns true thus last change SMALLER 60 seconds

Any input on getting this setup correctly is appreciated.
Thanks much.

Seems like rrd4j is not meant for historic calculations. For testing purpose I installed and configured MySQL persistance and it worked right out of the box. Log snippet:

2017-01-03 14:51:53 - test_switch received command OFF
2017-01-03 14:51:54.228 [INFO ] [enhab.model.script.test_switch] - changedSince returns  : true
2017-01-03 14:51:54.238 [INFO ] [enhab.model.script.test_switch] - historicState returns : 03.01.2017 14:49:41: test_switch -> OFF
2017-01-03 14:51:54.242 [INFO ] [enhab.model.script.test_switch] - lastUpdate returns    : Tue Jan 03 14:51:53 CET 2017
2017-01-03 14:51:54.259 [INFO ] [enhab.model.script.test_switch] - Function returns true thus last change SMALLER 60 seconds



2017-01-03 14:52:59 - test_switch received command ON
2017-01-03 14:53:00.071 [INFO ] [enhab.model.script.test_switch] - changedSince returns  : false
2017-01-03 14:53:00.304 [INFO ] [enhab.model.script.test_switch] - historicState returns : 03.01.2017 14:51:53: test_switch -> OFF
2017-01-03 14:53:00.398 [INFO ] [enhab.model.script.test_switch] - lastUpdate returns    : Tue Jan 03 14:52:59 CET 2017
2017-01-03 14:53:00.588 [INFO ] [enhab.model.script.test_switch] - Function returns false thus last change GREATER 60 seconds



2017-01-03 14:54:34 - test_switch received command OFF
2017-01-03 14:54:34.701 [INFO ] [enhab.model.script.test_switch] - changedSince returns  : false
2017-01-03 14:54:34.714 [INFO ] [enhab.model.script.test_switch] - historicState returns : 03.01.2017 14:52:59: test_switch -> ON
2017-01-03 14:54:34.718 [INFO ] [enhab.model.script.test_switch] - lastUpdate returns    : Tue Jan 03 14:54:34 CET 2017
2017-01-03 14:54:34.741 [INFO ] [enhab.model.script.test_switch] - Function returns false thus last change GREATER 60 seconds


2017-01-03 14:54:48 - test_switch received command ON
2017-01-03 14:54:49.249 [INFO ] [enhab.model.script.test_switch] - changedSince returns  : true
2017-01-03 14:54:49.260 [INFO ] [enhab.model.script.test_switch] - historicState returns : 03.01.2017 14:52:59: test_switch -> ON
2017-01-03 14:54:49.264 [INFO ] [enhab.model.script.test_switch] - lastUpdate returns    : Tue Jan 03 14:54:48 CET 2017
2017-01-03 14:54:49.559 [INFO ] [enhab.model.script.test_switch] - Function returns true thus last change SMALLER 60 seconds

Sorry for the monologue here. I just migrated to influx.persistance since I want to do some nice graphing with Grafana and the problem is back again. What I just saw is that RRD4J and Influx store 0 & 1 in the database while MySQL stores ON & OFF. Might that be a the reason for invalid changedSince return values?

here’s some output I gathered with InfluxDB

> select * from test_switch where time > 1483534699589000000
name: test_switch
time                    value
----                    -----
1483534740002000000     0
1483534740003000000     0
1483534768471000000     1
1483534768472000000     1
1483534800002000000     1
1483534800003000000     1
1483534860002000000     1
1483534920002000000     1
1483534920003000000     1
1483534980003000000     1
1483534980004000000     1
1483535015087000000     0

Values are properly persisted as soon as switch item changes.
And again the tail -f on events.log and openhab.log

/var/log/openhab$ tail -f openhab.log events.log |grep test_switch
2017-01-04 13:57:22 - test_switch received command ON
2017-01-04 13:57:23.370 [INFO ] [enhab.model.script.test_switch] - changedSince returns  : false
2017-01-04 13:57:23.506 [INFO ] [enhab.model.script.test_switch] - historicState returns : null
2017-01-04 13:57:23.585 [INFO ] [enhab.model.script.test_switch] - lastUpdate returns    : Wed Jan 04 13:57:22 CET 2017
2017-01-04 13:57:23.800 [INFO ] [enhab.model.script.test_switch] - Function returns false thus last change GREATER 60 seconds
2017-01-04 13:57:30 - test_switch received command OFF
2017-01-04 13:57:30.941 [INFO ] [enhab.model.script.test_switch] - changedSince returns  : false
2017-01-04 13:57:30.944 [INFO ] [enhab.model.script.test_switch] - historicState returns : null
2017-01-04 13:57:30.946 [INFO ] [enhab.model.script.test_switch] - lastUpdate returns    : Wed Jan 04 13:57:30 CET 2017
2017-01-04 13:57:30.954 [INFO ] [enhab.model.script.test_switch] - Function returns false thus last change GREATER 60 seconds
2017-01-04 13:57:43 - test_switch received command ON
2017-01-04 13:57:44.452 [INFO ] [enhab.model.script.test_switch] - changedSince returns  : false
2017-01-04 13:57:44.455 [INFO ] [enhab.model.script.test_switch] - historicState returns : null
2017-01-04 13:57:44.456 [INFO ] [enhab.model.script.test_switch] - lastUpdate returns    : Wed Jan 04 13:57:43 CET 2017
2017-01-04 13:57:44.462 [INFO ] [enhab.model.script.test_switch] - Function returns false thus last change GREATER 60 seconds
2017-01-04 13:58:19 - test_switch received command OFF
2017-01-04 13:58:20.099 [INFO ] [enhab.model.script.test_switch] - changedSince returns  : false
2017-01-04 13:58:20.103 [INFO ] [enhab.model.script.test_switch] - historicState returns : null
2017-01-04 13:58:20.105 [INFO ] [enhab.model.script.test_switch] - lastUpdate returns    : Wed Jan 04 13:58:19 CET 2017
2017-01-04 13:58:20.112 [INFO ] [enhab.model.script.test_switch] - Function returns false thus last change GREATER 60 seconds
2017-01-04 13:59:28 - test_switch received command ON
2017-01-04 13:59:28.981 [INFO ] [enhab.model.script.test_switch] - changedSince returns  : false
2017-01-04 13:59:28.985 [INFO ] [enhab.model.script.test_switch] - historicState returns : null
2017-01-04 13:59:28.987 [INFO ] [enhab.model.script.test_switch] - lastUpdate returns    : Wed Jan 04 13:59:28 CET 2017
2017-01-04 13:59:28.999 [INFO ] [enhab.model.script.test_switch] - Function returns false thus last change GREATER 60 seconds
2017-01-04 14:03:35 - test_switch received command OFF
2017-01-04 14:03:35.599 [INFO ] [enhab.model.script.test_switch] - changedSince returns  : false
2017-01-04 14:03:35.602 [INFO ] [enhab.model.script.test_switch] - historicState returns : null
2017-01-04 14:03:35.604 [INFO ] [enhab.model.script.test_switch] - lastUpdate returns    : Wed Jan 04 14:03:35 CET 2017
2017-01-04 14:03:35.611 [INFO ] [enhab.model.script.test_switch] - Function returns false thus last change GREATER 60 seconds

For comparrison the MySQL storage:
mysql> select ItemId from Items where ItemName = ‘test_switch’;
±-------+
| ItemId |
±-------+
| 39 |
±-------+
mysql> select * from Item39;
±--------------------±------+
| Time | Value |
±--------------------±------+

| 2017-01-03 15:00:42 | OFF |
| 2017-01-04 13:57:22 | ON |
| 2017-01-04 13:57:30 | OFF |
| 2017-01-04 13:57:43 | ON |
| 2017-01-04 13:58:19 | OFF |
| 2017-01-04 13:59:28 | ON |
| 2017-01-04 14:03:35 | OFF |
±--------------------±------+

I filed Github issue 4961 to have this behavior cross checked.