[IGN-3829] Error executing system.db.commitTransaction

When I use a named query transaction, but do not actually run any queries against it I receive an error.

If I do the same thing using system.db.beginTransaction I do not get an error.

Any ideas on how to get around this?

txId = system.db.beginNamedQueryTransaction("myDatabaseConnection")

system.db.commitTransaction(txId)
system.db.closeTransaction(txId)
Java Traceback:
Traceback (most recent call last):
  File "<input>", line 28, in <module>
	at com.inductiveautomation.ignition.common.script.builtin.AbstractDBUtilities.error(AbstractDBUtilities.java:362)

	at com.inductiveautomation.ignition.common.script.builtin.AbstractDBUtilities.commitTransaction(AbstractDBUtilities.java:438)

	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)

	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)

	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)

	at java.base/java.lang.reflect.Method.invoke(Unknown Source)

java.lang.Exception: java.lang.Exception: Error executing system.db.commitTransaction(142fa9d6-379f-43f9-b76a-e83f332779ee)


	at org.python.core.Py.JavaError(Py.java:552)

	at com.inductiveautomation.ignition.common.script.builtin.AbstractDBUtilities.error(AbstractDBUtilities.java:362)

	at com.inductiveautomation.ignition.common.script.builtin.AbstractDBUtilities.commitTransaction(AbstractDBUtilities.java:438)

	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)

	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)

	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)

	at java.base/java.lang.reflect.Method.invoke(Unknown Source)

	at org.python.core.PyReflectedFunction.__call__(PyReflectedFunction.java:188)

	at com.inductiveautomation.ignition.common.script.ScriptManager$ReflectedInstanceFunction.__call__(ScriptManager.java:539)

	at org.python.core.PyObject.__call__(PyObject.java:480)

	at org.python.core.PyObject.__call__(PyObject.java:484)

	at org.python.pycode._pyx671.f$0(<input>:29)

	at org.python.pycode._pyx671.call_function(<input>)

	at org.python.core.PyTableCode.call(PyTableCode.java:171)

	at org.python.core.PyCode.call(PyCode.java:18)

	at org.python.core.Py.runCode(Py.java:1614)

	at org.python.core.Py.exec(Py.java:1658)

	at org.python.util.PythonInterpreter.exec(PythonInterpreter.java:276)

	at org.python.util.InteractiveInterpreter.runcode(InteractiveInterpreter.java:131)

	at com.inductiveautomation.ignition.designer.gui.tools.jythonconsole.JythonConsole$ConsoleWorker.doInBackground(JythonConsole.java:605)

	at com.inductiveautomation.ignition.designer.gui.tools.jythonconsole.JythonConsole$ConsoleWorker.doInBackground(JythonConsole.java:593)

	at java.desktop/javax.swing.SwingWorker$1.call(Unknown Source)

	at java.base/java.util.concurrent.FutureTask.run(Unknown Source)

	at java.desktop/javax.swing.SwingWorker.run(Unknown Source)

	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)

	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)

	at java.base/java.lang.Thread.run(Unknown Source)

Caused by: java.lang.Exception: Error executing system.db.commitTransaction(142fa9d6-379f-43f9-b76a-e83f332779ee)

	... 26 more

Caused by: com.inductiveautomation.ignition.client.gateway_interface.GatewayException: Transaction "142fa9d6-379f-43f9-b76a-e83f332779ee" is closed.

	at com.inductiveautomation.ignition.client.gateway_interface.GatewayInterface.newGatewayException(GatewayInterface.java:351)

	at com.inductiveautomation.ignition.client.gateway_interface.GatewayInterface.sendMessage(GatewayInterface.java:325)

	at com.inductiveautomation.ignition.client.gateway_interface.GatewayInterface.sendMessage(GatewayInterface.java:278)

	at com.inductiveautomation.ignition.client.gateway_interface.GatewayInterface.invoke(GatewayInterface.java:945)

	at com.inductiveautomation.ignition.client.script.ClientDBUtilities._commitTransaction(ClientDBUtilities.java:231)

	at com.inductiveautomation.ignition.common.script.builtin.AbstractDBUtilities.commitTransaction(AbstractDBUtilities.java:436)

	... 24 more

