Mongodb gateway calls throw unhandled exceptions

I'm trying to build a functional interface to a basic mongodb database, and boy is it not falling into place easily. I have already given up on building a general gateway script executor so I can call normal mongodb methods from within project scripts (since all the mongo call have to be done at the gateway level), and now I am just building mapped methods to pass through to the gateway.

I have a project script that looks like this:

def find(db, col, filt, projection=None, sort=None, collation=None, limit=10, skip=0):
	payload = {"db": db, "collection": col, "filter": filt, "projection": projection, "sort": sort, "collation": collation, "limit": limit, "skip": skip}
	print("find", payload)
	return system.util.sendRequest("myProject", "mongo_find", payload=payload)	

with a gateway script ("mongo_find"):

def handleMessage(payload):
	db = payload.get("db", "mongodb")
	col = payload.get("collection", "test")
	filt = payload.get("filter", {})
	proj = payload.get("projection", {})
	sort = payload.get("sort", {})
	colla = payload.get("collation", {})
	limit = payload.get("limit", 10)
	skip = payload.get("skip", 0)
	return system.mongodb.find(db, col, filt, projection=proj, sort=sort, collation=colla, limit=limit, skip=skip)

The idea is that my project can just use my MyMongo.find() call and not worry about sending / formatting the gateway message.

However, it is terribly unstable. The only reason I am still trying to make this work is that I had it working briefly in some half-baked script capacity, but as it is above, I am constantly met with this error when I invoke the following in the script console (and I can't even tell if it is my code or if there is something gummed up in the Gateway itself):

MyMongo.find("mongodb", "test", {"testing": True})

16:51:02.491 [GatewayConnection-1] WARN com.inductiveautomation.ignition.client.gateway_interface.GatewayConnectionManager - Listener [com.inductiveautomation.ignition.client.util.gui.progress.ClientProgressManager$1@359d5753] threw uncaught error on push notification.
java.lang.NullPointerException: null
	at com.inductiveautomation.ignition.client.util.gui.progress.ClientProgressManager.updateTask(ClientProgressManager.java:228)
	at com.inductiveautomation.ignition.client.util.gui.progress.ClientProgressManager$1.receive(ClientProgressManager.java:114)
	at com.inductiveautomation.ignition.client.gateway_interface.FilteredPushNotificationListener.receiveNotification(FilteredPushNotificationListener.java:43)
	at com.inductiveautomation.ignition.client.gateway_interface.AbstractGatewayConnection.firePushNotification(AbstractGatewayConnection.java:1686)
	at com.inductiveautomation.ignition.client.gateway_interface.AbstractGatewayConnection.lambda$receiveNotification$1(AbstractGatewayConnection.java:1453)
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)
	at java.base/java.util.concurrent.FutureTask.run(Unknown Source)
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
	at java.base/java.lang.Thread.run(Unknown Source)
