Difference between tag change scripts and gateway message handler scripts?

I have an odd situation that I’m running into, and I’m not sure if my troubles are coming from how I’m calling some shared scripts.

I have some code that runs on a tag change script. It works fine, but it isn’t the prettiest… The tag itself is an expression tag inside a UDT that turns on if the ‘Force Refresh’ memory tag in the same UDT turns on. Right now, I’m just flipping the bit in the designer when I want to refresh the data from the controller. Here’s a copy of the code below:

#Reads will need the priority, string and data slicer configured in each tag script
if initialChange == False:
	if currentValue.value == True and previousValue.value == False:
		#gets port string for use in the script
		portQV = system.tag.read("[.]Port String")
		port = portQV.value
		#gets furnace name
		furnaceNameQV = system.tag.read("[.]../EquipmentName")
		furnaceName = furnaceNameQV.value
		startSegment = 1
		endSegment = 749
		breakpoint = startSegment
		x = 0
		#generate requests in chunks of 5 segments
		for num in range(startSegment, endSegment+1):
			if x == 3:
				#print str(num-x) + ' ' + str(num)
				#call readRecipeSegments function.  That function will do all of the unpacking of data
				shared.dimensionSerial.readRecipeSegments(port,furnaceName,num-x,num)
				breakpoint = num
				x = 0
			else:
				x=x+1
		if breakpoint != endSegment:
			#print str(breakpoint) + ' ' + str(endSegment)
			#this read catches any leftovers from the 10 segment chunking
			shared.dimensionSerial.readRecipeSegments(port,furnaceName,breakpoint,endSegment)
		#catches the special case of requesting only one segment
		if startSegment == endSegment:
			shared.dimensionSerial.readRecipeSegments(port,furnaceName,startSegment,endSegment)
		system.tag.write("[.]Force Refresh",False)
		

This code calls a script from the [shared] script library, which in turn calls other scripts in the same [shared] library to actually perform the reads on the serial line (custom protocol, PITA). Like I said, this is working code. The problem is that to read out all the segment data takes a while (a few minutes). So, I started working on a way for an operator to selectively refresh certain segments. I created a gateway message handler to listen for requests from the client. I have the following code inside:

	#retrieve values from the messageDetails
	port = payload['port']
	furnaceName = payload['furnaceName']
	startSegment = payload['startSegment']
	endSegment = payload['endSegment']
	print payload
	#code from original tag change script
	breakpoint = startSegment
	x = 0
	#generate requests in chunks of 5 segments
	for num in range(startSegment, endSegment+1):
		if x == 3:
			#print str(num-x) + ' ' + str(num)
			#call readRecipeSegments function.  That function will do all of the unpacking of data
			print 'calling the readRecipeSegments script'
			shared.dimensionSerial.readRecipeSegments(port,furnaceName,num-x,num)
			breakpoint = num
			x = 0
		else:
			x=x+1
	if breakpoint != endSegment:
		#print str(breakpoint) + ' ' + str(endSegment)
		#this read catches any leftovers from the 10 segment chunking
		shared.dimensionSerial.readRecipeSegments(port,furnaceName,breakpoint,endSegment)
	#catches the special case of requesting only one segment
	if startSegment == endSegment:
		shared.dimensionSerial.readRecipeSegments(port,furnaceName,startSegment,endSegment)

I’ve also verified that I’m passing identical port strings and other parameters to the [shared] script from both the tag change event script and from the gateway message handler script. However, when I try to use this message handler code, the gateway produces the following error log in the wrapper.log file (the first few lines are print statements for debugging):

