Gateway Start Fault

f.pinciaroli · June 8, 2018, 7:39am

Hello,

I have a probem.
The Gateway doesn’t start in any way. It faults with a lot of exceptions as I can see in the wrapper.log.
It seems that the exceptions are related to a shared script function that I call from my tags in valueChange Event.
Is it possible? Is possible that an error in a function blocks the gateway start?

There are many errors in the wrapper.log but the most recurrent is this:

INFO   | jvm 1    | 2018/06/08 09:31:08 | 	... 39 common frames omitted
INFO   | jvm 1    | 2018/06/08 09:31:08 | Caused by: simpleorm.utils.SException$Jdbc: Opening com.inductiveautomation.ignition.gateway.localdb.CountingDataSource@754fe7a1
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at simpleorm.sessionjdbc.SSessionJdbc.innerOpen(SSessionJdbc.java:113)
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at com.inductiveautomation.ignition.gateway.localdb.persistence.PersistenceSession.initialize(PersistenceSession.java:31)
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at com.inductiveautomation.ignition.gateway.localdb.PersistenceInterfaceImpl.getSession(PersistenceInterfaceImpl.java:62)
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at com.inductiveautomation.ignition.gateway.localdb.PersistenceInterfaceImpl.getSession(PersistenceInterfaceImpl.java:44)
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at com.inductiveautomation.xopc.scripting.legacy.IALabsGatewayScriptingFunctions.listDevices(IALabsGatewayScriptingFunctions.java:68)
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at sun.reflect.GeneratedMethodAccessor10.invoke(Unknown Source)
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at java.lang.reflect.Method.invoke(Method.java:498)
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at org.python.core.PyReflectedFunction.__call__(PyReflectedFunction.java:186)
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	... 36 common frames omitted
INFO   | jvm 1    | 2018/06/08 09:31:08 | Caused by: java.sql.SQLException: Connection is locked. Datasource only allows one connection at a time. More information was logged to the gateway console.
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at com.inductiveautomation.ignition.gateway.localdb.sqlite.SingleConnectionDatasource.getConnection(SingleConnectionDatasource.java:75)
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at com.inductiveautomation.ignition.gateway.localdb.DelegatingDataSource.getConnection(DelegatingDataSource.java:60)
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at simpleorm.sessionjdbc.SSessionJdbc.innerOpen(SSessionJdbc.java:111)
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	... 44 common frames omitted
INFO   | jvm 1    | 2018/06/08 09:31:08 | E [c.i.i.g.l.s.SingleConnectionDatasource] [07:31:08]: The following stack successfully received a connection. A new attempt was blocked for over 30000 ms 
INFO   | jvm 1    | 2018/06/08 09:31:08 | java.lang.Throwable: null
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at com.inductiveautomation.ignition.gateway.localdb.sqlite.SingleConnectionDatasource.getConnection(SingleConnectionDatasource.java:58)
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at com.inductiveautomation.ignition.gateway.localdb.DelegatingDataSource.getConnection(DelegatingDataSource.java:60)
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at simpleorm.sessionjdbc.SSessionJdbc.innerOpen(SSessionJdbc.java:111)
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at com.inductiveautomation.ignition.gateway.localdb.persistence.PersistenceSession.initialize(PersistenceSession.java:31)
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at com.inductiveautomation.ignition.gateway.localdb.PersistenceInterfaceImpl.getSession(PersistenceInterfaceImpl.java:62)
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at com.inductiveautomation.ignition.gateway.localdb.PersistenceInterfaceImpl.getSession(PersistenceInterfaceImpl.java:44)
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at com.inductiveautomation.xopc.scripting.legacy.IALabsGatewayScriptingFunctions.listDevices(IALabsGatewayScriptingFunctions.java:68)
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at sun.reflect.GeneratedMethodAccessor10.invoke(Unknown Source)
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at java.lang.reflect.Method.invoke(Method.java:498)
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at org.python.core.PyReflectedFunction.__call__(PyReflectedFunction.java:186)
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at com.inductiveautomation.ignition.common.script.ScriptManager$ReflectedInstanceFunction.__call__(ScriptManager.java:429)
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at org.python.core.PyObject.__call__(PyObject.java:371)
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at org.python.core.PyObject.__call__(PyObject.java:375)
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at org.python.pycode._pyx2.deviceNames$1(<module:shared.TagEvent>:27)
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at org.python.pycode._pyx2.call_function(<module:shared.TagEvent>)
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at org.python.core.PyTableCode.call(PyTableCode.java:165)
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at org.python.core.PyBaseCode.call(PyBaseCode.java:120)
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at org.python.core.PyFunction.__call__(PyFunction.java:307)
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at org.python.pycode._pyx2.valueChanged$2(<module:shared.TagEvent>:70)
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at org.python.pycode._pyx2.call_functINFO   | jvm 1    | 2018/06/08 09:31:08 | 	at org.python.core.PyFunction.function___call__(PyFunction.java:376)
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at org.python.core.PyFunction.__call__(PyFunction.java:371)
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at org.python.core.PyFunction.__call__(PyFunction.java:361)
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at org.python.core.PyFunction.__call__(PyFunction.java:356)
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at com.inductiveautomation.ignition.common.script.ScriptManager.runFunction(ScriptManager.java:647)
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at com.inductiveautomation.ignition.common.sqltags.scripts.TagScriptManager$FunctionInvokerImpl.run(TagScriptManager.java:493)
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at com.inductiveautomation.ignition.common.sqltags.scripts.AbstractTagScript.invoke(AbstractTagScript.java:33)
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at com.inductiveautomation.ignition.common.sqltags.scripts.TagScriptManager$Task.invoke(TagScriptManager.java:442)
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at com.inductiveautomation.ignition.common.sqltags.scripts.TagScriptManager$TagScriptDispatcher.run(TagScriptManager.java:405)
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at com.inductiveautomation.ignition.common.execution.impl.BasicExecutionEngine$ThrowableCatchingRunnable.run(BasicExecutionEngine.java:518)
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at java.lang.Thread.run(Thread.java:748)
INFO   | jvm 1    | 2018/06/08 09:31:08 | Caused by: org.python.core.PyException: Traceback (most recent call last):
INFO   | jvm 1    | 2018/06/08 09:31:08 |   File "<tagevent:valueChanged>", line 2, in valueChanged
INFO   | jvm 1    | 2018/06/08 09:31:08 |   File "<module:shared.TagEvent>", line 43, in valueChanged
INFO   | jvm 1    | 2018/06/08 09:31:08 |   File "<module:shared.TagEvent>", line 18, in deviceNames
INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at simpleorm.sessionjdbc.SSessionJdbc.innerOpen(SSessionJdbc.java:113) INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at com.inductiveautomation.ignition.gateway.localdb.persistence.PersistenceSession.initialize(PersistenceSession.java:31) INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at com.inductiveautomation.ignition.gateway.localdb.PersistenceInterfaceImpl.getSession(PersistenceInterfaceImpl.java:62) INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at com.inductiveautomation.ignition.gateway.localdb.PersistenceInterfaceImpl.getSession(PersistenceInterfaceImpl.java:44) INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at com.inductiveautomation.xopc.scripting.legacy.IALabsGatewayScriptingFunctions.listDevices(IALabsGatewayScriptingFunctions.java:68) INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at sun.reflect.GeneratedMethodAccessor10.invoke(Unknown Source) INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) INFO   | jvm 1    | 2018/06/08 09:31:08 | 	at java.lang.reflect.Method.invoke(Method.java:498) INFO   | jvm 1    | 2018/06/08 09:31:08 | 
INFO   | jvm 1    | 2018/06/08 09:31:08 | simpleorm.utils.SException$Jdbc: simpleorm.utils.SException$Jdbc: Opening com.inductiveautomation.ignition.gateway.localdb.CountingDataSource@754fe7a1
INFO   | jvm 1    | 2018/06/08 09:31:08 |

any suggestions on how to solve and repair the gateway?

Thanks, Federico

Sanderd17 · June 8, 2018, 10:53am

It appears to be an SQL problem. Given that the only critical SQL related thing in Ignition is the internal SQLite database, I’d check that first.

SQLite only allows one connection, so make sure that you don’t have that file open anywhere (restart your computer if you want to be sure).

pturmel · June 8, 2018, 12:49pm

You are directly accessing the Gateway’s internal database from python. I don’t think that is supported, And I’m not sure it can be supported, since there’s a whole bunch of thread-local stuff in that interface that probably cannot be guaranteed in jython.
Write a module that encapsulates the access to the internal database you need, or move that functionality to an external database.

pturmel · June 8, 2018, 12:59pm

In the meantime, with the gateway stopped, you can use various SQLite3 tools to explore the internal database and locate/update/delete the troublesome tags. That should let you restart the gateway. Good luck.

upisharam · January 26, 2021, 6:12am

simpleorm.utils.SException$Jdbc, experiencing similar issue. Any advice please, how did you resolve the issue.