16:52:02.443 [SwingWorker-pool-1-thread-7] ERROR designer.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 '0d67e022-b61f-4332-91f3-1fb6bc6e4f22'
	at com.inductiveautomation.ignition.client.gateway_interface.GatewayInterface.newGatewayException(GatewayInterface.java:360)
	at com.inductiveautomation.ignition.client.gateway_interface.GatewayInterface.sendMessage(GatewayInterface.java:330)
	at com.inductiveautomation.ignition.client.gateway_interface.GatewayInterface.sendMessage(GatewayInterface.java:287)
	at com.inductiveautomation.ignition.client.gateway_interface.GatewayInterface.invoke(GatewayInterface.java:967)
	at com.inductiveautomation.ignition.client.script.DesignerSystemUtilities$SendRequestManager.invokeRequest(DesignerSystemUtilities.java:388)
	at com.inductiveautomation.ignition.client.script.DesignerSystemUtilities.sendRequestInternal(DesignerSystemUtilities.java:217)
	at com.inductiveautomation.ignition.common.script.builtin.SystemUtilities.sendRequestInternal(SystemUtilities.java:910)
	at com.inductiveautomation.ignition.common.script.builtin.SystemUtilities.sendRequest(SystemUtilities.java:831)
	at jdk.internal.reflect.GeneratedMethodAccessor86.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:552)
	at org.python.core.PyObject.__call__(PyObject.java:400)
	at org.python.pycode._pyx1527.find$1(<module:Mongo>:8)
	at org.python.pycode._pyx1527.call_function(<module:Mongo>)
	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:158)
	at org.python.core.PyFunction.__call__(PyFunction.java:437)
	at org.python.pycode._pyx1526.f$0(<input>:1)
	at org.python.pycode._pyx1526.call_function(<input>)
	at org.python.core.PyTableCode.call(PyTableCode.java:173)
	at org.python.core.PyCode.call(PyCode.java:18)
	at org.python.core.Py.runCode(Py.java:1687)
	at org.python.core.Py.exec(Py.java:1731)
	at org.python.util.PythonInterpreter.exec(PythonInterpreter.java:277)
	at org.python.util.InteractiveInterpreter.runcode(InteractiveInterpreter.java:130)
	at com.inductiveautomation.ignition.designer.gui.tools.jythonconsole.JythonConsole$ConsoleWorker.doInBackground(JythonConsole.java:626)
	at com.inductiveautomation.ignition.designer.gui.tools.jythonconsole.JythonConsole$ConsoleWorker.doInBackground(JythonConsole.java:614)
	at java.desktop/javax.swing.SwingWorker$1.call(Unknown Source)
	at java.base/java.util.concurrent.FutureTask.run(Unknown Source)
	at java.desktop/javax.swing.SwingWorker.run(Unknown Source)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
	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 '0d67e022-b61f-4332-91f3-1fb6bc6e4f22'
	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:314)
	... 34 common frames omitted

I am sure there is a matching entry in the db (not that this should be erroring if there wasn't):

Honestly I am about | | this far away from giving up on the Ignition MongoDB driver entirely, I am certainly not excited about adding it to my license, and I may as well just send JSON objects to a separate server to then have it run as a mongo intermediary. Setting up that entire system and deploying it in parallel may be easier than trying to figure out where this is going wrong, unless someone has a really obvious tip for me to accept with great embarassment.

The way that this is all laid out is exceptionally annoying to debug.

system.util.sendRequest has a timeoutSec optional parameter:
https://docs.inductiveautomation.com/display/DOC81/system.util.sendRequest

If it's truly taking >60s though, then I would check the gateway logs to see if there are any errors from the module being logged there.

The error that spawns when I try to run this is as follows;

java.io.NotSerializableException: org.bson.BsonTimestamp

at java.base/java.io.ObjectOutputStream.writeObject0(Unknown Source)

at java.base/java.io.ObjectOutputStream.defaultWriteFields(Unknown Source)

at java.base/java.io.ObjectOutputStream.writeSerialData(Unknown Source)

at java.base/java.io.ObjectOutputStream.writeOrdinaryObject(Unknown Source)

at java.base/java.io.ObjectOutputStream.writeObject0(Unknown Source)

at java.base/java.io.ObjectOutputStream.writeObject(Unknown Source)

at java.base/java.util.concurrent.ConcurrentHashMap.writeObject(Unknown Source)

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 java.base/java.io.ObjectStreamClass.invokeWriteObject(Unknown Source)

at java.base/java.io.ObjectOutputStream.writeSerialData(Unknown Source)

at java.base/java.io.ObjectOutputStream.writeOrdinaryObject(Unknown Source)

at java.base/java.io.ObjectOutputStream.writeObject0(Unknown Source)

at java.base/java.io.ObjectOutputStream.defaultWriteFields(Unknown Source)

at java.base/java.io.ObjectOutputStream.writeSerialData(Unknown Source)

at java.base/java.io.ObjectOutputStream.writeOrdinaryObject(Unknown Source)

at java.base/java.io.ObjectOutputStream.writeObject0(Unknown Source)

at java.base/java.io.ObjectOutputStream.writeObject(Unknown Source)

at java.base/java.util.ArrayList.writeObject(Unknown Source)

at java.base/jdk.internal.reflect.GeneratedMethodAccessor142.invoke(Unknown Source)

at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)

at java.base/java.lang.reflect.Method.invoke(Unknown Source)

at java.base/java.io.ObjectStreamClass.invokeWriteObject(Unknown Source)

