Catching a tag write timeout exception

BinaryBush · August 11, 2021, 2:48pm

Hello,

I’ve been troubleshooting the following error:

java.util.concurrent.TimeoutException: null

at java.base/java.util.concurrent.CompletableFuture.timedGet(Unknown Source)

at java.base/java.util.concurrent.CompletableFuture.get(Unknown Source)

at com.inductiveautomation.ignition.gateway.script.GatewayTagUtilities.writeBlockingImpl(GatewayTagUtilities.java:261)

at com.inductiveautomation.ignition.common.script.builtin.AbstractTagUtilities.writeBlocking(AbstractTagUtilities.java:482)

at jdk.internal.reflect.GeneratedMethodAccessor55.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:540)

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

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

at org.python.pycode._pyx177310.pullOperatorLoadTimeFromPLC$6(:334)

at org.python.pycode._pyx177310.call_function()

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

at org.python.core.PyBaseCode.call(PyBaseCode.java:168)

at org.python.core.PyFunction.__call__(PyFunction.java:437)

at org.python.pycode._pyx177304.threadType1$2(:189)

at org.python.pycode._pyx177304.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 org.python.core.PyObject._callextra(PyObject.java:589)

at org.python.pycode._pyx177305.run$3(:15)

at org.python.pycode._pyx177305.call_function()

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

at org.python.core.PyBaseCode.call(PyBaseCode.java:306)

at org.python.core.PyBaseCode.call(PyBaseCode.java:197)

at org.python.core.PyFunction.__call__(PyFunction.java:485)

at org.python.core.PyMethod.instancemethod___call__(PyMethod.java:237)

at org.python.core.PyMethod.__call__(PyMethod.java:228)

at org.python.core.PyMethod.__call__(PyMethod.java:218)

at org.python.core.PyMethod.__call__(PyMethod.java:213)

at org.python.core.PyObject._jcallexc(PyObject.java:3565)

at org.python.core.PyObject._jcall(PyObject.java:3598)

at org.python.proxies.utils$JythonRunnable$33.run(Unknown Source)

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

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

I understand that this is occurring because my writes are failing to complete within the timeout. I was originally not using the optional timeout parameter, but now I am, although I have it set to 45000ms, which is the same as the default. There is no reason my writes should take more than 5 seconds to complete, 45 seconds should be plenty.

So that leads me to my next issue, I am trying to catch the error so I can pass in some parameters to the fault message to help me diagnose which PLC it is failing on, so I can investigate for connection issues. I am using a try/except clause around my writeBlocking calls but I am still getting unhandled exceptions.

The code for the above error message looks as such:

