OH 3.4 history.changedSince() always returns true

If you’ve verified that there is no entry in the database in the time passed to changedSince it’s probably worth filing an issue.

You can easily set up an easy test to verify the behavior. Create a Test Item that gets saved to InfluxDB.

var item = items.getItem('Test');
item.postUpdate( (item.state == "ON") ? "OFF" : "ON") );
setTimeout( () => {
  console.log('changedSince true: ' + items.getItem('Test').history.changedSince(time.toZDT('PT-1M'));
  console.log('changedSince false: ' + items.getItem('Test').history.changedSince(time.toZDT('PT-30S')); 
}, time.toZDT('PTM50S').getMillisFromNow());

You can set that in a Script and manually trigger it, or since it’s a temporary rule use the Scratchpad.

That will toggle the Test Switch Item, and set a timer for 50 seconds from now to call changedSince with a one minute ago. We know that the Item changed 50 seconds ago so changedSince from one minute ago should return true, and 30 seconds ago should return false.

However, is the database where you are looking for the data configured as the default persistence? If not, you’re querying the wrong database. That still doesn’t explain the behavior but it does mean you might be looking in the wrong place for the records.

1 Like

hmm…

I’ll check this but since all my other calls to history are working e.g. history.previousState() I think my influxdb is up and running without errors. influxdb is my default persistence service.

we will see if this is really a serious bug…

thanks :wink:

I changed your code because there was an error using your time variables…

instead I used this:

var item = items.getItem('Test');
var minute = time.ZonedDateTime.now().minusMinutes(1);
var seconds = time.ZonedDateTime.now().minusSeconds(30);
item.postUpdate( (item.state == "ON") ? "OFF" : "ON");
setTimeout( () => {
  console.log('changedSince true: ' + item.history.changedSince(minute));
  console.log('changedSince false: ' + item.history.changedSince(seconds)); 
}, 50000);

and here are the log entries:

2023-02-01 22:19:08.701 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'Test' changed from OFF to ON

==> /var/log/openhab/openhab.log <==
2023-02-01 22:19:58.776 [INFO ] [automation.script.ui.TestChangeSince] - changedSince true: true
2023-02-01 22:19:58.796 [INFO ] [automation.script.ui.TestChangeSince] - changedSince false: true

my persistence is set to store every item, it uses the * wildcard.

seems like the changedSince is broken somehow…

would be nice if you or someone could test this on their installation, to be sure this not only occurs on my system…

Yes, that was a typo. It should be PT50S. It’s an ISO8601 duration string that time.toZDT() can convert to a ZonedDateTime. I also had some missmatched parens.

I only use rrd4j so I’m not sure the test would work the same. But this corrected version produces…

var item = items.getItem('TestSwitch');
item.postUpdate( ((item.state == "ON") ? "OFF" : "ON") );
setTimeout( () => {
  console.log('changedSince true: ' + items.getItem('TestSwitch').history.changedSince(time.toZDT('PT-1M')));
  console.log('changedSince false: ' + items.getItem('TestSwitch').history.changedSince(time.toZDT('PT-30S'))); 
}, time.toZDT('PT50S').getMillisFromNow());
2023-02-01 14:41:10.148 [WARN ] [ore.internal.scheduler.SchedulerImpl] - Scheduled job 'org.openhab.automation.script.ui.scratchpad.timeout.1' failed and stopped
org.graalvm.polyglot.PolyglotException: Java heap space
        at org.rrd4j.core.Archive.fetchData(Archive.java:303) ~[?:?]
        at org.rrd4j.core.RrdDb.fetchData(RrdDb.java:986) ~[?:?]
        at org.rrd4j.core.FetchRequest.fetchData(FetchRequest.java:163) ~[?:?]
        at org.openhab.persistence.rrd4j.internal.RRD4jPersistenceService.query(RRD4jPersistenceService.java:330) ~[?:?]
        at org.openhab.core.persistence.extensions.PersistenceExtensions.getAllStatesBetween(PersistenceExtensions.java:1263) ~[bundleFile:?]
        at org.openhab.core.persistence.extensions.PersistenceExtensions.internalChanged(PersistenceExtensions.java:307) ~[bundleFile:?]
        at org.openhab.core.persistence.extensions.PersistenceExtensions.changedSince(PersistenceExtensions.java:286) ~[bundleFile:?]
        at org.openhab.core.persistence.extensions.PersistenceExtensions.changedSince(PersistenceExtensions.java:259) ~[bundleFile:?]
        at java.lang.invoke.DirectMethodHandle$Holder.invokeStatic(DirectMethodHandle$Holder) ~[?:?]
        at java.lang.invoke.LambdaForm$MH/0x00000001015e0c00.invoke(LambdaForm$MH) ~[?:?]
        at java.lang.invoke.LambdaForm$MH/0x0000000100d41400.invokeExact_MT(LambdaForm$MH) ~[?:?]
        at <js>.changedSince(/openhab/conf/automation/js/node_modules/openhab/items/item-history.js:68) ~[?:?]
        at <js>.:=>(<eval>:7) ~[?:?]

:scream:

After a restart I get the same thing. There appears to be a bug in rrd4j.

Note: I’m on the 4.0 SNAPSHOT

I tried mapdb…

2023-02-01 14:51:41.812 [INFO ] [nhab.automation.script.ui.scratchpad] - changedSince true: true
2023-02-01 14:51:41.817 [INFO ] [nhab.automation.script.ui.scratchpad] - changedSince false: true

So this looks to be a more universal problem.

Thanks a lot, good to know… can you tell me where exactly to file an issue for this? I never done this before… is there a github page or something?

See How to file an Issue.

This needs to be filed on core. Reference this thread and mention that it happens in 3.4.1 and the 4.0 snapshot.

1 Like

Thanks :wink:

Ooops looks a bit overwhelming should I look for issues in openhab-js or is it better to look in openhab-core??

No, this is definitely a problem in core. There isn’t an issue on this (I follow the issues in core fairly closely).

thanks i use core…

I don’t believe it’s a bug in core.

  1. Core has its unit test for this feature openhab-core/PersistenceExtensionsTest.java at a50a0886e89d47c1fcfd80dad6f80496a31dc1b4 · openhab/openhab-core · GitHub

  2. I tested this in jruby too:

SwitchItem1.toggle
SwitchItem1.persist(:influxdb)
after 30.seconds do
  logger.info "Changed since 40s: #{SwitchItem1.changed_since?(40.seconds.ago, :influxdb)}"
  logger.info "Changed since 20s: #{SwitchItem1.changed_since?(20.seconds.ago, :influxdb)}"
end

Result:

12:15:05.460 [INFO ] [enhab.automation.jrubyscripting.test3] - Changed since 40s: true
12:15:05.462 [INFO ] [enhab.automation.jrubyscripting.test3] - Changed since 20s: false
  1. I doubt that this is even a bug in jsscripting, as I’d imagine it would just be a simple call to core from jsscripting library.

Tried above snippet with this fix applied (snapshot #3299) and got

2023-02-02 09:45:15.395 [WARN ] [nhab.automation.script.ui.8e9939533b] - changedSince true: true
2023-02-02 09:45:15.406 [WARN ] [nhab.automation.script.ui.8e9939533b] - changedSince false: false

The reason why I think it’s a problem in core is @Dan saw the behavior with InfluxDB and I saw it with MapDB which implies something is going on in the Persistence code, not the add-on code.

Yes, it doesn’t do anything itself but wrap the call to the Java Persistence Actions. This is another reason why I identified core as the source.

The exception went away for me now with rrd4j on #3299 :partying_face: but I’m not getting

2023-02-02 11:53:04.985 [INFO ] [nhab.automation.script.ui.scratchpad] - changedSince true: false
2023-02-02 11:53:05.102 [INFO ] [nhab.automation.script.ui.scratchpad] - changedSince false: false

???

Note, I am passing the DB I want to query now so the code is

var item = items.getItem('TestSwitch');
item.postUpdate( ((item.state == "ON") ? "OFF" : "ON") );
setTimeout( () => {
  console.log('changedSince true: ' + items.getItem('TestSwitch').history.changedSince(time.toZDT('PT-1M'), 'rrd4j'));
  console.log('changedSince false: ' + items.getItem('TestSwitch').history.changedSince(time.toZDT('PT-30S'), 'rrd4j')); 
}, time.toZDT('PT50S').getMillisFromNow());

MapDB gives

2023-02-02 11:58:46.326 [INFO ] [nhab.automation.script.ui.scratchpad] - changedSince true: true
2023-02-02 11:58:46.332 [INFO ] [nhab.automation.script.ui.scratchpad] - changedSince false: true

I think MapDB can’t properly handle changedSince because it does only store one value.

I’m not sure if the binning of rrd4j makes changedSince unusable.

For InfluxDB it works perfectly fine for me. All other services should work.

But it knows when that one value was stored. If it assumes an everyChange strategy, which I think is the default, than if the entry is before the passed in time changedSince would be false and if after changedSince would be true.

That would be odd I think. Surely the binning would impact the ability to see the records between now and the passed in time to see if the state changed in that time? Unless you are going back a long way (days or more) the binning shouldn’t come into play. IIRC the first compression happens at least one day, maybe three days. So it should work at least for short times back (I’m using one minute above).

There was also a bug which should be fixed by Fix wrong .historicState call in .changedSince by J-N-K · Pull Request #3348 · openhab/openhab-core · GitHub.

InfluxDB heaves the same as before (correct).

MapDB now returns false in both cases, which is also the correct behavior in my opinion. We simply can’t know what the state before the stored value is, it could well be the same as the stored valued. Also MapDB doesn’t honor the query filter, it just returns the only value available.

Given that argument, lastUpdate in rrd4j is wrong because we can’t know if the most recent value in the database is because of an update or everyMinute.

Though I would argue that lastUpdate is broken across the board because we can’t know what strategies are configured and if there is any time based persistence we can’t know what we are getting.

To me, to make lastUpdate usable we have to make the same kinda of assumptions about the persistence strategies deployed that you say disqualify changedSince from working for MapDB.

I can buy the filter arrangement as meaning that MapDB can’t conform to the expected API (I guess, im not sure what you really mean by doesn’t honor the query filter and how that relates). But then shouldn’t it return null or throw an error instead of returning a misleading answer?

Last update, previousState and changedSince should just be taken out of persistence and be embedded into GenericItem class

That just moves the problem to restoreOnStartup, but the problem remains, unless we are OK with breaking the use case where we care about updates on very slowly updated Items (once a week for example).

@JimT

I think it should be just be made clear that not all extension methods are useful on all persistence services. averageSince doesn’t make sense for MapDB.

@rlkoshak

From my understanding rrd4j always reduces data. We define as default:

// 1. granularity of 10s for the last hour
// 2. granularity of 1m for the last week
// 3. granularity of 15m for the last year
// 4. granularity of 1h for the last 5 years
// 5. granularity of 1d for the last 10 years

So if you update every second, and request now-2s every second, you’ll already see the effect (unfortunately my test rule only did that for about 10s and then ran unto an IllegalMonitorStateException which is probably a bug in rrd4j).