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

ohb1138 · April 8, 2021, 3:41pm

ok, thank you for the confirmation!

Will we proceed with the RestoreOnStartup issue of JDBC within this topic?
If so, I would like to add one pair of the error message from the ImageItems that also cause trouble at startup to cover both type of issues?

rossko57 · April 8, 2021, 4:13pm

Start a new Github issue in openhab addons, put your evidence in there.

ohb1138 · April 8, 2021, 4:31pm

Thanks, I will do need to revoke my GitHub account … will post it here when issue is opened.

Thank you for your support!!!

ohb1138 · April 9, 2021, 12:43pm

Opened an issue in Github:

github.com/openhab/openhab-addons

[JDBC persistence MariaDB] binding causes errors at "restoreOnStartup" restore for Location and Image Items

opened 12:41PM - 09 Apr 21 UTC

closed 09:35PM - 14 Apr 21 UTC

ohb1138

bug

Hi there, after upgrading from OH v2.5.12 directly to OH v3.1.0-M3 the JDBC per…sistence MariaDB binding causes errors in karaf.log when restoring Image and Location Items at startup. The following errors only occur once per item during startup phase. I have two examples for each: Location Items: ``` 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 = '49.9725155,8.3393236', 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 51.5085,-0.1257 (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 = '49.9725,8.3393', 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 51.5085,-0.1257 (StringType) on item localStationLocation of type LocationItem, ignoring it ``` Image Items: ``` 2021-04-08 13:21:28.292 [DEBUG] [jdbc.internal.JdbcPersistenceService] - JDBC::query: item is MyCityCurrentConditionIcon 2021-04-08 13:21:28.292 [DEBUG] [persistence.jdbc.internal.JdbcMapper] - JDBC::getHistItemFilterQuery filter='true' numberDecimalcount='3' table='Item25' item='MyCityCurrentConditionIcon (Type=ImageItem, State=NULL, Label=Icon, Category=null)' itemName='MyCityCurrentConditionIcon' 2021-04-08 13:21:28.293 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::getHistItemFilterQueryProvider filter = org.openhab.core.persistence.FilterCriteria@1b63a0fa, numberDecimalcount = 3, table = Item25, simpleName = MyCityCurrentConditionIcon 2021-04-08 13:21:28.294 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::query queryString = SELECT time, value FROM Item25 ORDER BY time DESC LIMIT 0,1 2021-04-08 13:21:28.295 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::doGetHistItemFilterQuery sql=SELECT time, value FROM Item25 ORDER BY time DESC LIMIT 0,1 2021-04-08 13:21:28.298 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::ItemResultHandler::handleResult getState value = '[114, 97, 119, 32, 116, 121, 112, 101, 32, 40, 105, 109, 97, 103, 101, 47, 112, 110, 103, 41, 58, 32, 50, 55, 55, 51, 32, 98, 121, 116, 101, 115]', unit = 'null', getClass = 'class [B', clazz = 'byte[]' 2021-04-08 13:21:28.299 [ERROR] [nal.common.AbstractInvocationHandler] - An error occurred while calling method 'QueryablePersistenceService.query()' on 'org.openhab.persistence.jdbc.internal.JdbcPersistenceService@6bfdcace': class [B cannot be cast to class java.lang.String ([B and java.lang.String are in module java.base of loader 'bootstrap') 2021-04-08 13:21:28.317 [DEBUG] [jdbc.internal.JdbcPersistenceService] - JDBC::getName: returning name 'jdbc' for queryable persistence service. 2021-04-08 13:21:28.317 [ERROR] [ence.internal.PersistenceManagerImpl] - Exception occurred while querying persistence service 'jdbc': class [B cannot be cast to class java.lang.String ([B and java.lang.String are in module java.base of loader 'bootstrap') … 2021-04-08 13:21:28.583 [DEBUG] [jdbc.internal.JdbcPersistenceService] - JDBC::query: item is MyCityHourlyForecast03ConditionIcon 2021-04-08 13:21:28.584 [DEBUG] [persistence.jdbc.internal.JdbcMapper] - JDBC::getHistItemFilterQuery filter='true' numberDecimalcount='3' table='Item45' item='MyCityHourlyForecast03ConditionIcon (Type=ImageItem, State=NULL, Label=Icon, Category=null)' itemName='MyCityHourlyForecast03ConditionIcon' 2021-04-08 13:21:28.584 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::getHistItemFilterQueryProvider filter = org.openhab.core.persistence.FilterCriteria@515081eb, numberDecimalcount = 3, table = Item45, simpleName = MyCityHourlyForecast03ConditionIcon 2021-04-08 13:21:28.585 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::query queryString = SELECT time, value FROM Item45 ORDER BY time DESC LIMIT 0,1 2021-04-08 13:21:28.586 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::doGetHistItemFilterQuery sql=SELECT time, value FROM Item45 ORDER BY time DESC LIMIT 0,1 2021-04-08 13:21:28.588 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::ItemResultHandler::handleResult getState value = '[114, 97, 119, 32, 116, 121, 112, 101, 32, 40, 105, 109, 97, 103, 101, 47, 112, 110, 103, 41, 58, 32, 50, 55, 55, 51, 32, 98, 121, 116, 101, 115]', unit = 'null', getClass = 'class [B', clazz = 'byte[]' 2021-04-08 13:21:28.589 [ERROR] [nal.common.AbstractInvocationHandler] - An error occurred while calling method 'QueryablePersistenceService.query()' on 'org.openhab.persistence.jdbc.internal.JdbcPersistenceService@6bfdcace': class [B cannot be cast to class java.lang.String ([B and java.lang.String are in module java.base of loader 'bootstrap') 2021-04-08 13:21:28.594 [DEBUG] [jdbc.internal.JdbcPersistenceService] - JDBC::getName: returning name 'jdbc' for queryable persistence service. 2021-04-08 13:21:28.595 [ERROR] [ence.internal.PersistenceManagerImpl] - Exception occurred while querying persistence service 'jdbc': class [B cannot be cast to class java.lang.String ([B and java.lang.String are in module java.base of loader 'bootstrap') ``` I circumvented the issue by removing the "restoreOnStartup" option in the jdbc.persist and activated MapDB for this purpose. I saw that this problem has already appeared in the past: https://github.com/openhab/openhab1-addons/issues/5761 and maybe it has slipped back into OH with the upgrade to V3. I have investigated this issue in the openHAB community under the topic: [https://community.openhab.org/t/oh-3-1-m3-persistence-error-for-location-items-is-back-jdbc-restoreonstartup-throw-error-for-location-items/120430](url) and have been advised to open an issue here. Thank you for considering a solution! Cheers ohb1138

ohb1138 · April 9, 2021, 12:47pm

Here are the error messages captured with debugging turned on for the JDBC persistence MariaDB binding:

Two examples for failing updates at startup of Location items:

. . .
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 = '49.9725155,8.3393236', 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 51.5085,-0.1257 (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 = '49.9725,8.3393', 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 51.5085,-0.1257 (StringType) on item localStationLocation of type LocationItem, ignoring it
. . .

Two examples for failing updates at startup of Image items:

. . .
2021-04-08 13:21:28.292 [DEBUG] [jdbc.internal.JdbcPersistenceService] - JDBC::query: item is MyCityCurrentConditionIcon
2021-04-08 13:21:28.292 [DEBUG] [persistence.jdbc.internal.JdbcMapper] - JDBC::getHistItemFilterQuery filter='true' numberDecimalcount='3' table='Item25' item='MyCityCurrentConditionIcon (Type=ImageItem, State=NULL, Label=Icon, Category=null)' itemName='MyCityCurrentConditionIcon'
2021-04-08 13:21:28.293 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::getHistItemFilterQueryProvider filter = org.openhab.core.persistence.FilterCriteria@1b63a0fa, numberDecimalcount = 3, table = Item25, simpleName = MyCityCurrentConditionIcon
2021-04-08 13:21:28.294 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::query queryString = SELECT time, value FROM Item25 ORDER BY time DESC  LIMIT 0,1
2021-04-08 13:21:28.295 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::doGetHistItemFilterQuery sql=SELECT time, value FROM Item25 ORDER BY time DESC  LIMIT 0,1
2021-04-08 13:21:28.298 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::ItemResultHandler::handleResult getState value = '[114, 97, 119, 32, 116, 121, 112, 101, 32, 40, 105, 109, 97, 103, 101, 47, 112, 110, 103, 41, 58, 32, 50, 55, 55, 51, 32, 98, 121, 116, 101, 115]', unit = 'null', getClass = 'class [B', clazz = 'byte[]'
2021-04-08 13:21:28.299 [ERROR] [nal.common.AbstractInvocationHandler] - An error occurred while calling method 'QueryablePersistenceService.query()' on 'org.openhab.persistence.jdbc.internal.JdbcPersistenceService@6bfdcace': class [B cannot be cast to class java.lang.String ([B and java.lang.String are in module java.base of loader 'bootstrap')
2021-04-08 13:21:28.317 [DEBUG] [jdbc.internal.JdbcPersistenceService] - JDBC::getName: returning name 'jdbc' for queryable persistence service.
2021-04-08 13:21:28.317 [ERROR] [ence.internal.PersistenceManagerImpl] - Exception occurred while querying persistence service 'jdbc': class [B cannot be cast to class java.lang.String ([B and java.lang.String are in module java.base of loader 'bootstrap')
. . .
2021-04-08 13:21:28.583 [DEBUG] [jdbc.internal.JdbcPersistenceService] - JDBC::query: item is MyCityHourlyForecast03ConditionIcon
2021-04-08 13:21:28.584 [DEBUG] [persistence.jdbc.internal.JdbcMapper] - JDBC::getHistItemFilterQuery filter='true' numberDecimalcount='3' table='Item45' item='MyCityHourlyForecast03ConditionIcon (Type=ImageItem, State=NULL, Label=Icon, Category=null)' itemName='MyCityHourlyForecast03ConditionIcon'
2021-04-08 13:21:28.584 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::getHistItemFilterQueryProvider filter = org.openhab.core.persistence.FilterCriteria@515081eb, numberDecimalcount = 3, table = Item45, simpleName = MyCityHourlyForecast03ConditionIcon
2021-04-08 13:21:28.585 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::query queryString = SELECT time, value FROM Item45 ORDER BY time DESC  LIMIT 0,1
2021-04-08 13:21:28.586 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::doGetHistItemFilterQuery sql=SELECT time, value FROM Item45 ORDER BY time DESC  LIMIT 0,1
2021-04-08 13:21:28.588 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::ItemResultHandler::handleResult getState value = '[114, 97, 119, 32, 116, 121, 112, 101, 32, 40, 105, 109, 97, 103, 101, 47, 112, 110, 103, 41, 58, 32, 50, 55, 55, 51, 32, 98, 121, 116, 101, 115]', unit = 'null', getClass = 'class [B', clazz = 'byte[]'
2021-04-08 13:21:28.589 [ERROR] [nal.common.AbstractInvocationHandler] - An error occurred while calling method 'QueryablePersistenceService.query()' on 'org.openhab.persistence.jdbc.internal.JdbcPersistenceService@6bfdcace': class [B cannot be cast to class java.lang.String ([B and java.lang.String are in module java.base of loader 'bootstrap')
2021-04-08 13:21:28.594 [DEBUG] [jdbc.internal.JdbcPersistenceService] - JDBC::getName: returning name 'jdbc' for queryable persistence service.
2021-04-08 13:21:28.595 [ERROR] [ence.internal.PersistenceManagerImpl] - Exception occurred while querying persistence service 'jdbc': class [B cannot be cast to class java.lang.String ([B and java.lang.String are in module java.base of loader 'bootstrap')
. . .

ohb1138 · April 14, 2021, 7:37am

Installed provided fixes which solved the problem. Errors do not appear anymore.

THANK YOU!

I am just receiving the warning:

09:35:10.529 [WARN ] [org.apache.felix.fileinstall         ] - Error while starting bundle: file:/openhab/addons/org.openhab.persistence.jdbc-3.1.0-SNAPSHOT.jar
org.osgi.framework.BundleException: Could not resolve module: org.openhab.persistence.jdbc [284]
  Unresolved requirement: Import-Package: javassist; version="[3.25.0,4.0.0)"; resolution:="optional"
  Unresolved requirement: Import-Package: javassist.bytecode; version="[3.25.0,4.0.0)"; resolution:="optional"
  Unresolved requirement: Import-Package: org.osgi.framework; version="[1.9.0,2.0.0)"

	at org.eclipse.osgi.container.Module.start(Module.java:444) ~[org.eclipse.osgi-3.12.100.jar:?]
	at org.eclipse.osgi.internal.framework.EquinoxBundle.start(EquinoxBundle.java:383) ~[org.eclipse.osgi-3.12.100.jar:?]
	at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundle(DirectoryWatcher.java:1260) [bundleFile:3.6.4]
	at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundles(DirectoryWatcher.java:1233) [bundleFile:3.6.4]
	at org.apache.felix.fileinstall.internal.DirectoryWatcher.startAllBundles(DirectoryWatcher.java:1221) [bundleFile:3.6.4]
	at org.apache.felix.fileinstall.internal.DirectoryWatcher.doProcess(DirectoryWatcher.java:515) [bundleFile:3.6.4]
	at org.apache.felix.fileinstall.internal.DirectoryWatcher.process(DirectoryWatcher.java:365) [bundleFile:3.6.4]
	at org.apache.felix.fileinstall.internal.DirectoryWatcher.run(DirectoryWatcher.java:316) [bundleFile:3.6.4]

I will report on GitHub if this needs further attention.

cweitkamp · April 15, 2021, 1:58pm

My fix has been merged. It should be available in OH snapshot #2324 and later.

The warning is related to an OSGi Version updat in recent openHAB snapshot. This affects all bundles compiled from latest code. You will not be able to use them in older openHAB versions. To get them running you have to upgrade to latest openHAB nightly builds (e.g. build #2306 or higher).

system · May 27, 2021, 5:59am

This topic was automatically closed 41 days after the last reply. New replies are no longer allowed.