search

javaee / grizzly

Writing scalable server applications in the Java™ programming language has always been difficult. Before the advent of the Java New I/O API (NIO), thread management issues made it impossible for a server to scale to thousands of users. The Grizzly NIO framework has been designed to help developers to take advantage of the Java™ NIO API.
https://javaee.github.io/grizzly/
Other
222 stars 60 forks source link

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

Closed glassfishrobot closed 7 years ago

glassfishrobot commented 7 years ago

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]

glassfishrobot commented 7 years ago

Reported by crazymonkey

glassfishrobot commented 7 years ago

@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.

glassfishrobot commented 7 years ago

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.

glassfishrobot commented 7 years ago

@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.

glassfishrobot commented 7 years ago

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!

glassfishrobot commented 7 years ago

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

glassfishrobot commented 7 years ago

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