INFO   | jvm 1    | 2019/01/12 16:43:51 | {'furnaceName': u'L3', 'startSegment': 1, 'endSegment': 4, 'port': u'/dev/ttyS3'}
INFO   | jvm 1    | 2019/01/12 16:43:51 | calling the readRecipeSegments script
INFO   | jvm 1    | 2019/01/12 16:43:51 | /dev/ttyS3 L3 1 4
INFO   | jvm 1    | 2019/01/12 16:43:54 | E [MessageHandlerRunnable        ] [22:43:53]: Error executing global message handler script: readDimIIRecipeSegments . Repeat errors of this type will be logged as 'debug' messages.
INFO   | jvm 1    | 2019/01/12 16:43:54 | com.inductiveautomation.ignition.common.script.JythonExecException: Traceback (most recent call last):
INFO   | jvm 1    | 2019/01/12 16:43:54 |   File "<MessageHandlerScript:Shop_Floor/readDimIIRecipeSegments >", line 26, in handleMessage
INFO   | jvm 1    | 2019/01/12 16:43:54 |   File "<module:shared.dimensionSerial>", line 324, in readRecipeSegments
INFO   | jvm 1    | 2019/01/12 16:43:54 |   File "<module:shared.dimensionSerial>", line 106, in readValues
INFO   | jvm 1    | 2019/01/12 16:43:54 |   File "<module:shared.dimensionSerial>", line 106, in readValues
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at com.inductiveautomation.ignition.modules.serial.scripting.SerialScriptModule.getAndLockSerialPort(SerialScriptModule.java:131)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at com.inductiveautomation.ignition.modules.serial.scripting.SerialScriptModule.writeBytes(SerialScriptModule.java:438)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at com.inductiveautomation.ignition.modules.serial.scripting.SerialScriptModule.write(SerialScriptModule.java:422)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at sun.reflect.GeneratedMethodAccessor561.invoke(Unknown Source)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at java.lang.reflect.Method.invoke(Method.java:498)
INFO   | jvm 1    | 2019/01/12 16:43:54 |
INFO   | jvm 1    | 2019/01/12 16:43:54 | java.io.IOException: java.io.IOException: Port /dev/ttyS3 has not been opened.
INFO   | jvm 1    | 2019/01/12 16:43:54 |
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at org.python.core.Py.JavaError(Py.java:495)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at org.python.core.Py.JavaError(Py.java:488)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at org.python.core.PyReflectedFunction.__call__(PyReflectedFunction.java:188)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at org.python.core.PyReflectedFunction.__call__(PyReflectedFunction.java:204)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at org.python.core.PyObject.__call__(PyObject.java:404)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at org.python.core.PyObject.__call__(PyObject.java:408)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at org.python.pycode._pyx206.readValues$3(<module:shared.dimensionSerial>:162)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at org.python.pycode._pyx206.call_function(<module:shared.dimensionSerial>)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at org.python.core.PyTableCode.call(PyTableCode.java:165)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at org.python.core.PyBaseCode.call(PyBaseCode.java:184)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at org.python.core.PyFunction.__call__(PyFunction.java:350)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at org.python.pycode._pyx206.readRecipeSegments$6(<module:shared.dimensionSerial>:394)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at org.python.pycode._pyx206.call_function(<module:shared.dimensionSerial>)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at org.python.core.PyTableCode.call(PyTableCode.java:165)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at org.python.core.PyBaseCode.call(PyBaseCode.java:184)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at org.python.core.PyFunction.__call__(PyFunction.java:350)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at org.python.pycode._pyx207.handleMessage$1(<MessageHandlerScript:Shop_Floor/readDimIIRecipeSegments >:37)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at org.python.pycode._pyx207.call_function(<MessageHandlerScript:Shop_Floor/readDimIIRecipeSegments >)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at org.python.core.PyTableCode.call(PyTableCode.java:165)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at org.python.core.PyBaseCode.call(PyBaseCode.java:301)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at org.python.core.PyFunction.function___call__(PyFunction.java:376)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at org.python.core.PyFunction.__call__(PyFunction.java:371)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at org.python.core.PyFunction.__call__(PyFunction.java:361)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at org.python.core.PyFunction.__call__(PyFunction.java:356)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at com.inductiveautomation.ignition.common.script.ScriptManager.runFunction(ScriptManager.java:647)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at com.inductiveautomation.ignition.common.script.message.MessageHandlerRunnable.run(MessageHandlerRunnable.java:106)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at java.util.concurrent.FutureTask.run(FutureTask.java:266)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at java.lang.Thread.run(Thread.java:748)
INFO   | jvm 1    | 2019/01/12 16:43:54 | Caused by: org.python.core.PyException: Traceback (most recent call last):
INFO   | jvm 1    | 2019/01/12 16:43:54 |   File "<MessageHandlerScript:Shop_Floor/readDimIIRecipeSegments >", line 26, in handleMessage
INFO   | jvm 1    | 2019/01/12 16:43:54 |   File "<module:shared.dimensionSerial>", line 324, in readRecipeSegments
INFO   | jvm 1    | 2019/01/12 16:43:54 |   File "<module:shared.dimensionSerial>", line 106, in readValues
INFO   | jvm 1    | 2019/01/12 16:43:54 |   File "<module:shared.dimensionSerial>", line 106, in readValues
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at com.inductiveautomation.ignition.modules.serial.scripting.SerialScriptModule.getAndLockSerialPort(SerialScriptModule.java:131)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at com.inductiveautomation.ignition.modules.serial.scripting.SerialScriptModule.writeBytes(SerialScriptModule.java:438)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at com.inductiveautomation.ignition.modules.serial.scripting.SerialScriptModule.write(SerialScriptModule.java:422)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at sun.reflect.GeneratedMethodAccessor561.invoke(Unknown Source)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at java.lang.reflect.Method.invoke(Method.java:498)
INFO   | jvm 1    | 2019/01/12 16:43:54 |
INFO   | jvm 1    | 2019/01/12 16:43:54 | java.io.IOException: java.io.IOException: Port /dev/ttyS3 has not been opened.
INFO   | jvm 1    | 2019/01/12 16:43:54 |
INFO   | jvm 1    | 2019/01/12 16:43:54 |       ... 33 common frames omitted
INFO   | jvm 1    | 2019/01/12 16:43:54 | Caused by: java.io.IOException: Port /dev/ttyS3 has not been opened.
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at com.inductiveautomation.ignition.modules.serial.scripting.SerialScriptModule.getAndLockSerialPort(SerialScriptModule.java:131)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at com.inductiveautomation.ignition.modules.serial.scripting.SerialScriptModule.writeBytes(SerialScriptModule.java:438)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at com.inductiveautomation.ignition.modules.serial.scripting.SerialScriptModule.write(SerialScriptModule.java:422)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at sun.reflect.GeneratedMethodAccessor561.invoke(Unknown Source)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at java.lang.reflect.Method.invoke(Method.java:498)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       at org.python.core.PyReflectedFunction.__call__(PyReflectedFunction.java:186)
INFO   | jvm 1    | 2019/01/12 16:43:54 |       ... 30 common frames omitted

I don’t really understand what I’m doing wrong here. Am I running into some sort of threading problem? Or is the code running under a different context? I’m guessing the interaction with the serial module is causing part of the problem, but I’m not sure what to try next.

I think you are begging for trouble trying to read from a serial port in either a tag event or a message handler. You might find this discussion helpful: