[bug-15399]Restore disabled gateway failing in AuditManager

Ignition
1

I’m trying to restore a gateway backup onto a freshly installed 8.0.7 nightly (20191111).

I’m using the “restore disabled” feature, but Ignition keeps failing on restart due to what looks like an inability to connect to and validate the audit database.

Here’s the tail end of our wrapper.log when it fails:

INFO   | jvm 1    | 2019/11/11 19:41:01 | I [t.m.provider                  ] [19:41:01]: Tag provider initialized. Starting to load tags...
INFO   | jvm 1    | 2019/11/11 19:41:01 | I [t.m.provider                  ] [19:41:01]: Complete tag loading in 60 ms
INFO   | jvm 1    | 2019/11/11 19:41:01 | I [i.UserSourceManager           ] [19:41:01]: Starting up...
INFO   | jvm 1    | 2019/11/11 19:41:01 | I [AuditManager                  ] [19:41:01]: AuditManager starting up...
INFO   | jvm 1    | 2019/11/11 19:41:01 | E [a.DatasourceAuditProfile      ] [19:41:01]: Error verifying audit log table. profile-name=devcloudrds_audit
INFO   | jvm 1    | 2019/11/11 19:41:01 | com.inductiveautomation.ignition.gateway.datasource.DisabledDatabaseConnectionException: The database connection 'devcloudrds' is disabled.
INFO   | jvm 1    | 2019/11/11 19:41:01 |       at com.inductiveautomation.ignition.gateway.datasource.DatasourceManagerImpl.getConnectionImpl(DatasourceManagerImpl.java:152)
INFO   | jvm 1    | 2019/11/11 19:41:01 |       at com.inductiveautomation.ignition.gateway.datasource.DatasourceImpl.getConnection(DatasourceImpl.java:250)
INFO   | jvm 1    | 2019/11/11 19:41:01 |       at com.inductiveautomation.ignition.gateway.audit.DatasourceAuditProfile.checkTable(DatasourceAuditProfile.java:168)
INFO   | jvm 1    | 2019/11/11 19:41:01 |       at com.inductiveautomation.ignition.gateway.audit.DatasourceAuditProfile.startup(DatasourceAuditProfile.java:112)
INFO   | jvm 1    | 2019/11/11 19:41:01 |       at com.inductiveautomation.ignition.gateway.audit.AuditManagerImpl.createProfile(AuditManagerImpl.java:184)
INFO   | jvm 1    | 2019/11/11 19:41:01 |       at com.inductiveautomation.ignition.gateway.audit.AuditManagerImpl.getProfile(AuditManagerImpl.java:142)
INFO   | jvm 1    | 2019/11/11 19:41:01 |       at com.inductiveautomation.ignition.gateway.audit.AuditManagerImpl.getProfile(AuditManagerImpl.java:133)
INFO   | jvm 1    | 2019/11/11 19:41:01 |       at com.inductiveautomation.ignition.gateway.audit.AuditManagerImpl.startup(AuditManagerImpl.java:66)
INFO   | jvm 1    | 2019/11/11 19:41:01 |       at com.inductiveautomation.ignition.gateway.IgnitionGateway.startupInternal(IgnitionGateway.java:1034)
INFO   | jvm 1    | 2019/11/11 19:41:01 |       at com.inductiveautomation.ignition.gateway.redundancy.RedundancyManagerImpl.startup(RedundancyManagerImpl.java:277)
INFO   | jvm 1    | 2019/11/11 19:41:01 |       at com.inductiveautomation.ignition.gateway.IgnitionGateway.initRedundancy(IgnitionGateway.java:666)
INFO   | jvm 1    | 2019/11/11 19:41:01 |       at com.inductiveautomation.ignition.gateway.IgnitionGateway.lambda$initInternal$0(IgnitionGateway.java:604)
INFO   | jvm 1    | 2019/11/11 19:41:01 |       at com.inductiveautomation.ignition.common.execution.impl.BasicExecutionEngine$ThrowableCatchingRunnable.run(BasicExecutionEngine.java:518)
INFO   | jvm 1    | 2019/11/11 19:41:01 |       at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)
INFO   | jvm 1    | 2019/11/11 19:41:01 |       at java.base/java.util.concurrent.FutureTask.run(Unknown Source)
INFO   | jvm 1    | 2019/11/11 19:41:01 |       at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source)
INFO   | jvm 1    | 2019/11/11 19:41:01 |       at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
INFO   | jvm 1    | 2019/11/11 19:41:01 |       at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
INFO   | jvm 1    | 2019/11/11 19:41:01 |       at java.base/java.lang.Thread.run(Unknown Source)
INFO   | jvm 1    | 2019/11/11 19:41:01 | E [IgnitionGateway               ] [19:41:01]: Error during context startup.
INFO   | jvm 1    | 2019/11/11 19:41:01 | java.lang.NullPointerException: null
INFO   | jvm 1    | 2019/11/11 19:41:01 |       at com.inductiveautomation.ignition.gateway.audit.DatasourceAuditProfile.startup(DatasourceAuditProfile.java:115)
INFO   | jvm 1    | 2019/11/11 19:41:01 |       at com.inductiveautomation.ignition.gateway.audit.AuditManagerImpl.createProfile(AuditManagerImpl.java:184)
INFO   | jvm 1    | 2019/11/11 19:41:01 |       at com.inductiveautomation.ignition.gateway.audit.AuditManagerImpl.getProfile(AuditManagerImpl.java:142)
INFO   | jvm 1    | 2019/11/11 19:41:01 |       at com.inductiveautomation.ignition.gateway.audit.AuditManagerImpl.getProfile(AuditManagerImpl.java:133)
INFO   | jvm 1    | 2019/11/11 19:41:01 |       at com.inductiveautomation.ignition.gateway.audit.AuditManagerImpl.startup(AuditManagerImpl.java:66)
INFO   | jvm 1    | 2019/11/11 19:41:01 |       at com.inductiveautomation.ignition.gateway.IgnitionGateway.startupInternal(IgnitionGateway.java:1034)
INFO   | jvm 1    | 2019/11/11 19:41:01 |       at com.inductiveautomation.ignition.gateway.redundancy.RedundancyManagerImpl.startup(RedundancyManagerImpl.java:277)
INFO   | jvm 1    | 2019/11/11 19:41:01 |       at com.inductiveautomation.ignition.gateway.IgnitionGateway.initRedundancy(IgnitionGateway.java:666)
INFO   | jvm 1    | 2019/11/11 19:41:01 |       at com.inductiveautomation.ignition.gateway.IgnitionGateway.lambda$initInternal$0(IgnitionGateway.java:604)
INFO   | jvm 1    | 2019/11/11 19:41:01 |       at com.inductiveautomation.ignition.common.execution.impl.BasicExecutionEngine$ThrowableCatchingRunnable.run(BasicExecutionEngine.java:518)
INFO   | jvm 1    | 2019/11/11 19:41:01 |       at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)
INFO   | jvm 1    | 2019/11/11 19:41:01 |       at java.base/java.util.concurrent.FutureTask.run(Unknown Source)
INFO   | jvm 1    | 2019/11/11 19:41:01 |       at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source)
INFO   | jvm 1    | 2019/11/11 19:41:01 |       at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
INFO   | jvm 1    | 2019/11/11 19:41:01 |       at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
INFO   | jvm 1    | 2019/11/11 19:41:01 |       at java.base/java.lang.Thread.run(Unknown Source)
INFO   | jvm 1    | 2019/11/11 19:41:01 | I [IgnitionGateway               ] [19:41:01]: Ignition[state=STARTING] ContextState = FAULTED

Shouldn’t the audit module skip the database connection instead of failing when being restored in disabled mode? Or is something else going on here?

If that is what’s going on, is there any way to easily restore a backup taken from a machine with auditing enabled?

If it matters, the backup was made from a server running a snapshot build of 8.0.5 nightly from 2019-09-30…

2

It’s a bug caused by the changes that introduced a remote audit profile; I just put the fix up today and it should be available in nightlies pretty soon - bottleneck will be QA having the bandwidth to approve it.

1 Like
3

I’m trying to setup a server to test some of the more recent nightly changes. Can you recommend the most recent build I could use that won’t get stuck on this issue?

4

The changes were merged in on 10/30, so nightlies from 10/31 and later won’t work. You could go into the IDB and enable the one database connection to get the service started.

1 Like
5

This issue was fixed in the 8.0.7 nightly build that was uploaded today (11/13).