Postgres 10 troubles

Has anyone had trouble with using Postgresql version 10 (I’m on ignition version 7.8.4)? I just upgraded one of my production databases from 9.6. I’m only using that db for some transaction group stuff, not my main historian data. I didn’t notice any trouble with it for a couple weeks. Today, I was trying to modify some of the transaction groups pointed at that database, and one of the two groups is failing to run. I restarted the ignition service, and now I have two more transaction groups, also pointing at that database, that are failing to run.

The errors in the transaction group editor are non-specific. Just saying ‘Unable to start group’ and ‘Group state changed to fatally_errored’. The wrapper.log has a little more info, but I can’t make sense of it.

INFO   | jvm 1    | 2017/12/09 14:20:47 | ERROR [RT values_Generators_RT Generator 1] [14:20:47,195]: Unable to start group.
INFO   | jvm 1    | 2017/12/09 14:20:47 | java.lang.NullPointerException
INFO   | jvm 1    | 2017/12/09 14:20:47 |       at org.postgresql.jdbc2.AbstractJdbc2DatabaseMetaData.getColumns(AbstractJdbc2DatabaseMetaData.java:2502)
INFO   | jvm 1    | 2017/12/09 14:20:47 |       at org.postgresql.jdbc4.AbstractJdbc4DatabaseMetaData.getColumns(AbstractJdbc4DatabaseMetaData.java:99)
INFO   | jvm 1    | 2017/12/09 14:20:47 |       at com.inductiveautomation.ignition.gateway.db.schema.DBTableSchema.refreshTableState(DBTableSchema.java:245)
INFO   | jvm 1    | 2017/12/09 14:20:47 |       at com.inductiveautomation.factorysql.groups.AbstractTableItemGroup.checkTableStructure(AbstractTableItemGroup.java:181)
INFO   | jvm 1    | 2017/12/09 14:20:47 |       at com.inductiveautomation.factorysql.groups.AbstractTableItemGroup.prestartCheck(AbstractTableItemGroup.java:129)
INFO   | jvm 1    | 2017/12/09 14:20:47 |       at com.inductiveautomation.factorysql.groups.AbstractGroup.startExecution(AbstractGroup.java:262)
INFO   | jvm 1    | 2017/12/09 14:20:47 |       at com.inductiveautomation.factorysql.FSQLProjectRunner.loadGroupResource(FSQLProjectRunner.java:354)
INFO   | jvm 1    | 2017/12/09 14:20:47 |       at com.inductiveautomation.factorysql.FSQLProjectRunner.loadProject(FSQLProjectRunner.java:274)
INFO   | jvm 1    | 2017/12/09 14:20:47 |       at com.inductiveautomation.factorysql.FSQLProjectRunner$1.run(FSQLProjectRunner.java:194)
INFO   | jvm 1    | 2017/12/09 14:20:47 |       at com.inductiveautomation.ignition.common.execution.impl.BasicExecutionEngine$ThrowableCatchingRunnable.run(BasicExecutionEngine.java:537)
INFO   | jvm 1    | 2017/12/09 14:20:47 |       at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
INFO   | jvm 1    | 2017/12/09 14:20:47 |       at java.util.concurrent.FutureTask.run(FutureTask.java:266)
INFO   | jvm 1    | 2017/12/09 14:20:47 |       at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
INFO   | jvm 1    | 2017/12/09 14:20:47 |       at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
INFO   | jvm 1    | 2017/12/09 14:20:47 |       at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
INFO   | jvm 1    | 2017/12/09 14:20:47 |       at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
INFO   | jvm 1    | 2017/12/09 14:20:47 |       at java.lang.Thread.run(Thread.java:748)

The only error the database is reporting happened at when I restarted the ignition service. There were two identical looking sets of entries.