at java.base/java.io.ObjectOutputStream.writeSerialData(Unknown Source)

at java.base/java.io.ObjectOutputStream.writeOrdinaryObject(Unknown Source)

at java.base/java.io.ObjectOutputStream.writeObject0(Unknown Source)

at java.base/java.io.ObjectOutputStream.defaultWriteFields(Unknown Source)

at java.base/java.io.ObjectOutputStream.writeSerialData(Unknown Source)

at java.base/java.io.ObjectOutputStream.writeOrdinaryObject(Unknown Source)

at java.base/java.io.ObjectOutputStream.writeObject0(Unknown Source)

at java.base/java.io.ObjectOutputStream.writeObject(Unknown Source)

at com.inductiveautomation.ignition.common.Base64.encodeObject(Base64.java:496)

at com.inductiveautomation.ignition.gateway.servlets.GWSession.writeNotifications(GWSession.java:215)

at com.inductiveautomation.ignition.gateway.servlets.Gateway.doPost(Gateway.java:541)

at javax.servlet.http.HttpServlet.service(HttpServlet.java:523)

at javax.servlet.http.HttpServlet.service(HttpServlet.java:590)

at com.inductiveautomation.ignition.gateway.bootstrap.MapServlet.service(MapServlet.java:86)

at org.eclipse.jetty.servlet.ServletHolder$NotAsync.service(ServletHolder.java:1410)

at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:764)

at org.eclipse.jetty.servlet.ServletHandler$ChainEnd.doFilter(ServletHandler.java:1665)

at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:527)

at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:131)

at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:578)

at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:122)

at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:223)

at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1570)

at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:221)

at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1384)

at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:176)

at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:484)

at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1543)

at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:174)

at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1306)

at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:129)

at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:122)

at com.inductiveautomation.catapult.handlers.RemoteHostNameLookupHandler.handle(RemoteHostNameLookupHandler.java:121)

at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:122)

at org.eclipse.jetty.rewrite.handler.RewriteHandler.handle(RewriteHandler.java:301)

at org.eclipse.jetty.server.handler.HandlerList.handle(HandlerList.java:51)

at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:141)

at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:122)

at org.eclipse.jetty.server.Server.handle(Server.java:563)

at org.eclipse.jetty.server.HttpChannel.lambda$handle$0(HttpChannel.java:505)

at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:762)

at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:497)

at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:282)

at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:314)

at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:100)

at org.eclipse.jetty.io.SelectableChannelEndPoint$1.run(SelectableChannelEndPoint.java:53)

at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.runTask(AdaptiveExecutionStrategy.java:416)

at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.consumeTask(AdaptiveExecutionStrategy.java:385)

at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.tryProduce(AdaptiveExecutionStrategy.java:272)

at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.lambda$new$0(AdaptiveExecutionStrategy.java:140)

at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:411)

at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:969)

at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.doRunJob(QueuedThreadPool.java:1194)

at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1149)

at java.base/java.lang.Thread.run(Unknown Source)

I can confirm that if I run this command, it functions correctly:

Mongo.find("mongodb", "test", {"testing": 4})

but if I run either of these commands, it sticks until the timeout (and produces the aforementioned log error):

Mongo.find("mongodb", "test", {"testing": {"$exists": True}})
Mongo.find("mongodb", "test", {"testing": True})

I have both of these entries in my mongo collection:

I currently suspect there is something wrong with the drivers ability to serialize the python "True" that is "true" in mongo.

This is the issue. The query result must contain one of these types, but these types don't exist in the Vision Client scope. You can't return them from a handler.

I'll ping someone to find out if the entire result is supposed to be recursively converted to neutral/common types or not.

1 Like

So, for clarity, is there something I can do on my end to make this work?

At the moment... it looks like avoid returning a timestamp in the result, or don't try to send the result over a message handler to the client.

Or do extra handling (on the gateway) to convert from the mongo timestamp format into a plain Python type.

I see, it was the fact that my test entry has a timestamp rather than the True that was a problem.

For what it's worth I made that timestamp using the example from the IA documentation for the system.mongodb.insertOne() method, I just slightly changed the key.

I can confirm that this is also unserializable in python 3.10 if you try to bytes encode the bson.ObjectId type. It has to be string converted.