JDBC Persistence: DateTime items, time missing

Hi,

my ultimate goal is to show the sunrise and sunset times in a grafana dashboard.

These values are calculated by the astro binding, the items are defined as DateTime, the UI shows a sunrise time of 8:32 for today.

I persisted these values using the JDBC persistence service and a postgreSQL database. The “value” table column, generated for this item has a type of “timestamp”, which is fine. But the values written to this table only show the date, with the time part set to all “0” (e.g. 2017-12-15 00:00:00).

Am I missing something or is this a bug in the persistence service?

Thanks for your help!

There are two columns, one for the time that the Item was updated/changed/value was saved to the database, and the state of the Item at that time.

Astro calculates the new sunrise and sunset times around midnight.

So first, make sure you are looking at the right column in the database. Then try out the REST API to see what the previous state was for one of your Astro Items and verify what you get back is reasonable. If not then this is a bug and you should file an issue, probably in the ESH repo.

You can install the interactive REST API through PaperUI under the Misc tab. It will let you make the REST calls right from the docs themselves.

The database table for this item has two columns, time and value, booth of type timestamp. The “time” column has the correct time the item was persisted, the “value” column only the data and no information regarding time.

Using the REST API I get the following responses:
/rest/items/Astro_Sunrise_Time/state:
2017-12-15T08:32:00.000+0100
Which is correct

/rest/persistence/items/Astro_Sunrise_Time?serviceId=jdbc"

{
“name”: “Astro_Sunrise_Time”,
“datapoints”: “2”,
“data”: [
{
“time”: 1513292401341,
“state”: “2017-12-14T00:00:00.000+0100”
},
{
“time”: 1513292426538,
“state”: “2017-12-15T00:00:00.000+0100”
}
]
}

In this response the time information from the state is missing.

[Edit]

There already exists a bug report for this: https://github.com/openhab/openhab1-addons/issues/5255

1 Like

OK, good, because it definitely looks like a bug to me.

Just noticed this bug myself using mardiadb. This would be nice to have fixed for the 2.2 release…

I’ve also noticed that this causes “changedsince” rules to not function. I find that it registers the last change as midnight of the night before despite there being many new entries in the table. I tested by changing the hour value in the following test rule. Once you passed the midnight hour, it would change to HAS changed:

rule "Test"
    when 
        Time cron "10 * * * * ?"
    then
        if (!FirstFloorThermostatLastPollSuccess.changedSince(now.minusHours(9))) {
            logInfo("Test", "Hasn't changed")
        }
        if (FirstFloorThermostatLastPollSuccess.changedSince(now.minusHours(9))) {
            logInfo("Test", "HAS changed")
        }
end

I guess this makes sense as the last “change” was midnight despite there being many entries.

Are you sure about the “lastChanged()” problem, I would guess, that the time of the change is taken from the “time” column in the database, otherwise it would not would not work with items of other types.

Maybe you do not persist the value often enough or the item really has not changed. What happen to the item state, if every poll is successful?

Absolutely certain. I have spent the last 3 hours troubleshooting.

changedsince is looking for the last time the value actually changed in the value column. Even though there are new timestamps, the last time the value actually CHANGED was at midnight when the date changed… therefore the rule is working as expected… the database binding is not.

If you look at the debug of jdbc during the rule execution it returns 5 rows from the filter but since the values don’t change, it ignores them:

2017-12-16 08:05:30.011 [DEBUG] [jdbc.internal.JdbcPersistenceService] - JDBC::query: item is FirstFloorThermostatLastPollSuccess
2017-12-16 08:05:30.013 [DEBUG] [persistence.jdbc.internal.JdbcMapper] - JDBC::getHistItemFilterQuery filter='true' numberDecimalcount='3' table='Item16' item='FirstFloorThermostatLastPollSuccess (Type=DateTimeItem, State=2017-12-16T08:00:23)' itemName='FirstFloorThermostatLastPollSuccess'
2017-12-16 08:05:30.014 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::getHistItemFilterQueryProvider filter = org.openhab.core.persistence.FilterCriteria@2c8c955e, numberDecimalcount = 3, table = Item16, simpleName = FirstFloorThermostatLastPollSuccess
2017-12-16 08:05:30.015 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::query queryString = SELECT time, value FROM Item16 WHERE TIME>'2017-12-16 07:05:30' ORDER BY time ASC
2017-12-16 08:05:30.016 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::doGetHistItemFilterQuery sql=SELECT time, value FROM Item16 WHERE TIME>'2017-12-16 07:05:30' ORDER BY time ASC
2017-12-16 08:05:30.025 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::ItemResultHandler::handleResult getState value = '2017-12-16 00:00:00.0', getClass = 'class java.sql.Timestamp', clazz = 'Timestamp'
2017-12-16 08:05:30.026 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::ItemResultHandler::handleResult getState value = '2017-12-16 00:00:00.0', getClass = 'class java.sql.Timestamp', clazz = 'Timestamp'
2017-12-16 08:05:30.028 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::ItemResultHandler::handleResult getState value = '2017-12-16 00:00:00.0', getClass = 'class java.sql.Timestamp', clazz = 'Timestamp'
2017-12-16 08:05:30.029 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::ItemResultHandler::handleResult getState value = '2017-12-16 00:00:00.0', getClass = 'class java.sql.Timestamp', clazz = 'Timestamp'
2017-12-16 08:05:30.030 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::ItemResultHandler::handleResult getState value = '2017-12-16 00:00:00.0', getClass = 'class java.sql.Timestamp', clazz = 'Timestamp'
2017-12-16 08:05:30.032 [DEBUG] [jdbc.internal.JdbcPersistenceService] - JDBC::query: query for FirstFloorThermostatLastPollSuccess returned 5 rows in 19 ms
2017-12-16 08:05:30.033 [DEBUG] [jdbc.internal.JdbcPersistenceService] - JDBC::query: item is FirstFloorThermostatLastPollSuccess
2017-12-16 08:05:30.035 [DEBUG] [persistence.jdbc.internal.JdbcMapper] - JDBC::getHistItemFilterQuery filter='true' numberDecimalcount='3' table='Item16' item='FirstFloorThermostatLastPollSuccess (Type=DateTimeItem, State=2017-12-16T08:00:23)' itemName='FirstFloorThermostatLastPollSuccess'
2017-12-16 08:05:30.036 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::getHistItemFilterQueryProvider filter = org.openhab.core.persistence.FilterCriteria@76e51354, numberDecimalcount = 3, table = Item16, simpleName = FirstFloorThermostatLastPollSuccess
2017-12-16 08:05:30.037 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::query queryString = SELECT time, value FROM Item16 WHERE TIME<'2017-12-16 07:05:30' ORDER BY time DESC  LIMIT 0,1
2017-12-16 08:05:30.039 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::doGetHistItemFilterQuery sql=SELECT time, value FROM Item16 WHERE TIME<'2017-12-16 07:05:30' ORDER BY time DESC  LIMIT 0,1
2017-12-16 08:05:30.047 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::ItemResultHandler::handleResult getState value = '2017-12-16 00:00:00.0', getClass = 'class java.sql.Timestamp', clazz = 'Timestamp'
2017-12-16 08:05:30.049 [DEBUG] [jdbc.internal.JdbcPersistenceService] - JDBC::query: query for FirstFloorThermostatLastPollSuccess returned 1 rows in 15 ms
2017-12-16 08:05:30.051 [INFO ] [ome.model.script.Monitor Thermostats] - FirstFloor Thermostat hasn't changed in more than 60 minutes