2017-12-09 13:02:38 CST ERROR:  column i.indproc does not exist at character 610
2017-12-09 13:02:38 CST HINT:  Perhaps you meant to reference the column "i.indpred".
2017-12-09 13:02:38 CST STATEMENT:  SELECT NULL AS TABLE_CAT, NULL AS TABLE_SCHEM,  ct.relname AS TABLE_NAME, NOT i.indisunique AS NON_UNIQUE, NULL AS INDEX_QUALIFIER, ci.relname AS INDEX_NAME,  CASE i.indisclustered  WHEN true THEN 1 ELSE CASE am.amname  WHEN 'hash' THEN 2 ELSE 3 END  END AS TYPE,  a.attnum AS ORDINAL_POSITION,  CASE i.indproc WHEN 0 THEN a.attname ELSE ip.proname || '(' || ai.attname || ')' END AS COLUMN_NAME,  NULL AS ASC_OR_DESC,  ci.reltuples AS CARDINALITY,  ci.relpages AS PAGES,  NULL AS FILTER_CONDITION  FROM pg_class ct, pg_class ci, pg_attribute a, pg_am am, pg_attribute ai, pg_index i LEFT JOIN pg_proc ip ON (i.indproc = ip.oid)  WHERE ct.oid=i.indrelid AND ci.oid=i.indexrelid AND a.attrelid=ci.oid AND ci.relam=am.oid  AND ai.attnum = i.indkey[0] AND ai.attrelid = ct.oid  AND ct.relname = 'rt_vacuumfurnaces' ORDER BY NON_UNIQUE, TYPE, INDEX_NAME, ORDINAL_POSITION
2017-12-09 13:05:20 CST ERROR:  column i.indproc does not exist at character 610
2017-12-09 13:05:20 CST HINT:  Perhaps you meant to reference the column "i.indpred".
2017-12-09 13:05:20 CST STATEMENT:  SELECT NULL AS TABLE_CAT, NULL AS TABLE_SCHEM,  ct.relname AS TABLE_NAME, NOT i.indisunique AS NON_UNIQUE, NULL AS INDEX_QUALIFIER, ci.relname AS INDEX_NAME,  CASE i.indisclustered  WHEN true THEN 1 ELSE CASE am.amname  WHEN 'hash' THEN 2 ELSE 3 END  END AS TYPE,  a.attnum AS ORDINAL_POSITION,  CASE i.indproc WHEN 0 THEN a.attname ELSE ip.proname || '(' || ai.attname || ')' END AS COLUMN_NAME,  NULL AS ASC_OR_DESC,  ci.reltuples AS CARDINALITY,  ci.relpages AS PAGES,  NULL AS FILTER_CONDITION  FROM pg_class ct, pg_class ci, pg_attribute a, pg_am am, pg_attribute ai, pg_index i LEFT JOIN pg_proc ip ON (i.indproc = ip.oid)  WHERE ct.oid=i.indrelid AND ci.oid=i.indexrelid AND a.attrelid=ci.oid AND ci.relam=am.oid  AND ai.attnum = i.indkey[0] AND ai.attrelid = ct.oid  AND ct.relname = 'rt_vacuumfurnaces' ORDER BY NON_UNIQUE, TYPE, INDEX_NAME, ORDINAL_POSITION

As far as I can tell, 9.6 didn’t have that column in pg_index either. I know that Postgresql 10 changed something with how the version was being reported. Does the driver that Ignition uses need to be updated? How would I go about doing that? Is there versions to avoid, or tested, known good versions to use? Just use the latest one? Can I install a new driver and keep the old one for the historian database?

Digging into it a bit more, it looks like the JDBC driver for Postgresql first added support for Postgres 10+ version parsing in driver version 9.4.1210
The version that the gateway is running looks like it is 9.0-801. I’m guessing that is why I’m having problems.

What is the procedure for upgrading the JDBC driver?

I found some instructions here about just uploading the .jar file for the new driver and restarting the gateway. I did that, using the latest jdbc driver for postgresql. That seems to have gotten rid of my error message about the missing column in the database, but my transaction groups are still dead in the water.

I did notice an error message appearing in the designer console when clicking on a transaction group to edit it. Not sure if it was popping up before I changed the driver, I didn’t have the console pulled up at that point. Here’s the error message:

ERROR [GroupSchemaContext-Thread-44] Error refreshing table info for datasource: 'CQI9', table: 'rt_generators'
com.inductiveautomation.ignition.client.gateway_interface.GatewayException: Error executing gateway function.
	at com.inductiveautomation.ignition.client.gateway_interface.GatewayInterface.newGatewayException(GatewayInterface.java:327)
	at com.inductiveautomation.ignition.client.gateway_interface.GatewayInterface.sendMessage(GatewayInterface.java:301)
	at com.inductiveautomation.ignition.client.gateway_interface.GatewayInterface.sendMessage(GatewayInterface.java:258)
	at com.inductiveautomation.ignition.client.gateway_interface.GatewayInterface.invoke(GatewayInterface.java:884)
	at com.inductiveautomation.ignition.designer.db.DesignerDatasourceMetaProviderImpl.getTableInfo(DesignerDatasourceMetaProviderImpl.java:26)
	at com.inductiveautomation.factorysql.designer.model.BasicSchemaContext$RefreshJob.run(BasicSchemaContext.java:218)
Caused by: java.lang.NullPointerException
	at org.postgresql.jdbc2.AbstractJdbc2DatabaseMetaData.getColumns(AbstractJdbc2DatabaseMetaData.java:2502)
	at org.postgresql.jdbc4.AbstractJdbc4DatabaseMetaData.getColumns(AbstractJdbc4DatabaseMetaData.java:99)
	at com.inductiveautomation.ignition.gateway.db.DatasourceMetaProviderImpl.getColumns(DatasourceMetaProviderImpl.java:91)
	at com.inductiveautomation.ignition.gateway.db.DatasourceMetaProviderImpl.getTableInfo(DatasourceMetaProviderImpl.java:65)
	at com.inductiveautomation.ignition.gateway.servlets.gateway.functions.DatasourceMeta.getTableInfo(DatasourceMeta.java:32)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at com.inductiveautomation.ignition.gateway.servlets.gateway.AbstractGatewayFunction.invoke(AbstractGatewayFunction.java:209)
	at com.inductiveautomation.ignition.gateway.servlets.Gateway.doPost(Gateway.java:345)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:707)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
	at com.inductiveautomation.ignition.gateway.bootstrap.MapServlet.service(MapServlet.java:85)
	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:837)
	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:583)
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)
	at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548)
	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:226)
	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1160)
	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:511)
	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)
	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1092)
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
	at org.eclipse.jetty.server.handler.HandlerList.handle(HandlerList.java:52)
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134)
	at org.eclipse.jetty.server.Server.handle(Server.java:518)
	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:308)
	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:244)
	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273)
	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95)
	at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93)
	at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceAndRun(ExecuteProduceConsume.java:246)
	at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:156)
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:654)
	at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:572)
	at java.lang.Thread.run(Thread.java:748)

I’m still getting what looks like the same error message in the wrapper.log file:

