Commit Transaction fails in a Scheduled Gateway Event but works in a Timer Gateway Event

I have the following code in version 8.1.32.

datasource = 'myDatabaseName'
isolationLevel = system.db.READ_COMMITTED
timeout = 30000
txNumber = system.db.beginNamedQueryTransaction(datasource, isolationLevel, timeout)

params = {}

params['TimestampIgn'] = system.date.format(system.date.now(), "YYYY-MM-dd HH:mm:ss")
params['Asset'] = 0

ds = system.tag.read('[default]Datasets/TagPathFromPLC').value
tagPathsID = []
tagPaths = []

for row in range(ds.getRowCount()):
	tagPathID = ds.getValueAt(row, "TagPathID")
	tagPathsID.append(tagPathID)
	
	tagPathFromPLC = ds.getValueAt(row, "TagPathFromPLC")
	tagPaths.append(tagPathFromPLC)
	
vals = system.opc.readValues('Ignition OPC UA Server', tagPaths)

for index, tagPath in enumerate(tagPaths):
	# Only record good readings. Bad readings are lost but should be escalated to management if they continue.
	if str(vals[index].quality) == 'Good':
		params['TagPathID'] = tagPathsID[index]
		params['TagValueFromPLC'] = vals[index].value
		
		# For abnormal PLC values fix datatype entry.
		if type(params['TagValueFromPLC']) == bool:
			if params['TagValueFromPLC']:
				params['TagValueFromPLC'] = 1
			else:
				params['TagValueFromPLC'] = 0
		
		system.db.runNamedQuery("Data_Collection", "insert_HistoricalData", params, txNumber)

system.db.commitTransaction(txNumber)
system.db.closeTransaction(txNumber)

The above reads several tag paths from a dataset, looks up the PLC values from those paths, and saves the PLC values to a database in a single named query transaction. This code works fine in a Timer Gateway Event (every 60 seconds) but fails in a Scheduled Gateway Event (scheduled for ever minute).

The error in the gateway is:

com.inductiveautomation.ignition.common.script.JythonExecException: Traceback (most recent call last): File "", line 56, in onScheduledEvent at com.inductiveautomation.ignition.common.script.builtin.AbstractDBUtilities.error(AbstractDBUtilities.java:392) at com.inductiveautomation.ignition.common.script.builtin.AbstractDBUtilities.commitTransaction(AbstractDBUtilities.java:468) at jdk.internal.reflect.GeneratedMethodAccessor202.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()
at org.python.core.Py.JavaError(Py.java:547)
at com.inductiveautomation.ignition.common.script.builtin.AbstractDBUtilities.error(AbstractDBUtilities.java:392)
at com.inductiveautomation.ignition.common.script.builtin.AbstractDBUtilities.commitTransaction(AbstractDBUtilities.java:468)
at jdk.internal.reflect.GeneratedMethodAccessor202.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:190)
at com.inductiveautomation.ignition.common.script.ScriptManager$ReflectedInstanceFunction.__call__(ScriptManager.java:553)
at org.python.core.PyObject.__call__(PyObject.java:461)
at org.python.core.PyObject.__call__(PyObject.java:465)
at org.python.pycode._pyx9953.onScheduledEvent$1(:57)
at org.python.pycode._pyx9953.call_function()
at org.python.core.PyTableCode.call(PyTableCode.java:173)
at org.python.core.PyBaseCode.call(PyBaseCode.java:306)
at org.python.core.PyFunction.function___call__(PyFunction.java:474)
at org.python.core.PyFunction.__call__(PyFunction.java:469)
at org.python.core.PyFunction.__call__(PyFunction.java:464)
at com.inductiveautomation.ignition.common.script.ScriptManager.runFunction(ScriptManager.java:847)
at com.inductiveautomation.ignition.common.script.ScriptManager.runFunction(ScriptManager.java:829)
at com.inductiveautomation.ignition.gateway.project.ProjectScriptLifecycle$TrackingProjectScriptManager.runFunction(ProjectScriptLifecycle.java:852)
at com.inductiveautomation.ignition.common.script.ScriptManager$ScriptFunctionImpl.invoke(ScriptManager.java:1010)
at com.inductiveautomation.ignition.gateway.project.ProjectScriptLifecycle$AutoRecompilingScriptFunction.invoke(ProjectScriptLifecycle.java:934)
at com.inductiveautomation.ignition.common.script.ScheduledScriptManager$ScheduledScriptTask.run(ScheduledScriptManager.java:173)
at com.inductiveautomation.ignition.common.util.ExecutionQueue$PollAndExecute.run(ExecutionQueue.java:239)
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: org.python.core.PyException: java.lang.Exception: java.lang.Exception: Error executing system.db.commitTransaction()
... 27 common frames omitted
Caused by: java.lang.Exception: Error executing system.db.commitTransaction()
... 26 common frames omitted
java.lang.NullPointerException: null

