Problem when uninstalling a Module

lva · September 30, 2015, 2:14pm

Hello,

I got an error uninstalling a Module example on ignition 7.7.5 on Ubuntu … It happens to me 2 times …
Re-installing the ignition server fix this issue … Please find the log below …
Any idea how to fix this?

Thanks,

INFO | jvm 1 | 2015/09/30 16:03:30 | INFO [ModuleManager ] [16:03:30,605]: Shutdown of module “com.inductiveautomation.examples.simpletagprovider” completed in 6 ms
INFO | jvm 1 | 2015/09/30 16:03:30 | ERROR [ModuleManager ] [16:03:30,760]: Error running “uninstall” operation for module “com.inductiveautomation.examples.simpletagprovider”.
INFO | jvm 1 | 2015/09/30 16:03:30 | simpleorm.utils.SException$Jdbc: Executing 'SELECT PROJECTS.PROJECTS_ID, PROJECTS.Name, PROJECTS.Description, PROJECTS.Title, PROJECTS.LastModified, PROJECTS.LastModifiedBy, PROJECTS.EditCount, PROJECTS.PublishedEditCount, PROJECTS.FirstRollbackEditPoint, PROJECTS.UUID, PROJECTS.IsOEMLocked, PROJECTS.OEMLockId, PROJECTS.Enabled FROM PROJECTS WHERE PROJECTS_ID = ? ’ for [ProjectRecord -1]
INFO | jvm 1 | 2015/09/30 16:03:30 | at simpleorm.sessionjdbc.SSessionJdbcHelper.findInDatabase(SSessionJdbcHelper.java:136)
INFO | jvm 1 | 2015/09/30 16:03:30 | at simpleorm.sessionjdbc.SSessionJdbcHelper.doFindOrCreate(SSessionJdbcHelper.java:60)
INFO | jvm 1 | 2015/09/30 16:03:30 | at simpleorm.sessionjdbc.SSessionJdbc.find(SSessionJdbc.java:565)
INFO | jvm 1 | 2015/09/30 16:03:30 | at simpleorm.sessionjdbc.SSessionJdbc.find(SSessionJdbc.java:569)
INFO | jvm 1 | 2015/09/30 16:03:30 | at com.inductiveautomation.ignition.gateway.project.ProjectManagerImpl.getProject(ProjectManagerImpl.java:450)
INFO | jvm 1 | 2015/09/30 16:03:30 | at com.inductiveautomation.ignition.gateway.project.ProjectManagerImpl.getGlobalProject(ProjectManagerImpl.java:469)
INFO | jvm 1 | 2015/09/30 16:03:30 | at com.inductiveautomation.ignition.gateway.SRContext.createScriptManager(SRContext.java:1315)
INFO | jvm 1 | 2015/09/30 16:03:30 | at com.inductiveautomation.ignition.gateway.script.ScriptHintsManager.createScriptManager(ScriptHintsManager.java:94)
INFO | jvm 1 | 2015/09/30 16:03:30 | at com.inductiveautomation.ignition.gateway.script.ScriptHintsManager.access$200(ScriptHintsManager.java:15)
INFO | jvm 1 | 2015/09/30 16:03:30 | at com.inductiveautomation.ignition.gateway.script.ScriptHintsManager$1.moduleStopped(ScriptHintsManager.java:68)
INFO | jvm 1 | 2015/09/30 16:03:30 | at com.inductiveautomation.ignition.gateway.modules.ModuleManagerImpl.notifyModuleStartedOrStopped(ModuleManagerImpl.java:2510)
INFO | jvm 1 | 2015/09/30 16:03:30 | at com.inductiveautomation.ignition.gateway.modules.ModuleManagerImpl$5.call(ModuleManagerImpl.java:999)
INFO | jvm 1 | 2015/09/30 16:03:30 | at com.inductiveautomation.ignition.gateway.modules.ModuleManagerImpl.executeModuleOperation(ModuleManagerImpl.java:1095)
INFO | jvm 1 | 2015/09/30 16:03:30 | at com.inductiveautomation.ignition.gateway.modules.ModuleManagerImpl.uninstallModuleInternal(ModuleManagerImpl.java:993)
INFO | jvm 1 | 2015/09/30 16:03:30 | at com.inductiveautomation.ignition.gateway.modules.ModuleManagerImpl.access$1400(ModuleManagerImpl.java:122)
INFO | jvm 1 | 2015/09/30 16:03:30 | at com.inductiveautomation.ignition.gateway.modules.ModuleManagerImpl$UninstallCommand.execute(ModuleManagerImpl.java:1791)
INFO | jvm 1 | 2015/09/30 16:03:30 | at com.inductiveautomation.ignition.gateway.modules.ModuleManagerImpl$Receiver.receiveCall(ModuleManagerImpl.java:1766)
INFO | jvm 1 | 2015/09/30 16:03:30 | at com.inductiveautomation.ignition.gateway.redundancy.QueueableMessageReceiver.receiveCall(QueueableMessageReceiver.java:45)
INFO | jvm 1 | 2015/09/30 16:03:30 | at com.inductiveautomation.ignition.gateway.redundancy.RedundancyManagerImpl.dispatchMessage(RedundancyManagerImpl.java:652)
INFO | jvm 1 | 2015/09/30 16:03:30 | at com.inductiveautomation.ignition.gateway.redundancy.RedundancyManagerImpl$ExecuteTask.run(RedundancyManagerImpl.java:672)
INFO | jvm 1 | 2015/09/30 16:03:30 | at com.inductiveautomation.ignition.common.execution.impl.BasicExecutionEngine$ThrowableCatchingRunnable.run(BasicExecutionEngine.java:537)
INFO | jvm 1 | 2015/09/30 16:03:30 | at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
INFO | jvm 1 | 2015/09/30 16:03:30 | at java.util.concurrent.FutureTask.run(FutureTask.java:266)
INFO | jvm 1 | 2015/09/30 16:03:30 | at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
INFO | jvm 1 | 2015/09/30 16:03:30 | at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
INFO | jvm 1 | 2015/09/30 16:03:30 | at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
INFO | jvm 1 | 2015/09/30 16:03:30 | at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
INFO | jvm 1 | 2015/09/30 16:03:30 | at java.lang.Thread.run(Thread.java:745)
INFO | jvm 1 | 2015/09/30 16:03:30 | Caused by: java.sql.SQLTransactionRollbackException: transaction rollback: serialization failure
INFO | jvm 1 | 2015/09/30 16:03:30 | at org.hsqldb.jdbc.JDBCUtil.sqlException(JDBCUtil.java:403)
INFO | jvm 1 | 2015/09/30 16:03:30 | at org.hsqldb.jdbc.JDBCUtil.sqlException(JDBCUtil.java:247)
INFO | jvm 1 | 2015/09/30 16:03:30 | at org.hsqldb.jdbc.JDBCPreparedStatement.fetchResult(JDBCPreparedStatement.java:4655)
INFO | jvm 1 | 2015/09/30 16:03:30 | at org.hsqldb.jdbc.JDBCPreparedStatement.executeQuery(JDBCPreparedStatement.java:284)
INFO | jvm 1 | 2015/09/30 16:03:30 | at org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:93)
INFO | jvm 1 | 2015/09/30 16:03:30 | at com.inductiveautomation.ignition.gateway.localdb.hsql.DelegatingDataSource$DelegatingConnection$DelegatingPreparedStatement.executeQuery(DelegatingDataSource.java:574)
INFO | jvm 1 | 2015/09/30 16:03:30 | at simpleorm.sessionjdbc.SSessionJdbcHelper.findInDatabase(SSessionJdbcHelper.java:134)
INFO | jvm 1 | 2015/09/30 16:03:30 | … 27 more
INFO | jvm 1 | 2015/09/30 16:03:30 | Caused by: org.hsqldb.HsqlException: transaction rollback: serialization failure
INFO | jvm 1 | 2015/09/30 16:03:30 | at org.hsqldb.error.Error.error(Error.java:136)
INFO | jvm 1 | 2015/09/30 16:03:30 | at org.hsqldb.error.Error.error(Error.java:106)
INFO | jvm 1 | 2015/09/30 16:03:30 | at org.hsqldb.Session.executeCompiledStatement(Session.java:1380)
INFO | jvm 1 | 2015/09/30 16:03:30 | at org.hsqldb.Session.execute(Session.java:1001)
INFO | jvm 1 | 2015/09/30 16:03:30 | at org.hsqldb.jdbc.JDBCPreparedStatement.fetchResult(JDBCPreparedStatement.java:4647)
INFO | jvm 1 | 2015/09/30 16:03:30 | … 31 more
INFO | jvm 1 | 2015/09/30 16:03:30 | ERROR [ConfirmationPanel$1 ] [16:03:30,766]: simpleorm.utils.SException$Jdbc: Executing 'SELECT PROJECTS.PROJECTS_ID, PROJECTS.Name, PROJECTS.Description, PROJECTS.Title, PROJECTS.LastModified, PROJECTS.LastModifiedBy, PROJECTS.EditCount, PROJECTS.PublishedEditCount, PROJECTS.FirstRollbackEditPoint, PROJECTS.UUID, PROJECTS.IsOEMLocked, PROJECTS.OEMLockId, PROJECTS.Enabled FROM PROJECTS WHERE PROJECTS_ID = ? ’ for [ProjectRecord -1]
INFO | jvm 1 | 2015/09/30 16:03:30 | simpleorm.utils.SException$Jdbc: Executing 'SELECT PROJECTS.PROJECTS_ID, PROJECTS.Name, PROJECTS.Description, PROJECTS.Title, PROJECTS.LastModified, PROJECTS.LastModifiedBy, PROJECTS.EditCount, PROJECTS.PublishedEditCount, PROJECTS.FirstRollbackEditPoint, PROJECTS.UUID, PROJECTS.IsOEMLocked, PROJECTS.OEMLockId, PROJECTS.Enabled FROM PROJECTS WHERE PROJECTS_ID = ? ’ for [ProjectRecord -1]
INFO | jvm 1 | 2015/09/30 16:03:30 | at simpleorm.sessionjdbc.SSessionJdbcHelper.findInDatabase(SSessionJdbcHelper.java:136)
INFO | jvm 1 | 2015/09/30 16:03:30 | at simpleorm.sessionjdbc.SSessionJdbcHelper.doFindOrCreate(SSessionJdbcHelper.java:60)
INFO | jvm 1 | 2015/09/30 16:03:30 | at simpleorm.sessionjdbc.SSessionJdbc.find(SSessionJdbc.java:565)
INFO | jvm 1 | 2015/09/30 16:03:30 | at simpleorm.sessionjdbc.SSessionJdbc.find(SSessionJdbc.java:569)
INFO | jvm 1 | 2015/09/30 16:03:30 | at com.inductiveautomation.ignition.gateway.project.ProjectManagerImpl.getProject(ProjectManagerImpl.java:450)
INFO | jvm 1 | 2015/09/30 16:03:30 | at com.inductiveautomation.ignition.gateway.project.ProjectManagerImpl.getGlobalProject(ProjectManagerImpl.java:469)
INFO | jvm 1 | 2015/09/30 16:03:30 | at com.inductiveautomation.ignition.gateway.SRContext.createScriptManager(SRContext.java:1315)
INFO | jvm 1 | 2015/09/30 16:03:30 | at com.inductiveautomation.ignition.gateway.script.ScriptHintsManager.createScriptManager(ScriptHintsManager.java:94)
INFO | jvm 1 | 2015/09/30 16:03:30 | at com.inductiveautomation.ignition.gateway.script.ScriptHintsManager.access$200(ScriptHintsManager.java:15)
INFO | jvm 1 | 2015/09/30 16:03:30 | at com.inductiveautomation.ignition.gateway.script.ScriptHintsManager$1.moduleStopped(ScriptHintsManager.java:68)
INFO | jvm 1 | 2015/09/30 16:03:30 | at com.inductiveautomation.ignition.gateway.modules.ModuleManagerImpl.notifyModuleStartedOrStopped(ModuleManagerImpl.java:2510)
INFO | jvm 1 | 2015/09/30 16:03:30 | at com.inductiveautomation.ignition.gateway.modules.ModuleManagerImpl$5.call(ModuleManagerImpl.java:999)
INFO | jvm 1 | 2015/09/30 16:03:30 | at com.inductiveautomation.ignition.gateway.modules.ModuleManagerImpl.executeModuleOperation(ModuleManagerImpl.java:1095)
INFO | jvm 1 | 2015/09/30 16:03:30 | at com.inductiveautomation.ignition.gateway.modules.ModuleManagerImpl.uninstallModuleInternal(ModuleManagerImpl.java:993)
INFO | jvm 1 | 2015/09/30 16:03:30 | at com.inductiveautomation.ignition.gateway.modules.ModuleManagerImpl.access$1400(ModuleManagerImpl.java:122)
INFO | jvm 1 | 2015/09/30 16:03:30 | at com.inductiveautomation.ignition.gateway.modules.ModuleManagerImpl$UninstallCommand.execute(ModuleManagerImpl.java:1791)
INFO | jvm 1 | 2015/09/30 16:03:30 | at com.inductiveautomation.ignition.gateway.modules.ModuleManagerImpl$Receiver.receiveCall(ModuleManagerImpl.java:1766)
INFO | jvm 1 | 2015/09/30 16:03:30 | at com.inductiveautomation.ignition.gateway.redundancy.QueueableMessageReceiver.receiveCall(QueueableMessageReceiver.java:45)
INFO | jvm 1 | 2015/09/30 16:03:30 | at com.inductiveautomation.ignition.gateway.redundancy.RedundancyManagerImpl.dispatchMessage(RedundancyManagerImpl.java:652)
INFO | jvm 1 | 2015/09/30 16:03:30 | at com.inductiveautomation.ignition.gateway.redundancy.RedundancyManagerImpl$ExecuteTask.run(RedundancyManagerImpl.java:672)
INFO | jvm 1 | 2015/09/30 16:03:30 | at com.inductiveautomation.ignition.common.execution.impl.BasicExecutionEngine$ThrowableCatchingRunnable.run(BasicExecutionEngine.java:537)
INFO | jvm 1 | 2015/09/30 16:03:30 | at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
INFO | jvm 1 | 2015/09/30 16:03:30 | at java.util.concurrent.FutureTask.run(FutureTask.java:266)
INFO | jvm 1 | 2015/09/30 16:03:30 | at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
INFO | jvm 1 | 2015/09/30 16:03:30 | at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
INFO | jvm 1 | 2015/09/30 16:03:30 | at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
INFO | jvm 1 | 2015/09/30 16:03:30 | at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
INFO | jvm 1 | 2015/09/30 16:03:30 | at java.lang.Thread.run(Thread.java:745)
INFO | jvm 1 | 2015/09/30 16:03:30 | Caused by: java.sql.SQLTransactionRollbackException: transaction rollback: serialization failure
INFO | jvm 1 | 2015/09/30 16:03:30 | at org.hsqldb.jdbc.JDBCUtil.sqlException(JDBCUtil.java:403)
INFO | jvm 1 | 2015/09/30 16:03:30 | at org.hsqldb.jdbc.JDBCUtil.sqlException(JDBCUtil.java:247)
INFO | jvm 1 | 2015/09/30 16:03:30 | at org.hsqldb.jdbc.JDBCPreparedStatement.fetchResult(JDBCPreparedStatement.java:4655)
INFO | jvm 1 | 2015/09/30 16:03:30 | at org.hsqldb.jdbc.JDBCPreparedStatement.executeQuery(JDBCPreparedStatement.java:284)
INFO | jvm 1 | 2015/09/30 16:03:30 | at org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:93)
INFO | jvm 1 | 2015/09/30 16:03:30 | at com.inductiveautomation.ignition.gateway.localdb.hsql.DelegatingDataSource$DelegatingConnection$DelegatingPreparedStatement.executeQuery(DelegatingDataSource.java:574)
INFO | jvm 1 | 2015/09/30 16:03:30 | at simpleorm.sessionjdbc.SSessionJdbcHelper.findInDatabase(SSessionJdbcHelper.java:134)
INFO | jvm 1 | 2015/09/30 16:03:30 | … 27 more
INFO | jvm 1 | 2015/09/30 16:03:30 | Caused by: org.hsqldb.HsqlException: transaction rollback: serialization failure
INFO | jvm 1 | 2015/09/30 16:03:30 | at org.hsqldb.error.Error.error(Error.java:136)
INFO | jvm 1 | 2015/09/30 16:03:30 | at org.hsqldb.error.Error.error(Error.java:106)
INFO | jvm 1 | 2015/09/30 16:03:30 | at org.hsqldb.Session.executeCompiledStatement(Session.java:1380)
INFO | jvm 1 | 2015/09/30 16:03:30 | at org.hsqldb.Session.execute(Session.java:1001)
INFO | jvm 1 | 2015/09/30 16:03:30 | at org.hsqldb.jdbc.JDBCPreparedStatement.fetchResult(JDBCPreparedStatement.java:4647)
INFO | jvm 1 | 2015/09/30 16:03:30 | … 31 more

lva · September 30, 2015, 2:37pm

I also noticed that “Emmergency mode” was activated … (I can see that in the Licensing screen on the admin web page…)

lva · October 1, 2015, 2:35pm

I just remove the context.getExecutionManager().shutdown(); in the shutdown method and I can’t reproduce this issue anymore …

@Override
public void shutdown() {
//Clean up the things we’ve registered with the platform, namely, our provider type.
try {
if (context != null) {
//Remove our value update task
//if (context.getExecutionManager() != null) {
// context.getExecutionManager().shutdown();
//}
//Shutdown our provider
ourProvider.shutdown();
}
} catch (Exception e) {
logger.error(“Error stopping Gateway module.”, e);
}
logger.info(“Gateway module stopped.”);
}

Kevin.Herron · October 1, 2015, 2:43pm

Yes, you want to unregister your task from the ExecutionManager using the unRegister or unRegisterAll methods, but you DO NOT shut it down - it’s a SHARED ExecutionManager, so the rest of the system is still using it.