def pullOperatorLoadTimeFromPLC(plant, deviceName, opName):
	logger = system.util.getLogger("Project6.prod_record.pullOperatorLoadTimeFromPLC")
	UDTPath = '[Project6]Plant %s/%s/%s/' % (plant, deviceName, opName)
	paths = [
	UDTPath+'OPC/Operator Load Time/Time/Time_8_/LoadTime',
	UDTPath+'OPC/Operator Load Time/Time/Time_8_/ReadyToGrab',
	UDTPath+'OPC/Operator Load Time/Time/Time_7_/LoadTime',
	UDTPath+'OPC/Operator Load Time/Time/Time_7_/ReadyToGrab',
	UDTPath+'OPC/Operator Load Time/Time/Time_6_/LoadTime',
	UDTPath+'OPC/Operator Load Time/Time/Time_6_/ReadyToGrab',
	UDTPath+'OPC/Operator Load Time/Time/Time_5_/LoadTime',
	UDTPath+'OPC/Operator Load Time/Time/Time_5_/ReadyToGrab',
	UDTPath+'OPC/Operator Load Time/Time/Time_4_/LoadTime',
	UDTPath+'OPC/Operator Load Time/Time/Time_4_/ReadyToGrab',
	UDTPath+'OPC/Operator Load Time/Time/Time_3_/LoadTime',
	UDTPath+'OPC/Operator Load Time/Time/Time_3_/ReadyToGrab',
	UDTPath+'OPC/Operator Load Time/Time/Time_2_/LoadTime',
	UDTPath+'OPC/Operator Load Time/Time/Time_2_/ReadyToGrab',
	UDTPath+'OPC/Operator Load Time/Time/Time_1_/LoadTime',
	UDTPath+'OPC/Operator Load Time/Time/Time_1_/ReadyToGrab',
	UDTPath+'OPC/Operator Load Time/Time/Time_0_/LoadTime',
	UDTPath+'OPC/Operator Load Time/Time/Time_0_/ReadyToGrab',
	]
	values = system.tag.readBlocking(paths)
	#Mass write all values back to zero immediately after reading.
	try:
		system.tag.writeBlocking(paths, [0,False,0,False,0,False,0,False,0,False,0,False,0,False,0,False,0,False], writeTimeout)
	except:
		logger.warn("Failed to write zeroes to operator load time opc tags for plant %s %s %s" % (plant, deviceName, opName))
	#Get current target load time:
	try:
		targetLoadTime = get.getOperatorLoadTimeOPC(plant, deviceName, opName)
	except:
		targetLoadTime = 0
		logger.warn("Failed to get target load time for plant %s %s %s" % (plant, deviceName, opName))
	#
	#Start sql insert
	for value in values:
		if isinstance(value.value,float):
			loadTime = value.value
			if loadTime>0:
				currentTime = get.getOpCurrentLocalTime(plant, deviceName, opName).replace(tzinfo=None)
				params ={
				'table':'P'+str(plant)+'_pd_operator_load_time',
				'deviceName': deviceName,
				'opName': opName,
				'operatorLoadTime':loadTime,
				'date_time':currentTime,
				'targetLoadTime':targetLoadTime,
				}
				try:
					system.db.runNamedQuery("Project6","Operator Load Time/insertOperatorLoadTime", params)
				except:
					try:
						system.db.runNamedQuery("Operator Load Time/insertOperatorLoadTime", params)
					except:
						logger.fatal("Failed to run sql query for plant %s %s %s" % (plant, deviceName, opName))
						return
		else:
			pass

Does anyone have any ideas on what I can do to properly catch this error?

Thanks

bkarabinchak.psi · August 11, 2021, 4:09pm

Generally speaking try/except will only catch python errors. To catch java errors in Ignition, you have to import them, for instance to catch an error that the database throws you would need

import java.lang.Exception
try:
   system.db.runUpdateQuery("somequery")
except Exception, e:
## catches python errors
except java.lang.Exception, e:
## Catches database thrown errors

Looking at your stack trace it looks like ultimately you get java.util.concurrent.TimeoutException so that is the exception you would need to import and catch specifically. It doesn’t look like you get much info back (null) but at least catching this specifically you could start logging those instances and perhaps some sort of pattern that is causing it.

BinaryBush · August 11, 2021, 5:36pm

I’ve replaced mine with the java excepts now and we will see if I can capture it. Thank you for the help.

BinaryBush · August 12, 2021, 9:29am

So far I’ve been unable to catch this error, I’ve tried putting the try/except in a few different places. It makes the most sense to me that it should be directly around the system.tag.writeBlocking call, such as this:

	#Mass write all values back to zero immediately after reading.
	try:
		system.tag.writeBlocking(paths, [0,False,0,False,0,False,0,False,0,False,0,False,0,False,0,False,0,False], writeTimeout)
	except java.util.concurrent.TimeoutException, e:
		logger.warn("Java Timeout exception for plant %s %s %s" % (plant, deviceName, opName))

However this is not catching the error and it is still unhandled. I also tried putting it in the calling script that calls this function but that did not catch it either.

pturmel · August 12, 2021, 10:59am

Are you calling writeBlocking from a Vision client? If so, the exception would be wrapped by a GatewayException. Consider catching java.lang.Throwable instead.

BinaryBush · August 12, 2021, 11:19am

No, I’m using a tag event script to send a message to a project message handler which then calls a thread handler that dispatches the call to a thread pool.

bkarabinchak.psi · August 12, 2021, 12:07pm

Trivial but maybe important - you’re importing the java error? import java.util.concurrent.TimeoutException or import java.lang.Throwable. I don’t think you can reference them without importing them.

BinaryBush · August 12, 2021, 12:43pm

Correct, I am importing java.util.concurrent.TimeoutException

BinaryBush · August 12, 2021, 8:14pm

Another interesting note, is that these show up under the startup/shutdown gateway scripts logs, even though I do not have any gateway startup/shutdown scripts configured.

