Performance issues with Tag Change Script + DB Insert + Many Threads Waiting

Hi everyone,

I’m running into a performance problem that’s causing real-world impact on production, and I’d love to hear any advice or best practices from the community.

We have a Tag Change script that triggers when a PLC sends a flag. This script collects a lot of OPC tag values, formats them, and calls a stored procedure to insert the data into our database.

The thing is, if the response from Ignition to the PLC is delayed, the part gets rejected. Recently, as we added more machines, I’ve noticed the execution is slower — even though CPU and memory usage look fine. The Gateway status page does show a high number of threads in “Waiting” state, so I’m wondering if that’s normal or if it means we’re hitting some bottleneck.

We currently use a sleep(2) at the start of the script to give time for all tags to update before reading, otherwise some values come in wrong. But I suspect that with more concurrent executions, this delay is contributing to thread build-up.

Here’s the script for reference:

	from time import sleep

	if system.tag.read("[.]Status").value == 1 and system.tag.read("[.]Enable").value == True :
#	Delay to read all tags 
		sleep(2)

		
#Script para buscar el nombre de las variables "VAR", leer los valores y concatenarlos en un string 'rowData'
		Path=tagPath.split("/")
		system.tag.writeBlocking("[.]test", tagPath)

		searchTags=system.tag.browse('/'.join(Path[:2])+'/Var', {"tagType":"AtomicTag",'valueSource':'opc',"recursive":True,'name':'*Var*'}).results
		rowData=''
		paths=[]

		for x in searchTags:
			if x['value'].value != None:
				paths.append(str(x['fullPath']))
				
		data=[]
		

		for x in paths:
			read=system.tag.readBlocking(x)[0].value
			if not isinstance(read,unicode):
				data.append("%.2f" % system.tag.readBlocking(x)[0].value)
			
		
		rowData=';'.join(data)
		
	###################Verificar si el registro tiene fecha concatenada o por tags aparte
		if system.tag.readBlocking("[.]Year")[0].value > 0:

			Y=system.tag.readBlocking("[.]Year")[0].value
			M=system.tag.readBlocking("[.]Month")[0].value
			D=system.tag.readBlocking("[.]Day")[0].value
			h=system.tag.readBlocking("[.]Hour")[0].value
			m=system.tag.readBlocking("[.]Minute")[0].value
			s=system.tag.readBlocking("[.]Seconds")[0].value
		
		else :
			a=system.tag.readBlocking("[.]Date_Time")
			
			Y=''
			M=''
			D=''
			h=''
			m=''
			s=''
			count =0
			for x in a[0].value:
				if count >= 0 and count < 4:
					Y+=str(x)
				elif count > 4 and count < 6:
					M+=str(x)
				elif count > 6 and count < 8:
					D+=str(x)
				elif count > 8 and count < 10:
					h+=str(x)
				elif count > 10 and count < 12:
					m+=str(x)
				elif count > 12 and count < 14:
					s+=str(x)
				count+=1

# 	Lectura de las variables principales						
						
		VarName =int(system.tag.readBlocking("[.]VarName")[0].value)
		VarValue=float(system.tag.readBlocking( "[.]VarValue")[0].value)
		MfPlant =int(system.tag.readBlocking( "[.]MfPlant")[0].value)
		MfPlantD =int(system.tag.readBlocking( "[.]MfPlantD")[0].value)
		Tool =int(system.tag.readBlocking( "[.]Tool")[0].value)
		DMC =str(system.tag.readBlocking( "[.]DMC")[0].value)
		DMCPre =str(system.tag.readBlocking( "[.]DMCPre")[0].value)
		qcode =int(system.tag.readBlocking("[.]QCode")[0].value)
		rawData=str(rowData)
# Variable params que servira para concatenar en string todas las variables y publicarlas en el log		
		params = {
					
			'VarName' :VarName,
			'Date_dd' :str(D),
			'Date_mm' :str(M),
			'Date_yyyy' :str(Y),
			'Time_hh' :str(h),
			'Time_mm' :str(m),
			'Time_ss' :str(s),
			'VarValue' :VarValue,
			'MfPlant' :MfPlant,
			'MfPlantD' :MfPlantD,
			'Tool' :Tool,
			'DMC' :DMC,
			'DMCPre' :DMCPre,
			'qcode' :qcode,
			'rawData':str(rowData)
					
			}
		
								
