HTTP/2 PUT/POST requests fail with IOStrategy set to SameThreadIOStrategy

[arinban]

Testing a simple server built using Jersey/Grizzly exchanging simple JSON payload (Jackson). POST/PUT/GET requests work fine with HTTP1.1 in this setup combined with any server IOStrategy. I then enabled HTTP/2 via Http2AddOn and got responses back correctly for GET requests, however PUT/POST requests started timing out from the client side. Eventually i found that if i change IOStrategy on the Grizzly server to something other than SameThreadIOStrategy it started to work properly for PUT and POST too.

Below is a stack trace from the server:

r2d2_simple-microservice-server.1.ujq155t6brll@devbox | Apr 19, 2017 5:38:13 PM org.glassfish.grizzly.http.server.HttpHandler doHandle r2d2_simple-microservice-server.1.ujq155t6brll@devbox | WARNING: GRIZZLY0200: Service exception r2d2_simple-microservice-server.1.ujq155t6brll@devbox | org.glassfish.jersey.server.ContainerException: java.io.IOException: Blocking read timeout r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.jersey.grizzly2.httpserver.GrizzlyHttpContainer$ResponseWriter.rethrow(GrizzlyHttpContainer.java:324) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.jersey.grizzly2.httpserver.GrizzlyHttpContainer$ResponseWriter.failure(GrizzlyHttpContainer.java:306) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.jersey.server.ServerRuntime$Responder.process(ServerRuntime.java:509) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.jersey.server.ServerRuntime$2.run(ServerRuntime.java:334) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.jersey.internal.Errors$1.call(Errors.java:271) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.jersey.internal.Errors$1.call(Errors.java:267) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.jersey.internal.Errors.process(Errors.java:315) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.jersey.internal.Errors.process(Errors.java:297) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.jersey.internal.Errors.process(Errors.java:267) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:317) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:305) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:1154) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.jersey.grizzly2.httpserver.GrizzlyHttpContainer.service(GrizzlyHttpContainer.java:384) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.http.server.HttpHandler.runService(HttpHandler.java:206) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.http.server.HttpHandler.doHandle(HttpHandler.java:180) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.http.server.HttpHandlerChain.doHandle(HttpHandlerChain.java:198) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.http.server.HttpServerFilter.handleRead(HttpServerFilter.java:235) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.java:119) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilterChain.java:284) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultFilterChain.java:201) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChain.java:133) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChain.java:112) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:77) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.http2.Http2Connection.sendMessageUpstream(Http2Connection.java:1227) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.http2.Http2Connection.sendMessageUpstream(Http2Connection.java:1202) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.http2.Http2BaseFilter.sendUpstream(Http2BaseFilter.java:864) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.http2.Http2ServerFilter.processInRequest(Http2ServerFilter.java:805) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.http2.Http2ServerFilter.processCompleteHeader(Http2ServerFilter.java:742) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.http2.Http2BaseFilter.processHeadersFrame(Http2BaseFilter.java:701) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.http2.Http2BaseFilter.processInFrame(Http2BaseFilter.java:529) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.http2.Http2BaseFilter.processFrames(Http2BaseFilter.java:177) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.http2.Http2ServerFilter.handleRead(Http2ServerFilter.java:531) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.java:119) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilterChain.java:284) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultFilterChain.java:201) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChain.java:133) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChain.java:112) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:77) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTransport.java:539) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.strategies.AbstractIOStrategy.fireIOEvent(AbstractIOStrategy.java:112) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.strategies.SameThreadIOStrategy.executeIoEvent(SameThreadIOStrategy.java:103) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.strategies.AbstractIOStrategy.executeIoEvent(AbstractIOStrategy.java:89) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.nio.SelectorRunner.iterateKeyEvents(SelectorRunner.java:415) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.nio.SelectorRunner.iterateKeys(SelectorRunner.java:384) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.nio.SelectorRunner.doSelect(SelectorRunner.java:348) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.nio.SelectorRunner.run(SelectorRunner.java:279) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:593) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.run(AbstractThreadPool.java:573) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at java.lang.Thread.run(Thread.java:745) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | Caused by: java.io.IOException: Blocking read timeout r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.http2.DefaultInputBuffer.poll0(DefaultInputBuffer.java:296) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.http2.DefaultInputBuffer.poll(DefaultInputBuffer.java:261) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.http2.Http2Stream.pollInputData(Http2Stream.java:661) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.http2.Http2BaseFilter.checkIfHttp2StreamChain(Http2BaseFilter.java:805) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.http2.Http2ServerFilter.handleRead(Http2ServerFilter.java:422) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.java:119) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilterChain.java:284) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultFilterChain.java:201) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.filterchain.DefaultFilterChain.read(DefaultFilterChain.java:352) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.filterchain.FilterChainContext.read(FilterChainContext.java:736) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.http.io.InputBuffer.blockingRead(InputBuffer.java:1103) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.http.server.io.ServerInputBuffer.blockingRead(ServerInputBuffer.java:95) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.http.io.InputBuffer.fill(InputBuffer.java:1127) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.http.io.InputBuffer.read(InputBuffer.java:348) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.grizzly.http.server.NIOInputStreamImpl.read(NIOInputStreamImpl.java:83) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.jersey.message.internal.EntityInputStream.read(EntityInputStream.java:102) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.jersey.message.internal.ReaderInterceptorExecutor$UnCloseableInputStream.read(ReaderInterceptorExecutor.java:296) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at com.fasterxml.jackson.core.json.ByteSourceJsonBootstrapper.ensureLoaded(ByteSourceJsonBootstrapper.java:522) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at com.fasterxml.jackson.core.json.ByteSourceJsonBootstrapper.detectEncoding(ByteSourceJsonBootstrapper.java:129) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at com.fasterxml.jackson.core.json.ByteSourceJsonBootstrapper.constructParser(ByteSourceJsonBootstrapper.java:246) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at com.fasterxml.jackson.core.JsonFactory._createParser(JsonFactory.java:1271) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at com.fasterxml.jackson.core.JsonFactory.createParser(JsonFactory.java:810) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at com.fasterxml.jackson.jaxrs.base.ProviderBase._createParser(ProviderBase.java:822) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at com.fasterxml.jackson.jaxrs.base.ProviderBase.readFrom(ProviderBase.java:763) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.jersey.message.internal.ReaderInterceptorExecutor$TerminalReaderInterceptor.invokeReadFrom(ReaderInterceptorExecutor.java:256) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.jersey.message.internal.ReaderInterceptorExecutor$TerminalReaderInterceptor.aroundReadFrom(ReaderInterceptorExecutor.java:235) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.jersey.message.internal.ReaderInterceptorExecutor.proceed(ReaderInterceptorExecutor.java:155) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.jersey.server.internal.MappableExceptionWrapperInterceptor.aroundReadFrom(MappableExceptionWrapperInterceptor.java:74) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.jersey.message.internal.ReaderInterceptorExecutor.proceed(ReaderInterceptorExecutor.java:155) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.jersey.message.internal.MessageBodyFactory.readFrom(MessageBodyFactory.java:1085) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.jersey.message.internal.InboundMessageContext.readEntity(InboundMessageContext.java:874) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.jersey.server.ContainerRequest.readEntity(ContainerRequest.java:271) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.jersey.server.internal.inject.EntityParamValueFactoryProvider$EntityValueFactory.provide(EntityParamValueFactoryProvider.java:96) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.jersey.server.spi.internal.ParamValueFactoryWithSource.provide(ParamValueFactoryWithSource.java:71) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.jersey.server.spi.internal.ParameterValueHelper.getParameterValues(ParameterValueHelper.java:94) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$AbstractMethodParamInvoker.getParamValues(JavaResourceMethodDispatcherProvider.java:127) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$ResponseOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:160) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:99) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:389) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:347) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:102) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | at org.glassfish.jersey.server.ServerRuntime$2.run(ServerRuntime.java:326) r2d2_simple-microservice-server.1.ujq155t6brll@devbox | ... 45 more

