OutputStreamContentProvider blocks forever during an HTTP2 upload after idle timeout is reached

[gsavin]

Jetty version(s)

Tested on:

• 9.4.31.v20200723
• 9.4.36.v20210114
• 9.4.46.v20220331

Java version/vendor (use: java -version)

openjdk version "1.8.0_312"
OpenJDK Runtime Environment (build 1.8.0_312-b07)
OpenJDK 64-Bit Server VM (build 25.312-b07, mixed mode)

OS type/version

Centos 8.5

Description

I am using an HTTP2 client to upload large file. During upload, if the network link is cut (I am unplugging it), the DeferredContentProvider I am using (through OutputStreamContentProvider) is blocked on the flush() operation following the write(). Once idle timeout is reached, the content provider is not notified and stay blocked forever.

I tried to dig into Jetty code, but I am not sure what to look for. It looks like when the HttpConnectionOverHTTP2#abort is called, the HttpExchange object associated to the channel is null, so Request.abort is not called. It has been set to null by the dissociate that happened a bit earlier (we can see in the stack that the disassociate has been caused by the idle timeout being reached):

disassociate:85, HttpChannel (org.eclipse.jetty.client)
exchangeTerminated:162, HttpChannel (org.eclipse.jetty.client)
exchangeTerminated:115, HttpChannelOverHTTP2 (org.eclipse.jetty.http2.client.http)
terminateResponse:476, HttpReceiver (org.eclipse.jetty.client)
terminateResponse:461, HttpReceiver (org.eclipse.jetty.client)
abort:557, HttpReceiver (org.eclipse.jetty.client)
abortResponse:152, HttpChannel (org.eclipse.jetty.client)
abort:145, HttpChannel (org.eclipse.jetty.client)
abort:264, HttpExchange (org.eclipse.jetty.client)
onIdleTimeout:199, HttpReceiverOverHTTP2 (org.eclipse.jetty.http2.client.http)
notifyIdleTimeout:700, HTTP2Stream (org.eclipse.jetty.http2)
onIdleExpired:264, HTTP2Stream (org.eclipse.jetty.http2)
checkIdleTimeout:171, IdleTimeout (org.eclipse.jetty.io)
idleCheck:113, IdleTimeout (org.eclipse.jetty.io)

Any clue about how to fix this? Thanks.

How to reproduce?

Here is a dirty MRE leading to this error if network is unplugged during writing:

import org.eclipse.jetty.client.HttpClient;
import org.eclipse.jetty.client.HttpClientTransport;
import org.eclipse.jetty.client.api.Request;
import org.eclipse.jetty.client.api.Response;
import org.eclipse.jetty.client.util.InputStreamResponseListener;
import org.eclipse.jetty.client.util.OutputStreamContentProvider;
import org.eclipse.jetty.http.HttpHeader;
import org.eclipse.jetty.http.HttpMethod;
import org.eclipse.jetty.http2.client.HTTP2Client;
import org.eclipse.jetty.http2.client.http.HttpClientTransportOverHTTP2;
import org.eclipse.jetty.util.ssl.SslContextFactory;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

import javax.net.ssl.SSLContext;
import java.io.IOException;
import java.io.InputStream;
import java.io.OutputStream;
import java.nio.file.Files;
import java.nio.file.Paths;
import java.util.concurrent.TimeUnit;

public class MRE {
    static final Logger LOG = LoggerFactory.getLogger(MRE.class);
    static String HOST = "https://__IP__:__PORT__";
    static long TIMEOUT = 30_000;

    public static void main(String... args) throws Exception {
        final SslContextFactory factory = new SslContextFactory.Client(true);
        final SSLContext sslContext = SSLContext.getInstance("TLS");
        sslContext.init(null, null, null);
        factory.setSslContext(sslContext);

        HTTP2Client http2Client = new HTTP2Client();
        HttpClientTransport transport = new HttpClientTransportOverHTTP2(http2Client);
        HttpClient client = new HttpClient(transport, factory);
        client.setIdleTimeout(TIMEOUT);
        client.setConnectTimeout(TIMEOUT);

        OutputStreamContentProvider content = new OutputStreamContentProvider();
        try (OutputStream output = content.getOutputStream()) {
            LOG.info("START");
            client.start();
            InputStreamResponseListener listener = new InputStreamResponseListener();

            LOG.info("REQUESTING");
            final Request request = client.newRequest(HOST + "/upload")
                    .method(HttpMethod.POST)
                    .header(HttpHeader.AUTHORIZATION, "Bearer __TOKEN__")
                    .content(content)
                    .idleTimeout(TIMEOUT, TimeUnit.MILLISECONDS);

            request.send(listener);

            LOG.info("WRITING");
            try (InputStream is = Files.newInputStream(Paths.get("/some/file"))) {
                byte[] buffer = new byte[1024];
                int len = 0;
                while ((len = is.read(buffer)) != -1) {
                    output.write(buffer, 0, len);
                }
            }

            LOG.info("WAITING");
            Response result = listener.get(TIMEOUT, TimeUnit.MILLISECONDS);
            if (result.getStatus() != 200) {
                throw new IOException("Upload failed");
            }
        } finally {
            client.stop();
            LOG.info("STOPPED");
        }
    }
}

[joakime]

Don't think the header(HttpHeader.AUTHORIZATION, "Bearer __TOKEN__") is important here. What kind of server are you uploading to? This seems to be a simple POST with Content-Type: application/octet-stream, is that a correct assumption?

[gsavin]

Agree, the bearer does not matter. It's uploaded to a Jetty server. And your assumption is correct, it's application/octet-stream.

[gsavin]

I don't know if it helps, but if I replace the OutputStreamContentProvider with an InputStreamContentProvider in my example code (removing the writing block), the idle timeout is detected.

        try (InputStream is = Files.newInputStream(path);
             InputStreamContentProvider content = new InputStreamContentProvider(is)) {
            ...
        }

[gsavin]

I managed to make it work with OutputStreamContentProvider, overriding the onComplete method of the listener to notify the provider. Not sure this is the proper way to do it, but at least it's working.

OutputStreamContentProvider content = new OutputStreamContentProvider();
...
InputStreamResponseListener listener = new InputStreamResponseListener() {
                public void onComplete(Result result) {
                    super.onComplete(result);

                    if (result.isSucceeded()) {
                        content.succeeded();
                    } else {
                        content.failed(result.getFailure());
                    }
                }
            };
};

[joakime]

This still smells like a bug on our side.

[github-actions[bot]]

This issue has been automatically marked as stale because it has been a full year without activity. It will be closed if no further activity occurs. Thank you for your contributions.

[github-actions[bot]]

This issue has been automatically marked as stale because it has been a full year without activity. It will be closed if no further activity occurs. Thank you for your contributions.

[sbordet]

@gsavin the problem is that you are not closing the OutputStreamContentProvider to signal that no more content needs to be sent.

You need to do this:

OutputStream output = ...
...
LOG.info("WRITING");
try (InputStream is = Files.newInputStream(Paths.get("/some/file"))) {
  byte[] buffer = new byte[1024];
  int len = 0;
  while ((len = is.read(buffer)) != -1) {
    output.write(buffer, 0, len);
  }
}

// Signal that there is no more content to write.
output.close();

Your code's try-with-resources for OutputStream output is too wide and does not close the OutputStream when it should.

Please remove the "hack" of calling OutputStreamContentProvider.succeeded()/failed(), it's not necessary.