Error on system.util.sendRequest. No response ever received

[jeffrey.minton]

I am getting an error when trying to make a system.util.sendRequest call to a message handler on my gateway.

the sendRequest call is in a custom method called refreshData defined on a power table. The relevant parts of the function are bellow

def refreshData(self):

    ...

    resultData = None
	
	print 'Make Request'
	try:
		resultData = system.util.sendRequest('SPC_Config', 'GetSampleDataReportData', payload) #, timeoutSec = 600)
	except:
		print 'Request Failure'
	
	print 'Request Done'

    ...

I am calling this function using an invokeAsynchronous call. See an example of the call bellow

system.util.invokeAsynchronous(event.source.parent.parent.getComponent('Sample Data Table').refreshData)

The message handler on the gateway calls a function in a script file that queries the database and does some tranforms on the data. It is returning a python dict containing pyDataSets. Bellow is the relevant code from the script.

def getReportData():
	
	chartData = system.db.runPrepQuery(chartQuery, parameterList, "db_name")

	tableData = system.db.runPrepQuery(tableQuery, parameterList, "db_name")

	returnData = {
		'chartData': chartData,
		'tableData': tableData
	}

	return returnData

The code in the gateway message handler that calls the function above and returns the results is bellow

reportData = project.sampleDataReport.getReportData()

return reportData

I can see when viewing log data from my scripts and the debug/trace messages from the MassageHandlerRunnable log that everything is working correctly on the gateway. Bellow are relevant log entries for MessageHandlerRunnable. You can see where it gets the results from the getReportData function which are exopected to be empty. It then converts the data to a java object and appears to attempt to send back the result.

|MessageHandlerRunnable|11Oct2021 11:36:36|Send message to Result Handler with: {'tableData': [ ], 'chartData': [ ]}|
|MessageHandlerRunnable|11Oct2021 11:36:36|Converting python result to java object|
|MessageHandlerRunnable|11Oct2021 11:36:36|Python function ran. Result: {'tableData': [ ], 'chartData': [ ]}|
|MessageHandlerRunnable|11Oct2021 11:36:34|Valid runnable Python function found|

However on the client nothing seems to be returned. The client waits for some time and eventually an exception is thrown. The exception is bellow. It appears to show that the call failed and no result was ever reveived.

11:37:34.287 [Thread-73] ERROR client.scripting.SystemUtilities - Error invoking sendRequest from client.
com.inductiveautomation.ignition.client.gateway_interface.GatewayException: Results for asynchronous rpc call were not received within the specified amount of time [60000 ms] for task '355707ef-d109-4a0f-bd88-42d7ed64aa01'
at com.inductiveautomation.ignition.client.gateway_interface.GatewayInterface.newGatewayException(GatewayInterface.java:351)
at com.inductiveautomation.ignition.client.gateway_interface.GatewayInterface.sendMessage(GatewayInterface.java:321)
at com.inductiveautomation.ignition.client.gateway_interface.GatewayInterface.sendMessage(GatewayInterface.java:278)
at com.inductiveautomation.ignition.client.gateway_interface.GatewayInterface.invoke(GatewayInterface.java:945)
at com.inductiveautomation.ignition.client.script.DesignerSystemUtilities$SendRequestManager.invokeRequest(DesignerSystemUtilities.java:339)
at com.inductiveautomation.ignition.client.script.DesignerSystemUtilities.sendRequestInternal(DesignerSystemUtilities.java:215)
at com.inductiveautomation.ignition.common.script.builtin.SystemUtilities.sendRequestInternal(SystemUtilities.java:931)
at com.inductiveautomation.ignition.common.script.builtin.SystemUtilities.sendRequest(SystemUtilities.java:852)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.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:188)
at com.inductiveautomation.ignition.common.script.ScriptManager$ReflectedInstanceFunction.call(ScriptManager.java:539)
at org.python.core.PyObject.call(PyObject.java:515)
at org.python.core.PyObject.call(PyObject.java:519)
at org.python.pycode.pyx86.refreshData$1(:96)
at org.python.pycode.pyx86.call_function()
at org.python.core.PyTableCode.call(PyTableCode.java:171)
at org.python.core.PyBaseCode.call(PyBaseCode.java:308)
at org.python.core.PyBaseCode.call(PyBaseCode.java:199)
at org.python.core.PyFunction.call(PyFunction.java:482)
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:223)
at com.inductiveautomation.ignition.common.script.ScriptManager.runFunction(ScriptManager.java:842)
at com.inductiveautomation.ignition.client.script.DesignerSystemUtilities.lambda$_invokeAsyncImpl$1(DesignerSystemUtilities.java:138)
at java.base/java.lang.Thread.run(Unknown Source)
Caused by: java.util.concurrent.TimeoutException: Results for asynchronous rpc call were not received within the specified amount of time [60000 ms] for task '355707ef-d109-4a0f-bd88-42d7ed64aa01'
at com.inductiveautomation.ignition.client.util.gui.progress.ClientProgressManager$RunningTask.waitForResult(ClientProgressManager.java:453)
at com.inductiveautomation.ignition.client.gateway_interface.GatewayInterface.sendMessage(GatewayInterface.java:305)
... 26 common frames omitted

