RuntimeIOException: Parser is terminated when doing lots of requests with Connection: Keep-Alive #12356
Comments
|
@gregw don't trust the binaries and jar files in the reproducer.zip Start with a fresh copy of gradle from a known source, or convert the project to maven. |
|
The safer code / example can be found here -> https://github.com/joakime/issue-12356-reproducer It's a maven build, but the Spring Application doesn't stay running. (it's not setup properly) The Spring Application starts/runs, but then is immediately closed/stopped. |
|
Testing an empty non-spring Jetty 12.0.14, using embedded Jetty. And testing it using Unable to reproduce using Jetty (without Spring Boot) Server side shows ... |
|
@gg-dt Can you comment on why your reproducing code is existing immediately when run? I also can't see in the source code that it is actually doing anything? |
|
@joakime I adapted your maven-based reproducer to actually use Jetty instead of Tomcat, and I added a RestController to it which accepts GET requests on I then started it using So it seems to me the error (only?) occurs when a non-200 response like 404 occurs. @joakime can you please run ab against an inexistant endpoint like |
|
Good info, thanks! |
The test you saw in #12356 (comment) was done against a standard Jetty server where 100% of requests result in a 404. Basically this code. package examples;
import org.eclipse.jetty.server.Server;
public class SimplestServer
{
public static void main(String[] args) throws Exception
{
Server server = new Server(9090);
// This has a connector listening on port 9090
// and no handlers, meaning all requests will result
// in a 404 response
server.start();
System.err.println("Hint: Hit Ctrl+C to stop Jetty.");
server.join();
}
}Let me give your spring example project a test too. |
|
@joakime I've tested the latest spring-boot reproducer and I am definitely getting This is most likely an issue in the new spring-boot integration code of jetty-12, as that was refactored very recently. But I'll do some hammering on a raw jetty as well just to triple check our error paths. |
|
@gregw the ab tests against the spring-boot reproducer show the following output on The interesting bits would be ... Why are half failed? (that's a strange coincidence) Also, that output looks different than what the Embedded Jetty direct output produces ... Meanwhile, I'll leave it in your hands to review the Spring integration on the spring side (as you have some experience there). |
|
@gg-dt whilst we debug this.... I'll just say my usual rant against ab..... it is really a bad way to benchmark a server (see my ancient blog: https://webtide.com/lies-damned-lies-and-benchmarks-2/). When a benchmaking tool reports throughput, it is typically measuring latency. You need to measure latency in order to truly measure throughput. Having said that, tools like ab are good at finding bugs like this one :) |
|
@gregw not sure if this means anything, but if you run So, You can verify the behavior of your |
|
Including my spring-reproducer output here, in case it matters to someone. |
That most definitely means something. The parser instance is reused on a persistent connection, so it is subsequent requests on the same connection that are seeing the In the case of non persistent requests, the parser is thrown away after every request, so no chance of getting this failure. |
|
So I have tried several variations of: public class TestServer
{
public static void main(String[] args) throws Exception
{
Server server = new Server();
ServerConnector connector = new ServerConnector(server);
connector.setPort(8080);
server.addConnector(connector);
server.setHandler(new Handler.Abstract()
{
@Override
public boolean handle(Request request, Response response, Callback callback)
{
request.getContext().execute(() -> Response.writeError(request, response, callback, 404));
return true;
}
});
server.start();
server.join();
}
}With 404 sent from another thread, with no handler, 404 from the handling thread etc. All of them, in pure jetty 12.0 run without an issue with output like: So it is almost certainly an aspect of the spring integration..... but the mystery is: what could the spring integration code possibly be doing to core jetty to make it fail like it does. I.e. if I want to get that error, what must I do??? I'm going to keep on trying to reproduce the error directly in jetty for an hour or two before diving into spring integration... because even if the spring integration is buggy, and application should not be able to trick jetty into this state. |
|
I've tried all sorts of evil things to reproduce.. writing twice, completing then writing... but I get 'already completed' ISE. However, switching back to testing the spring-boot reproducer, I get the exception with only 2 requests: So this should be easier to debug. standby... |
|
Ah - This is not the latest spring integration code, as it is still using servlets rather than direct jetty-12 handlers. The sequence of events is as follows: The first request is received and parsed: This fails to find a matching resource and exits handling after something calls sendError The sendError handling looks for an finds an error page: which is dispatched with an error dispatch, which writes the error page: which when generated is seen as a persistent connection and BUT when this is actually generated, a SHUTDOWN_OUT is done, as if the connection was not persistent?!?!? The connection is now half closed and the parser CLOSED. We read seeking EOF, but see the second request, which "correctly" fails as the parser is CLOSED: So the issue is: Why is an EE10 servlet sending a persistent 404 response, but then closing the connection??? Switching back to pure jetty EE10 to try to reproduce... |
|
Still no reproduction with: public class TestWebAppServer
{
public static void main(String[] args) throws Exception
{
Server server = new Server();
WebAppContext webapp = new WebAppContext();
webapp.setContextPath("/");
webapp.setBaseResourceAsString(".");
ErrorPageErrorHandler errorHandler = new ErrorPageErrorHandler();
errorHandler.addErrorPage(404, "/error404");
webapp.setErrorHandler(errorHandler);
webapp.addServlet(new HttpServlet() {
@Override
protected void doGet(HttpServletRequest req, HttpServletResponse resp) throws IOException
{
resp.setStatus(404);
resp.getOutputStream().write("404 Not Found".getBytes());
}
}, "/error404");
server.setHandler(webapp);
ServerConnector connector = new ServerConnector(server);
connector.setPort(8080);
server.addConnector(connector);
server.start();
server.join();
}
} |
|
I was able to, sort of, reproduce with the minimal ab test of only 2 requests ... Got a pcapng of it as well (doesn't tell us much that we don't already know) |
|
OK, I know what the issue is, and it is in normal jetty, the HttpGenerator!!! The following server will fail in exactly the same way: public class TestServer
{
public static void main(String[] args) throws Exception
{
Server server = new Server();
ServerConnector connector = new ServerConnector(server);
connector.setPort(8080);
server.addConnector(connector);
server.setHandler(new Handler.Abstract()
{
@Override
public boolean handle(Request request, Response response, Callback callback)
{
try
{
Callback.Completable writeCB = new Callback.Completable();
response.write(false, BufferUtil.toBuffer("Not Found!!!!"), writeCB);
writeCB.get();
callback.succeeded();
}
catch (Throwable t)
{
callback.failed(t);
}
return true;
}
});
server.start();
server.join();
}
}The issue is that the way that response is written, the content-length is unknown and there is no chunking available. So with HTTP/1.0, jetty has no other option but to use EOF termination to mark the end of the response body. Now, as a server, jetty is actually entitled to close the connection at any time between requests, even after sending a keep-alive, so this is really a "bug" rather than a bug. But ab is also entitled to try to send another request on that connection if it sees keep-alive. As it is an idempotent request (GET), a normal browser would just retry on a new connection, but ab is counting it as a failure... which I guess is OK too. This is never triggered normally as we are careful to always write our error pages in such a way that the content-length is known and thus even with HTTP/1.0 we can be persistent. But spring-boot obviously has an error handler that is forcing a commit before the response is closed, thus we have no other choice but to close the connection. This is an inefficient way to generate error pages, as you throw away a perfectly good connection. So to fix/improve this we need to: |
Fix #12356 Do not send keep-alive when not persistent
|
@gg-dt I have opened #12375 with a fix for this. Note that for real deployments, this is not really an issue. Either the response is written is a way that is really persistent (and we don't trigger this issue); OR the response is written in a way that cannot use persistent connections for HTTP/1.0 so it is a little more inefficient as the client may try the connection for another request, but a) the inefficiency is mostly on the client side; b) any app that closes connections like that is not going to be efficient anyway. If you were getting this error for real request (not 404s), then it is kind of pointless benchmarking it until you fix the response generation so that it can persist connection in HTTP/1.0 or avoid chunking in HTTP/1.1. Doing that will give you huge performance improvements. |
I don't always see a lockup. As shown in my example output - sometimes some 40000 requests go good. Looked like some race condition to me.
Ok, thanks for the analysis. Are you in contact with the Spring project regarding the flushing in the error page generation or should I tell them? And just for my understanding: Why does Jetty not close the TCP connection if the error handler flushes? |
Fix #12356 Do not send keep-alive when not persistent --------- Signed-off-by: Simone Bordet <[email protected]> Co-authored-by: Simone Bordet <[email protected]>
Jetty version(s)
12.0.13
Jetty Environment
core
Java version/vendor
(use: java -version)openjdk 21.0.2 2024-01-16 LTS
OS type/version
Windows 11
Description
When running Apache HTTP's ab tool the
-koption (keep the connection alive), after a couple of requests (usually some hundred), ab logsapr_socket_recv: Software caused connection abort (113). When enabling debug logging in Jetty you can see these exceptions:How to reproduce?
I attached a reproducer Java application with spring boot and jetty.
reproducer.zip(UNSAFE, DO NOT DOWNLOAD OR USE AS-IS)./gradlew bootRunab -n 100000 -k "http://localhost:8080/"The text was updated successfully, but these errors were encountered: