Has anyone tried to enable the “wrapper.java.additional.5=-Dignition.storageengine=hsql” in v7.9.9 (b2018081621)?
We are using it in 7.8.4 (b2016082217) by recommendation of the support team, to fix some performance issues we were having with webdev.
We upgraded one of our Ignition servers to Version: 7.9.9 (b2018081621), and we started experiencing some slowness again.
I guess it is no longer available, I tried to enable in a test instance with this results.
INFO | jvm 2 | 2018/10/23 16:02:40 | I [g.InternalDatabaseManager ] [21:02:40]: Starting up...
INFO | jvm 2 | 2018/10/23 16:02:40 | I [g.I.HSQLSettings ] [21:02:40]: Looking for existing internal database "settings"...
INFO | jvm 2 | 2018/10/23 16:02:40 | I [g.I.HSQLSettings ] [21:02:40]: ... no files found, will create.
INFO | jvm 2 | 2018/10/23 16:02:40 | I [g.I.HSQLSettings ] [21:02:40]: Creating new internal database "settings".
INFO | jvm 2 | 2018/10/23 16:02:40 | I [o.e.j.s.ServerConnector ] [21:02:40]: Started ServerConnector@5182ff9b{SSL,[ssl, http/1.1]}{0.0.0.0:8043}
INFO | jvm 2 | 2018/10/23 16:02:40 | I [o.e.j.s.ServerConnector ] [21:02:40]: Started ServerConnector@787d30c5{SSL,[ssl, http/1.1]}{0.0.0.0:8060}
INFO | jvm 2 | 2018/10/23 16:02:40 | I [o.e.j.s.Server ] [21:02:40]: Started @10335ms
INFO | jvm 2 | 2018/10/23 16:02:40 | I [h.d.H.ENGINE ] [21:02:40]: Checkpoint start
INFO | jvm 2 | 2018/10/23 16:02:40 | I [h.d.H.ENGINE ] [21:02:40]: checkpointClose start
INFO | jvm 2 | 2018/10/23 16:02:40 | I [h.d.H.ENGINE ] [21:02:40]: checkpointClose synched
INFO | jvm 2 | 2018/10/23 16:02:40 | I [h.d.H.ENGINE ] [21:02:40]: checkpointClose script done
INFO | jvm 2 | 2018/10/23 16:02:40 | I [h.d.H.ENGINE ] [21:02:40]: checkpointClose end
INFO | jvm 2 | 2018/10/23 16:02:40 | I [h.d.H.ENGINE ] [21:02:40]: Checkpoint end - txts: 1
INFO | jvm 2 | 2018/10/23 16:02:40 | I [h.d.H.ENGINE ] [21:02:40]: dataFileCache open start
INFO | jvm 2 | 2018/10/23 16:02:40 | I [h.d.H.ENGINE ] [21:02:40]: dataFileCache open end
INFO | jvm 2 | 2018/10/23 16:02:40 | I [g.InternalDatabaseManager ] [21:02:40]: Upgrading schema for module "ignition"
INFO | jvm 2 | 2018/10/23 16:02:40 | I [g.InternalDatabaseManager ] [21:02:40]: Upgrading schema for module "ignition"
INFO | jvm 2 | 2018/10/23 16:02:40 | W [g.I.HSQLSettings ] [21:02:40]: Unable to connect to internal database "settings", shutting down...
INFO | jvm 2 | 2018/10/23 16:02:40 | I [h.d.H.ENGINE ] [21:02:40]: Database closed
INFO | jvm 2 | 2018/10/23 16:02:40 | W [g.I.HSQLSettings ] [21:02:40]: Unable to restore from autobackups because none were found.
INFO | jvm 2 | 2018/10/23 16:02:40 | E [g.I.HSQLSettings ] [21:02:40]: Startup of internal database "settings" failed, autobackups disabled.
INFO | jvm 2 | 2018/10/23 16:02:40 | java.sql.SQLSyntaxErrorException: user lacks privilege or object not found java.lang.ClassNotFoundException: com.inductiveautomation.ignition.gateway.localdb.HSQLUtilFunctions com.inductiveautomation.ignition.gateway.localdb.HSQLUtilFunctions in statement [CREATE FUNCTION BLOB_LENGTH(LOB BLOB) RETURNS BIGINT LANGUAGE JAVA EXTERNAL NAME 'CLASSPATH:com.inductiveautomation.ignition.gateway.localdb.HSQLUtilFunctions.getBlobLength']
INFO | jvm 2 | 2018/10/23 16:02:40 | at org.hsqldb.jdbc.JDBCUtil.sqlException(Unknown Source)
INFO | jvm 2 | 2018/10/23 16:02:40 | at org.hsqldb.jdbc.JDBCUtil.sqlException(Unknown Source)
INFO | jvm 2 | 2018/10/23 16:02:40 | at org.hsqldb.jdbc.JDBCStatement.fetchResult(Unknown Source)
INFO | jvm 2 | 2018/10/23 16:02:40 | at org.hsqldb.jdbc.JDBCStatement.executeUpdate(Unknown Source)
INFO | jvm 2 | 2018/10/23 16:02:40 | at org.apache.commons.dbcp.DelegatingStatement.executeUpdate(DelegatingStatement.java:228)
INFO | jvm 2 | 2018/10/23 16:02:40 | at com.inductiveautomation.ignition.gateway.localdb.AbstractDBInterface.runUpdateQuery(AbstractDBInterface.java:221)
INFO | jvm 2 | 2018/10/23 16:02:40 | at com.inductiveautomation.ignition.gateway.localdb.LocalDBManagerImpl$SingleConnectionDBInterface.runUpdateQuery(LocalDBManagerImpl.java:712)
INFO | jvm 2 | 2018/10/23 16:02:40 | at com.inductiveautomation.ignition.gateway.localdb.DDLSchemaFeature.apply(DDLSchemaFeature.java:35)
INFO | jvm 2 | 2018/10/23 16:02:40 | at com.inductiveautomation.ignition.gateway.localdb.LocalDBManagerImpl.updateSchema(LocalDBManagerImpl.java:320)
INFO | jvm 2 | 2018/10/23 16:02:40 | at com.inductiveautomation.ignition.gateway.localdb.LocalDBManagerImpl.access$200(LocalDBManagerImpl.java:84)
INFO | jvm 2 | 2018/10/23 16:02:40 | at com.inductiveautomation.ignition.gateway.localdb.LocalDBManagerImpl$HsqlSettingsDbManager.onConnected(LocalDBManagerImpl.java:852)
INFO | jvm 2 | 2018/10/23 16:02:40 | at com.inductiveautomation.ignition.gateway.localdb.hsql.HsqlDbManager.startupInternal(HsqlDbManager.java:355)
INFO | jvm 2 | 2018/10/23 16:02:40 | at com.inductiveautomation.ignition.gateway.localdb.hsql.HsqlDbManager.startup(HsqlDbManager.java:222)
INFO | jvm 2 | 2018/10/23 16:02:40 | at com.inductiveautomation.ignition.gateway.localdb.LocalDBManagerImpl.setup(LocalDBManagerImpl.java:169)
INFO | jvm 2 | 2018/10/23 16:02:40 | at com.inductiveautomation.ignition.gateway.SRContext.startupInternal(SRContext.java:1215)
INFO | jvm 2 | 2018/10/23 16:02:40 | at com.inductiveautomation.ignition.gateway.redundancy.RedundancyManagerImpl.startup(RedundancyManagerImpl.java:224)
INFO | jvm 2 | 2018/10/23 16:02:40 | at com.inductiveautomation.ignition.gateway.SRContext.asyncInit(SRContext.java:1036)
INFO | jvm 2 | 2018/10/23 16:02:40 | at com.inductiveautomation.ignition.gateway.SRContext.access$300(SRContext.java:289)
INFO | jvm 2 | 2018/10/23 16:02:40 | at com.inductiveautomation.ignition.gateway.SRContext$2.run(SRContext.java:767)
INFO | jvm 2 | 2018/10/23 16:02:40 | at com.inductiveautomation.ignition.common.execution.impl.BasicExecutionEngine$ThrowableCatchingRunnable.run(BasicExecutionEngine.java:518)
INFO | jvm 2 | 2018/10/23 16:02:40 | at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)
INFO | jvm 2 | 2018/10/23 16:02:40 | at java.util.concurrent.FutureTask.run(Unknown Source)
INFO | jvm 2 | 2018/10/23 16:02:40 | at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(Unknown Source)
INFO | jvm 2 | 2018/10/23 16:02:40 | at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source)
INFO | jvm 2 | 2018/10/23 16:02:40 | at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
INFO | jvm 2 | 2018/10/23 16:02:40 | at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
INFO | jvm 2 | 2018/10/23 16:02:40 | at java.lang.Thread.run(Unknown Source)
INFO | jvm 2 | 2018/10/23 16:02:40 | Caused by: org.hsqldb.HsqlException: user lacks privilege or object not found java.lang.ClassNotFoundException: com.inductiveautomation.ignition.gateway.localdb.HSQLUtilFunctions com.inductiveautomation.ignition.gateway.localdb.HSQLUtilFunctions
INFO | jvm 2 | 2018/10/23 16:02:40 | at org.hsqldb.error.Error.error(Unknown Source)
INFO | jvm 2 | 2018/10/23 16:02:40 | at org.hsqldb.Routine.getMethods(Unknown Source)
INFO | jvm 2 | 2018/10/23 16:02:40 | at org.hsqldb.Routine.getMethod(Unknown Source)
INFO | jvm 2 | 2018/10/23 16:02:40 | at org.hsqldb.Routine.resolveReferences(Unknown Source)
INFO | jvm 2 | 2018/10/23 16:02:40 | at org.hsqldb.Routine.resolve(Unknown Source)
INFO | jvm 2 | 2018/10/23 16:02:40 | at org.hsqldb.StatementSchema.getResult(Unknown Source)
INFO | jvm 2 | 2018/10/23 16:02:40 | at org.hsqldb.StatementSchema.execute(Unknown Source)
INFO | jvm 2 | 2018/10/23 16:02:40 | at org.hsqldb.Session.executeCompiledStatement(Unknown Source)
INFO | jvm 2 | 2018/10/23 16:02:40 | at org.hsqldb.Session.executeDirectStatement(Unknown Source)
INFO | jvm 2 | 2018/10/23 16:02:40 | at org.hsqldb.Session.execute(Unknown Source)
INFO | jvm 2 | 2018/10/23 16:02:40 | ... 25 common frames omitted
INFO | jvm 2 | 2018/10/23 16:02:40 | Caused by: java.lang.ClassNotFoundException: com.inductiveautomation.ignition.gateway.localdb.HSQLUtilFunctions
INFO | jvm 2 | 2018/10/23 16:02:40 | at java.net.URLClassLoader.findClass(Unknown Source)
INFO | jvm 2 | 2018/10/23 16:02:40 | at java.lang.ClassLoader.loadClass(Unknown Source)
INFO | jvm 2 | 2018/10/23 16:02:40 | at java.lang.ClassLoader.loadClass(Unknown Source)
INFO | jvm 2 | 2018/10/23 16:02:40 | at java.lang.Class.forName0(Native Method)
INFO | jvm 2 | 2018/10/23 16:02:40 | at java.lang.Class.forName(Unknown Source)
INFO | jvm 2 | 2018/10/23 16:02:40 | ... 34 common frames omitted
INFO | jvm 2 | 2018/10/23 16:02:40 | I [g.InternalDatabaseManager ] [21:02:40]: DBManager shutting down (immediate)...
It looks like we deleted the HSQLUtilFunctions class at some point. There is an internal ticket to add it back so that upgrades from legacy DBs work, which would also fix this command line flag, but:
Thank you, the change to HSQL helped us last time.
Do you know whats the last version that has the HSQLUtilFunctions class?
I will open a ticket for support. I will try to port the line to an IGN instance runnning in HSQL and compare performance.
Thanks and Regards,
JGC.
For reference purposes, I was able to compare performance the same webdev script in both v7.9.9 (b2018081621) vs 7.8.4 (b2016082217) using the HSQL hack.
I take speed measurement using Chrome Dev tools calling the webdev module to get the json with 793 tags of data with the following format, bot Ignitions reading from the same source, only one instance enabled at the same time *(for those tags).
{
name: "TAGNAME",
path: "fullTagPath",
dataType: "Int4",
qualifiedValue: {
value: "0",
quality: "Good",
timestamp: "2018/10/26 16:06:42"
}
},
7.8.4 (b2016082217) using the HSQL hack.
v7.9.9 (b2018081621)
As a point of note, the v7.9.9 IGN instance is only running this set of tags for a single line (pretty light workload), while the v7.8.4 is running about 16 lines and has multiple processes pulling data at the same time, therefore it currently has considerably workload (we have about 50k tags in this instance).
The performance is considerably different, I will be opening a ticket with IA support, but wanted to share this.
I doubt we’re going to add back in the HSQL internal storage, but we should be able to add a cache to the webdev module to avoid the slowdown caused by the storage change.
This may not be a great idea, but I had some similar situations where I wanted a large JSON object of UDT data… Rather than hitting the tags direct from WebDev I create a dataset tag that has a runScript expression to call a gateway script that does all the needed tag reads and stores the result, then in the WebDev (or Vision) I just use the dataSet tag for the summary data. I found it to be significantly faster and more efficient.
That sound like a good idea, if I understand correctly, you have a dataset with all the tag info, then in the webdev/vision you just read that tag and send it in json, how to you convert the dataset to JSON, do you use the system.util.jsonEncode?