OH 3.1-M3 - Persistence Error for Location Items is back: JDBC restoreOnStartup throw error for Location items

ohb1138 · April 8, 2021, 8:56am

Hi all,
I just migrated from OH 2.5.12 to OH 3.1-M3 and found the following errors just at startup in my log:

10:36:52.065 [ERROR] [org.openhab.core.items.GenericItem   ] - Tried to set invalid state XX.XXXXXX,YY.YYYYYY (StringType) on item locationEX of type LocationItem, ignoring it
10:36:52.113 [ERROR] [org.openhab.core.items.GenericItem   ] - Tried to set invalid state XX.XXXXXX,YY.YYYYYY (StringType) on item localStationLocation of type LocationItem, ignoring it

My research in the community lead to this issue reported on GitHub:

My MariaDB version is 10.3.24 and and OH level see above:

my jdbc.persist looks like:

Strategies {
    every5Minutes : "0 0/5 * * * ?"
    default = everyChange, every5Minutes, restoreOnStartup
}

Items {
    * : strategy = everyChange, every5Minutes, restoreOnStartup
}

Am I on the right path or is this something different?

I circumvented it by running the following commands in a rule at startup:

    locationEX.sendCommand("XX.XXXXXX,YY.YYYYYY")
    localStationLocation.sendCommand("XX.XXXXXX,YY.YYYYYY")

Cheers
Justus

rossko57 · April 8, 2021, 9:04am

So the database was written by OH2.5? I didn’t think Location were persisted at all under OH2.

The message doesn’t say anything about JDBC, is there some other clue not shown?
Reminder that rrd4j is installed by default, persists and restores everything, in OH3.

ohb1138 · April 8, 2021, 9:07am

No, it is a new clean database created for OH3 only I switched the database as there have been other obstacles to remain with the existing OH2 database.

But I have set the default persistence in the new OH3 UI to JDBC!

ohb1138 · April 8, 2021, 9:08am

I also found that still two JDBC clients are running:

openhab> list | grep JDBC
265 │ Active │  80 │ 1.4.6.0                 │ MariaDB JDBC Client
266 │ Active │  80 │ 3.1.0.M3                │ openHAB Add-ons :: Bundles :: Persistence Service :: JDBC
openhab>

Is this necessary or can I remove the old one?
And how would I do that ?

rossko57 · April 8, 2021, 9:45am

“Default persistence” only tells the system which service to use if one is not specified e.g.in charts or rule queries.
It never has and never will affect which services are installed or how they are configured.

You have rrd4j installed and persisting everything.

Are there any clues which service is involved here? Do you have a JDBC config that you expect to include those Items? EDIT - yes you do, of course.
Most likely this is JDBC but it would be good to confirm.

That’s probably correct; a JDBC service and a Maria plug-in. I’ve no idea what version the Maria part should be, just in case that’s a legacy from OH2

ohb1138 · April 8, 2021, 10:02am

But how to do that? Set some DEBUG or TRACE on the JDBC bindings?

rossko57 · April 8, 2021, 10:06am

That seems like a good idea.
But I suppose we could apply some logic. Assuming the error throws at every persist attempt … rrd4j is defaulting to everyMinute I believe, you’ve configured your JDBC for every five?

Oh wait, you’re posting different stuff in another thread now, that’s too messy for me.

ohb1138 · April 8, 2021, 10:09am

But the error only occurs ONCE at startup and then never again. This is why I assume that is has to do with the JDBC persistence settings as I have configured RestoreOnStartup and therefore are related to the mentioned issue on GitHub …

Sorry, this is a totally different story and directly directed to Jens as he advised me on another JDBC error
The other error messages have nothing to do with this one - So you can stick to that one

ohb1138 · April 8, 2021, 11:09am

@rossko57,

I have two error types but they are not related. My finding for the LocationItem is that after another reboot only one of the error entries reoccured:

2021-04-08 12:56:37.216 [ERROR] [org.openhab.core.items.GenericItem  ] - Tried to set invalid state XX.XXXX,YY.YYYY (StringType) on item localStationLocation of type LocationItem, ignoring it

I don’t know if this will stay for ever or if the other error message will return

Fortunately I have only these two LocationItems and a circumvention. I will try to find out how to DEBUG the JDBC stuff to get more information about these errors.

EDIT: The other error just followed 10 minutes later:

13:07:04.138 [ERROR] [org.openhab.core.items.GenericItem   ] - Tried to set invalid state 49.9725155,8.3393236 (StringType) on item locationJR of type LocationItem, ignoring it

So it is still those two errors.

ohb1138 · April 8, 2021, 11:43am

Ok, here I have captured the DEBUG output from the karaf.log. The error message comes from JDBC but it somehow does persist the Item anyway (see output from MariaDB below):

