IllegalStateException - Attempt to release request processing resources has failed for a request. (Trino 442 version failure)

[sajjoseph]

Jetty version(s)

JETTY 12.0.7

Jetty Environment

ee10

Java version/vendor (use: java -version) openjdk version "21.0.1" 2023-10-17 LTS OS type/version Mac Description

Receiving the following exception in Trino 442 version

2024-03-20T19:32:59.743Z        WARN    async-http-response-2   org.glassfish.jersey.server.ServerRuntime$Responder     Attempt to release request processing resources has failed for a request.
java.lang.IllegalStateException: s=HANDLING rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=false al=0
        at org.eclipse.jetty.ee10.servlet.ServletChannelState.complete(ServletChannelState.java:772)
        at org.eclipse.jetty.ee10.servlet.AsyncContextState.complete(AsyncContextState.java:61)
        at org.glassfish.jersey.servlet.async.AsyncContextDelegateProviderImpl$ExtensionImpl.complete(AsyncContextDelegateProviderImpl.java:102)
        at org.glassfish.jersey.servlet.internal.ResponseWriter.commit(ResponseWriter.java:173)
        at org.glassfish.jersey.server.ContainerResponse.close(ContainerResponse.java:404)
        at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:184)
        at java.base/java.util.stream.ReferencePipeline$2$1.accept(ReferencePipeline.java:179)
        at java.base/java.util.Spliterators$ArraySpliterator.forEachRemaining(Spliterators.java:1024)
        at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509)
        at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499)
        at java.base/java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:151)
        at java.base/java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:174)
        at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
        at java.base/java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:596)
        at org.glassfish.jersey.server.ServerRuntime$Responder.release(ServerRuntime.java:774)
        at org.glassfish.jersey.server.ServerRuntime$Responder.process(ServerRuntime.java:376)
        at org.glassfish.jersey.server.ServerRuntime$AsyncResponder$3.run(ServerRuntime.java:905)
        at org.glassfish.jersey.internal.Errors$1.call(Errors.java:248)
        at org.glassfish.jersey.internal.Errors$1.call(Errors.java:244)
        at org.glassfish.jersey.internal.Errors.process(Errors.java:292)
        at org.glassfish.jersey.internal.Errors.process(Errors.java:274)
        at org.glassfish.jersey.internal.Errors.process(Errors.java:244)
        at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:265)
        at org.glassfish.jersey.server.ServerRuntime$AsyncResponder.resume(ServerRuntime.java:937)
        at org.glassfish.jersey.server.ServerRuntime$AsyncResponder.resume(ServerRuntime.java:893)
        at io.airlift.jaxrs.AsyncResponseHandler$1.onSuccess(AsyncResponseHandler.java:99)
        at com.google.common.util.concurrent.Futures$CallbackListener.run(Futures.java:1135)
        at io.airlift.concurrent.BoundedExecutor.drainQueue(BoundedExecutor.java:79)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
        at java.base/java.lang.Thread.run(Thread.java:1583)

How to reproduce?

Use DBeaver to trigger a query that pulls large volume of data from a Trino cluster and cancel the query after receiving some data (don't wait till the entire data transfer)

[sajjoseph]

Two more exceptions:

NullPointerException

2024-03-21T01:53:48.702Z	WARN	async-http-response-20	org.eclipse.jetty.util.Blocker	Blocking.Shared incomplete
2024-03-21T01:53:48.702Z	ERROR	async-http-response-20	org.glassfish.jersey.server.ServerRuntime$Responder	Error while closing the output stream in order to commit response.
java.lang.NullPointerException: Cannot invoke "org.eclipse.jetty.server.Response.write(boolean, java.nio.ByteBuffer, org.eclipse.jetty.util.Callback)" because the return value of "org.eclipse.jetty.ee10.servlet.ServletChannel.getResponse()" is null
	at org.eclipse.jetty.ee10.servlet.HttpOutput.channelWrite(HttpOutput.java:204)
	at org.eclipse.jetty.ee10.servlet.HttpOutput.channelWrite(HttpOutput.java:189)
	at org.eclipse.jetty.ee10.servlet.HttpOutput.flush(HttpOutput.java:672)
	at io.airlift.http.server.TimingFilter$TimedServletOutputStream.flush(TimingFilter.java:282)
	at org.glassfish.jersey.servlet.internal.ResponseWriter$NonCloseableOutputStreamWrapper.flush(ResponseWriter.java:307)
	at org.glassfish.jersey.message.internal.CommittingOutputStream.flush(CommittingOutputStream.java:263)
	at org.glassfish.jersey.message.internal.OutboundMessageContext.close(OutboundMessageContext.java:864)
	at org.glassfish.jersey.server.ContainerResponse.close(ContainerResponse.java:403)
	at org.glassfish.jersey.server.ServerRuntime$Responder.writeResponse(ServerRuntime.java:749)
	at org.glassfish.jersey.server.ServerRuntime$Responder.processResponse(ServerRuntime.java:385)
	at org.glassfish.jersey.server.ServerRuntime$Responder.process(ServerRuntime.java:375)
	at org.glassfish.jersey.server.ServerRuntime$AsyncResponder$3.run(ServerRuntime.java:905)
	at org.glassfish.jersey.internal.Errors$1.call(Errors.java:248)
	at org.glassfish.jersey.internal.Errors$1.call(Errors.java:244)
	at org.glassfish.jersey.internal.Errors.process(Errors.java:292)
	at org.glassfish.jersey.internal.Errors.process(Errors.java:274)
	at org.glassfish.jersey.internal.Errors.process(Errors.java:244)
	at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:265)
	at org.glassfish.jersey.server.ServerRuntime$AsyncResponder.resume(ServerRuntime.java:937)
	at org.glassfish.jersey.server.ServerRuntime$AsyncResponder.resume(ServerRuntime.java:893)
	at io.airlift.jaxrs.AsyncResponseHandler$1.onSuccess(AsyncResponseHandler.java:99)
	at com.google.common.util.concurrent.Futures$CallbackListener.run(Futures.java:1135)
	at io.airlift.concurrent.BoundedExecutor.drainQueue(BoundedExecutor.java:79)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
	at java.base/java.lang.Thread.run(Thread.java:1583)