Caused by: java.sql.SQLException: Transaction "142fa9d6-379f-43f9-b76a-e83f332779ee" is closed.

	at com.inductiveautomation.ignition.gateway.datasource.DatasourceManagerImpl.getTx(DatasourceManagerImpl.java:284)

	at com.inductiveautomation.ignition.gateway.datasource.DatasourceManagerImpl.commitTransaction(DatasourceManagerImpl.java:297)

	at com.inductiveautomation.ignition.gateway.servlets.gateway.functions.TxControl.commitTransaction(TxControl.java:28)

	at jdk.internal.reflect.GeneratedMethodAccessor266.invoke(null)

	at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(null)

	at java.lang.reflect.Method.invoke(null)

	at com.inductiveautomation.ignition.gateway.servlets.gateway.AbstractGatewayFunction.invoke(AbstractGatewayFunction.java:225)

	at com.inductiveautomation.ignition.gateway.servlets.Gateway.doPost(Gateway.java:405)

	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:86)

	at org.eclipse.jetty.servlet.ServletHolder$NotAsyncServlet.service(ServletHolder.java:1391)

	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:760)

	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:547)

	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)

	at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:590)

	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)

	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:235)

	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1607)

	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)

	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1297)

	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)

	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:485)

	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1577)

	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)

	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1212)

	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)

	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)

	at org.eclipse.jetty.rewrite.handler.RewriteHandler.handle(RewriteHandler.java:322)

	at org.eclipse.jetty.server.handler.HandlerList.handle(HandlerList.java:59)

	at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:146)

	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)

	at org.eclipse.jetty.server.Server.handle(Server.java:500)

	at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:383)

	at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:547)

	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:375)

	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:270)

	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)

	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103)

	at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:117)

	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336)

	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:313)

	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171)

	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:129)

	at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:388)

	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:806)

	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:938)

	at java.lang.Thread.run(null)

Traceback (most recent call last):
  File "<input>", line 28, in <module>
	at com.inductiveautomation.ignition.common.script.builtin.AbstractDBUtilities.error(AbstractDBUtilities.java:362)

	at com.inductiveautomation.ignition.common.script.builtin.AbstractDBUtilities.commitTransaction(AbstractDBUtilities.java:438)

	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)

	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)

	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)

	at java.base/java.lang.reflect.Method.invoke(Unknown Source)

java.lang.Exception: java.lang.Exception: Error executing system.db.commitTransaction(142fa9d6-379f-43f9-b76a-e83f332779ee)

What is the underlying database behind the JDBC driver? It might help to know that while taking a look at this.

the JDBC driver is com.microsoft.sqlserver.jdbc.SQLServerDriver

@Jonathan , I looked into this and it looks like the transaction handling with Named Queries is slightly different than the standard method with beginTransaction. We essentially “queue” the transaction with beginNamedQueryTransaction() and then only put it into effect when a statement is run; this helps prevent a connection from getting tied up prematurely in some situations. In essence, it is an optimization.

That said, there is a bug here, as these queued transactions do stack up in the named query executor (though they’re not real at this point) in your example above. We should be more graceful about detecting the queued transaction and cleaning things up.

Thanks for looking into it. For now I have placed a simple select query so that I do not receive an error in my testing. It would be great to get this on the bug list to be fixed in a future release. I am currently running 8.1.7.

You’re welcome. We’ll definitely get it in the backlog, it isn’t a difficult fix. For now you could also do something like this to catch that error:

import java.lang.Exception
logger = system.util.getLogger("named-query-test")
# Begin named query transaction
txId = system.db.beginNamedQueryTransaction("db")
attemptedQuery = False

# Optionally run statements and raise flag
# attemptedQuery = True

try:
	system.db.commitTransaction(txId)
	system.db.closeTransaction(txId)
except java.lang.Exception as e:
	if attemptedQuery:
		raise e  # if we get an exception at this point, something might have actually gone wrong so re-raise exception
	else:
		logger.warnf("Attempt to close tx %s failed, presumably due to queued but not active txId", txId) # optional log

… that said, SELECT 1 isn’t exactly an expensive query to just run either. :wink:

Was this ever fixed?

No, hasn’t yet been picked up.

Is there a different workaround for this? The one above does not seem to work for me.

The summary of my named queries is