I am wondering if anyone else has seen things like this. Also I see nothing in the docs but are there limitations as to what data can be returned to sendRequest calls?

[pturmel]

I would not expect this to work. You can't safely use components' properties or methods in background threads. ("Use" == read or write.) That you are losing something is the least bad thing that can happen (up to and including complete client lockup). Also, print is not likely to work in a background thread (though it sometimes does). Use a logger instead.

Review this topic, then report back if you still have problems while following Swing's rules:

Update GUI via Asynchronous thread

Since this sort of thing pops up often, I created a set of wrappers that simplify this stuff, and allows you to directly use functions in your script modules. The wrappers take care of stuffing the arguments you supply into a temporary fuction’s default argument. For your case, try assignLater(). Nick’s example becomes: # In a script module in your project: import shutil def fileTransfer(label): path = system.file.openFile() newPath = "F:\NewFolder" shutil.copy2(path, newPath) sh…

[jeffrey.minton]

Thanks for the info. I changed the call to the component method so that I am no longer doing background processing. I am just calling the bellow function directly.

event.source.parent.parent.getComponent(‘Sample Data Table’).refreshData()

The problem is still happening. I see in exception that it is still referring to “asynchronous rpc call.” As far as I know I have not explicit async calls in the process anymore. Is the sendRequest function intrinsically async and causing the issue still?

[pturmel]

Yes. Running queries and reading/writing tags with scripting also involve gateway round trips. You probably need a background thread, but you need to use invokeLater to pass the results back into the UI.

[jeffrey.minton]

So I think this issue is unrelated to running the sendRequest in any gui thread. It fails the same way when just simply calling the sendRequest method from the script console.

[bkarabinchak.psi]

I would expect as much because your error is - Results for asynchronous rpc call were not received within the specified amount of time [60000 ms], no matter what context you are calling it from your gateay script is taking too long to return a result.

You can change that by doing system.util.sendRequest(..., timeoutSec=120) to lengthen the timeout time to 120 seconds (or whatever you want it to be), or you can try optimizing your gateway script, but right here is the cause.

chartData = system.db.runPrepQuery(chartQuery, parameterList, "db_name")

tableData = system.db.runPrepQuery(tableQuery, parameterList, "db_name")

How fast do these queries run in a vacuum? If its taking over 60 seconds to get a response and these two queries are all you are doing, I suspect you could probably optimize your tables a bit via indexing or other means.

[jeffrey.minton]

That is the thing. It doesn’t appear to be due to any delay in the server side queries. I have logging on the gateway script. The function is returning the data in < 2 seconds

[bkarabinchak.psi]

In your getReportData(): do you do any custom logging so that you can verify it’s actually running? Something is going on. Do you see any issues in your logs? Perhaps a typo in the message handler name.

[jeffrey.minton]

Yes I do. Here are the log messages. I expect the datasets to be empty so that is not an issue.

I sorted them first to last in time order. The returnData message is right before the return statement in the function.

Logger	        Time	            Message
getReportData	09Nov2021 10:34:51	parameterList: [False, 'BK1 Lining', 'All Tests', 'All Work Orders', 'All Case Numbers', 'All Batch Numbers', 'All Shifts', 'All Drawing Numbers', '20211005', '20211012']
getReportData	09Nov2021 10:34:51	Chart Results: <PyDataset rows:0 cols:6>
getReportData	09Nov2021 10:34:51	Chart X Value:
getReportData	09Nov2021 10:34:51	No data in chart
getReportData	09Nov2021 10:34:51	selectedPlotSampleTakenDatetime:
getReportData	09Nov2021 10:34:51	[False, 'BK1 Lining', 'All Tests', 'All Work Orders', 'All Case Numbers', 'All Batch Numbers', 'All Shifts', 'All Drawing Numbers', '20211005', '20211012', '']
getReportData	09Nov2021 10:34:52	Table Results<PyDataset rows:0 cols:22>
getReportData	09Nov2021 10:34:52	chartData: <PyDataset rows:0 cols:6>
getReportData	09Nov2021 10:34:52	tableData: <PyDataset rows:0 cols:22>
getReportData	09Nov2021 10:34:52	returnData: {'tableData': [], 'chartData': []}```

[bkarabinchak.psi]

Your best bet might be to call IA at this point then. Seems like it is trying to return it but your client is just not getting it for some reason that the logs are not showing.

[jeffrey.minton]

Thanks. That’s what I’ll do