#	Creacion y ejecucion del SP					
		query = """DECLARE    
				@return_value int,
		        @Result int
		EXEC    @return_value = [dbo].["""+str(tag['parameters']['NORIS SP'])+"""]
		        @VarName = ? ,
		        @Date_dd = ?,
		        @Date_mm = ?,
		        @Date_yyyy = ?,
		        @Time_hh = ?,
		        @Time_mm = ?,
		        @Time_ss = ?,
		        @VarValue = ?,
		        @MfPlant = ?,
		        @MfPlantD = ?,
		        @Tool = ?,
		        @DMC = ?,
		        @DMCPre = ?,
				@RawData = ?,
				@qcode = ?,
				@EmpNr=Null,
		        @Result = @Result OUTPUT
		SELECT    @Result as N'@Result'"""
		
		
		Result=system.db.runPrepQuery(query,[VarName,D,M,Y,h,m,s,VarValue,MfPlant,MfPlantD,Tool,DMC,DMCPre,rawData,qcode] ,'NORIS_GW_Local_CentralServer')
		
#Funcion para escribir en el Log de Ignition si el dato se inserto correctamente o con error
		
		keys=[]
		
		SP=tag['parameters']['NORIS SP']
		
		for x in params.keys():
			
			keys.append(x + ": "+ str(params[x]))
			
		texto = "\n".join(keys)
		
		year=str(system.tag.readBlocking("[.]Year")[0].value)
		month=str(system.tag.readBlocking("[.]Month")[0].value)
		day=str(system.tag.readBlocking("[.]Day")[0].value)
		hour=str(system.tag.readBlocking("[.]Hour")[0].value)
		minute=str(system.tag.readBlocking("[.]Minute")[0].value)
		second=str(system.tag.readBlocking("[.]Seconds")[0].value)
		
		date= day +'-'+month +'-'+year +' '+hour +':'+minute +':'+second+'execution Value: '+str(Result[0][0])
	
		
		if Result[0][0] == 30:	
			Message=SP +" Execute Succsesful " + date +"\n"+  "Values inserted:" + texto
			
			logger = system.util.getLogger("NORIS "+ SP)
			logger.info(Message)
		elif Result[0][0] == 30:	
			Message=SP +" Execute Failure bad date" + date 
			logger = system.util.getLogger("NORIS "+ SP)
			logger.info(Message)		
			
		else:
				Message=SP +" Execute Failure " + date +"\n"+  "Values inserted:" + texto
				
				logger = system.util.getLogger("NORIS "+ SP)
				logger.error(Message)
		status=str(system.tag.readBlocking("[.]Status")[0].quality)
		while status != 'Good':
			status=str(system.tag.readBlocking("[.]Status")[0].quality)
			sleep(1)
		system.tag.writeBlocking("[.]Status", Result[0][0])
				

Questions for the community:

  • Is having many threads in “Waiting” state normal for this kind of Tag Change load?
  • Could my sleep(2) be causing more harm than good with multiple machines triggering at once?
  • Any tips for re-structuring this so it’s more efficient, but still ensures all tags are updated before writing to the DB?
  • Would you handle the tag reads or the stored procedure differently?

Thanks in advance for any suggestion

You’re doing a lot of individual tag reads. Someone with better Python skills than myself will likely respond, but going to guess get rid of the “for tag in paths read loop” and do a single read of all the tags.

1 Like

When you say tag change script, are you talking about a Tag Value Change event or a Gateway Tag Change event? If the its the former you are blocking your ENTIRE tag system, there are so many blocking operations occuring in this script, apart from the sleep.

Second, as Robert mentioned, you need to remove all of your single tag read calls of readBlocking, this is definitely contributing to your script’s delay. Condense them as much as possible into single calls to read as many tags as possible

Don't, ever, use sleep in a tag change script.

If you need the values before they come from the PLC via normal means, use system.opc.readvalues()

Always do all for your tag reads and writes as a single request, pass the tag paths as a list and extract the tag values from the returned list.

There is a lot more, but that will get you started.

2 Likes

It is a Tag Change Value, it is a UDT and each machine that we register, has its own tags and its own scritp to store the info.

Absolutely wrong spot for this type of work. Anything touching DB or doing blocking work (such as sleeping) MUST be in a Gateway Tag Change event.

If this is defined on a UDT and used in multiple places, you are locking your entire tag system on your gateway. Tag value change events MUST execute in <10ms to prevent interference.

