How to time duration of tag.readBlocking, and duration of DB.runUpdateQuery

Good morning All,
I have a new piece of equipment with a Windows 10 PC running an Ignition Gateway version 8.0.2. We’re using a single client, and both the Gateway and Client are running on that same PC. MySQL 8.0 is also loaded onto that PC.

Every few seconds we’re using a gateway event/tag change script to read about 1300 tags from the PLC and write them to our MySQL db. Because the PLC tags are in a somewhat complex UDT structure, these tag reads are done via 5 separate system.tag.readBlocking() instructions. They are formatted into a list of lists and then written to the db using ~100 calls of DB.runUpdateQuery.

I need to now time how long the script takes to:
1.) perform the combined 5 tag.readBlocking()s
2.) perform the combined ~100 db.runUpdateQuery()s

Does anyone have experience with this? Do you know a good way to time these operations? I saw in another thread that someone used wireshark for something similar, but I’m not sure if it would work for my circumstances.

You can try this

start = system.date.now()
**your code here**
end = system.date.now()
elapsed = system.date.millisBetween(start,end)
system.tag.write("executionTime",elapsed)

A lot of gateway operations are too fast to yield practical values in milliseconds. I recommend:

from java.lang import System

def someFunction(...):
    startts = System.nanoTime()
    # Some code
    endts = System.nanoTime()
    system.tag.write("executionNanos", endts-startts)

Include extra calls to nanoTime() to investigate different parts of your script.

2 Likes

Thanks guys. That worked great.
I ended up creating a Gateway memory dataset tag and writing those processing times to it for each DB update. Another script deletes rows in the dataset greater than 100 every few minutes. The dataset is displayed on a table using a simple binding.

I’ll try to remember to add the code tomorrow.
Thanks again!

Here is the code for timing those readBlockings and DB Inserts. The code is probably not very elegant, but it works. If you scroll to the bottom, you can see how I used the System.nanoTime() as recommended by PTurmel.

if not initialChange:
	if not newValue.value:
		from java.lang import System
		import time
		
		# writeSize is the total number of UDT array elements to proccess from
		# the list of 500 elements
		readSize = 499
		writeSize = readSize
		
		# contruct PLC tag read string patterns
		tagPathPattern = "[default]New Application Tags/Data/Data_%s_/"
		
		promPosPathsList = []
		promForcePathsList = []
		timePathsList = []
		tempPathsList = []
		forcePathsList = []
		tempTagPath = []
		forceTagPath = []
		queryList = []

		startTime = System.nanoTime()
		
		# read time values from PLC
		for i in range(0, readSize):
			basePath = tagPathPattern % i
			timeTagPath = basePath + "Time"
			timePathsList.append(timeTagPath)
		time = system.tag.readBlocking(timePathsList)
		
		# get current datetime from system clock
		now = system.date.now()
		year = system.date.getYear(now)
		month = system.date.getMonth(now)
		day = system.date.getDayOfMonth(now)		
		today = system.date.getDate(year, month, day)
		
		timeList=[]; rawTime=[]
		for i in range(0, readSize):
			# extract individual components from time value
			if time[i].value != 0:
				timeValSplit = str(time[i].value).split('.')
				secondsVal = timeValSplit[0]
				millisecondsVal = timeValSplit[1][:3]
				
				# converts time obtained from UDT array elements (in seconds and 
				# milliseconds since midnight of today) to a mySQL compatable
				# datetime format
				tempDate1 = system.date.addSeconds(today, int(secondsVal))
				tempDate2 = system.date.addMillis(tempDate1, int(millisecondsVal))
				finalDate = system.date.format(tempDate2, "yyyy-MM-dd HH:mm:ss.SSS")
				finalDateStr = "\"" + str(finalDate) + "\""
				timeList.append(finalDateStr)
			else: #Find Length of populated array in order to not write blank rows to DB
				writeSize = i
				break
				
		# read promess position values from PLC
		for i in range(0, writeSize):	
			basePath = tagPathPattern % i
			promPosTagPath = basePath + "PromessPosition"
			promPosPathsList.append(promPosTagPath)
		promPos = system.tag.readBlocking(promPosPathsList)
		promPosList = []
		for i in promPos:
			promPosList.append(i.value)
					
		# read promess force values from PLC
		for i in range(0, writeSize):	
			basePath = tagPathPattern % i
			promForceTagPath = basePath + "PromessForce"
			promForcePathsList.append(promForceTagPath)
		promForce = system.tag.readBlocking(promForcePathsList)
		promForceList = []
		for i in promForce:
			promForceList.append(i.value)	
					
		# Prepare to read temp and force values from PLC	
		for i in range(0, writeSize):	
			basePath = tagPathPattern % i
			for j in range(0, 5):
				tempTagPath = basePath + "Temperature/Temperature_%s_" % j
				tempPathsList.append(tempTagPath)
				forceTagPath = basePath + "Force/Force_%s_" % j		
				forcePathsList.append(forceTagPath)
				
		# read temp values from PLC
		temp = system.tag.readBlocking(tempPathsList)
		tempList = []
		for i in temp:
			tempList.append(i.value)
				
		# read force values from PLC
		force = system.tag.readBlocking(forcePathsList)
		forceList = []
		for i in force:
			forceList.append(i.value)		
		
		time10 = System.nanoTime()
		
		# contruct database query string patterns
		sqlString1 = "INSERT INTO data"
		sqlString2 = " VALUES ( %s, %s, %s, %s, %s, %s, %s, %s, %s, %s, %s, %s, %s )"	
		for i in range(0, writeSize):
			j = (i*5)
			tempStr = sqlString2 % (timeList[i], promPosList[i], promForceList[i],tempList[j],tempList[j+1],tempList[j+2],tempList[j+3],tempList[j+4],forceList[j],forceList[j+1],forceList[j+2],forceList[j+3],forceList[j+4])
			finalQuery = sqlString1 + tempStr
			queryList.append(finalQuery)
		
		time20 = System.nanoTime()
			
			# perform all database inserts
		for elem in queryList:
			system.db.runUpdateQuery(elem, "MySQL_Conn")
		
		time30 = System.nanoTime()
		
		#time calculations-load list
		localTime = system.date.now()
		readTime = (time10-startTime)/1000000.0
		dbInsertTime = (time30-time20)/1000000.0
		myTimeList = [localTime,readTime,dbInsertTime]

		#Write to Dataset
		dataset = system.tag.read("[default]New Application Tags/Durations")
		newDataset = system.dataset.addRow(dataset.value,0,myTimeList)
		system.tag.write("[default]New Application Tags/Durations",newDataset)