Worker threads hanging after Http2 connection issues #2877
Description
Jetty 9.4.8
I have a very deterministic repro for this, but it's using a bunch of internal code, so I will try to help reproduce with available open code:
With the following jersey resource:
package repro;
import java.io.IOException;
import java.io.InputStream;
import javax.ws.rs.Consumes;
import javax.ws.rs.PUT;
import javax.ws.rs.Path;
import javax.ws.rs.Produces;
import javax.ws.rs.core.MediaType;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
@Consumes(MediaType.APPLICATION_JSON)
@Produces(MediaType.APPLICATION_JSON)
@Path("/")
public final class StreamResource {
private static final Logger log = LoggerFactory.getLogger(StreamResource.class);
@PUT
@Path("stream")
@Consumes(MediaType.APPLICATION_OCTET_STREAM)
public void putStream(InputStream stream) {
try {
log.info("Start reading stream");
long length = exhaustSlowly(stream);
log.info("Finished reading stream: {}", length);
} catch (IOException e) {
log.error("Failed to read stream", e);
throw new RuntimeException(e);
}
}
private long exhaustSlowly(InputStream in) throws IOException {
long total = 0;
long read;
byte[] buf = createBuffer();
while ((read = in.read(buf)) != -1) {
total += read;
log.info("Sleeping");
try {
Thread.sleep(100);
} catch (InterruptedException e) {
Thread.currentThread().interrupt();
throw new RuntimeException(e);
}
log.info("Finished sleeping");
log.info("Total: {}", total);
}
log.info("Finished reading: {}", total);
return total;
}
private byte[] createBuffer() {
return new byte[8192];
}
}
and a client using OkHttp 3.9.0 (pre fixes to session window handling: square/okhttp#3920), I can reliably get Jetty to forget to notify worker threads that the streams (and connections) have been closed (mind you I call this endpoint from 2 threads concurrently, but I don't think this is required - it's simply to allow me to overflow the session window).
Here is the stacktrace of the hanging worker threads:
java.lang.Thread.State: WAITING
at java.lang.Object.wait(Object.java:-1)
at java.lang.Object.wait(Object.java:502)
at org.eclipse.jetty.server.HttpInput.blockForContent(HttpInput.java:565)
at org.eclipse.jetty.server.HttpInput$1.blockForContent(HttpInput.java:1084)
at org.eclipse.jetty.server.HttpInput.read(HttpInput.java:306)
at REDACTED
at com.google.common.io.CountingInputStream.read(CountingInputStream.java:63)
at java.io.FilterInputStream.read(FilterInputStream.java:107)
at org.glassfish.jersey.message.internal.EntityInputStream.read(EntityInputStream.java:97)
at repro.StreamResource.exhaustSlowly(StreamResource.java:43)
at repro.StreamResource.putStream(StreamResource.java:31)
at sun.reflect.NativeMethodAccessorImpl.invoke0(NativeMethodAccessorImpl.java:-1)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
And here is the jetty debug log (caution it's pretty long, but there are some interesting bits towards the end: the threads are able to read from a closed HTTP2Session): https://gist.github.com/jkozlowski/cee4fca14311e6b5f488861ca7cf35c1
I am aware of #2679, but I haven't yet been able to test with the RC (I am getting some NP exceptions). I will continue digging, but I would appreciate any help.
I am also aware of configuration options that will make the HttpInput.blockForContent timeout, but I would like to get to the bottom of why the callbacks are missed.
Happy to try to work on a runnable repro, but I thought I'd open this sooner rather than later, in case you can figure out the issue just from the logs.