Oh and here are the rows from the mariadb:

“2017-12-16 07:09:53.818”;"2017-12-16 00:00:00.000"
“2017-12-16 07:22:24.256”;"2017-12-16 00:00:00.000"
“2017-12-16 07:34:54.439”;"2017-12-16 00:00:00.000"
“2017-12-16 07:47:54.376”;"2017-12-16 00:00:00.000"
“2017-12-16 08:00:23.850”;“2017-12-16 00:00:00.000”

And here is the event.log showing that they should have changed:

2017-12-16 07:09:53.818 [vent.ItemStateChangedEvent] - FirstFloorThermostatLastPollSuccess changed from 2017-12-16T06:57:13.000-0500 to 2017-12-16T07:09:53.000-0500
2017-12-16 07:22:24.257 [vent.ItemStateChangedEvent] - FirstFloorThermostatLastPollSuccess changed from 2017-12-16T07:09:53.000-0500 to 2017-12-16T07:22:24.000-0500
2017-12-16 07:34:54.440 [vent.ItemStateChangedEvent] - FirstFloorThermostatLastPollSuccess changed from 2017-12-16T07:22:24.000-0500 to 2017-12-16T07:34:54.000-0500
2017-12-16 07:47:54.376 [vent.ItemStateChangedEvent] - FirstFloorThermostatLastPollSuccess changed from 2017-12-16T07:34:54.000-0500 to 2017-12-16T07:47:54.000-0500
2017-12-16 08:00:23.852 [vent.ItemStateChangedEvent] - FirstFloorThermostatLastPollSuccess changed from 2017-12-16T07:47:54.000-0500 to 2017-12-16T08:00:23.000-0500

You are absolutely right, I got this wrong! As the value does only change once a day because of the bug changedSince() can not work correctly!

No worries, I was stuck in the same thinking for about 2 hours and then the lightbulb went on. That’s actually why I first edited my comment as I adjusted it from being confused why it wasn’t working to knowing why it wasn’t working.

I have a lot changed all at once as I built a fresh vm on debian 9 instead of 8 with mariadb instead of mysql, oh2.2, jdbc instead of mysql binding etc. Also using VSCode as editor. On and on with the changes.

I wonder if this merits a comment in the 2.2 thread? I suspect since this issue has been open for 6 months it isn’t going to get fixed in 2 days so I just wrote 3 new rules and added 3 new switch items to translate the datetime item into a switch item so that I can monitor changed since.

This would appear to be because the persistence is using a java.sql.Date object, which does not support time values.

From the JavaDoc:
This method is deprecated and should not be used because SQL Date values do not have a time component.

For my use case I found a simple workaround, which might be useful for others to:

In addition to the DateTime items for the various astro times I persist these items in addition as string. For the Astro binding this is as simple as defining the items as String and not as DateTime:

String   Astro_Sunrise_Time_String   	"Sonenaufgang [%s]"	    <sun>    (gAstroPersist)         { channel="astro:sun:home:rise#start" }

For other items a simple conversion in a rule might be necessary.

When querying the database, these strings can be converted back to timestamps. Here is a example to receive the latest sunrise time:

SELECT
 time,
 CAST (value AS  timestamp)
FROM
  astro_sunrise_time_string_view
WHERE time=(SELECT MAX(time) FROM astro_sunrise_time_string_view) AND time >= CURRENT_DATE;

I created views for all items to improve the readability, but the query will work with the tables created by the JDBC binding (itemxx) as well. The important part is the CAST() function.

The changedSince() and other persistence functions should work with these string type items as well.

They actually have a pull with a fix now. You can download the new jar from here: https://drive.google.com/open?id=1VubglapT0geUCijWyjWxzAulWy6j4ZNM

1 Like