INFO   | jvm 1    | 2017/12/09 18:11:57 | ERROR [RT values_Generators_RT Generator 1] [18:11:57,264]: Unable to start group.
INFO   | jvm 1    | 2017/12/09 18:11:57 | java.lang.NullPointerException
INFO   | jvm 1    | 2017/12/09 18:11:57 |       at org.postgresql.jdbc2.AbstractJdbc2DatabaseMetaData.getColumns(AbstractJdbc2DatabaseMetaData.java:2502)
INFO   | jvm 1    | 2017/12/09 18:11:57 |       at org.postgresql.jdbc4.AbstractJdbc4DatabaseMetaData.getColumns(AbstractJdbc4DatabaseMetaData.java:99)
INFO   | jvm 1    | 2017/12/09 18:11:57 |       at com.inductiveautomation.ignition.gateway.db.schema.DBTableSchema.refreshTableState(DBTableSchema.java:245)
INFO   | jvm 1    | 2017/12/09 18:11:57 |       at com.inductiveautomation.factorysql.groups.AbstractTableItemGroup.checkTableStructure(AbstractTableItemGroup.java:181)
INFO   | jvm 1    | 2017/12/09 18:11:57 |       at com.inductiveautomation.factorysql.groups.AbstractTableItemGroup.prestartCheck(AbstractTableItemGroup.java:129)
INFO   | jvm 1    | 2017/12/09 18:11:57 |       at com.inductiveautomation.factorysql.groups.AbstractGroup.startExecution(AbstractGroup.java:262)
INFO   | jvm 1    | 2017/12/09 18:11:57 |       at com.inductiveautomation.factorysql.FSQLProjectRunner.loadGroupResource(FSQLProjectRunner.java:354)
INFO   | jvm 1    | 2017/12/09 18:11:57 |       at com.inductiveautomation.factorysql.FSQLProjectRunner.loadProject(FSQLProjectRunner.java:274)
INFO   | jvm 1    | 2017/12/09 18:11:57 |       at com.inductiveautomation.factorysql.FSQLProjectRunner$1.run(FSQLProjectRunner.java:194)
INFO   | jvm 1    | 2017/12/09 18:11:57 |       at com.inductiveautomation.ignition.common.execution.impl.BasicExecutionEngine$ThrowableCatchingRunnable.run(BasicExecutionEngine.java:537)
INFO   | jvm 1    | 2017/12/09 18:11:57 |       at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
INFO   | jvm 1    | 2017/12/09 18:11:57 |       at java.util.concurrent.FutureTask.run(FutureTask.java:266)
INFO   | jvm 1    | 2017/12/09 18:11:57 |       at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
INFO   | jvm 1    | 2017/12/09 18:11:57 |       at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
INFO   | jvm 1    | 2017/12/09 18:11:57 |       at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
INFO   | jvm 1    | 2017/12/09 18:11:57 |       at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
INFO   | jvm 1    | 2017/12/09 18:11:57 |       at java.lang.Thread.run(Thread.java:748)

Not sure what to try next.

Ok, so I was able to get my affected transaction groups running again, by copying the tables. I did the following:
ALTER TABLE rt_generators RENAME TO rt_generators_buggered; CREATE TABLE rt_generators (LIKE rt_generators_buggered INCLUDING ALL); GRANT ALL ON rt_generators TO ignition;

After that, I cycled the transaction groups writing to that table to Disabled, saved the project, then set them back to Enabled and saved the project again. They were all working after that. I’m still getting an error refreshing table data when I click the root folder of the transaction group tree that these were in. It looks like it’s trying to refresh data for a table with a blank name. Also, if I try pointing any of the transaction groups at the _buggered tables, ignition promptly freaks out again. It won’t even display the list of tables to choose the original name. I have to remove the “_buggered” part of the name, then it works fine again.

[quote=“Brian, post:4, topic:16275”]```
GRANT ALL ON rt_generators TO ignition;

Hmmm. Do you not set up your databases to be owned by the ignition user?  There might be some obscure permission that doesn't translate in the upgrade that's biting you.

Phil,

This database (the whole database virtual server, actually) is something that we had installed here for years before we had ignition installed. I have a mobile website that pulls data from it to display real-time (or nearly real-time) information on our equipment (current temperatures and such). When we installed ignition, we spun up a dedicated virtual server for it, and installed a separate copy of postgresql on that server for ignition use (historian and other general usage tables). That database is owned by the ignition account. But the older server (the one I just upgraded postgresql on), I just gave ignition an account on, and permissions for the real-time tables that it needs to push data to. That’s where the ‘rt_’ part of the name of the tables comes from. With the tables being updated, my old mobile website can continue to function. In fact, the problem cropped up because I was trying to add a column with another data point to a couple of the tables. They were working fine before I touched it.

Anyway, backstory aside, I’m not sure this is a permissions issue. I think permission denied events get logged to the postgresql server log, and I wasn’t seeing anything related to the rt_ tables. Also, I have 7 total rt_ tables being updated on that server, and only 3 were having issues. The other 4 were cruising right along. Now, that being said, I haven’t touched the config of the transaction groups dealing with those tables. I was a little afraid to mess with them, honestly. I should probably go back and poke them now that I have a working ‘fix’ for the problem.

This whole incident is making me hesitant to upgrade the postgresql instance on the production ignition server… At least until I have a decent theory as to what was happening.

You aren't paranoid if they/him/her/it (your install) is really out to get you... /-:
FWIW, I haven't tried pg10 yet.