historicState not working with RRD4J

Hi, i wanted to fine tune my rule which is controlling my lights when im starting/pause/stop a movie on plex with the historicState of items however im getting the below error.

any tips what im doing wrong here?

persistence is working and item S_LR_LIGHT_Ceiling_S is showing on HABpanel as ON for the last couple of hours

errors

2018-02-19 00:38:46.841 [ERROR] [ntime.internal.engine.RuleEngineImpl] - Rule 'Lights dimmed when playing': cannot invoke method public abstract org.eclipse.smarthome.core.types.State org.eclipse.smarthome.core.persistence.HistoricItem.getState() on null

2018-02-19 00:49:15.659 [ERROR] [ntime.internal.engine.RuleEngineImpl] - Rule 'Lights on when paused': cannot invoke method public abstract org.eclipse.smarthome.core.types.State org.eclipse.smarthome.core.persistence.HistoricItem.getState() on null

same for rule “Lights dimmed when stopped”

rule

import org.joda.time.DateTime
import org.openhab.core.persistence.*
import org.openhab.core.library.types.*
var DateTime time_play_started

rule "Lights dimmed when playing"
when
	Item PlexTVStatus changed to Playing
then
	time_play_started = now
	logInfo("plex","Start Time:" + time_play_started + S_LR_LIGHT_Ceiling_S.historicState(time_play_started).state)
	if (Movie_Mode.state == ON)
		{if (S_LR_LIGHT_Ceiling_S.state == ON) {sendCommand(S_LR_LIGHT_Ceiling_D, 30)}
	}
end

rule "Lights on when paused"
when
    Item PlexTVStatus changed to Paused
then
	if ((Movie_Mode.state == ON) && (S_LR_LIGHT_Ceiling_S.historicState(time_play_started).state == ON))
        sendCommand(S_LR_LIGHT_Ceiling_D, 60)
end

rule "Lights dimmed when stopped"
when
	Item PlexTVStatus changed to Stopped
then
	if ((Movie_Mode.state == ON) && (S_LR_LIGHT_Ceiling_S.historicState(time_play_started).state == ON))
        sendCommand(S_LR_LIGHT_Ceiling_D, 100)
	
end

Can u post how you defined S_LR_LIGHT_Ceiling_S

Log shows this itself is null

@luckymallari its actually a Philips Hue bulb

Switch S_LR_LIGHT_Ceiling_S "Ceiling Light" (R_LR_LIGHT_S, R_LR_LIGHT, R_LR, gLights)	{ channel="hue:0210:0017884e88f5:1:color" }

Are you certain you have persistence configured on these Items and it is working?

The error is indicating that the result of S_LR_LIGHT_Ceiling_S.historicState(time_play_started) is null and null doesn’t have a .state method.

If you are running on OH 2.x you should not be importing any of those imports.

Add some tests and logging to check what historicState is returning before blindly calling .state.

@rlkoshak im quite sure the persistence is working for S_LR_LIGHT_Ceiling_S cause i have add a “TimeLine” item for it to my HABPanel which is working without any issues.

i also removed now the all imports from it.

in regards to the logging i had added the below in my rule, which is obviously not the way it needs to be done. Maybe you could point me in the right direction here.

logInfo("plex","Start Time:" + time_play_started + S_LR_LIGHT_Ceiling_S.historicState(time_play_started).state)

i also checked via REST API, please see below extract from it.

