IllegalStateException in HttpOutput with Jersey #4461

electrum · 2020-01-07T20:06:27Z

Jetty version
9.4.25.v20191220

Java version
OpenJDK 1.8.0_232 (Zulu)

OS type/version
macOS Mojave 10.14.6

Description
Jetty 9.4.25 seems to have a regression (or stricter behavior) in the HttpOutput state machine (likely introduced by #4409) which causes the following exception on write():

java.lang.IllegalStateException: s=OPEN,api=BLOCKED,sc=false,e=null

Unfortunately, I was not able to create a simple reproduction, but it reproduces reliably when running a Presto unit test in the presto-jmx module from this branch: https://github.com/electrum/presto/tree/jetty9425:

mvn clean install -DskipTests -pl presto-jmx -am -T1C
mvn test -pl presto-jmx -Dtest=io.prestosql.plugin.jmx.TestJmxQueries#testQuery

After running the above, look for the following error in the test output after 5-10 seconds. You can kill the test at this point, since it takes a while to eventually time out.

2020-01-07T14:01:47.723-0600 SEVERE An I/O error has occurred while writing a response message entity to the container output stream.
org.glassfish.jersey.server.internal.process.MappableException: com.fasterxml.jackson.databind.JsonMappingException: s=OPEN,api=BLOCKED,sc=false,e=null (through reference chain: io.prestosql.client.QueryResults["data"]->java.util.Collections$UnmodifiableRandomAccessList[12])
	at org.glassfish.jersey.server.internal.MappableExceptionWrapperInterceptor.aroundWriteTo(MappableExceptionWrapperInterceptor.java:91)
	at org.glassfish.jersey.message.internal.WriterInterceptorExecutor.proceed(WriterInterceptorExecutor.java:163)
	at org.glassfish.jersey.message.internal.MessageBodyFactory.writeTo(MessageBodyFactory.java:1135)
	at org.glassfish.jersey.server.ServerRuntime$Responder.writeResponse(ServerRuntime.java:662)
	at org.glassfish.jersey.server.ServerRuntime$Responder.processResponse(ServerRuntime.java:395)
	at org.glassfish.jersey.server.ServerRuntime$Responder.process(ServerRuntime.java:385)
	at org.glassfish.jersey.server.ServerRuntime$AsyncResponder$3.run(ServerRuntime.java:884)
	at org.glassfish.jersey.internal.Errors$1.call(Errors.java:272)
	at org.glassfish.jersey.internal.Errors$1.call(Errors.java:268)
	at org.glassfish.jersey.internal.Errors.process(Errors.java:316)
	at org.glassfish.jersey.internal.Errors.process(Errors.java:298)
	at org.glassfish.jersey.internal.Errors.process(Errors.java:268)
	at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:289)
	at org.glassfish.jersey.server.ServerRuntime$AsyncResponder.resume(ServerRuntime.java:916)
	at org.glassfish.jersey.server.ServerRuntime$AsyncResponder.resume(ServerRuntime.java:872)
	at io.airlift.http.server.AsyncResponseHandler$1.onSuccess(AsyncResponseHandler.java:102)
	at com.google.common.util.concurrent.Futures$CallbackListener.run(Futures.java:1058)
	at io.airlift.concurrent.BoundedExecutor.drainQueue(BoundedExecutor.java:78)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)
