Mysql not restoring item on startup

Add-ons Persistence Services
1

Some of my items do not get their value’s restored on startup, while (as far as i can see) everything is setup right.

Item definition:

Number	verd2_cvruimte_cv_programma	"CV programma"	(_grpPersist)

Persistence definition:

Strategies {
	everyMonth		: "0	0	0	1	* ?"
	everyDay		: "0	0	0	*	* ?"
	everyHour		: "0	0	*	*	* ?"
	everyFiveMinutes	: "0	*/5	*	*	* ?"
	everyMinute		: "0	*	*	*	* ?"
	default = everyChange
}

Items {
	_grpPersist*				: strategy = restoreOnStartup, everyChange
}

Sitemap:

Switch item=verd2_cvruimte_cv_programma mappings=[0="Off", 1="On", 2="Tijdl", 3="Auto"]

log file (with debug trace) It shows a value change (Item101) and restart of openHAB

**2018-08-25 12:44:19.062 [DEBUG] [sql.internal.MysqlPersistenceService] - mySQL: Stored item 'verd2_cvruimte_cv_programma' as '2'[2] in SQL database at 2018-08-25 12:44:19.047.**
**2018-08-25 12:44:19.066 [DEBUG] [sql.internal.MysqlPersistenceService] - mySQL: query: INSERT INTO Item101 (TIME, VALUE) VALUES(?,?) ON DUPLICATE KEY UPDATE VALUE=?;**
2018-08-25 12:45:15.415 [INFO ] [basic.internal.servlet.WebAppServlet] - Stopped Basic UI
2018-08-25 12:45:22.314 [DEBUG] [org.openhab.persistence.mysql       ] - BundleEvent STOPPING - org.openhab.persistence.mysql
2018-08-25 12:45:22.319 [DEBUG] [org.openhab.persistence.mysql       ] - ServiceEvent UNREGISTERING - {org.openhab.core.persistence.PersistenceService}={service.id=371, service.bundleid=215, service.scope=bundle, user=openhab, url=jdbc:mysql://127.0.0.1:3306/openhab, component.name=org.openhab.persistence.mysql, reconnectCnt=1, component.id=249, password=DKtXmbAl1IKF7God, localtime=true, waitTimeout=28800, service.pid=org.openhab.mysql} - org.openhab.persistence.mysql
2018-08-25 12:45:22.336 [DEBUG] [sql.internal.MysqlPersistenceService] - mySQL persistence bundle stopping. Disconnecting from database.
2018-08-25 12:45:22.341 [DEBUG] [sql.internal.MysqlPersistenceService] - mySQL: Disconnected from database jdbc:mysql://127.0.0.1:3306/openhab
2018-08-25 12:45:22.355 [DEBUG] [nal.MysqlPersistenceServiceActivator] - mySQL persistence bundle has been stopped.
2018-08-25 12:45:22.358 [DEBUG] [org.openhab.persistence.mysql       ] - BundleEvent STOPPED - org.openhab.persistence.mysql
2018-08-25 12:45:22.588 [INFO ] [ui.habmin.internal.servlet.HABminApp] - Stopped HABmin servlet
2018-08-25 12:45:26.135 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Stopped Paper UI
2018-08-25 12:45:26.169 [INFO ] [panel.internal.HABPanelDashboardTile] - Stopped HABPanel
2018-08-25 12:45:26.193 [INFO ] [.dashboard.internal.DashboardService] - Stopped Dashboard
2018-08-25 12:45:38.988 [INFO ] [panel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel
2018-08-25 12:45:41.574 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Time zone set to 'Europe/Amsterdam'.
2018-08-25 12:45:41.584 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Location set to '53.191773999999995,6.552160499999999'.
2018-08-25 12:45:41.588 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Locale set to 'nl_NL'.
2018-08-25 12:45:41.592 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Measurement system set to 'SIUnits'.
2018-08-25 12:45:53.109 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Verwarming.items'
2018-08-25 12:45:54.121 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'mysql.persist'
2018-08-25 12:45:56.844 [INFO ] [thome.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007
2018-08-25 12:46:37.664 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Verwarming.rules'
2018-08-25 12:46:46.362 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model '_default.sitemap'
2018-08-25 12:46:46.859 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'all.things'
2018-08-25 12:46:51.114 [INFO ] [ternal.dhcp.DHCPPacketListenerServer] - DHCP request packet listener online
2018-08-25 12:46:54.027 [INFO ] [basic.internal.servlet.WebAppServlet] - Started Basic UI at /basicui/app
2018-08-25 12:46:54.235 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /paperui
2018-08-25 12:47:07.395 [DEBUG] [org.openhab.persistence.mysql       ] - BundleEvent STARTING - org.openhab.persistence.mysql
2018-08-25 12:47:07.404 [DEBUG] [nal.MysqlPersistenceServiceActivator] - mySQL persistence bundle has been started.
2018-08-25 12:47:07.406 [DEBUG] [org.openhab.persistence.mysql       ] - BundleEvent STARTED - org.openhab.persistence.mysql
2018-08-25 12:47:07.419 [DEBUG] [org.openhab.persistence.mysql       ] - ServiceEvent REGISTERED - {org.openhab.core.persistence.PersistenceService}={service.id=371, service.bundleid=215, service.scope=bundle, user=openhab, url=jdbc:mysql://127.0.0.1:3306/openhab, component.name=org.openhab.persistence.mysql, reconnectCnt=1, component.id=249, password=DKtXmbAl1IKF7God, localtime=true, waitTimeout=28800, service.pid=org.openhab.mysql} - org.openhab.persistence.mysql
2018-08-25 12:47:07.436 [DEBUG] [sql.internal.MysqlPersistenceService] - mySQL: Attempting to connect to database jdbc:mysql://127.0.0.1:3306/openhab
2018-08-25 12:47:08.408 [DEBUG] [sql.internal.MysqlPersistenceService] - mySQL: Connected to database jdbc:mysql://127.0.0.1:3306/openhab
2018-08-25 12:47:08.422 [DEBUG] [sql.internal.MysqlPersistenceService] - mySQL: Setting wait_timeout to 28800 seconds.
2018-08-25 12:47:08.437 [DEBUG] [sql.internal.MysqlPersistenceService] - mySQL configuration complete.
**2018-08-25 12:47:08.962 [DEBUG] [sql.internal.MysqlPersistenceService] - mySQL query: item is verd2_cvruimte_cv_programma**
**2018-08-25 12:47:08.965 [DEBUG] [sql.internal.MysqlPersistenceService] - mySQL: query:SELECT Time, Value FROM Item101 ORDER BY Time DESC LIMIT 0,1**
**2018-08-25 12:47:08.972 [DEBUG] [sql.internal.MysqlPersistenceService] - mySQL: query returned 1 rows in 6ms**
2018-08-25 12:47:10.322 [INFO ] [ui.habmin.internal.servlet.HABminApp] - Started HABmin servlet at /habmin

After the restart the corresponding button (in basicui and in habpanel) is not ‘active’

2

Is there anylogfile i can check? Any addditional debugging i can do?

3

Have you tried a bundle restart?
Here is a github issue I found : https://github.com/openhab/openhab1-addons/issues/4998

4

The logfile shows the value is stored, openhab restarts and the value being read from MySQL. So restarting the bundle and the linked issue don’t seem to be related. Thanks for the reply though :+1:

I might end up installing a development environment and debug it, but hoped to get an answer on the forums.

5

I’d add a [%d] to your Item description for now, so you can be sure you are looking at failure to restore value or a button display/update issue.

6

Good one! The value is actually restored to the item and the label shows the correct number, just the button is not updated.

I guess the problem is not with persistence, but with the UI (or how they interact),
If the item got updated from a rule or whatever, the correct button is visually active.

7

It’s never been clear to me when or how the various UI get refreshed.

I can see that refreshing from a ‘restore’ action wouldn’t generally need to invoke a refresh - “what do you expect when are looking at UI before system booted?” basis, perhaps.
I would imagine in normal use it all gets sorted out with typical startup activity on other Items, and only shows up when we’re having a close look.

I wonder if a clumsy workaround might be to have a ‘System started’ rule force an update of your Item with it’s existing (restored) value. Might not work out if you have other rules triggered on update.