item.previousState(false) does not reflect the state before current state

[HomeOfSourceCode]

As I understood, item.previousState(false) should reflect the state before current state of an item regarding to persistance database. It is clear, that this dos not work with

• MAPDB (no history values stored)
• RRD4J (because older values are commulated, maybe no correct timestamp too)

But should work with any SQL-Database if persistance is configured as strategy = everyChange, everyUpdate

I made some tests. It is working as expected with item.previousState(true) but not working with item.previousState(false)

My test szenario:

Switch          swSwitch05
Switch          swSwitch10

My rules:

rule "swSwitch05 pressed"
    when
        Item swSwitch05 changed to ON
    then
        swSwitch10.postUpdate(ON)
        swSwitch05.postUpdate(OFF)
end

rule "test of previousState"
    when 
        Item swSwitch10 received update
    then
        Thread::sleep(100)
        logInfo("Logger","swSwitch10 State              :"+swSwitch10.state.toString)
        logInfo("Logger","swSwitch10 previousState-true :"+swSwitch10.previousState(true,"jdbc").state.toString+": "+swSwitch10.previousState(true,"jdbc").timestamp.toString)
        logInfo("Logger","swSwitch10 previousState-false:"+swSwitch10.previousState(false,"jdbc").state.toString+": "+swSwitch10.previousState(false,"jdbc").timestamp.toString)
end

If I change swSwitch10 from OFF to ON:

2018-01-25 12:02:23.168 [INFO ] [clipse.smarthome.model.script.Logger] - swSwitch10 State              :ON
2018-01-25 12:02:23.168 [INFO ] [clipse.smarthome.model.script.Logger] - swSwitch10 previousState-true :OFF: Thu Jan 25 11:59:16 CET 2018
2018-01-25 12:02:23.168 [INFO ] [clipse.smarthome.model.script.Logger] - swSwitch10 previousState-false:ON: Thu Jan 25 12:02:23 CET 2018

This is wrong: item.previousState(false) should be swSwitch10 OFF with timestamp Thu Jan 25 11:59:16 CET 2018. But is the same as current state of item.

If I update swSwitch10 from ON to ON:

2018-01-25 12:05:10.575 [INFO ] [clipse.smarthome.model.script.Logger] - swSwitch10 State              :ON
2018-01-25 12:05:10.575 [INFO ] [clipse.smarthome.model.script.Logger] - swSwitch10 previousState-true :OFF: Thu Jan 25 11:59:16 CET 2018
2018-01-25 12:05:10.575 [INFO ] [clipse.smarthome.model.script.Logger] - swSwitch10 previousState-false:ON: Thu Jan 25 12:05:10 CET 2018

This is wrong too.

For me it looks like item.previousState(false) is item.state on every time?

[sjsf]

Looks like the PersistenceExtensions always takes the "last persisted state" into account - which most likely will reflect the "current" state of the item. Clearly not what you would have expected from the method name...

To me this looks like a bug and the "most recent" entry should be discarded for that matter - @kaikreuzer please object if you remember differently.

[kaikreuzer]

I agree, looks like a bug.

[htreu]

The root cause here is the non deterministic behaviour of the rule engine and the persistence manager: Both RuleEngineImpl and PersistenceManagerImpl implement the StateChangeListener interface and thus will be informed about item changes (the RuleEngine triggering rules for this item, the PersistenceManager persisting the current item state). The order in which both components get called is not deterministic though. When the script item.previousState is executed the persistence may or may not have happened.

In order to resolve this bug there are two possible resolutions:

1. Order the StateChangeListeners in GenericItem. This will introduce a wonky order dependency on both components which has to be documented vice versa and may break easily.
2. Remember the state changed and state updated times in the item (transiently) and use these timestamps when persisting the current state in the persistence service. When calculating previousState this timestamp can be used to filter out the current state (if it is already persisted, the timestamps on item and 1st result from the persistence service match).

[sjsf]

The second option looks more robust to me.

Plus: it would allow any item to directly answer the question of when it was last updated itself, without the need to query (or use) a persistence service. Nice side-effect, IMHO.