{
  "name": "S_LR_LIGHT_Ceiling_S",
  "datapoints": "1440",
  "data": [
    {
      "time": 1519044360000,
      "state": "ON"
    },
    {
      "time": 1519044360000,
      "state": "ON"
    },
    {
      "time": 1519044420000,
      "state": "ON"
    },
    {
      "time": 1519044420000,
      "state": "ON"
    },
    {
      "time": 1519044480000,
      "state": "ON"
    },
    {
      "time": 1519044480000,
      "state": "ON"
    },
    {
      "time": 1519044540000,
      "state": "ON"
    },
    {
      "time": 1519044540000,
      "state": "ON"
    },
    {
      "time": 1519044600000,
      "state": "ON"
    },
    {
      "time": 1519044600000,
      "state": "ON"
    },
    {
      "time": 1519044660000,
      "state": "ON"
    },
    {
      "time": 1519044660000,
      "state": "ON"
    },
    {
      "time": 1519044720000,
      "state": "ON"
    },
    {
      "time": 1519044720000,
      "state": "ON"
    },
    {
      "time": 1519044780000,
      "state": "ON"
    },
    {
      "time": 1519044780000,
      "state": "ON"
    },
    {
      "time": 1519044840000,
      "state": "ON"
    },
    {
      "time": 1519044840000,
      "state": "ON"
    },
    {
      "time": 1519044900000,
      "state": "ON"
    },
    {
      "time": 1519044900000,
      "state": "ON"
    },
    {
      "time": 1519044960000,
      "state": "ON"
    },
    {
      "time": 1519044960000,
      "state": "ON"
    },
    {
      "time": 1519045020000,
      "state": "ON"
    },
    {
      "time": 1519045020000,
      "state": "ON"
    },
    {
      "time": 1519045080000,
      "state": "ON"
    },
    {
      "time": 1519045080000,
      "state": "ON"
    },
    {
      "time": 1519045140000,
      "state": "ON"
    },
    {
      "time": 1519045140000,
      "state": "ON"
    },
    {
      "time": 1519045200000,
      "state": "ON"
    },
    {
      "time": 1519045200000,
      "state": "ON"
    },
    {
      "time": 1519045260000,
      "state": "ON"
    },
    {
      "time": 1519045260000,
      "state": "ON"
    },
    {
      "time": 1519045320000,
      "state": "ON"
    },
    {
      "time": 1519045320000,
      "state": "ON"
    },
    {
      "time": 1519045380000,
      "state": "ON"
    },
    {
      "time": 1519045380000,
      "state": "ON"
    },
    {
      "time": 1519045440000,
      "state": "ON"
    },
    {
      "time": 1519045440000,
      "state": "ON"
    },
    {
      "time": 1519045500000,
      "state": "ON"
    },
    {
      "time": 1519045500000,
      "state": "ON"
    },
    {
      "time": 1519045560000,
      "state": "ON"
    },
    {
      "time": 1519045560000,
      "state": "ON"
    },
    {
      "time": 1519045620000,
      "state": "ON"
    },
    {
      "time": 1519045620000,
      "state": "ON"
    },
    {
      "time": 1519045680000,
      "state": "ON"
    },
    {
      "time": 1519045680000,
      "state": "ON"
    },
    {
      "time": 1519045740000,
      "state": "ON"
    },
    {
      "time": 1519045740000,
      "state": "ON"
    },
    {
      "time": 1519045800000,
      "state": "ON"
    },
    {
      "time": 1519045800000,
      "state": "ON"
    },
    {
      "time": 1519045860000,
      "state": "ON"
    },
    {
      "time": 1519045860000,
      "state": "ON"
    },
    {
      "time": 1519045920000,
      "state": "ON"
    },
    {
      "time": 1519045920000,
      "state": "ON"
    },
    {
      "time": 1519045980000,
      "state": "ON"
    },
    {
      "time": 1519045980000,
      "state": "ON"
    },
    {
      "time": 1519046040000,
      "state": "ON"
    },
    {
      "time": 1519046040000,
      "state": "ON"
    },
    {
      "time": 1519046100000,
      "state": "ON"
    },
    {
      "time": 1519046100000,
      "state": "ON"
    },
    {
      "time": 1519046160000,
      "state": "ON"
    },
    {
      "time": 1519046160000,
      "state": "ON"
    },
    {
      "time": 1519046220000,
      "state": "ON"
    },
.
.
. some further down the 
.
.
{
      "time": 1519129980000,
      "state": "ON"
    },
    {
      "time": 1519129980000,
      "state": "ON"
    },
    {
      "time": 1519130040000,
      "state": "ON"
    },
    {
      "time": 1519130040000,
      "state": "ON"
    },
    {
      "time": 1519130100000,
      "state": "ON"
    },
    {
      "time": 1519130100000,
      "state": "ON"
    },
    {
      "time": 1519130160000,
      "state": "ON"
    },
    {
      "time": 1519130160000,
      "state": "ON"
    },
    {
      "time": 1519130220000,
      "state": "ON"
    },
    {
      "time": 1519130220000,
      "state": "ON"
    },
    {
      "time": 1519130280000,
      "state": "ON"
    },
    {
      "time": 1519130280000,
      "state": "ON"
    },
    {
      "time": 1519130340000,
      "state": "ON"
    },
    {
      "time": 1519130340000,
      "state": "ON"
    },
    {
      "time": 1519130400000,
      "state": "ON"
    },
    {
      "time": 1519130400000,
      "state": "ON"
    },
    {
      "time": 1519130460000,
      "state": "ON"
    },
    {
      "time": 1519130460000,
      "state": "ON"
    },
    {
      "time": 1519130520000,
      "state": "ON"
    },
    {
      "time": 1519130520000,
      "state": "ON"
    },
    {
      "time": 1519130580000,
      "state": "ON"
    },
    {
      "time": 1519130580000,
      "state": "ON"
    },
    {
      "time": 1519130640000,
      "state": "ON"
    },
    {
      "time": 1519130640000,
      "state": "ON"
    },
    {
      "time": 1519130700000,
      "state": "ON"
    },
    {
      "time": 1519130700000,
      "state": "ON"
    }
  ]
}

