(SOLVED) JDBC Persistence troubles

astrnad · January 15, 2017, 2:44pm

Hi community,

i can’t seem to get my persistence going (again) as it already has been working.
But from the start: I’m using openhab2 (build 720), JDBC Persistence MariaDB (installed via PaperUI) against a MariaDB Server on the network (ver. 5.5.51-MariaDB).

On startup of OH2, the log shows 2 peculiar entries:

2017-01-15 14:48:03.797 [WARN ] [nce.extensions.PersistenceExtensions] - There is no queryable persistence service registered with the id 'jdbc'
...
2017-01-15 14:48:04.008 [INFO ] [persistence.jdbc.internal.JdbcMapper] - JDBC::openConnection: Driver is available::Yank setupDataSource

Albeit the first log entry might be related to a rule trying to fetch historic data before the DB connection is initialized.

Anyways, no other log entries (and i must admit, i have no clue how to set just the JDBC persistence to DEBUG or TRACE) hint me: The DB is there, the tables are all there, but nothing gets inserted…

Here’s the jdbc.persist:

Strategies {
	// if no strategy is specified for an item entry below, the default list will be used
	everyMinute	: "0 * * * * ?"
    every5Minutes : "0 */5 * * * ?"
   	everyHour   : "0 0 * * * ?"
   	everyDay    : "0 0 0 * * ?"
   	default = everyChange
}

And some items using these strategies:

Switch  Heizung_Anf_WPBoiler                     "Anforderung Wärmepumpe: Boiler [MAP(heizung.map):%s]"        <light>    (gHeizung,gPersistEvery5Minutes) { mqtt="<[broker:agb9/heizung/wp/boiler/status:state:MAP(heizunganf.map)]" }
Switch  Heizung_Anf_PassiveKuehlung              "Anforderung Passive Kühlung [MAP(heizung.map):%s]"           <light>    (gHeizung,gPersistEvery5Minutes) { mqtt="<[broker:agb9/heizung/wp/passivekuehlung/status:state:MAP(heizunganf.map)]" }
Switch  Heizung_Anf_Frostschutz                  "Anforderung Frostschutz [MAP(heizung.map):%s]"               <light>    (gHeizung,gPersistEvery5Minutes) { mqtt="<[broker:agb9/heizung/wp/frostschutz/status:state:MAP(heizunganf.map)]" }
Switch  Heizung_Anf_Sole_Aussenlufterwaermung    "Anforderung Sole Aussenlufterwärmung [MAP(heizung.map):%s]"  <light>    (gHeizung,gPersistEvery5Minutes) { mqtt="<[broker:agb9/heizung/wp/sole/aussenlufterwaermung/status:state:MAP(heizunganf.map)]" }
Switch  Heizung_Anf_WPNTHeizkreis                "Anforderung Wärmepumpe: NT-Heizkreis [MAP(heizung.map):%s]"  <light>    (gHeizung,gPersistEvery5Minutes) { mqtt="<[broker:agb9/heizung/wp/nt-heizkreis/status:state:MAP(heizunganf.map)]" }
Number  Heizung_Raumtemperatur                   "Raumtemperatur [%.1f °C]"                                    <heating>  (gHeizung,gPersistEvery5Minutes) { mqtt="<[broker:agb9/heizung/wp/raumtemperatur/ist/temperatur:state:default]" }
Number  Heizung_Raumtemperatur_Soll              "Raumtemperatur Soll [%.1f °C]"                               <heating>  (gHeizung,gPersistDaily)         { mqtt="<[broker:agb9/heizung/wp/raumtemperatur/soll/temperatur:state:default]" }
Number  Heizung_WP_Starts                        "Wärmepumpe Starts heute [%s]"                                <heating>  (gHeizung,gPersistEveryHour)

The values come in through MQTT fine, i can see the commands in events.log, but the values don’t appear in the DB. Yesterday i even set up a new openhabianpi because i wanted to rule out, that i’ve tinkered around with it enough to brake OH2, but after copying over my items and rules and persistence and service config, still no entries in the DB…

Can anyone hint me where to start?

Best regards,
Alex

watou · January 15, 2017, 2:50pm

Try

$ ssh openhab@localhost -p 8101 (password is habopen)
openhab> log:set TRACE org.openhab.persistence.jdbc
openhab> config:list  
(look for the relevant config in the output)
openhab> log:tail
(press Control-C to get the prompt back again)

Report anything unexplainable here. Good luck!

astrnad · January 15, 2017, 3:30pm

This is odd - as soon as i try to ssh into the karaf console, the java process goes to 100% CPU and is stuck there. I have used the console on the previous install with no problems…
Rebooted, after trying to ssh into karaf, still the same problem…

Received disconnect from 127.0.0.1: 2: Session has timed out waiting for authentication after 120000 ms.

EDIT: Strike that, seems to be the key generation process after first time karaf login…