IllegalStateException Error while closing the output stream in order to commit response.

2024-03-21T01:53:48.712Z	ERROR	async-http-response-21	org.glassfish.jersey.server.ServerRuntime$Responder	Error while closing the output stream in order to commit response.
java.lang.IllegalStateException: s=IDLE rs=BLOCKING os=ABORTED is=IDLE awp=false se=false i=true al=0
	at org.eclipse.jetty.ee10.servlet.ServletChannelState.complete(ServletChannelState.java:772)
	at org.eclipse.jetty.ee10.servlet.AsyncContextState.complete(AsyncContextState.java:61)
	at org.glassfish.jersey.servlet.async.AsyncContextDelegateProviderImpl$ExtensionImpl.complete(AsyncContextDelegateProviderImpl.java:102)
	at org.glassfish.jersey.servlet.internal.ResponseWriter.commit(ResponseWriter.java:173)
	at org.glassfish.jersey.server.ContainerResponse.close(ContainerResponse.java:404)
	at org.glassfish.jersey.server.ServerRuntime$Responder.writeResponse(ServerRuntime.java:749)
	at org.glassfish.jersey.server.ServerRuntime$Responder.processResponse(ServerRuntime.java:385)
	at org.glassfish.jersey.server.ServerRuntime$Responder.process(ServerRuntime.java:375)
	at org.glassfish.jersey.server.ServerRuntime$AsyncResponder$3.run(ServerRuntime.java:905)
	at org.glassfish.jersey.internal.Errors$1.call(Errors.java:248)
	at org.glassfish.jersey.internal.Errors$1.call(Errors.java:244)
	at org.glassfish.jersey.internal.Errors.process(Errors.java:292)
	at org.glassfish.jersey.internal.Errors.process(Errors.java:274)
	at org.glassfish.jersey.internal.Errors.process(Errors.java:244)
	at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:265)
	at org.glassfish.jersey.server.ServerRuntime$AsyncResponder.resume(ServerRuntime.java:937)
	at org.glassfish.jersey.server.ServerRuntime$AsyncResponder.resume(ServerRuntime.java:893)
	at io.airlift.jaxrs.AsyncResponseHandler$1.onSuccess(AsyncResponseHandler.java:99)
	at com.google.common.util.concurrent.Futures$CallbackListener.run(Futures.java:1135)
	at io.airlift.concurrent.BoundedExecutor.drainQueue(BoundedExecutor.java:79)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
	at java.base/java.lang.Thread.run(Thread.java:1583)

[joakime]

java.lang.NullPointerException: Cannot invoke "org.eclipse.jetty.server.Response.write(boolean, java.nio.ByteBuffer, org.eclipse.jetty.util.Callback)" because the return value of "org.eclipse.jetty.ee10.servlet.ServletChannel.getResponse()" is null

That stacktrace looks suspiciously like jersey is using the response after it has been completed (and possibly even been recycled).

[sbordet]

@sajjoseph is there a way we can reproduce this ourselves? For example, it is a test in the Trino test suite that fails?

[sajjoseph]

I am not aware of an existing Trino test case that causes this error. I will look for one though.

End user's machine                   Local Trino server               Remote Trino Server
-------------------                    -------------                  ---------------
DBeaver  -> Trino JDBC driver   ->    Jetty server (12.0.7)  +   ->     Database
                                      Trino JDBC driver          

Failure is happening between Local Trino Server and Remote Trino Server communication. DBeaver will trigger the query cancel and then Local Trino server will trigger cancel against the Remote Trino server. This is when the local Trino Server's log file has the above exceptions. Note that this was not occurring with earlier versions of Jetty (11.x series). Trino team very recently updated Trino to use Jetty 12.0.7 with ee10 and we started seeing these exceptions.

[sajjoseph]

Quick update: 12.0.8 version seems to have the issues fixed. I am continuously testing and the above exception is not occurring.

Thanks!