Remove the .state at the end of the log statement to see if historicState is returning null.

@rlkoshak updated the log entry as you suggested and the log is showing indeed "NULL"
but why? i checked again via rest API and i have entries in there for all the time.

im on OH 2.3 #1212
persistance: rrd4j

2018-02-21 00:00:41.959 [INFO ] [.eclipse.smarthome.model.script.plex] - Start Time:2018-02-21T00:00:41.930+04:00 HistoricalState:null

just put persistence on DEBUG and the state is getting write in the database.
so i must doing something wrong in the way im trying to get the date, but what :thinking:

2018-02-21 17:05:00.344 [DEBUG] [sistence.rrd4j.internal.RRD4jService] - Stored 'S_LR_LIGHT_Ceiling_S' with state 'ON' in rrd4j database (again)

2018-02-21 17:05:00.347 [DEBUG] [sistence.rrd4j.internal.RRD4jService] - Stored 'S_LR_LIGHT_Ceiling_S' with state '1' in rrd4j database
1 Like

I’m also seeing this with rrd4j only difference is im using kodi as my triggers.

States are peristed just fine, on everychange and everyminute

Try adding a small Thread::sleep before calling historicState. At least in your first rule you are trying to get the historicState from now and the persistence may not be done saving the most recent update or is unable to handle a time so soon.

Beyond that I’ve no ideas.

for testing purpose i created a simple rule (below) to test the historicstate and it seems not to work at all by some reason. all my lights are returning with “null” :face_with_raised_eyebrow:

rule

var DateTime time_play_started

rule "Test"
when
	Item S_Test1_S changed to ON
then
	time_play_started = now
	logInfo("test"," HistoricalState 1: " + S_LR_LIGHT_Ceiling_S.historicState(now.minusDays(1)))
	logInfo("test"," HistoricalState 2: " + S_KR_LIGHT_Ceiling_S.historicState(now.minusDays(1)))
	logInfo("test"," HistoricalState 3: " + S_KI_LIGHT_Ceiling_S.historicState(now.minusDays(1)))
	logInfo("test"," HistoricalState 4: " + S_PR_LIGHT_Ceiling_S.historicState(now.minusDays(1)))
	logInfo("test"," HistoricalState 5: " + S_DR_LIGHT_DiningTable1_S.historicState(now.minusDays(1)))

end

log showing persistence is working

2018-02-24 11:55:00.076 [DEBUG] [sistence.rrd4j.internal.RRD4jService] - Stored 'Presence' with state '1' in rrd4j database

