DataChannelServlet Error

Multiple times each day, my system throws a DataChannelServlet error that is immediately followed by a disconnect & reconnect of every Vision client - 35 clients in total. This error appears in the log of my primary front end Vision server.

The message states:
"local='ignition-ignvisgw-master' method=doGet: No pending message was found with id '0'. Request was made from ignition-igntaggw-master"

The log properties are coming from:
gan-remote-connection-id ignition-igntaggw-master

Hovering over the DataChannelServlet error displays the following, "metro.Transports.Websocket.Servlet.DataChannelServlet"

When this occurs, the disconnect & reconnect is fairly quick. Any open screen's objects will simply turn red and then clear again. On the client side, the warning message that is logged is as follows:

Message: Connection to Gateway lost, due to exception.
Time: Thu Apr 4 10:48:48AM
Severity: WARN
Logger: com.inductiveautomation.ignition.client.gateway_interface.GatewayConnectionManager
Stack Trace: com.inductiveautomation.ignition.client.gateway_interface.GatewayException: Read timed out
    at com.inductiveautomation.ignition.client.gateway_interface.GatewayInterface.newGatewayException(GatewayInterface.java:360)
    at com.inductiveautomation.ignition.client.gateway_interface.GatewayInterface.getResponse(GatewayInterface.java:556)
    at com.inductiveautomation.ignition.client.gateway_interface.GatewayInterface.sendMessage(GatewayInterface.java:292)
    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.tags.impl.GatewayTagInterface$GatewayProviderProxy.lambda$readAsync$0(GatewayTagInterface.java:340)
    at java.base/java.util.concurrent.CompletableFuture$AsyncRun.run(Unknown Source)
    at java.base/java.util.concurrent.CompletableFuture$AsyncRun.exec(Unknown Source)
    at java.base/java.util.concurrent.ForkJoinTask.doExec(Unknown Source)
    at java.base/java.util.concurrent.ForkJoinPool$WorkQueue.topLevelExec(Unknown Source)
    at java.base/java.util.concurrent.ForkJoinPool.scan(Unknown Source)
    at java.base/java.util.concurrent.ForkJoinPool.runWorker(Unknown Source)
    at java.base/java.util.concurrent.ForkJoinWorkerThread.run(Unknown Source)
Caused by: java.net.SocketTimeoutException: Read timed out
    at java.base/sun.nio.ch.NioSocketImpl.timedRead(Unknown Source)
    at java.base/sun.nio.ch.NioSocketImpl.implRead(Unknown Source)
    at java.base/sun.nio.ch.NioSocketImpl.read(Unknown Source)
    at java.base/sun.nio.ch.NioSocketImpl$1.read(Unknown Source)
    at java.base/java.net.Socket$SocketInputStream.read(Unknown Source)
    at java.base/java.io.BufferedInputStream.fill(Unknown Source)
    at java.base/java.io.BufferedInputStream.read1(Unknown Source)
    at java.base/java.io.BufferedInputStream.read(Unknown Source)
    at java.base/sun.net.www.http.HttpClient.parseHTTPHeader(Unknown Source)
    at java.base/sun.net.www.http.HttpClient.parseHTTP(Unknown Source)
    at java.base/sun.net.www.protocol.http.HttpURLConnection.getInputStream0(Unknown Source)
    at java.base/sun.net.www.protocol.http.HttpURLConnection.getInputStream(Unknown Source)
    at java.base/java.net.HttpURLConnection.getResponseCode(Unknown Source)
    at com.inductiveautomation.ignition.client.gateway_interface.GatewayInterface.getResponse(GatewayInterface.java:450)
    ... 11 common frames omitted

This issue appears at random, sometimes only 5 minutes apart, but it's occurring about 15-20x each day. I've logged traffic on our network through various switches, but I am not seeing anything out of the ordinary when this issue appears in Ignition.

Any insight is appreciated!

Another item I should have mentioned...

Oddly, I do not log any messages on my back end tag gateway (ignition-igntaggw-master) when this issue occurs. Only the front end vision gateway (ignition-ignvisgw-master) throws a log message.

Wow, that's ugly. I would not expect a GAN error to kill your Vision connections. You should definitely report this to IA support. The errors in the Vision clients are side effects of the gateway breakage--I don't think those traces are relevant (just the normally tag poll failing).

Thanks for the response, Phil. I'll get in contact with IA support.

I read it differently - I think something else is hiccuping all network comms on this frontend gateway, so both GAN and Vision are showing symptoms of that one root cause.

I honestly can't fathom a path for a GAN interruption to affect Vision clients.

Oooo! Good point.

Checking my GAN on both front end and back end gateways, I have <4ms ping times between everything. Also, I don't have any connection events listed for any of the gateways' "details" when viewing them in the GAN. I was hoping I'd see a connection event corresponding with the diagnostic log messages .

I opened an IA support ticket and will work through that channel for a resolution. I'll try to post back here with information regarding cause and resolution once they're known.

2 Likes

After working with IA for a very long period, supplying log files, many discussions, I am told that this issue is was a bug that is fixed in 8.1.41. I haven't had the chance to fully test 8.1.41 to verify.

1 Like

What version were you experiencing this on Travis_Graham?

I think I'm showing this on 8.1.35 possibly. [pturmel]

Any insight if that bug affects this version?

I was on 8.1.32 at the time. I'm now on 8.1.43 and issue is resolved.

I'd guess .35 is affected, since the fix wasn't completed until .41.

1 Like