2021-04-08 13:21:28.442 [DEBUG] [jdbc.internal.JdbcPersistenceService] - JDBC::query: item is locationJR
2021-04-08 13:21:28.443 [DEBUG] [persistence.jdbc.internal.JdbcMapper] - JDBC::getHistItemFilterQuery filter='true' numberDecimalcount='3' table='Item372' item='locationJR (Type=LocationItem, State=NULL, Label=JR Location, Category=null)' itemName='locationJR'
2021-04-08 13:21:28.444 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::getHistItemFilterQueryProvider filter = org.openhab.core.persistence.FilterCriteria@17ac9388, numberDecimalcount = 3, table = Item372, simpleName = locationJR
2021-04-08 13:21:28.444 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::query queryString = SELECT time, value FROM Item372 ORDER BY time DESC  LIMIT 0,1
2021-04-08 13:21:28.445 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::doGetHistItemFilterQuery sql=SELECT time, value FROM Item372 ORDER BY time DESC  LIMIT 0,1
2021-04-08 13:21:28.448 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::ItemResultHandler::handleResult getState value = 'XX.XXXXXX,YY.YYYYYY', unit = 'null', getClass = 'class java.lang.String', clazz = 'String'
2021-04-08 13:21:28.449 [DEBUG] [jdbc.internal.JdbcPersistenceService] - JDBC::query: query for locationJR returned 1 rows in 6 ms
2021-04-08 13:21:28.450 [ERROR] [org.openhab.core.items.GenericItem  ] - Tried to set invalid state XX.XXXXXX,YY.YYYYYY (StringType) on item locationJR of type LocationItem, ignoring it


2021-04-08 13:21:28.491 [DEBUG] [jdbc.internal.JdbcPersistenceService] - JDBC::query: item is localStationLocation
2021-04-08 13:21:28.492 [DEBUG] [persistence.jdbc.internal.JdbcMapper] - JDBC::getHistItemFilterQuery filter='true' numberDecimalcount='3' table='Item40' item='localStationLocation (Type=LocationItem, State=NULL, Label=Location, Category=location)' itemName='localStationLocation'
2021-04-08 13:21:28.493 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::getHistItemFilterQueryProvider filter = org.openhab.core.persistence.FilterCriteria@7ac8c3b8, numberDecimalcount = 3, table = Item40, simpleName = localStationLocation
2021-04-08 13:21:28.494 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::query queryString = SELECT time, value FROM Item40 ORDER BY time DESC  LIMIT 0,1
2021-04-08 13:21:28.495 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::doGetHistItemFilterQuery sql=SELECT time, value FROM Item40 ORDER BY time DESC  LIMIT 0,1
2021-04-08 13:21:28.497 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::ItemResultHandler::handleResult getState value = 'XX.XXXX,YY.YYYY', unit = 'null', getClass = 'class java.lang.String', clazz = 'String'
2021-04-08 13:21:28.498 [DEBUG] [jdbc.internal.JdbcPersistenceService] - JDBC::query: query for localStationLocation returned 1 rows in 6 ms
2021-04-08 13:21:28.499 [ERROR] [org.openhab.core.items.GenericItem  ] - Tried to set invalid state XX.XXXX,YY.YYYY (StringType) on item localStationLocation of type LocationItem, ignoring it

...
| 2021-04-08 11:50:00.462 | XX.XXXXXX,YY.YYYYYY |
| 2021-04-08 11:55:00.777 | XX.XXXXXX,YY.YYYYYY |
| 2021-04-08 12:00:39.751 | XX.XXXXXX,YY.YYYYYY |
| 2021-04-08 12:05:00.928 | XX.XXXXXX,YY.YYYYYY |
| 2021-04-08 12:10:00.916 | XX.XXXXXX,YY.YYYYYY |
| 2021-04-08 12:15:00.896 | XX.XXXXXX,YY.YYYYYY |
| 2021-04-08 13:21:34.667 | XX.XXXXXX,YY.YYYYYY |
| 2021-04-08 13:25:00.969 | XX.XXXXXX,YY.YYYYYY |
| 2021-04-08 13:30:00.826 | XX.XXXXXX,YY.YYYYYY |
| 2021-04-08 13:35:00.722 | XX.XXXXXX,YY.YYYYYY |
+-------------------------+----------------------+
197 rows in set (0.001 sec)

MariaDB [my_oh_db]>