If this is the case, converting it to a gateway event shouldn’t be hard. Also, since each one is unique, defining the OPC paths to the relevant tags in the script shouldn’t be much of an issue.

4 Likes

Given that they are using only one result value from the result, it might be possible to call this entire script as async and keep running?

1 Like

It’s not just the loop(s) as mentioned by @robertm but you have blocks like this:

		VarName =int(system.tag.readBlocking("[.]VarName")[0].value)
		VarValue=float(system.tag.readBlocking( "[.]VarValue")[0].value)
		MfPlant =int(system.tag.readBlocking( "[.]MfPlant")[0].value)
		MfPlantD =int(system.tag.readBlocking( "[.]MfPlantD")[0].value)
		Tool =int(system.tag.readBlocking( "[.]Tool")[0].value)
		DMC =str(system.tag.readBlocking( "[.]DMC")[0].value)
		DMCPre =str(system.tag.readBlocking( "[.]DMCPre")[0].value)
		qcode =int(system.tag.readBlocking("[.]QCode")[0].value)

…that should be combined into a single read:

	tagVals = system.tag.readBlocking([
		"[.]VarName",
		"[.]VarValue",
		"[.]MfPlant",
		"[.]MfPlantD",
		"[.]Tool",
		"[.]DMC",
		"[.]DMCPre",
		"[.]QCode"])

	VarName = int(tagVals[0].value)
	VarValue = float(tagVals[1].value)
	MfPlant = int(tagVals[2].value)
	MfPlantD = int(tagVals[3].value)
	Tool = int(tagVals[4].value)
	DMC = str(tagVals[5].value)
	DMCPre = str(tagVals[6].value)
	qcode = int(tagVals[7].value)

…though if you have the tag types set properly, it could be even simpler:

VarName, VarValue, MfPlant, MfPlantD, Tool, DMC, DMCPre, qcode = system.tag.readBlocking([
		"[.]VarName",
		"[.]VarValue",
		"[.]MfPlant",
		"[.]MfPlantD",
		"[.]Tool",
		"[.]DMC",
		"[.]DMCPre",
		"[.]QCode"])

(So long as you then reference .value on each of the variables.)

3 Likes

I’d still rather it just be a gateway script, since its unique per UDT anyways. Gateway scripts are a bit more visible than an async thread fired off.

Depending on PLC structures, they might be able to make the script a bit more generic and load in sets of tag paths/opc paths dependent on the tag that triggered the run.

change this to

VarName, VarValue, MfPlant, MfPlantD, Tool, DMC, DMCPre, qcode = [qv.value for qv in system.tag.readBlocking([
    "[.]VarName",
    "[.]VarValue",
    "[.]MfPlant",
    "[.]MfPlantD",
    "[.]Tool",
    "[.]DMC",
    "[.]DMCPre",
    "[.]QCode"])]

and you don’t have to call .value

3 Likes

I am inclined to agree, I just keep hearing the excuse that "We want it all self contained in the UDT, no confusing lists to update to add a new device..."

If it were a generic script, then sure. But if they are already making the script unique per UDT, it kind of defeats the purpose. They already have to change lists of something in there. A lot more visible for it to be in one dedicated gateway script place than scattered about on tags.

My fast .02 since I don’t have a lot of time:

change to

	for x in searchTags:
		if x['value'].value != None:
			paths.append(str(x['fullPath']))

	data=[]
	for value in [qv.value for qv in system.readBlocking(paths)] :
		if not isinstance(value, unicode):
			data.append("%.2f" % value)

though I’m not a fan of the isinstance check.

Edit: good catch @Ryan_Deardorff

2 Likes

if not isinstance(value,unicode):

1 Like

Since this is in a UDT, sometimes Gateway Tag Change Sripts aren’t easily resused.

Consider this thread and the queue @pturmel has: Java concurrent queue for tag change scripts

Basically you still have the tag change script in the UDT. It would stash a tag path or such into the queue, and then you have a timer script running that drains the queue, doing something with the previous data you stashed.

1 Like

Also consider the Bulk Script Tag Actor in my Integration Toolkit.

My solution for that has been to make use of the fact that Gateway Tag Change scripts allow wildcards (*) in the tag paths. I have a delegation script that parses out the rest of the path and passes the tag data off to the appropriate library function.

3 Likes