Now digging into the logging

watou · January 15, 2017, 3:41pm

Good hunting!

astrnad · January 15, 2017, 3:51pm

----------------------------------------------------------------
Pid:            org.eclipse.smarthome.persistence
BundleLocation: null
Properties:
   default = jdbc
   service.pid = org.eclipse.smarthome.persistence
----------------------------------------------------------------

and

----------------------------------------------------------------
Pid:            org.openhab.jdbc
BundleLocation: null
Properties:
   password = xxx
   service.pid = org.openhab.jdbc
   url = jdbc:mariadb://10.0.0.100:3306/openhab
   user = openhab
----------------------------------------------------------------

seem to be the relevant config sections in karaf, but apart from the Bundlelocation = null, nothing seems to be out of order here…

Now the DEBUG/TRACE log shows that the historicState query from a rule executes just fine and returns a value:

2017-01-15 16:46:07.427 [DEBUG] [jdbc.internal.JdbcPersistenceService] - JDBC::query: item is Stromzaehler_Gesamt
2017-01-15 16:46:07.431 [DEBUG] [persistence.jdbc.internal.JdbcMapper] - JDBC::getHistItemFilterQuery filter='true' numberDecimalcount='3' table='item0029' item='Stromzaehler_Gesamt (Type=NumberItem, State=186501)' itemName='Stromzaehler_Gesamt'
2017-01-15 16:46:07.434 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::getHistItemFilterQueryProvider filter = org.openhab.core.persistence.FilterCriteria@1342c61, numberDecimalcount = 3, table = item0029, simpleName = Stromzaehler_Gesamt
2017-01-15 16:46:07.438 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::query queryString = SELECT time, value FROM item0029 WHERE TIME<'2017-01-15 16:45:07' ORDER BY time DESC  LIMIT 0,1
2017-01-15 16:46:07.440 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::doGetHistItemFilterQuery sql=SELECT time, value FROM item0029 WHERE TIME<'2017-01-15 16:45:07' ORDER BY time DESC  LIMIT 0,1
2017-01-15 16:46:07.447 [DEBUG] [nhab.persistence.jdbc.db.JdbcBaseDAO] - JDBC::ItemResultHandler::handleResult getState value = '42235.0', getClass = 'class java.lang.Double', clazz = 'Double'
2017-01-15 16:46:07.449 [DEBUG] [jdbc.internal.JdbcPersistenceService] - JDBC::query: query for Stromzaehler_Gesamt returned 1 rows in 18 ms

But cat openhab.log | grep INSERT returns nothing… (And i have waited long enough so one of the persistence strategies should have kicked in by now)
A touch jdbc.persist does get the persistence file get reloaded, but still no INSERTs happening. I’m stumped

astrnad · January 15, 2017, 4:02pm

Oh, i forgot the Items definition in the jdbc.persist:

Items {
    // persist all items once a day and on every change and restore them from the db at startup
    //* : strategy = everyChange, everyDay, restoreOnStartup

	gZWavePersist*   : strategy = everyChange, restoreOnStartup
	//gPersist* : strategy = everyMinute, restoreOnStartup
	//gHeizung* : strategy = every5Minutes, restoreOnStartup
	gPersistEveryMinute : strategy = everyMinute, restoreOnStartup
	gPersistEvery5Minutes : strategy = every5Minutes, restoreOnStartup
	gPersistEveryHour : strategy = everyHour, restoreOnStartup
	gPersistDaily : strategy = everyDay, restoreOnStartup
	gPersistChange : strategy = everyChange, restoreOnStartup
	
}

So at least the Heizung_Anf* items had to be persisted every 5 minutes, if my configuration is correct…

watou · January 15, 2017, 4:27pm

It may not be helpful, but I use the MySQL persistence service to store and query to a MariaDB server. I don’t restoreOnStartup, however.

But what you are reporting should not be specific to the JDBC persistence service. I wonder if the error early on in the logs leads to this lack of inserts? At the openhab> prompt, could you bundle:list to find the ID for the JDBC persistence service, bundle:stop it and bundle:start it, to see if reloading it makes a difference?

@lewie, do you have any further troubleshooting ideas?

astrnad · January 15, 2017, 4:51pm

There seem to be two relevant bundles:

213 | Active   |  80 | 1.3.5.0               | MariaDB JDBC Client
214 | Active   |  80 | 1.9.0.201701130210    | openHAB JDBC SQL Persistence bundle

I stopped and started both, and i can see the debug messages from the bundles coming up flow by, but no errors. After restart, the historic data queries from my rules do like before, but i can’t see any inserts happening.

I published to one of the topics of my items to see if a change in value would bring the persistence to save it, but still to no avail…

I also realized that i had the persistence items messed up, they missed the * to indicate a group - But after the file got reloaded, there are still no inserts happening…

astrnad · January 15, 2017, 11:41pm

Ok, this seems to be related to the persistence groups somehow - setting a strategy for * items persists all items fine… Will investigate further

astrnad · January 16, 2017, 8:19pm

@watou After investigating further into the persistence thing i got going on here, i found the following:

On these items:

Number  Stromzaehler_Gesamt        "Stromzähler Gesamt [%s]"              (gStromzaehler) { autoupdate="true", knx="<13.001:0/3/1" }
Number  Stromzaehler_Gesamt_Watt   "Stromzähler Gesamt Leistung [%s W]"   (gStromzaehler)

With these persistence settings:

Strategies {
	everyMinute	: "0 * * * * ?"
   	default = everyChange
}

Items {
	//gStromzaehler* : strategy = everyMinute, restoreOnStartup
	Stromzaehler_Gesamt : strategy = everyMinute, restoreOnStartup
	Stromzaehler_Gesamt_Watt : strategy = everyMinute, restoreOnStartup
}

the items will be persisted properly (every minute, as set).

When i change the persistence settings to the following:

Items {
	gStromzaehler* : strategy = everyMinute, restoreOnStartup
	//Stromzaehler_Gesamt : strategy = everyMinute, restoreOnStartup
	//Stromzaehler_Gesamt_Watt : strategy = everyMinute, restoreOnStartup
}

to reflect that i want to persist the group of items with the same settings, no INSERT is done.
In both cases, getting a value for one of the items in a rule works fine.

Do i have to set anything else to persist a group of items with one setting?

watou · January 16, 2017, 9:12pm

I don’t see a problem with your setup. But I use

Strategies {
  default = everyChange
}
Items {
  Persist* : strategy = everyChange
}

that works fine with the MySQL persistence service. You might see if this issue pertains to your everyMinute strategy:

astrnad · January 16, 2017, 10:05pm

@watou Thanks for the input, but sadly, after updating to Build 723, the issue is still there.
I don’t think it’s an issue with the scheduler, since persisting an item every minute works without a hitch, it’s persisting a group that doesn’t do as i hoped it would.
I also tried persisting a group on every change - same issue, no INSERTs happening.

I’m clueless (again)

watou · January 16, 2017, 10:50pm

Any chance you could try the MySQL persistence service instead to see if there is any difference? That could possibly help locate the origin of the issue.

astrnad · January 17, 2017, 6:08pm

Ok, here’s what i did:

Uninstalled all bundles related to MariaDB or JDBC
Emptied addons folder (had a MariaDB driver in there)
Installed MySQL persistence from PaperUI
Deleted all tables in the persistence DB
Copied over the relevant persistence settings from jdbc.cfg to mysql.cfg
Copied over the relevant persistence settings from jdbc.persist to mysql.persist
Fired up openhab
Changed default persistence to mysql in PaperUI
Restarted openhab

With the same items, same groups and same persistence settings i get the same results as with JDBC: When i persist single items, tables get created and items persisted.
Changing this to groups as outlined above no more inserts happen

So my guess is that i either have a typo hidden in my configuration somewhere or that persistence with groups is somehow broken (at least for my setup).

I have TRACE level enabled for org.openhab.persistence.mysql, but there’s nothing to be seen about group persistence.

watou · January 17, 2017, 6:58pm

I don’t have trouble persisting all items in a group, but I’m using the everyChange strategy. Could you test that, or test using a different cron expression? It looks like you ruled out the JDBC persistence service as the root cause, since the MySQL persistence service produces the same outcome.

astrnad · January 17, 2017, 8:25pm

I changed the strategy for the group to the following:

gStromzaehler* : strategy = everyChange//, restoreOnStartup

and still no inserts
I’m sorry @watou, i’m really out of ideas here - and since you can persist groups, i think i must have a typo somewhere in the configuration. But then again, there’s not even a TRACE or DEBUG message on the persistence layer…

astrnad · January 17, 2017, 8:30pm

There’s another thing here… Every so often, after saving the mysql.persist file, openhab won’t pick it up automatically, a touch on the file won’t do either, i have to restart openhab to make it reload the persistence file.

astrnad · January 17, 2017, 8:39pm

I think i got it by the ears @watou…
What my items file didn’t show (because it wasn’t there) was the definition of the groups, the items were in (gStromzaehler). Defined the group simply as Group gStromzaehler, restarted openhab, and now these group items get persisted by group whenever there is a change
Changing to persist on a cron expression works too!

Thank you very much for your patience

watou · January 17, 2017, 9:18pm

Ah! Yes, you can have items in a (group), but without having defined the Group item, it won’t work! So happy you got it figured out.

dikkedimi · July 24, 2018, 11:05am

I have this notification too. But in my case it’s probably related to MySQL (mariadb) not functioning properly. There is no openhab user (there used to be afaik). I’m having trouble connecting with the database with all users. Skipping the grant tables doesn’t allow me to modify user permissions. Sigh. It used to work before I updated my raspi.