We have an installation using an ODATA server on SQL Anywhere Network Server Version 17.0.11.6933.

The installation work fine up to a certain request rate, after which the response time deteriorates rapidly. We are now trying to find the bottleneck.

The only things we found which explicitly states an error are the diagnostics files which are created when we are near or over the critical request rate. They are all more or less identically like the example cited below.

It sounds like some java job is complaining that its partner has closed the connection. Is there any way to find out who is complaining, is it the database server itself, the ODATA producer or something else? And, maybe, some hint about the partner who closed the channel.

Content of the diagnostics file:

javax.xml.stream.XMLStreamException: org.eclipse.jetty.io.EofException
at com.sun.xml.internal.stream.writers.XMLStreamWriterImpl.flush(XMLStreamWriterImpl.java:399)
at com.sybase.odata.producer.odata.MetadataDocWriter.writeMetadataDoc(MetadataDocWriter.java:159)
at com.sybase.odata.producer.handler.GetHandler.handleRequestImpl(GetHandler.java:191)
at com.sybase.odata.producer.handler.AbstractHandler.handleRequest(AbstractHandler.java:1076)
at com.sybase.odata.producer.servlets.ODataServlet.doGet(ODataServlet.java:466)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:618)
at com.sybase.odata.producer.servlets.ODataServlet.service(ODataServlet.java:487)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:725)
at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:799)
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:550)
at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1435)
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:501)
at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1350)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:234)
at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:146)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
at org.eclipse.jetty.server.Server.handle(Server.java:516)
at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:388)
at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:633)
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:380)
at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:277)
at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105)
at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:313)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:129)
at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:383)
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:882)
at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1036)
at java.lang.Thread.run(Thread.java:836)
Caused by: org.eclipse.jetty.io.EofException
at org.eclipse.jetty.io.ChannelEndPoint.flush(ChannelEndPoint.java:279)
at org.eclipse.jetty.io.WriteFlusher.flush(WriteFlusher.java:422)
at org.eclipse.jetty.io.WriteFlusher.write(WriteFlusher.java:277)
at org.eclipse.jetty.io.AbstractEndPoint.write(AbstractEndPoint.java:381)
at org.eclipse.jetty.server.HttpConnection$SendCallback.process(HttpConnection.java:820)
at org.eclipse.jetty.util.IteratingCallback.processing(IteratingCallback.java:241)
at org.eclipse.jetty.util.IteratingCallback.iterate(IteratingCallback.java:223)
at org.eclipse.jetty.server.HttpConnection.send(HttpConnection.java:550)
at org.eclipse.jetty.server.HttpChannel.sendResponse(HttpChannel.java:910)
at org.eclipse.jetty.server.HttpChannel.write(HttpChannel.java:987)
at org.eclipse.jetty.server.HttpOutput.channelWrite(HttpOutput.java:285)
at org.eclipse.jetty.server.HttpOutput.channelWrite(HttpOutput.java:269)
at org.eclipse.jetty.server.HttpOutput.flush(HttpOutput.java:749)
at java.util.zip.DeflaterOutputStream.flush(DeflaterOutputStream.java:282)
at com.sun.xml.internal.stream.writers.UTF8OutputStreamWriter.flush(UTF8OutputStreamWriter.java:138)
at com.sun.xml.internal.stream.writers.XMLStreamWriterImpl.flush(XMLStreamWriterImpl.java:397)
... 35 more
Caused by: java.io.IOException: An existing connection was forcibly closed by the remote host
at sun.nio.ch.SocketDispatcher.writev0(Native Method)
at sun.nio.ch.SocketDispatcher.writev(SocketDispatcher.java:55)
at sun.nio.ch.IOUtil.write(IOUtil.java:148)
at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:509)
at java.nio.channels.SocketChannel.write(SocketChannel.java:502)
at org.eclipse.jetty.io.ChannelEndPoint.flush(ChannelEndPoint.java:273)
... 50 more

asked 27 Oct, 07:53

tedfroehlich's gravatar image

tedfroehlich
2302516
accept rate: 20%

edited 27 Oct, 08:01

Volker%20Barth's gravatar image

Volker Barth
39.1k353534804

I don't have a clue but as a general question: Do you run OData with a log file ("dbsrvsrv17 -xs odata(LOG=...)") and if so, does this reveal any hints?

(27 Oct, 08:00) Volker Barth
Replies hidden
1

Yes, we are running OData with LogVerbosity=3, and it indeed reports an error:

R. 2022-10-27 08:49:52. [odata_register:207] Request GET http://10.0.0.5:8090/odata_register/$metadata

E. 2022-10-27 08:49:52. [odata_register:207] (HTTP 500 Internal Server Error - 30000) An unexpected error occurred in the producer and was written to file "C:\ProgramData\SQL Anywhere 17\diagnostics\ODP17_20221027_084952_751.txt"

The requests preceding the error vary. A cursory look gives the request for metadata, GET calls to different procedures, POST calls to different database views

(27 Oct, 08:21) tedfroehlich
1

I know, that I must be late. Here is what I see: 1. the end-user tries to get $metadata; 2. OData producer prepares it (builds XML tags as a collection of strings), and starts flushing it to the connection (between the user and the server, or client and OData server). Technically, it is a socket and we throw our bytes into it. 3. At some point of time, when this happens, the connection is terminated.

Internet says, this errors happens when SOMEBODY closes the connection. I doubt that something goes wrong with the server, because the error says that "remote host forcibly closed the connection". So it means that the user all of a sudden decided to give up, and terminated the connection, or somebody did it for him.

Now, we come to the point who is guilty? Again, Internet says, the connection is closed, when the "RST" (reset) packet comes from any party (in our case, again, I assume this is a client). And people suggest to run Wireshark on the server side and check all incoming packets to this port. If you see the RST packet coming from the client, you probably has to start Wireshark on the client side and assure that it was sent by HIM, not by his firewall, router or a proxy server.

People tell, that sometimes (if the connection is long enough) the browser/client can terminate it after some timeout (e.g. at SAP Cloud etc, the timeout is usually 30 seconds, so if your connection is active for this time, it should be m-m-m-m killed). This you can confirm only if you detect/capture RST packet.

Now we come to the question, what if our response time was so long, that the end-user gave up. In theory (I have never done this before) since OData server is just a stupid Java servlet. Thank God, it is running on SAP JVM, so it is better to switch to SAP JDK (8 of course), and profile it as a regular Java application.

Unfortunately, Java profiling goes beyond this comment, but if you don't have an answer on this topic, feel free to try my idea. As I said, I don't know what happened, but I wish I can come to you and check it myself :) I like these riddles.

(28 Oct, 15:43) Vlad
Be the first one to answer this question!
toggle preview

Follow this question

By Email:

Once you sign in you will be able to subscribe for any updates here

By RSS:

Answers

Answers and Comments

Markdown Basics

  • *italic* or _italic_
  • **bold** or __bold__
  • link:[text](http://url.com/ "title")
  • image?![alt text](/path/img.jpg "title")
  • numbered list: 1. Foo 2. Bar
  • to add a line break simply add two spaces to where you would like the new line to be.
  • basic HTML tags are also supported

Question tags:

×216
×16
×13

question asked: 27 Oct, 07:53

question was seen: 134 times

last updated: 28 Oct, 15:43