2018-02-24 11:55:00.142 [DEBUG] [sistence.rrd4j.internal.RRD4jService] - Stored 'PresenceMatthias' with state '1' in rrd4j database (again)

2018-02-24 11:55:00.144 [DEBUG] [sistence.rrd4j.internal.RRD4jService] - Stored 'PresenceMatthias' with state '1' in rrd4j database

2018-02-24 11:55:00.186 [DEBUG] [sistence.rrd4j.internal.RRD4jService] - Stored 'PresenceMatthias_Mobile' with state 'ON' in rrd4j database (again)

2018-02-24 11:55:00.188 [DEBUG] [sistence.rrd4j.internal.RRD4jService] - Stored 'PresenceMatthias_Mobile' with state '1' in rrd4j database

2018-02-24 11:55:00.203 [DEBUG] [sistence.rrd4j.internal.RRD4jService] - Stored 'PresenceMatthias_Home_GPS' with state 'ON' in rrd4j database (again)

2018-02-24 11:55:00.205 [DEBUG] [sistence.rrd4j.internal.RRD4jService] - Stored 'PresenceMatthias_Home_GPS' with state '1' in rrd4j database

2018-02-24 11:55:00.226 [DEBUG] [sistence.rrd4j.internal.RRD4jService] - Stored 'MattDistanceFromHome' with state '44.99393295366847' in rrd4j database

2018-02-24 11:55:00.240 [DEBUG] [sistence.rrd4j.internal.RRD4jService] - Stored 'PresenceEunOk' with state '1' in rrd4j database (again)

2018-02-24 11:55:00.242 [DEBUG] [sistence.rrd4j.internal.RRD4jService] - Stored 'PresenceEunOk' with state '1' in rrd4j database

2018-02-24 11:55:00.260 [DEBUG] [sistence.rrd4j.internal.RRD4jService] - Stored 'PresenceEunOk_GPS_Home' with state 'ON' in rrd4j database (again)

2018-02-24 11:55:00.262 [DEBUG] [sistence.rrd4j.internal.RRD4jService] - Stored 'PresenceEunOk_GPS_Home' with state '1' in rrd4j database

2018-02-24 11:55:00.277 [DEBUG] [sistence.rrd4j.internal.RRD4jService] - Stored 'PresenceEunOk_Mobile_Online' with state 'ON' in rrd4j database (again)

2018-02-24 11:55:00.279 [DEBUG] [sistence.rrd4j.internal.RRD4jService] - Stored 'PresenceEunOk_Mobile_Online' with state '1' in rrd4j database

2018-02-24 11:55:00.296 [DEBUG] [sistence.rrd4j.internal.RRD4jService] - Stored 'EunOkDistanceFromHome' with state '30.285198096173566' in rrd4j database

2018-02-24 11:55:00.311 [DEBUG] [sistence.rrd4j.internal.RRD4jService] - Stored 'S_HW_MOTIONSENSOR_Temp' with state '24.60000000000000142108547152020037174224853515625' in rrd4j database

2018-02-24 11:55:00.325 [DEBUG] [sistence.rrd4j.internal.RRD4jService] - Stored 'Temperature' with state '27.00' in rrd4j database

2018-02-24 11:55:00.341 [DEBUG] [sistence.rrd4j.internal.RRD4jService] - Stored 'CNF_LIGHTSCENE_EditingSceneNum' with state '0' in rrd4j database

2018-02-24 11:55:00.355 [DEBUG] [sistence.rrd4j.internal.RRD4jService] - Stored 'S_MD_S' with state 'ON' in rrd4j database (again)

2018-02-24 11:55:00.357 [DEBUG] [sistence.rrd4j.internal.RRD4jService] - Stored 'S_MD_S' with state '1' in rrd4j database

2018-02-24 11:55:00.379 [DEBUG] [sistence.rrd4j.internal.RRD4jService] - Stored 'S_Test1_S' with state 'ON' in rrd4j database (again)