self.tx = system.db.beginNamedQueryTransaction(self.isolationLevel, self.timeout)
...
self.idx = system.db.runNamedQuery(createNamedQuery, self.newData, tx=self.tx, getKey=1)
...
deleteAliasesQuery = self.namedQueryFolder + '/deleteAliases'
system.db.runNamedQuery(deleteAliasesQuery,{'idx':self.idx}, tx=self.tx)
createAliasesQuery = self.namedQueryFolder + '/createAliases'
for (i, alias) in system.dataset.toPyDataSet(self.aliases):
		system.db.runNamedQuery(createAliasesQuery, {"customerId":self.idx, "alias":alias}, tx=self.tx)
...
system.db.commitTransaction(self.tx)
system.db.closeTransaction(self.tx)

This way always throws me caused by GatewayException: java.sql.SQLException: Datasource "4" does not exist in this Gateway. caused by Exception: java.sql.SQLException: Datasource "4" does not exist in this Gateway.
where the Datasource always correseponds to my isolation level - in this case my self.isolationLevel = system.db.REPEATABLE_READ. Setting self.isolationLevel = system.db.SERIALIZABLE then tells me Datasource “8” does not exist in my gateway.

The above work around does not work for me. Putting my namedQueries inside a try/except silences their error but I can’t imagine they are still running since they don’t have the right datasource and I do not see them come through.

Trying:

try:
    self.tx = system.db.beginNamedQueryTransaction(self.isolationLevel, self.timeout)
except java.lang.Exception, e:
    pass
...
try:
    self.idx = system.db.runNamedQuery(createNamedQuery, self.newData, tx=self.tx, getKey=1)
except java.lang.Exception, e:
    pass
...
deleteAliasesQuery = self.namedQueryFolder + '/deleteAliases'
try:
    system.db.runNamedQuery(deleteAliasesQuery,{'idx':self.idx}, tx=self.tx)
except java.lang.Exception, e:
    pass
createAliasesQuery = self.namedQueryFolder + '/createAliases'
for (i, alias) in system.dataset.toPyDataSet(self.aliases):
try:
		system.db.runNamedQuery(createAliasesQuery, {"customerId":self.idx, "alias":alias}, tx=self.tx)
except java.lang.Exception, e:
    pass
...
system.db.commitTransaction(self.tx)
system.db.closeTransaction(self.tx)

Then throws me errors like

caused by Exception: Error executing system.db.commitTransaction(5ddb00c3-61d9-4696-a355-fb1fc7b585a2)
	caused by GatewayException: Transaction "5ddb00c3-61d9-4696-a355-fb1fc7b585a2" is closed.
	caused by SQLException: Transaction "5ddb00c3-61d9-4696-a355-fb1fc7b585a2" is closed.

Putting the commit/close inside the try/except as well silences this error sure, but nothing is inserted and I get another error when self.idx is referenced as it is a None but I am expecting the ID indicating to me the query did never actually execute.

Is there some way to make this work or is it not feasible currently?

If you’re going to omit the database argument (and use the project default database, which is perfectly fine), you’ll probably want to use keyword arguments. It is interpreting the first argument as the database connection name.

Try:

...
self.tx = system.db.beginNamedQueryTransaction(isolationLevel=self.isolationLevel, timeout=self.timeout)
...

Scratch all that. This works. Thank you.

The documentation for system.db.beginNamedQueryTransaction - Ignition User Manual 8.0 - Ignition Documentation confused me a bit I guess.

For example notice here system.db.runNamedQuery - Ignition User Manual 8.0 - Ignition Documentation

If a parameter is optional it says so immediately after the parameter - indicating it’s a keyword

String tx - An optional transaction ID, obtained from beginNamedQueryTransaction. If blank, will not be part of a transaction.

Boolean getKey - Optional. Only used for Update Query types. A flag indicating whether or not the result should be the number of rows affected (getKey=0) or the newly generated key value that was created as a result of the update (getKey=1). Not all databases support automatic retrieval of generated keys.

Whereas with beginNamedQueryTransaction it says it at the very end of the paramter description

Long timeout timeout - The amount of time, in milliseconds, that this connection is allowed to remain open without being used. Timeout counter is reset any time a query or call is executed against the transaction, or when committed or rolled-back. If omitted, defaults to 30,000.

I recognize this is my own fault I must have missed that. I do think its better that immediately after a parameter it’s indicated if its a mandatory or optional paramter.