Caused by: com.fasterxml.jackson.databind.JsonMappingException: s=OPEN,api=BLOCKED,sc=false,e=null (through reference chain: io.prestosql.client.QueryResults["data"]->java.util.Collections$UnmodifiableRandomAccessList[12])
	at com.fasterxml.jackson.databind.JsonMappingException.wrapWithPath(JsonMappingException.java:394)
	at com.fasterxml.jackson.databind.JsonMappingException.wrapWithPath(JsonMappingException.java:365)
	at com.fasterxml.jackson.databind.ser.std.StdSerializer.wrapAndThrow(StdSerializer.java:338)
	at com.fasterxml.jackson.databind.ser.impl.IndexedListSerializer.serializeContents(IndexedListSerializer.java:123)
	at com.fasterxml.jackson.databind.ser.impl.IndexedListSerializer.serialize(IndexedListSerializer.java:79)
	at com.fasterxml.jackson.databind.ser.impl.IndexedListSerializer.serialize(IndexedListSerializer.java:18)
	at com.fasterxml.jackson.databind.ser.std.IterableSerializer.serializeContents(IterableSerializer.java:107)
	at com.fasterxml.jackson.databind.ser.std.IterableSerializer.serialize(IterableSerializer.java:74)
	at com.fasterxml.jackson.databind.ser.std.IterableSerializer.serialize(IterableSerializer.java:12)
	at com.fasterxml.jackson.databind.ser.std.StdDelegatingSerializer.serialize(StdDelegatingSerializer.java:168)
	at com.fasterxml.jackson.databind.ser.BeanPropertyWriter.serializeAsField(BeanPropertyWriter.java:727)
	at com.fasterxml.jackson.databind.ser.std.BeanSerializerBase.serializeFields(BeanSerializerBase.java:721)
	at com.fasterxml.jackson.databind.ser.BeanSerializer.serialize(BeanSerializer.java:166)
	at com.fasterxml.jackson.databind.ser.DefaultSerializerProvider._serialize(DefaultSerializerProvider.java:480)
	at com.fasterxml.jackson.databind.ser.DefaultSerializerProvider.serializeValue(DefaultSerializerProvider.java:319)
	at com.fasterxml.jackson.databind.ObjectWriter$Prefetch.serialize(ObjectWriter.java:1433)
	at com.fasterxml.jackson.databind.ObjectWriter.writeValue(ObjectWriter.java:921)
	at io.airlift.jaxrs.JsonMapper.writeTo(JsonMapper.java:233)
	at org.glassfish.jersey.message.internal.WriterInterceptorExecutor$TerminalWriterInterceptor.invokeWriteTo(WriterInterceptorExecutor.java:266)
	at org.glassfish.jersey.message.internal.WriterInterceptorExecutor$TerminalWriterInterceptor.aroundWriteTo(WriterInterceptorExecutor.java:251)
	at org.glassfish.jersey.message.internal.WriterInterceptorExecutor.proceed(WriterInterceptorExecutor.java:163)
	at org.glassfish.jersey.server.internal.JsonWithPaddingInterceptor.aroundWriteTo(JsonWithPaddingInterceptor.java:109)
	at org.glassfish.jersey.message.internal.WriterInterceptorExecutor.proceed(WriterInterceptorExecutor.java:163)
	at org.glassfish.jersey.server.internal.MappableExceptionWrapperInterceptor.aroundWriteTo(MappableExceptionWrapperInterceptor.java:85)
	... 20 more
Caused by: java.lang.IllegalStateException: s=OPEN,api=BLOCKED,sc=false,e=null
	at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:767)
	at io.airlift.http.server.TimingFilter$TimedServletOutputStream.write(TimingFilter.java:163)
	at org.glassfish.jersey.servlet.internal.ResponseWriter$NonCloseableOutputStreamWrapper.write(ResponseWriter.java:325)
	at org.glassfish.jersey.message.internal.CommittingOutputStream.write(CommittingOutputStream.java:224)
	at org.glassfish.jersey.message.internal.WriterInterceptorExecutor$UnCloseableOutputStream.write(WriterInterceptorExecutor.java:300)
	at com.fasterxml.jackson.core.json.UTF8JsonGenerator._flushBuffer(UTF8JsonGenerator.java:2136)
	at com.fasterxml.jackson.core.json.UTF8JsonGenerator._writeCustomStringSegment2(UTF8JsonGenerator.java:1657)
	at com.fasterxml.jackson.core.json.UTF8JsonGenerator._writeStringSegment(UTF8JsonGenerator.java:1396)
	at com.fasterxml.jackson.core.json.UTF8JsonGenerator._writeStringSegments(UTF8JsonGenerator.java:1281)
	at com.fasterxml.jackson.core.json.UTF8JsonGenerator.writeString(UTF8JsonGenerator.java:502)
	at com.fasterxml.jackson.databind.ser.std.StringSerializer.serialize(StringSerializer.java:41)
	at com.fasterxml.jackson.databind.ser.impl.IndexedListSerializer.serializeContents(IndexedListSerializer.java:119)
	... 40 more

The text was updated successfully, but these errors were encountered:

gbrehmer · 2020-01-08T11:51:59Z

same here but with other frameworks (spring boot 2.2)