...
| 2021-04-08 11:50:00.481 | XX.XXXX,YY.YYYY       |
| 2021-04-08 11:55:00.788 | XX.XXXX,YY.YYYY       |
| 2021-04-08 12:00:45.056 | XX.XXXX,YY.YYYY       |
| 2021-04-08 12:05:00.940 | XX.XXXX,YY.YYYY       |
| 2021-04-08 12:10:00.927 | XX.XXXX,YY.YYYY       |
| 2021-04-08 12:15:00.906 | XX.XXXX,YY.YYYY       |
| 2021-04-08 12:56:50.366 | XX.XXXX,YY.YYYY       |
| 2021-04-08 13:00:00.854 | XX.XXXX,YY.YYYY       |
| 2021-04-08 13:05:00.601 | XX.XXXX,YY.YYYY       |
| 2021-04-08 13:10:00.241 | XX.XXXX,YY.YYYY       |
| 2021-04-08 13:15:00.251 | XX.XXXX,YY.YYYY       |
| 2021-04-08 13:21:44.709 | XX.XXXX,YY.YYYY       |
| 2021-04-08 13:25:00.999 | XX.XXXX,YY.YYYY       |
| 2021-04-08 13:30:00.873 | XX.XXXX,YY.YYYY       |
| 2021-04-08 13:35:00.742 | XX.XXXX,YY.YYYY       |
| 2021-04-08 13:40:00.697 | XX.XXXX,YY.YYYY       |
+-------------------------+-----------------------+
851 rows in set (0.002 sec)

MariaDB [my_oh_db]>

rossko57 · April 8, 2021, 11:45am

I’ll bet if you remove JDBC restoreOnStartup from these Items, the messages will go away.

I do not know but suspect the default rrd4j will not be persisting these Locations, doesn’t handle the type. (so of course not attempting restore either)

A sensible workaround is to use MapDB for restore purposes, not other services, its made for the purpose.

ohb1138 · April 8, 2021, 12:12pm

Thanks, I will check on this … when I know why this happens and that it does not cause any harm,I might simply ignore them.

My MariaDB is “just there” as it is running anyway on my NAS. And as my OH is running in docker I would need to think of adding an additional service.
It is unfortunate that the RestoreOnStartup only works with MapDB … I think this was different with 2.5 as I used MariaDB their natively (no JDBC) with the MYSQL binding and I remember it working there

But I appreciate your clarification. But it doesn’t make me happy

rossko57 · April 8, 2021, 12:22pm

No-one said that. If you can persist Locations (can you?) via JDBC then it should be able to restore them also.
You’ve probably stumbled on a bug in the JDBC extension relating purely to Location and restore - but let’s find out.

ohb1138 · April 8, 2021, 1:06pm

Sorry, I misunderstand your previous response!

Yes OH persists the Locations into MariaDB via JDBC … see output from MariaDB select * from Item40; statement above

rossko57 · April 8, 2021, 1:18pm

But X,Y is not a valid location value, it’s supposed to be numbers.
Is it making a muff of trying to persist Items that haven’t been populated yet? They should have NULL or UNDEF state and be ignored by persistence service.

ohb1138 · April 8, 2021, 1:19pm

This is just anonymized to keep my location private. Of course this has valid lattitude and longitude information!!!

rossko57 · April 8, 2021, 1:22pm

There’s no “of course” about it, we know only what you tell us.

So for the sake of clarity, you can persist and retrieve valid locations? And the error messages do not include X,Y but have valid locations too?

Based on the report that it only happens at start up, taken with the message saying it can’t update an Item, it sure looks like a bug in JDBC about restoring.
You can prove that by taking the restore off those Items, then create an issue in Github.

Meantime, you can work around a need to restore by using Mapdb just for those. (It’s more efficient nyway)

ohb1138 · April 8, 2021, 1:35pm

Sorry - language barrier - this was not meant as an offense and you are right :+1

Yes

Yes, valid numbers!

Yes only at startup. The entries in the MariaDB show that persistence works during the normal persistence frequency steps. And hence I assume that it might be a problem in the RestoreOnStartup process

I have to check how quick I can get it up and running for my purposes in my environment. Thanks for advising to this option!!!

ohb1138 · April 8, 2021, 2:21pm

@rossko57,
I am stuck in my mind
I am searching the internet on “how to install MabDB” to use it as an alternative persistence to MariaDB. There is no installation guide, no docker image, no nothing that explains what to do to get MapDB installed. I found something about a JAR File but I don’t know what to do with that …
You said openHAB includes rrd4j. Is this true for the docker image as well? Does rrd4j write its data to the userdata directory? And is MapDB maybe also part of the docker image???
Do you have any link to a documentation how I get MapDB installed - especially for a docker based OH … On a raspi I would understand just to simply install a package and configure it. But what is the best way for my docker environment?

Thank you for your advice. I continue searching in parallel but I already asked all major search engines in the web

EDIT: I just installed the MapDB persistence binding and copied the jdbc.persist to a new mapdb.persist file. I removed the RestoreOnStartup from the jdbc.persistand kept it in the mapdb.persist.

Currently I see no more errors at startup anymore but I would like to this solved for others …
I assume that MapDB seems to be “there” (???) somehow as I understand it is a very lightweight Java based kind of caching database storage … It looks like as if it is working and nothing needs to be installed …
The other errors I saw all occured to ImageItems and they are also now gone … I guess it is due to the same reason as they also only occurred on startup …

This means that your suggested circumvention works and that the issues are tied to the RestoreOnStartup option for JDBC.

rossko57 · April 8, 2021, 3:34pm

Yes.

Nobody knows why the docs fell out of OH3, but it hardly needs any.