pturmel · August 12, 2021, 9:51pm

Click on the “+” sign to get the details to show us.

BinaryBush · August 13, 2021, 9:12am

Hi Phil,

Hitting the plus just shows the error message that I pasted in the original post:

pturmel · August 13, 2021, 11:16am

I’m going to guess you have more places to put try-except blocks. Please catch java.lang.Throwable instead of TimeoutException.

BinaryBush · August 13, 2021, 11:23am

Ok, I just swapped them all over. I’ve wrapped every system.tag.writeBlocking I can find with it, but the exception actually references the next line after the system.tag.writeBlocking as the line that the error occurred on which is what is strange to me, and the next line is simply the beginning of my for loop.

BinaryBush · August 13, 2021, 11:29am

Also, do you know if errors without a try/catch are raised to the calling functions try/catch clause? So for example if I have:

def callingFunction()
	#
	try:
		someFunction(someArgs)
	except:
		print ("Failed")

def someFunction(someArgs)
	#
	somethingThatCausesAnException()

If an error occurs in “someFunction”, will the error be caught by the try/catch of callingFunction or be reported in the gateway logs as an unhandled exception?

bkarabinchak.psi · August 13, 2021, 12:41pm

The error of someFunction will be caught by your except clause as long as it’s the right sort of except. For example

def callingFunction():
    try:
        someFunction()
    except TypeError,e :
         print "type error occured"
    except KeyError, e:
         print "key error occured"

def someFunction():
    d = {'someKey':'someValue'}
    return d['nonExistantKey']

someFunction will trigger a KeyError and you will see “key error occured”. You would also catch this with just a plain except or a except Exception, but if you don’t have except\except Exception\except KeyError, then the error will bubble up either to the GUI or to the gateway logs depending on where you are calling this function.

For the record this is how I do things. I created a custom error FormError that I raise inside functions when a user enters invalid input into forms, and on my GUI I try/except FormError when they are trying to create or update a record. Like

try:
    createForm(data)
except FormError, e:
    system.gui.messageBox(str(e))

Where createForm calls a list of functions some of which may raise a FormError.

BinaryBush · August 13, 2021, 12:49pm

So with knowing that, as long as I am excepting java.lang.Throwable and java.util.concurrent.TimeoutException in the calling script at the top of my hierarchy, I should be able to catch any unhandled errors of those two types from any call lower in the program stack, right?

If this is the case, that’s how I am doing it, I have one script, my thread handler, that dispatches all of the rest of the calls, so putting the try/except in my thread handler should catch everything, however I am still getting unhandled exceptions to the gateway via this method.

bkarabinchak.psi · August 13, 2021, 12:54pm

It’s pretty common practice to do try/except with multiple error clauses. That is correct though from your testing it seems like java.util.concurrent.TimeoutException is not working and it will come through as a java.lang.Throwable as @pturmel said.

You can make it separate if you want to see which one specifically is being triggered

try:
    system.tag.writeBlocking(...)
except java.lang.Throwable, e:
    # handle gracefully
except java.util.concurrent.TimeoutException, e:
    # also handle gracefully

In general though, as a little python 2 tidbit that you can use to help keep things more modular, you can catch and handle multiple errors in one except clause

try:
    # Do something
except (KeyError, TypeError), e:
    # Handle KeyError and TypeError the same way

This is helpful for when you want to handle multiple different error conditions the same way

BinaryBush · August 13, 2021, 1:14pm

So what I’ve done is removed all try/excepts from my writeBlocking calls and added a single try/except to the single call that handles all of the other calls in my project. I am excepting both errors listed above just like you have it:

except java.lang.Throwable, e:
    # handle gracefully
except java.util.concurrent.TimeoutException, e:
    # also handle gracefully

However, they are somehow STILL getting through to the gateway, not sure where to go from here.

Kevin.Herron · August 13, 2021, 1:16pm

writeBlockingImpl logs this exception and then returns error QualityCodes.

You guys are trying to catch something that is never thrown.

BinaryBush · August 13, 2021, 1:36pm

Thanks Kevin, do you have any suggestions on how I can diagnose this issue to find out exactly which tags are having write timeouts? It’s a parameterized UDT so it could be any PLC that I have that is causing this error.