2018-02-24 11:55:00.381 [DEBUG] [sistence.rrd4j.internal.RRD4jService] - Stored 'S_Test1_S' with state '1' in rrd4j database

2018-02-24 11:55:00.397 [DEBUG] [sistence.rrd4j.internal.RRD4jService] - Stored 'S_Test2_S' with state 'OFF' in rrd4j database (again)

2018-02-24 11:55:00.399 [DEBUG] [sistence.rrd4j.internal.RRD4jService] - Stored 'S_Test2_S' with state '0' in rrd4j database

2018-02-24 11:55:00.414 [DEBUG] [sistence.rrd4j.internal.RRD4jService] - Stored 'S_Test3_S' with state 'OFF' in rrd4j database (again)

2018-02-24 11:55:00.416 [DEBUG] [sistence.rrd4j.internal.RRD4jService] - Stored 'S_Test3_S' with state '0' in rrd4j database

2018-02-24 11:55:00.432 [DEBUG] [sistence.rrd4j.internal.RRD4jService] - Stored 'S_LR_LIGHT_Ceiling_S' with state 'ON' in rrd4j database (again)

2018-02-24 11:55:00.434 [DEBUG] [sistence.rrd4j.internal.RRD4jService] - Stored 'S_LR_LIGHT_Ceiling_S' with state '1' in rrd4j database

2018-02-24 11:55:00.454 [DEBUG] [sistence.rrd4j.internal.RRD4jService] - Stored 'S_KR_LIGHT_Ceiling_S' with state 'OFF' in rrd4j database (again)

2018-02-24 11:55:00.456 [DEBUG] [sistence.rrd4j.internal.RRD4jService] - Stored 'S_KR_LIGHT_Ceiling_S' with state '0' in rrd4j database

2018-02-24 11:55:00.474 [DEBUG] [sistence.rrd4j.internal.RRD4jService] - Stored 'S_KI_LIGHT_Ceiling_S' with state 'ON' in rrd4j database (again)

2018-02-24 11:55:00.476 [DEBUG] [sistence.rrd4j.internal.RRD4jService] - Stored 'S_KI_LIGHT_Ceiling_S' with state '1' in rrd4j database

2018-02-24 11:55:00.493 [DEBUG] [sistence.rrd4j.internal.RRD4jService] - Stored 'S_PR_LIGHT_Ceiling_S' with state 'OFF' in rrd4j database (again)

2018-02-24 11:55:00.495 [DEBUG] [sistence.rrd4j.internal.RRD4jService] - Stored 'S_PR_LIGHT_Ceiling_S' with state '0' in rrd4j database

2018-02-24 11:55:00.511 [DEBUG] [sistence.rrd4j.internal.RRD4jService] - Stored 'S_DR_LIGHT_DiningTable1_S' with state 'ON' in rrd4j database (again)

2018-02-24 11:55:00.513 [DEBUG] [sistence.rrd4j.internal.RRD4jService] - Stored 'S_DR_LIGHT_DiningTable1_S' with state '1' in rrd4j database

2018-02-24 11:55:00.529 [DEBUG] [sistence.rrd4j.internal.RRD4jService] - Stored 'S_GR_LIGHT_Ceiling_S' with state 'OFF' in rrd4j database (again)

2018-02-24 11:55:00.531 [DEBUG] [sistence.rrd4j.internal.RRD4jService] - Stored 'S_GR_LIGHT_Ceiling_S' with state '0' in rrd4j database

2018-02-24 11:55:00.548 [DEBUG] [sistence.rrd4j.internal.RRD4jService] - Stored 'S_BR_LIGHT_Ceiling_S' with state 'OFF' in rrd4j database (again)

2018-02-24 11:55:00.550 [DEBUG] [sistence.rrd4j.internal.RRD4jService] - Stored 'S_BR_LIGHT_Ceiling_S' with state '0' in rrd4j database

log showing the error

2018-02-24 12:03:15.530 [INFO ] [.eclipse.smarthome.model.script.test] -  HistoricalState 1: org.openhab.core.persistence.internal.QueryablePersistenceServiceDelegate$1@1e83766