2020-01-08 11:27:17.629  WARN 14955 --- [qtp509559152-14,] org.eclipse.jetty.server.HttpChannel     : /vendor-es2015.ab355fce23594e19a032.js
org.springframework.web.util.NestedServletException: Request processing failed; nested exception is java.lang.IllegalStateException: s=OPEN,api=BLOCKED,sc=false,e=null
        at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1014)
        at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:898)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:503)
        at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:590)
        at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:755)
        at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1617)
        at XXX.web.filter.CachingHttpHeadersFilter.doFilter(CachingHttpHeadersFilter.java:52)
        at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1604)
        at XXX.web.filter.RequestAndResponseLoggingFilter.doFilterWrapped(RequestAndResponseLoggingFilter.java:65)
        at XXX.web.filter.RequestAndResponseLoggingFilter.doFilterInternal(RequestAndResponseLoggingFilter.java:49)
        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
        at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1604)
        at org.springframework.web.filter.CorsFilter.doFilterInternal(CorsFilter.java:92)
        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
        at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1604)
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:320)
        at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:126)
        at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:90)
        at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:334)
Caused by: java.lang.IllegalStateException: s=OPEN,api=BLOCKED,sc=false,e=null
        at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:767)
        at org.springframework.security.web.util.OnCommittedResponseWrapper$SaveContextServletOutputStream.write(OnCommittedResponseWrapper.java:645)
        at org.springframework.util.StreamUtils.copy(StreamUtils.java:143)
        at org.springframework.http.converter.ResourceHttpMessageConverter.writeContent(ResourceHttpMessageConverter.java:132)
        at org.springframework.http.converter.ResourceHttpMessageConverter.writeInternal(ResourceHttpMessageConverter.java:124)
        at org.springframework.http.converter.ResourceHttpMessageConverter.writeInternal(ResourceHttpMessageConverter.java:45)
        at org.springframework.http.converter.AbstractHttpMessageConverter.write(AbstractHttpMessageConverter.java:227)
        at org.springframework.web.servlet.resource.ResourceHttpRequestHandler.handleRequest(ResourceHttpRequestHandler.java:489)
        at org.springframework.web.servlet.mvc.HttpRequestHandlerAdapter.handle(HttpRequestHandlerAdapter.java:53)
        at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1040)
        at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:943)
        at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006)
        at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:898)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:503)
        at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:590)
        at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:755)
        at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1617)
        at XXX.web.filter.CachingHttpHeadersFilter.doFilter(CachingHttpHeadersFilter.java:52)
        at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1604)

sbordet · 2020-01-08T16:03:24Z

@electrum thanks for the reproducer, we were able to confirm that's a Jetty bug.
We are working on a fix.

Signed-off-by: Joakim Erdfelt <joakim.erdfelt@gmail.com>

joakime · 2020-01-08T21:15:40Z

A smaller testcase that can replicate this can be found in branch jetty-9.4.x-4461-aggregate-gzip-blocked

See: https://github.com/eclipse/jetty.project/blob/jetty-9.4.x-4461-aggregate-gzip-blocked/jetty-servlet/src/test/java/org/eclipse/jetty/servlet/AggregateBufferTest.java

Signed-off-by: Joakim Erdfelt <joakim.erdfelt@gmail.com>

joakime · 2020-01-08T22:01:32Z

Opened PR #4465