Any help with explaining why this works for a timer but not a scheduled event is appreciated.

I tried packaging up the code into a function I could call from my script library and it still failed from the scheduled gateway event. I then modified the function to include the project name and it worked.

txNumber = system.db.beginNamedQueryTransaction("projectName", datasource, isolationLevel, timeout)

So my only explanation for this is timer events are called from Vision scope while scheduled events are called from gateway scope.

No, most gateway events use a legacy scope, where the Scheduled event uses modern scope. You are having difficulties because you are writing your event logic right in the event script window. Don't do that. Events should be one-liners delegating to a project library script function, which is always a consistent, modern, scope.

1 Like

Just for clarity does legacy scope mean Vision?

No. Gateway events are gateway scope. Just a mangled (Jython v2.1 compatible) mess of a scope.

Delegate to project library script functions. Always. Really.

2 Likes

:melting_face:

ok...

Then what was the issue here, besides form? It's good to know what should be done here, but I'm interested to understand why it doesn't work in the first place. Do we just chalk it up to legacy scope weirdness, or is there a more concrete explanation here?

Yes, because it is complicated, and I do not want to misspeak about what's really happening.

There are many good reasons to delegate to project library functions everywhere--this is just one more that is particular to legacy gateway events.

2 Likes

I took a quick look at this.. I started by taking a simplified version of your script into a timer gateway event script:

project = 'Test2'
datasource = 'mariadb'
isolationLevel = system.db.READ_COMMITTED
timeout = 30000
txNumber = system.db.beginNamedQueryTransaction(project=project, datasource=datasource, isolationLevel=isolationLevel, timeout=timeout)
system.util.logger("testing").info("txNumber is %s" % txNumber)
system.db.commitTransaction(txNumber)
system.db.closeTransaction(txNumber)

... which produced the same NPE that you encountered:

Click for stack trace
+jvm 3    | 2024/05/20 14:27:01 | I [testing                       ] [14:27:01.781]: txNumber is None
jvm 3    | 2024/05/20 14:27:01 | E [c.i.i.c.s.TimerScriptTask     ] [14:27:01.782]: Error executing global timer script: Test2/Testing @15,000ms . Repeat errors of this type will be logged as 'debug' messages.
jvm 3    | 2024/05/20 14:27:01 | com.inductiveautomation.ignition.common.script.JythonExecException: Traceback (most recent call last):
jvm 3    | 2024/05/20 14:27:01 |   File "<TimerScript:Test2/Testing @15,000ms >", line 6, in <module>
jvm 3    | 2024/05/20 14:27:01 | 	at com.inductiveautomation.ignition.common.script.builtin.AbstractDBUtilities.error(AbstractDBUtilities.java:392)
jvm 3    | 2024/05/20 14:27:01 | 	at com.inductiveautomation.ignition.common.script.builtin.AbstractDBUtilities.commitTransaction(AbstractDBUtilities.java:468)
jvm 3    | 2024/05/20 14:27:01 | 	at jdk.internal.reflect.GeneratedMethodAccessor31.invoke(Unknown Source)
jvm 3    | 2024/05/20 14:27:01 | 	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
jvm 3    | 2024/05/20 14:27:01 | 	at java.base/java.lang.reflect.Method.invoke(Unknown Source)
jvm 3    | 2024/05/20 14:27:01 | java.lang.Exception: java.lang.Exception: Error executing system.db.commitTransaction()
jvm 3    | 2024/05/20 14:27:01 |
jvm 3    | 2024/05/20 14:27:01 | 	at org.python.core.Py.JavaError(Py.java:545)
jvm 3    | 2024/05/20 14:27:01 | 	at com.inductiveautomation.ignition.common.script.builtin.AbstractDBUtilities.error(AbstractDBUtilities.java:392)
jvm 3    | 2024/05/20 14:27:01 | 	at com.inductiveautomation.ignition.common.script.builtin.AbstractDBUtilities.commitTransaction(AbstractDBUtilities.java:468)
jvm 3    | 2024/05/20 14:27:01 | 	at jdk.internal.reflect.GeneratedMethodAccessor31.invoke(Unknown Source)
jvm 3    | 2024/05/20 14:27:01 | 	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
jvm 3    | 2024/05/20 14:27:01 | 	at java.base/java.lang.reflect.Method.invoke(Unknown Source)
jvm 3    | 2024/05/20 14:27:01 | 	at org.python.core.PyReflectedFunction.__call__(PyReflectedFunction.java:190)
jvm 3    | 2024/05/20 14:27:01 | 	at com.inductiveautomation.ignition.common.script.ScriptManager$ReflectedInstanceFunction.__call__(ScriptManager.java:553)
jvm 3    | 2024/05/20 14:27:01 | 	at org.python.core.PyObject.__call__(PyObject.java:461)
jvm 3    | 2024/05/20 14:27:01 | 	at org.python.core.PyObject.__call__(PyObject.java:465)
jvm 3    | 2024/05/20 14:27:01 | 	at org.python.pycode._pyx3.f$0(<TimerScript:Test2/Testing @15,000ms >:7)
jvm 3    | 2024/05/20 14:27:01 | 	at org.python.pycode._pyx3.call_function(<TimerScript:Test2/Testing @15,000ms >)
jvm 3    | 2024/05/20 14:27:01 | 	at org.python.core.PyTableCode.call(PyTableCode.java:173)
jvm 3    | 2024/05/20 14:27:01 | 	at org.python.core.PyCode.call(PyCode.java:18)
jvm 3    | 2024/05/20 14:27:01 | 	at org.python.core.Py.runCode(Py.java:1703)
jvm 3    | 2024/05/20 14:27:01 | 	at com.inductiveautomation.ignition.common.script.ScriptManager.runCode(ScriptManager.java:804)
jvm 3    | 2024/05/20 14:27:01 | 	at com.inductiveautomation.ignition.gateway.project.ProjectScriptLifecycle$TrackingProjectScriptManager.runCode(ProjectScriptLifecycle.java:859)
jvm 3    | 2024/05/20 14:27:01 | 	at com.inductiveautomation.ignition.common.script.ScriptManager.runCode(ScriptManager.java:752)
jvm 3    | 2024/05/20 14:27:01 | 	at com.inductiveautomation.ignition.gateway.project.ProjectScriptLifecycle$TrackingProjectScriptManager.runCode(ProjectScriptLifecycle.java:840)
jvm 3    | 2024/05/20 14:27:01 | 	at com.inductiveautomation.ignition.common.script.TimerScriptTask.run(TimerScriptTask.java:92)
jvm 3    | 2024/05/20 14:27:01 | 	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)
jvm 3    | 2024/05/20 14:27:01 | 	at java.base/java.util.concurrent.FutureTask.runAndReset(Unknown Source)
jvm 3    | 2024/05/20 14:27:01 | 	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source)
jvm 3    | 2024/05/20 14:27:01 | 	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
jvm 3    | 2024/05/20 14:27:01 | 	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
jvm 3    | 2024/05/20 14:27:01 | 	at java.base/java.lang.Thread.run(Unknown Source)
jvm 3    | 2024/05/20 14:27:01 | Caused by: org.python.core.PyException: java.lang.Exception: java.lang.Exception: Error executing system.db.commitTransaction()
jvm 3    | 2024/05/20 14:27:01 | 	... 26 common frames omitted
jvm 3    | 2024/05/20 14:27:01 | Caused by: java.lang.Exception: Error executing system.db.commitTransaction()
jvm 3    | 2024/05/20 14:27:01 | 	... 25 common frames omitted
jvm 3    | 2024/05/20 14:27:01 | Caused by: java.lang.NullPointerException: null

As to the reason why this error occurred, it seems to stem from targeting a project in which there are no actual named queries (and thus no executors, whose retrieval attempt is the source of the NPE). Once I added a single named query to the project, it started generating valid transaction identifiers and no errors.

The reason why this was on my radar to begin with is that we did fix an issue in 8.1.40 that would generate an error if you system.db.beginNamedQueryTransaction()'d and then attempted to commit/close it without performing any actions.

I'll probably log a low-priority ticket to address the NPE since we shouldn't be tripping on that.

2 Likes