[Solved] Database error during start-up

havaak · April 18, 2020, 2:06pm

Enviroment:

jdbc.cfg

url=jdbc:mariadb://xxx.xxx.xxx.xxx:3306/OpenHAB
user=openhab
password="password"
tableUseRealItemNames=true
tableIdDigitCount=0
reconnectCnt=0

version:

Logging in as openhab

                          __  _____    ____      
  ____  ____  ___  ____  / / / /   |  / __ )     
 / __ \/ __ \/ _ \/ __ \/ /_/ / /| | / __  | 
/ /_/ / /_/ /  __/ / / / __  / ___ |/ /_/ /      
\____/ .___/\___/_/ /_/_/ /_/_/  |_/_____/     
    /_/                        2.5.0
                               Release Build   

Hit '<tab>' for a list of available commands
and '[cmd] --help' for help on a specific command.
Hit '<ctrl-d>' or type 'system:shutdown' or 'logout' to shutdown openHAB.

During startup I get the following error:

2020-04-18 15:54:17.852 [ERROR] [org.knowm.yank.Yank                 ] - Error in SQL query!!!
java.sql.SQLException: Error preparing query: Query was 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.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.8.0_232]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:1.8.0_232]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_232]
	at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_232]
	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_232]
	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.AbstractComponentManager.enableInternal(AbstractComponentManager.java:666) [bundleFile:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.enable(AbstractComponentManager.java:432) [bundleFile:?]
	at org.apache.felix.scr.impl.manager.ConfigurableComponentHolder.enableComponents(ConfigurableComponentHolder.java:665) [bundleFile:?]
	at org.apache.felix.scr.impl.BundleComponentActivator.initialEnable(BundleComponentActivator.java:338) [bundleFile:?]
	at org.apache.felix.scr.impl.Activator.loadComponents(Activator.java:382) [bundleFile:?]
	at org.apache.felix.scr.impl.Activator.access$200(Activator.java:49) [bundleFile:?]
	at org.apache.felix.scr.impl.Activator$ScrExtension.start(Activator.java:264) [bundleFile:?]
	at org.apache.felix.scr.impl.AbstractExtender.createExtension(AbstractExtender.java:196) [bundleFile:?]
	at org.apache.felix.scr.impl.AbstractExtender.modifiedBundle(AbstractExtender.java:169) [bundleFile:?]
	at org.apache.felix.scr.impl.AbstractExtender.modifiedBundle(AbstractExtender.java:49) [bundleFile:?]
	at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:482) [osgi.core-6.0.0.jar:?]
	at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:415) [osgi.core-6.0.0.jar:?]
	at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:232) [osgi.core-6.0.0.jar:?]
	at org.osgi.util.tracker.BundleTracker$Tracked.bundleChanged(BundleTracker.java:444) [osgi.core-6.0.0.jar:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:908) [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.framework.EquinoxEventPublisher.publishBundleEventPrivileged(EquinoxEventPublisher.java:213) [org.eclipse.osgi-3.12.100.jar:?]
	at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:120) [org.eclipse.osgi-3.12.100.jar:?]
	at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:112) [org.eclipse.osgi-3.12.100.jar:?]
	at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor.publishModuleEvent(EquinoxContainerAdaptor.java:168) [org.eclipse.osgi-3.12.100.jar:?]
	at org.eclipse.osgi.container.Module.publishEvent(Module.java:476) [org.eclipse.osgi-3.12.100.jar:?]
	at org.eclipse.osgi.container.Module.start(Module.java:467) [org.eclipse.osgi-3.12.100.jar:?]
	at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1634) [org.eclipse.osgi-3.12.100.jar:?]
	at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1614) [org.eclipse.osgi-3.12.100.jar:?]
	at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.doContainerStartLevel(ModuleContainer.java:1585) [org.eclipse.osgi-3.12.100.jar:?]
	at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1528) [org.eclipse.osgi-3.12.100.jar:?]
	at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1) [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.EventManager$EventThread.run(EventManager.java:340) [org.eclipse.osgi-3.12.100.jar:?]
2020-04-18 15:54:24.163 [INFO ] [ui.habmin.internal.servlet.HABminApp] - Started HABmin servlet at /habmin
2020-04-18 15:54:24.583 [INFO ] [openhab.ui.paper.internal.PaperUIApp] - Started Paper UI at /paperui
2020-04-18 15:54:24.851 [INFO ] [panel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel

Where is this error coming from or what is it caused by?

tia

Han

Udo_Hartmann · April 19, 2020, 6:20am

Does jdbc work as expected (i.e. persisting items)?

havaak · April 19, 2020, 6:21am

Yes, it does.

Udo_Hartmann · April 19, 2020, 6:25am

Does the error occur at each startup?

havaak · April 19, 2020, 7:04am

yes, it does. I remember that before I had a list of database items that was checked during startup, which also ended in an error. I will try to find that in the old error logs.

havaak · April 19, 2020, 7:23am

found that log:

2019-12-29 21:40:01.342 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table newName= sensor_ah_douche_temperature_7
2019-12-29 21:40:01.349 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: Table oldName='sensor_ah_douche_temperature_7' newName='sensor_ah_douche_temperature_7' nothing to rename
2019-12-29 21:40:01.354 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table Name= light_vh_woonkamer_plafond_2_ct_s2_102
2019-12-29 21:40:01.360 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table Name= light_vh_woonkamer_plafond_2_ct_s2_102 id= 102
2019-12-29 21:40:01.364 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table id= 102
2019-12-29 21:40:01.373 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table newName= light_vh_woonkamer_plafond_2_ct_s2_102
2019-12-29 21:40:01.384 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: Table oldName='light_vh_woonkamer_plafond_2_ct_s2_102' newName='light_vh_woonkamer_plafond_2_ct_s2_102' nothing to rename

------ cut-------

2019-12-29 21:40:05.204 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table Name= sensor_ah_douche_motion_40
2019-12-29 21:40:05.205 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table Name= sensor_ah_douche_motion_40 id= 40
2019-12-29 21:40:05.216 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table id= 40
2019-12-29 21:40:05.218 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table newName= sensor_ah_douche_motion_40
2019-12-29 21:40:05.220 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: Table oldName='sensor_ah_douche_motion_40' newName='sensor_ah_douche_motion_40' nothing to rename
2019-12-29 21:40:05.221 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table Name= sensor_vh_keuken_hue_temperature_149
2019-12-29 21:40:05.223 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table Name= sensor_vh_keuken_hue_temperature_149 id= 149
2019-12-29 21:40:05.224 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table id= 149
2019-12-29 21:40:05.225 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table newName= sensor_vh_keuken_hue_temperature_149
2019-12-29 21:40:05.227 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: Table oldName='sensor_vh_keuken_hue_temperature_149' newName='sensor_vh_keuken_hue_temperature_149' nothing to rename
2019-12-29 21:40:05.228 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table Name= sensor_vh_studeerkamer_greenwavepowernode1_watts_189
2019-12-29 21:40:05.230 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table Name= sensor_vh_studeerkamer_greenwavepowernode1_watts_189 id= 189
2019-12-29 21:40:05.231 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table id= 189
2019-12-29 21:40:05.241 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table newName= sensor_vh_studeerkamer_greenwavepowernode1_watts_189
2019-12-29 21:40:05.242 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: Table oldName='sensor_vh_studeerkamer_greenwavepowernode1_watts_189' newName='sensor_vh_studeerkamer_greenwavepowernode1_watts_189' nothing to rename
2019-12-29 21:40:05.252 [ERROR] [org.knowm.yank.Yank                 ] - Error in SQL query!!!

Udo_Hartmann · April 19, 2020, 7:36am

hmm… so I guess you changed something about the persistence? Did you change tableUseRealItemNames to true recently?

havaak · April 19, 2020, 7:55am

I added and removed mapdb to take of persistence of values over startup. Removed some database items in that proces. I did not change tableUseRealItemNames

Udo_Hartmann · April 19, 2020, 8:06am

Hmm… that’s strange. I don’t see any reason to rename tables over and over again. As I don’t use RealItemNames I have no idea other than clean-cache, but there is a good chance that this won’t help.

Another option would be to

stop openHAB
rename all tables in openhab_db to a new name like “Itemname_oldTable”
start openHAB and give openHAB some time to recreate all tables
ensure that there is no more error in openhab.log
insert old data from the old tables to the recreated tables.

havaak · April 19, 2020, 8:27am

I’m going to give this a try. Thx will report back!

havaak · April 19, 2020, 11:07am

Well, that didn’t go to well Database backup succeeded but turned out to be half empty. Even with a new database I get the same error during startup.

havaak · April 19, 2020, 11:46am

Error is generated just after the database is created.

Udo_Hartmann · April 20, 2020, 3:58am

Are you sure that your jdbc.persist file is correct?

havaak · April 20, 2020, 5:09am

I would like to think so

Strategies {
	everySecond		: "0 * * * * ?"
	every10Seconds	: "0/10 * * * * ?"
	every50Seconds	: "0/50 * * * * ?"
	everyMinute		: "0 * * * * ?"
	every5Minutes	: "0 */5 * ? * *"
	every10Minutes	: "0 */10 * ? * *"
	everyHour 		: "0 0 * * * ?"
	everyDay  		: "0 0 0 * * ?"
	everyNight 		: "0 59 23 * * ?"

	// If no strategy is specified for an item entry below, the default list will be used.
	default = everyChange, everyUpdate, restoreOnStartup
}

/*
 * Each line in this section defines for which item(s) which strategy(ies) should be applied.
 * You can list single items, use "*" for all items or "groupitem*" for all members of a group
 * item (excl. the group item itself).
 */
 
 Items {

// timebased persistence
gPersist_2359u*						: strategy = everyNight, restoreOnStartup
gPersist_5Min*						: strategy = every5Minutes, restoreOnStartup

gRestore*							: strategy = everyUpdate, restoreOnStartup
gClimateItems*					 	: strategy = everyUpdate, restoreOnStartup
//gLuminance*							: strategy = everyUpdate, restoreOnStartup
//gBatteryPowered* 					: strategy = everyUpdate, restoreOnStartup
gCV*								: strategy = everyUpdate, restoreOnStartup
gPowerMeasurement*					: strategy = every10Seconds, restoreOnStartup
gVoltageMeasument*                  : strategy = everyChange, restoreOnStartup
gMotionDetectors*                   : strategy = everyChange, restoreOnStartup
gStatusItems*						: strategy = everyChange, restoreOnStartup
gScene*								: strategy = everyUpdate, restoreOnStartup									
gLights*							: strategy = everyChange, restoreOnStartup
gTOD*								: strategy = everyUpdate, restoreOnStartup	
gAutomated*							: strategy = everyUpdate, restoreOnStartup									
Presence_Sensors*					: strategy = everyChange, restoreOnStartup
gPersist*							: strategy = everyChange, restoreOnStartup
	
}

havaak · April 24, 2020, 6:38pm

I enabled log:set TRACE org.openhab.persistence.jdbc and the following came by in the log:

2020-04-24 20:27:23.829 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table Name= light_vh_toilet_135
2020-04-24 20:27:23.831 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table Name= light_vh_toilet_135 id= 135
2020-04-24 20:27:23.832 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table id= 135
2020-04-24 20:27:23.833 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: found Table newName= light_vh_toilet_135
2020-04-24 20:27:23.834 [WARN ] [persistence.jdbc.internal.JdbcMapper] - JDBC::formatTableNames: Table oldName='light_vh_toilet_135' newName='light_vh_toilet_135' nothing to rename
2020-04-24 20:27:23.840 [DEBUG] [persistence.jdbc.internal.JdbcMapper] - JDBC::updateItemTableNames
2020-04-24 20:27:23.841 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::updateItemTableNamesProvider namesList.size = 0
2020-04-24 20:27:23.843 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::query queryString =
2020-04-24 20:27:23.864 [ERROR] [org.knowm.yank.Yank                 ] - Error in SQL query!!!
2020-04-24 20:27:23.916 [DEBUG] [jdbc.internal.JdbcPersistenceService] - JDBC::getName: returning name 'jdbc' for queryable persistence service.
2020-04-24 20:27:23.917 [DEBUG] [jdbc.internal.JdbcPersistenceService] - JDBC::updateConfig: configuration complete for service=jdbc.
2020-04-24 20:27:23.930 [DEBUG] [jdbc.internal.JdbcPersistenceService] - JDBC::getName: returning name 'jdbc' for queryable persistence service.
2020-04-24 20:27:23.935 [DEBUG] [jdbc.internal.JdbcPersistenceService] - JDBC::getName: returning name 'jdbc' for queryable persistence service.
2020-04-24 20:27:23.937 [DEBUG] [jdbc.internal.JdbcPersistenceService] - JDBC::getName: returning name 'jdbc' for queryable persistence service.
2020-04-24 20:27:23.940 [DEBUG] [jdbc.internal.JdbcPersistenceService] - JDBC::getName: returning name 'jdbc' for queryable persistence service.
2020-04-24 20:27:23.942 [DEBUG] [jdbc.internal.JdbcPersistenceService] - JDBC::getName: returning name 'jdbc' for queryable persistence service.

it looks like there is some kind of error in the binding.

@wborn @hilbrand are you able to advise or refer?

kind regards, Han

wborn · April 24, 2020, 9:16pm

I don’t use this persistence add-on. But after a brief look at the stacktrace and code it seems the rebuildTableNames setting is still true .

github.com/openhab/openhab1-addons

bundles/persistence/org.openhab.persistence.jdbc/java/org/openhab/persistence/jdbc/internal/JdbcMapper.java

0feffe659


      
          if (conf.getRebuildTableNames()) {
              formatTableNames();
          } else {

Maybe you enabled it and then removed it… instead of setting it to false ?

According to the docs:

rename existing tables using tableUseRealItemNames and tableIdDigitCount . USE WITH CARE! Deactivate after Renaming is done!

havaak · April 25, 2020, 5:07am

I added

rebuildTableNames=false

to jdbc.cfg and the error message is gone! Thanks @wborn and @Udo_Hartmann for helping me cleaning up my start-up!

wborn · April 25, 2020, 10:32am

I’ve created a PR to improve this in OH3:

github.com/openhab/openhab-addons

[jdbc] Improve rebuildTableNames behavior

master ← wborn:jdbc-improve-rebuild

opened 10:27AM - 25 Apr 20 UTC

wborn

+8 -3

When the setting is removed instead of set to false, tables will continue to be …rebuild every startup causing an exception: ``` 2020-04-18 15:54:17.852 [ERROR] [org.knowm.yank.Yank ] - Error in SQL query!!! java.sql.SQLException: Error preparing query: Query was 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.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.8.0_232] at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:1.8.0_232] at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_232] at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_232] 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_232] 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.AbstractComponentManager.enableInternal(AbstractComponentManager.java:666) [bundleFile:?] at org.apache.felix.scr.impl.manager.AbstractComponentManager.enable(AbstractComponentManager.java:432) [bundleFile:?] at org.apache.felix.scr.impl.manager.ConfigurableComponentHolder.enableComponents(ConfigurableComponentHolder.java:665) [bundleFile:?] at org.apache.felix.scr.impl.BundleComponentActivator.initialEnable(BundleComponentActivator.java:338) [bundleFile:?] at org.apache.felix.scr.impl.Activator.loadComponents(Activator.java:382) [bundleFile:?] at org.apache.felix.scr.impl.Activator.access$200(Activator.java:49) [bundleFile:?] at org.apache.felix.scr.impl.Activator$ScrExtension.start(Activator.java:264) [bundleFile:?] at org.apache.felix.scr.impl.AbstractExtender.createExtension(AbstractExtender.java:196) [bundleFile:?] at org.apache.felix.scr.impl.AbstractExtender.modifiedBundle(AbstractExtender.java:169) [bundleFile:?] at org.apache.felix.scr.impl.AbstractExtender.modifiedBundle(AbstractExtender.java:49) [bundleFile:?] at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:482) [osgi.core-6.0.0.jar:?] at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:415) [osgi.core-6.0.0.jar:?] at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:232) [osgi.core-6.0.0.jar:?] at org.osgi.util.tracker.BundleTracker$Tracked.bundleChanged(BundleTracker.java:444) [osgi.core-6.0.0.jar:?] at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:908) [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.framework.EquinoxEventPublisher.publishBundleEventPrivileged(EquinoxEventPublisher.java:213) [org.eclipse.osgi-3.12.100.jar:?] at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:120) [org.eclipse.osgi-3.12.100.jar:?] at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:112) [org.eclipse.osgi-3.12.100.jar:?] at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor.publishModuleEvent(EquinoxContainerAdaptor.java:168) [org.eclipse.osgi-3.12.100.jar:?] at org.eclipse.osgi.container.Module.publishEvent(Module.java:476) [org.eclipse.osgi-3.12.100.jar:?] at org.eclipse.osgi.container.Module.start(Module.java:467) [org.eclipse.osgi-3.12.100.jar:?] at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1634) [org.eclipse.osgi-3.12.100.jar:?] at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1614) [org.eclipse.osgi-3.12.100.jar:?] at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.doContainerStartLevel(ModuleContainer.java:1585) [org.eclipse.osgi-3.12.100.jar:?] at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1528) [org.eclipse.osgi-3.12.100.jar:?] at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1) [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.EventManager$EventThread.run(EventManager.java:340) [org.eclipse.osgi-3.12.100.jar:?] ``` So let's prevent the error and log some instructions to disable the setting again. See [Database error during start-up](https://community.openhab.org/t/solved-database-error-during-start-up/96896?u=wborn)