Environment

Ubuntu Xenial, Jersey v 2.25.1

Affected Versions

[2.3.30, 2.4.0]

[arinban]

• Issue Imported From: https://github.com/javaee/grizzly/issues/1906
• Original Issue Raised By:@glassfishrobot
• Original Issue Assigned To:@rlubke
• Original Issue Closed By:@glassfishrobot

[arinban]

@glassfishrobot Commented Reported by crazymonkey

[arinban]

@glassfishrobot Commented @rlubke said: It's working fine here with just Grizzly. If you can provide a test case (maven project preferably) we can take a look.

[arinban]

@glassfishrobot Commented crazymonkey said: Can't upload files here but here's a simple project: https://github.com/thecrazymonkey/testcode.git should just work with mvn package and mvn exec:exec - it will by default start HTTP/2 server with SameThreadIOStrategy

The way I test it is using nghttp or h2load (nghttp2.org) nghttp -v -H "Content-Type:application/json" -H ":method: PUT" -d src/main/resources/smalljson.json http://localhost:8080/rest/putjson or nghttp -v -H "Content-Type:application/json" -H ":method: POST" -d src/main/resources/smalljson.json http://localhost:8080/rest/getsetjson Those two above fail for me. Normal GET works fine : nghttp -v -H "Content-Type:application/json" -v http://localhost:8080/rest/getjson

To verify that POST works ok with HTTP1.1 you can do h2load --h1 -n 1 -H "Content-Type:application/json" -H ":method: POST" -d src/main/resources/smalljson.json http://localhost:8080/rest/getsetjson

HTH Thanks for looking into this.

[arinban]

@glassfishrobot Commented @rlubke said: Okay, I've had some time to look at this and it's not a bug.

The problem here is that when you're using SameThreadIOStrategy, you have to be very careful that operations don't block the thread.

In the HTTP/2 test case, Jersey initiates a blocking read after the Request (Header frame) is processed. Because this blocks the I/O thread, the Data frame is never consumed from the wire.

It works in the HTTP/1.1 case as the request headers and body are sent as a single packet (something that isn't possible in HTTP/2.0) and thus doesn't block the thread. However, if the body comes over multiple packets, this issue would present itself.

So the option is to use the WorkerThreadIOStrategy (which would apply globally to all protocols on that transport) and eat the cost of the context switch, or leave it as SameThreadIOStrategy and configure the HTTP/2 AddOn with a custom thread pool:

Http2Configuration configuration = Http2Configuration
                .builder()
                .threadPoolConfig(ThreadPoolConfig.defaultConfig().setMaxPoolSize(5).setCorePoolSize(5))
                .build();

You can also pass in an existing ExecutorService to the AddOn if you want more control over its lifecycle.

[arinban]

@glassfishrobot Commented crazymonkey said: Ah, interesting, thanks for the explanation. I've thought that the HTTP/2 filter hides this from the application layer completely - i.e. delivers the "logical" (HEADERS + DATA) request to Jersey in one go. Good to know. Thanks!

[arinban]

@glassfishrobot Commented This issue was imported from java.net JIRA GRIZZLY-1906

[arinban]

@glassfishrobot Commented Marked as works as designed on Friday, April 21st 2017, 2:03:57 pm