JDBC Persistence Problem - [org.knowm.yank.Yank ] - Error in SQL query!

jenrad · April 6, 2020, 7:29am

Hallo,
I’ve got a problem with my jdbc persistence. Yesterday after reboot I couldn’t save any data because of missing missing ‘serverTimezone’ in my jdbc connection string. Because of other tutorials I could solve this problem. But after jdbc persistence tried to start working again there are a lot of warnings and errors in the log. It seems to be ok (so values were saved in database again) but I very much like to understand this error. This always happens after changing my jdbc.cfg (under services)

Here are the relevant log entries:

2020-04-06 09:11:13.457 [INFO ] [persistence.jdbc.internal.JdbcMapper] - JDBC::openConnection: Driver is available::Yank setupDataSource
2020-04-06 09:11:13.477 [WARN ] [.zaxxer.hikari.util.DriverDataSource] - Registered driver with driverClassName=com.mysql.jdbc.Driver was not found, trying direct instantiation.
2020-04-06 09:11:13.540 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table Name= Item7
2020-04-06 09:11:13.542 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table with Prefix 'Item' Name= Item7 id= 7
2020-04-06 09:11:13.545 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table id= 7
2020-04-06 09:11:13.547 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table newName= Item7
2020-04-06 09:11:13.549 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: Table oldName='Item7' newName='Item7' nothing to rename
2020-04-06 09:11:13.552 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table Name= Item2
2020-04-06 09:11:13.554 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table with Prefix 'Item' Name= Item2 id= 2
2020-04-06 09:11:13.556 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table id= 2
2020-04-06 09:11:13.559 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table newName= Item2
2020-04-06 09:11:13.561 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: Table oldName='Item2' newName='Item2' nothing to rename
2020-04-06 09:11:13.563 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table Name= Item6
2020-04-06 09:11:13.566 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table with Prefix 'Item' Name= Item6 id= 6
2020-04-06 09:11:13.568 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table id= 6
2020-04-06 09:11:13.571 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table newName= Item6
2020-04-06 09:11:13.573 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: Table oldName='Item6' newName='Item6' nothing to rename
2020-04-06 09:11:13.575 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table Name= Item3
2020-04-06 09:11:13.578 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table with Prefix 'Item' Name= Item3 id= 3
2020-04-06 09:11:13.580 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table id= 3
2020-04-06 09:11:13.583 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table newName= Item3
2020-04-06 09:11:13.585 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: Table oldName='Item3' newName='Item3' nothing to rename
2020-04-06 09:11:13.588 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table Name= Item5
2020-04-06 09:11:13.590 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table with Prefix 'Item' Name= Item5 id= 5
2020-04-06 09:11:13.592 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table id= 5
2020-04-06 09:11:13.595 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table newName= Item5
2020-04-06 09:11:13.597 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: Table oldName='Item5' newName='Item5' nothing to rename
2020-04-06 09:11:13.599 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table Name= Item4
2020-04-06 09:11:13.602 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table with Prefix 'Item' Name= Item4 id= 4
2020-04-06 09:11:13.605 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table id= 4
2020-04-06 09:11:13.608 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table newName= Item4
2020-04-06 09:11:13.611 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: Table oldName='Item4' newName='Item4' nothing to rename
2020-04-06 09:11:13.613 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table Name= Item1
2020-04-06 09:11:13.615 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table with Prefix 'Item' Name= Item1 id= 1
2020-04-06 09:11:13.618 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table id= 1
2020-04-06 09:11:13.620 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table newName= Item1
2020-04-06 09:11:13.623 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: Table oldName='Item1' newName='Item1' nothing to rename
2020-04-06 09:11:13.626 [ERROR] [org.knowm.yank.Yank                 ] - Error in SQL query!!!
java.sql.SQLException: SQL String cannot be empty Query:  Parameters: []
	at org.apache.commons.dbutils.AbstractQueryRunner.rethrow(AbstractQueryRunner.java:392) ~[commons-dbutils-1.6.jar:1.6]
	at org.apache.commons.dbutils.QueryRunner.update(QueryRunner.java:491) ~[commons-dbutils-1.6.jar:1.6]
	at org.apache.commons.dbutils.QueryRunner.update(QueryRunner.java:457) ~[commons-dbutils-1.6.jar:1.6]
	at org.knowm.yank.Yank.execute(Yank.java:194) [yank-3.2.0.jar:?]
	at org.knowm.yank.Yank.execute(Yank.java:177) [yank-3.2.0.jar:?]
	at org.openhab.persistence.jdbc.db.JdbcBaseDAO.doUpdateItemTableNames(JdbcBaseDAO.java:319) [bundleFile:?]
	at org.openhab.persistence.jdbc.internal.JdbcMapper.updateItemTableNames(JdbcMapper.java:125) [bundleFile:?]
	at org.openhab.persistence.jdbc.internal.JdbcMapper.formatTableNames(JdbcMapper.java:345) [bundleFile:?]
	at org.openhab.persistence.jdbc.internal.JdbcMapper.checkDBSchema(JdbcMapper.java:218) [bundleFile:?]
	at org.openhab.persistence.jdbc.internal.JdbcPersistenceService.updateConfig(JdbcPersistenceService.java:223) [bundleFile:?]
	at org.openhab.persistence.jdbc.internal.JdbcPersistenceService.activate(JdbcPersistenceService.java:65) [bundleFile:?]
	at sun.reflect.GeneratedMethodAccessor184.invoke(Unknown Source) ~[?:?]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_222]
	at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_222]
	at org.apache.felix.scr.impl.inject.methods.BaseMethod.invokeMethod(BaseMethod.java:228) [bundleFile:?]
	at org.apache.felix.scr.impl.inject.methods.BaseMethod.access$500(BaseMethod.java:41) [bundleFile:?]
	at org.apache.felix.scr.impl.inject.methods.BaseMethod$Resolved.invoke(BaseMethod.java:664) [bundleFile:?]
	at org.apache.felix.scr.impl.inject.methods.BaseMethod.invoke(BaseMethod.java:510) [bundleFile:?]
	at org.apache.felix.scr.impl.inject.methods.ActivateMethod.invoke(ActivateMethod.java:317) [bundleFile:?]
	at org.apache.felix.scr.impl.inject.methods.ActivateMethod.invoke(ActivateMethod.java:307) [bundleFile:?]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.createImplementationObject(SingleComponentManager.java:340) [bundleFile:?]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.createComponent(SingleComponentManager.java:114) [bundleFile:?]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:982) [bundleFile:?]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.getServiceInternal(SingleComponentManager.java:955) [bundleFile:?]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:900) [bundleFile:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse$1.run(ServiceFactoryUse.java:212) [org.eclipse.osgi-3.12.100.jar:?]
	at java.security.AccessController.doPrivileged(Native Method) [?:1.8.0_222]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.factoryGetService(ServiceFactoryUse.java:210) [org.eclipse.osgi-3.12.100.jar:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.getService(ServiceFactoryUse.java:111) [org.eclipse.osgi-3.12.100.jar:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceConsumer$2.getService(ServiceConsumer.java:45) [org.eclipse.osgi-3.12.100.jar:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.getService(ServiceRegistrationImpl.java:508) [org.eclipse.osgi-3.12.100.jar:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.getService(ServiceRegistry.java:461) [org.eclipse.osgi-3.12.100.jar:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.getService(BundleContextImpl.java:624) [org.eclipse.osgi-3.12.100.jar:?]
	at org.apache.felix.scr.impl.manager.SingleRefPair.getServiceObject(SingleRefPair.java:86) [bundleFile:?]
	at org.apache.felix.scr.impl.inject.BindParameters.getServiceObject(BindParameters.java:47) [bundleFile:?]
	at org.apache.felix.scr.impl.inject.methods.BindMethod.getServiceObject(BindMethod.java:664) [bundleFile:?]
	at org.apache.felix.scr.impl.manager.DependencyManager.getServiceObject(DependencyManager.java:2308) [bundleFile:?]
	at org.apache.felix.scr.impl.manager.DependencyManager.doInvokeBindMethod(DependencyManager.java:1805) [bundleFile:?]
	at org.apache.felix.scr.impl.manager.DependencyManager.invokeBindMethod(DependencyManager.java:1788) [bundleFile:?]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.invokeBindMethod(SingleComponentManager.java:435) [bundleFile:?]
	at org.apache.felix.scr.impl.manager.DependencyManager$MultipleDynamicCustomizer.addedService(DependencyManager.java:325) [bundleFile:?]
	at org.apache.felix.scr.impl.manager.DependencyManager$MultipleDynamicCustomizer.addedService(DependencyManager.java:294) [bundleFile:?]
	at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1216) [bundleFile:?]
	at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1137) [bundleFile:?]
	at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.trackAdding(ServiceTracker.java:944) [bundleFile:?]
	at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.track(ServiceTracker.java:880) [bundleFile:?]
	at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:1168) [bundleFile:?]
	at org.apache.felix.scr.impl.BundleComponentActivator$ListenerInfo.serviceChanged(BundleComponentActivator.java:125) [bundleFile:?]
	at org.eclipse.osgi.internal.serviceregistry.FilteredServiceListener.serviceChanged(FilteredServiceListener.java:109) [org.eclipse.osgi-3.12.100.jar:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:920) [org.eclipse.osgi-3.12.100.jar:?]
	at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) [org.eclipse.osgi-3.12.100.jar:?]
	at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148) [org.eclipse.osgi-3.12.100.jar:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEventPrivileged(ServiceRegistry.java:862) [org.eclipse.osgi-3.12.100.jar:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEvent(ServiceRegistry.java:801) [org.eclipse.osgi-3.12.100.jar:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.register(ServiceRegistrationImpl.java:127) [org.eclipse.osgi-3.12.100.jar:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.registerService(ServiceRegistry.java:225) [org.eclipse.osgi-3.12.100.jar:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.registerService(BundleContextImpl.java:469) [org.eclipse.osgi-3.12.100.jar:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:906) [bundleFile:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:892) [bundleFile:?]
	at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:128) [bundleFile:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:959) [bundleFile:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:732) [bundleFile:?]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.reconfigure(SingleComponentManager.java:734) [bundleFile:?]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.reconfigure(SingleComponentManager.java:673) [bundleFile:?]
	at org.apache.felix.scr.impl.manager.ConfigurableComponentHolder.configurationUpdated(ConfigurableComponentHolder.java:435) [bundleFile:?]
	at org.apache.felix.scr.impl.manager.RegionConfigurationSupport.configurationEvent(RegionConfigurationSupport.java:316) [bundleFile:?]
	at org.apache.felix.scr.impl.manager.RegionConfigurationSupport$2.configurationEvent(RegionConfigurationSupport.java:118) [bundleFile:?]
	at org.apache.felix.cm.impl.ConfigurationManager$FireConfigurationEvent.sendEvent(ConfigurationManager.java:1709) [bundleFile:?]
	at org.apache.felix.cm.impl.ConfigurationManager$FireConfigurationEvent.run(ConfigurationManager.java:1651) [bundleFile:?]
	at org.apache.felix.cm.impl.UpdateThread.run0(UpdateThread.java:138) [bundleFile:?]
	at org.apache.felix.cm.impl.UpdateThread.run(UpdateThread.java:105) [bundleFile:?]
	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_222]

Thank you very much for help!!

Udo_Hartmann · April 6, 2020, 4:14pm

This seems to be the source of the problem…

Are you sure your jdbc.cfg is correct?

jenrad · April 6, 2020, 6:52pm

I hope my config is correct. So after saving changings of jdbd.cfg the error comes up. Afterwards all values are stored in the database without any problems. My jdbc.cfg looks like this (without all uncommented lines)

url=jdbc:mysql://xx.xx.xx.xx:xxxx/dbname?serverTimezone=Europe/Berlin
user=xxxx
password=xxxx
tableIdDigitCount=0

That’s it. So nothing special

Udo_Hartmann · April 6, 2020, 7:08pm

Hmm…

looks good to me.

I’m not aware of any other prerequisites…

atm I’m not at home, so I can’t test, but afaik openHAB copies the configuration to other files. So maybe there is an error in the “internal” file.

jenrad · April 6, 2020, 7:27pm

Ok, thanks. An internal file would make sense. Would be intresting to check this file but I don’t know there I have to look to…

Udo_Hartmann · April 6, 2020, 7:30pm

That’s the point… I’m not sure about the file name and where to find it.

jenrad · April 7, 2020, 5:38am

I changed my jdbc.cfg a bit:

url=jdbc:mysql://xx.xx.xx.xx:xxxx/dbname?serverTimezone=Europe/Berlin
user=xxxx
password=xxxx
tableIdDigitCount=0
sqltype.NUMBER        =   DOUBLE
sqltype.STRING        =   VARCHAR(65500)
tableNamePrefix=Item
tableIdDigitCount=0
rebuildTableNames=false
enableLogTime=false

After saving only few messages are left and no errors. So rebuilding the tables seems to cause the error.

2020-04-07 07:18:51.284 [INFO ] [persistence.jdbc.internal.JdbcMapper] - JDBC::openConnection: Driver is available::Yank setupDataSource
2020-04-07 07:18:51.298 [WARN ] [.zaxxer.hikari.util.DriverDataSource] - Registered driver with driverClassName=com.mysql.jdbc.Driver was not found, trying direct instantiation.

Now there is only a warning. In other discussions you can find the info that the driver should be renamed.

old: com.mysql.jdbc.Driver
new: com.mysql.cj.jdbc.Driver

But I don’t know there the driverClassName is definied. In the end it’s just a warning and everything seems to work…

jenrad · April 7, 2020, 5:49am

Hi again,
I just found the reason: I checked my database version =>

mysql -V
mysql  Ver 15.1 Distrib 10.3.22-MariaDB, for debian-linux-gnueabihf (armv8l) using readline 5.2

So I’ve got an mariadb instead of a mysql. Because of this I changed my connection string to mariadb.

url=jdbc:mariadb://<ip>:<port>/<dbname>?serverTimezone=Europe/Berlin

Now only the info is left, no errors or warnings.

2020-04-07 07:41:15.225 [INFO ] [persistence.jdbc.internal.JdbcMapper] - JDBC::openConnection: Driver is available::Yank setupDataSource

system · May 18, 2020, 9:49pm

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