2018-02-24 12:03:15.538 [INFO ] [.eclipse.smarthome.model.script.test] -  HistoricalState 2: org.openhab.core.persistence.internal.QueryablePersistenceServiceDelegate$1@18ee3ed

2018-02-24 12:03:15.545 [INFO ] [.eclipse.smarthome.model.script.test] -  HistoricalState 3: org.openhab.core.persistence.internal.QueryablePersistenceServiceDelegate$1@1ce9990

2018-02-24 12:03:15.552 [INFO ] [.eclipse.smarthome.model.script.test] -  HistoricalState 4: org.openhab.core.persistence.internal.QueryablePersistenceServiceDelegate$1@b7d6cb

2018-02-24 12:03:15.560 [INFO ] [.eclipse.smarthome.model.script.test] -  HistoricalState 5: org.openhab.core.persistence.internal.QueryablePersistenceServiceDelegate$1@f484bc

ok after a couple of coffees and mor testing it seems to work now, but im not sure why.
rrd4j is set as default in paperUI but i to set it in the rule again.

like this its working

var DateTime time_play_started

rule "Test"
when
	Item S_Test1_S changed to ON
then
	time_play_started = now
	logInfo("test"," HistoricalState 1: " + S_LR_LIGHT_Ceiling_S.historicState(now.minusDays(1),"rrd4j").state)
	logInfo("test"," HistoricalState 2: " + S_KR_LIGHT_Ceiling_S.historicState(now.minusDays(1),"rrd4j").state)
	logInfo("test"," HistoricalState 3: " + S_KI_LIGHT_Ceiling_S.historicState(now.minusDays(1),"rrd4j").state)
	logInfo("test"," HistoricalState 4: " + S_PR_LIGHT_Ceiling_S.historicState(now.minusDays(1),"rrd4j").state)
	logInfo("test"," HistoricalState 5: " + S_DR_LIGHT_DiningTable1_S.historicState(now.minusDays(1),"rrd4j").state)

end

however as soon as im using the var its not working (see HistoricalState 1: log entry).

var DateTime time_play_started

rule "Test"
when
	Item S_Test1_S changed to ON
then
	time_play_started = now
	logInfo("test"," HistoricalState 1: " + S_LR_LIGHT_Ceiling_S.historicState(time_play_started,"rrd4j").state)
	logInfo("test"," HistoricalState 2: " + S_KR_LIGHT_Ceiling_S.historicState(now.minusDays(1),"rrd4j").state)
	logInfo("test"," HistoricalState 3: " + S_KI_LIGHT_Ceiling_S.historicState(now.minusDays(1),"rrd4j").state)
	logInfo("test"," HistoricalState 4: " + S_PR_LIGHT_Ceiling_S.historicState(now.minusDays(1),"rrd4j").state)
	logInfo("test"," HistoricalState 5: " + S_DR_LIGHT_DiningTable1_S.historicState(now.minusDays(1),"rrd4j").state)

end

log

2018-02-24 12:47:34.927 [ERROR] [ntime.internal.engine.RuleEngineImpl] - Rule 'Test': cannot invoke method public abstract org.eclipse.smarthome.core.types.State org.eclipse.smarthome.core.persistence.HistoricItem.getState() on null

I assume you have configured your RRD4J persistence to save every change and every minute.
So in this case now won’t work because the state of your item S_LR_LIGHT_Ceiling_S probably won’t be necessary saved by the minute strategy (and by the every change strategy either).

So this won’t work:

     logInfo("test"," HistoricalState 1: " + S_LR_LIGHT_Ceiling_S.historicState(now.minusSeconds(59),"rrd4j").state)

but this will:

     logInfo("test"," HistoricalState 2: " + S_LR_LIGHT_Ceiling_S.historicState(now.minusSeconds(61),"rrd4j").state)

Edit: The “fail-value” from now.minusSeconds(xx) will differ and depends on the time the rule is loaded in relation to the minute strategy from RRD4J persistence.