Added tests to check that aggregation continues after first flush of an aggregated buffer (this triggers both #4461 and the discovered bug of not aggregating because of empty at capacity aggregate buffer). Added getAggregateSize method that does a compact to avoid empty at capacity aggregate buffer Call onWriteComplete if residue of an overflow aggregation can itself be aggregated. Signed-off-by: Greg Wilkins <gregw@webtide.com>

Removed implicit compact from GzipHandler Signed-off-by: Greg Wilkins <gregw@webtide.com>

Improve test coverage Signed-off-by: Greg Wilkins <gregw@webtide.com>

Remove case that can never happen. Signed-off-by: Greg Wilkins <gregw@webtide.com>

updates from review Signed-off-by: Greg Wilkins <gregw@webtide.com>

joakime · 2020-01-09T17:32:02Z

Alternate PR #4466 has been opened. (PR #4465 has been closed)

Fix jetty#4461 HttpOutput Aggregation (jetty#4466)

Pulls in upstream fix jetty/jetty.project#4461

* add gzip transport support * upgrade jetty to 9.4.28.v20200408 Pulls in upstream fix jetty/jetty.project#4461

joakime added a commit that referenced this issue Jan 8, 2020

Issue #4461 - Servlet that replicates the BLOCKED issue

5fc543f

Signed-off-by: Joakim Erdfelt <joakim.erdfelt@gmail.com>

joakime added a commit that referenced this issue Jan 8, 2020

Issue #4461 - Addressing aggregation concerns in HttpOutput and Gzip

339e597

Signed-off-by: Joakim Erdfelt <joakim.erdfelt@gmail.com>

joakime mentioned this issue Jan 8, 2020

Issue #4461 - Aggregate Buffer issue with GzipHandler #4465

Closed

gregw mentioned this issue Jan 9, 2020

Fix #4461 HttpOutput Aggregation #4466

Merged

gregw added a commit that referenced this issue Jan 9, 2020

Issue #4461 HttpOutput Aggregation

5a36100

Removed implicit compact from GzipHandler Signed-off-by: Greg Wilkins <gregw@webtide.com>

gregw added a commit that referenced this issue Jan 9, 2020

Issue #4461 HttpOutput Aggregation

356b1c7

Improve test coverage Signed-off-by: Greg Wilkins <gregw@webtide.com>

gregw added a commit that referenced this issue Jan 9, 2020

Issue #4461 HttpOutput Aggregation

bda1db7

Remove case that can never happen. Signed-off-by: Greg Wilkins <gregw@webtide.com>

gregw added a commit that referenced this issue Jan 9, 2020

Issue #4461 HttpOutput Aggregation

5cbcfbd

updates from review Signed-off-by: Greg Wilkins <gregw@webtide.com>

gregw closed this as completed in 96f6f2b Jan 9, 2020

tswstarplanet mentioned this issue Jan 12, 2020

Fix #4461 HttpOutput Aggregation (#4466) tswstarplanet/jetty.project#3

Merged

tswstarplanet added a commit to tswstarplanet/jetty.project that referenced this issue Jan 12, 2020

Merge pull request #3 from eclipse/jetty-9.4.x

1031705

Fix jetty#4461 HttpOutput Aggregation (jetty#4466)

sbordet mentioned this issue Jan 14, 2020

Jetty 9.4.25 stops responding after a few hours #4476

Closed

sbordet added this to To do in Jetty 9.4.26 via automation Jan 15, 2020

sbordet moved this from To do to Done in Jetty 9.4.26 Jan 15, 2020

joakime mentioned this issue Jan 16, 2020

QueuedThreadPool should support ThreadFactory behaviors #4121

Closed

sbordet mentioned this issue Feb 3, 2020

SelectorManager: Random close error #4297

Closed

oleborup mentioned this issue Feb 5, 2020

Upgrade to Jetty 9.4.26.v20200117 spring-projects/spring-boot#20040

Closed

phemmer added a commit to phemmer/minecraft-prometheus-exporter that referenced this issue May 16, 2020

upgrade jetty to 9.4.28.v20200408

f3763a5

Pulls in upstream fix jetty/jetty.project#4461

phemmer mentioned this issue May 16, 2020

add gzip transport support sladkoff/minecraft-prometheus-exporter#42

Merged

sladkoff pushed a commit to sladkoff/minecraft-prometheus-exporter that referenced this issue May 16, 2020

add gzip transport support (#42)

574b723

* add gzip transport support * upgrade jetty to 9.4.28.v20200408 Pulls in upstream fix jetty/jetty.project#4461

dzikoysk mentioned this issue May 27, 2020

Intermittent Exception while downloading dependencies dzikoysk/reposilite#84

Closed

jansupol mentioned this issue Jun 24, 2020

ChunkedOutput race condition eclipse-ee4j/jersey#4493

Closed

joakime mentioned this issue Jun 4, 2021

EventSource does not work with GzipHandler #4317

Closed

This was referenced Jan 17, 2023

PLEASE FIX OR REPORT | Unexpected exception thrown for events-async-8 Consensys/teku#6654

Closed

Better handling sse sendComment error Consensys/teku#6694

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

IllegalStateException in HttpOutput with Jersey #4461

IllegalStateException in HttpOutput with Jersey #4461

electrum commented Jan 7, 2020

gbrehmer commented Jan 8, 2020

sbordet commented Jan 8, 2020

joakime commented Jan 8, 2020

joakime commented Jan 8, 2020

joakime commented Jan 9, 2020

IllegalStateException in HttpOutput with Jersey #4461

IllegalStateException in HttpOutput with Jersey #4461

Comments

electrum commented Jan 7, 2020

gbrehmer commented Jan 8, 2020

sbordet commented Jan 8, 2020

joakime commented Jan 8, 2020

joakime commented Jan 8, 2020

joakime commented Jan 9, 2020