Inconsistency in pooled-but-unused TCP connection error between Windows and Linux/MacOs

[NilsRenaud]

Version

I use Vert.x 4.5.2

Context

This is the timeline:

• A Vert.x HTTP Client send a request to an HTTP Server
• The client receive the response, but the connection is still available in the connection pool
• The HTTP server is killed.

Then:

• on Linux/MacOs: nothing happen on client side.
• on Windows: we can observe this ERROR log, by Vert.x:

10:28:27.883 [vert.x-eventloop-thread-1] ERROR io.vertx.core.net.impl.ConnectionBase -- Connection reset
java.net.SocketException: Connection reset
	at java.base/sun.nio.ch.SocketChannelImpl.throwConnectionReset(SocketChannelImpl.java:394)
	at java.base/sun.nio.ch.SocketChannelImpl.read(SocketChannelImpl.java:426)
	at io.netty.buffer.PooledByteBuf.setBytes(PooledByteBuf.java:255)
	at io.netty.buffer.AbstractByteBuf.writeBytes(AbstractByteBuf.java:1132)
	at io.netty.channel.socket.nio.NioSocketChannel.doReadBytes(NioSocketChannel.java:357)
	at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:151)
	at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:788)
	at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:724)
	at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:650)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:562)
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997)
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.base/java.lang.Thread.run(Thread.java:833)

I think that this error should be hidden as the connection is not used when the exception happen. So this could be logged at debug or trace level instead. Moreover, when multiple connections are open to the same HTTP Server, then this message appears multiple times.

This is a broader issue than just a Windows compatibility one (see "Investigation" below), as it would end up the same on MacOs/Linux in case of any failure of a pooled-but-unused connection.

Workaround

Fortunately, there is a workaround: one can set a connection exception handler before sending the request, then the exception will be sent to the connection error handler and not be treated as uncaught.

Vertx.vertx()

         .createHttpClient()

         .request(GET, 8080, "localhost", "/")

         .flatMap(req -> {

             req.connection().exceptionHandler(t -> logger.info("Caught error to ignore: ", t)); // Workaround

             req.exceptionHandler(t -> logger.error("REQUEST ERROR: ", t));

             return req.send();

         })


Do you have a reproducer?

Yes, although this seems to happen only when the process itself is killed. I've tried otherwise but didn't succeed in failing the connection on client side. Although I guess this could be done using Mock in Vert.x test.

Server code:

import io.vertx.core.Vertx;

import io.vertx.core.http.HttpServerOptions;

import io.vertx.core.http.HttpServerRequest;

import org.slf4j.Logger;

import org.slf4j.LoggerFactory;



public class TestServerHttp {

    private static final Logger logger = LoggerFactory.getLogger(TestClientHttp.class);


    public static void main(String[] args) {

        HttpServerOptions options = new HttpServerOptions();

        options.setPort(8080);

        Vertx.vertx()

                .createHttpServer(options)

                .requestHandler(TestServerHttp::handleRequest)

                .listen();

    }


    private static void handleRequest(HttpServerRequest req) {

       req.body().onSuccess(buff -> {

           req.response().end("response !").onSuccess(v -> {

               logger.info("Stop thread after client request completion");

               System.exit(0);

           })
;

       });

    }

}

Client code:

import io.vertx.core.Vertx;

import org.slf4j.Logger;

import org.slf4j.LoggerFactory;


import static io.vertx.core.http.HttpMethod.GET;



public class TestClientHttp {

    private static final Logger logger = LoggerFactory.getLogger(TestClientHttp.class);



    public static void main(String[] args) {

        Vertx.vertx()

                .createHttpClient()

                .request(GET, 8080, "localhost", "/")

                .flatMap(req -> {

                    //req.connection().exceptionHandler(t -> logger.info("CONNECTION ERROR: ", t)); // workaround

                    req.exceptionHandler(t -> logger.error("REQUEST ERROR: ", t));

                    return req.send();

                })

                .onSuccess(resp -> logger.info("response from server " + resp.statusCode()));

    }

}

Investigation

I've run this reproducer on MacOs and No exception at all is thrown when the server process is killed. This is why no exception is logged on Linux/MacOs. But if we achieved to have this java.net.SocketException thrown by java.base/sun.nio.ch.SocketChannelImpl.throwConnectionReset(SocketChannelImpl.java:394) (or any other socket exception) then Vert.x behavior would be the same.

[vietj]

thanks I am not sure this is achievable unless as you said you set an exception handler on the connection.

The pool itself does not interact with the connection exception handler, since the connection exists outside of the pool and one could set an exception handler on it and the pool would overwrite it.

as a facility, you can set a connect handler on the HttpClientBuilder that would facilitate the setup of such strategy instead of melting that in your request/response code

[NilsRenaud]

Thanks for looking at this, but can't we update the connection's exceptionHandler when it goes back to its pool, or as soon as the response is 100% read ?
Such exception handler could log the disconnection as warning instead of error since there will be no immediate issue with the connection being lost.

[vietj]

thing is that a connection can be partially in the pool like HTTP/2

[NilsRenaud]

I saw that HTTP/1.1 and HTTP/2 connections both have a notion of active stream, so I guess we could hook something here and update the connection exception handler as soon as this active stream count reaches 0.
What do you think ?