-
Notifications
You must be signed in to change notification settings - Fork 375
Description
Affects version: 3.1.11, (probably 2.47 and 3.0.18, not tested)
We have a test where we simulate a system failure and test the behavior of our application during the shutdown. This test has started to fail when we have upgraded jetty from 3.1.9 to 3.1.11. We observe that connections that were open during the shutdown get an unexpected 200 response code, however our application can only produce 204 response code. From code analysis I can tell that the following is happening:
org.eclipse.jetty.ee10.servlet.ServletChannelState#onError is called and it should do a couple of things:
- Invoke listeners
runInContext(asyncEvent, () -> { for (AsyncListener listener : asyncListeners) { try { listener.onError(asyncEvent);
And then call org.eclipse.jetty.ee10.servlet.ServletChannelState#sendError(java.lang.Throwable) method that would set 500 response code and would update an important in future variable _sendError = true;
From 3.1.11, more precisely from the commit 431b933 of @jansupol , there is now a CompletedAsyncContextListener, that would do the following:
`
@OverRide
public void onError(AsyncEvent event) throws IOException {
complete();
}
public void complete() {
completed.set(true);
final AsyncContext asyncContext = asyncContextRef.getAndSet(null);
if (asyncContext != null) {
asyncContext.complete();
}
}
`
So the complete method, is actually calling back jetty's ServletChannelState#complete and causing a response to be completed. However, since the previously mentioned _sendError is not set yet. Jetty assumes that the request was handled and sends a default 200 response.
So, to my understanding, this sounds a bit wrong, why does CompletedAsyncContextListener#onError calls the complete method? While I am not a big specialist of neither of Jersey, Jetty or servlets, this sounds wrong. From now on I need your help to find the problem and try to find a solution for it.
Logs with Jersey 3.1.9:
`
[2025-12-09 11:26:15,746] [DEBUG] [] [o.e.j.e.servlet.ServletChannelState] [] - onError s=HANDLING rs=ASYNC os=OPEN is=IDLE awp=false se=false i=false al=1
org.eclipse.jetty.io.EofException: null
at org.eclipse.jetty.server.internal.HttpChannelState.onClose(HttpChannelState.java:525)
at org.eclipse.jetty.server.internal.HttpConnection.close(HttpConnection.java:628)
at org.eclipse.jetty.util.IO.close(IO.java:615)
at org.eclipse.jetty.util.IO.close(IO.java:630)
at org.eclipse.jetty.io.ManagedSelector$CloseConnections.update(ManagedSelector.java:1000)
at org.eclipse.jetty.io.ManagedSelector$SelectorProducer.processUpdates(ManagedSelector.java:577)
at org.eclipse.jetty.io.ManagedSelector$SelectorProducer.produce(ManagedSelector.java:544)
at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.produceTask(AdaptiveExecutionStrategy.java:526)
at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.tryProduce(AdaptiveExecutionStrategy.java:251)
at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.run(AdaptiveExecutionStrategy.java:204)
at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:311)
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:981)
at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.doRunJob(QueuedThreadPool.java:1211)
at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1166)
at java.base/java.lang.Thread.run(Thread.java:1474)
[2025-12-09 11:26:15,747] [DEBUG] [] [o.e.j.e.servlet.ServletChannelState] [] - complete ServletChannelState@1948a2f6{s=HANDLING rs=ASYNC os=OPEN is=IDLE awp=false se=false i=false al=1}
[2025-12-09 11:26:15,747] [DEBUG] [] [o.e.j.e.servlet.ServletChannelState] [] - unhandle ServletChannelState@1948a2f6{s=HANDLING rs=COMPLETE os=OPEN is=IDLE awp=false se=false i=false al=1}
[2025-12-09 11:26:15,747] [DEBUG] [] [o.e.j.e.servlet.ServletChannelState] [] - nextAction(false) COMPLETE ServletChannelState@1948a2f6{s=HANDLING rs=COMPLETING os=OPEN is=IDLE awp=false se=false i=false al=1}
[2025-12-09 11:26:15,747] [DEBUG] [] [o.e.j.ee10.servlet.ServletChannel] [] - action COMPLETE ServletChannel@41850adb{s=ServletChannelState@1948a2f6{s=HANDLING rs=COMPLETING os=OPEN is=IDLE awp=false se=false i=false al=1},r=0,c=false/false,a=HANDLING,uri=http://localhost:8080/test-product/v1/persistence/scenarios/persist_up_to,age=1133}
[2025-12-09 11:26:15,747] [DEBUG] [] [o.e.jetty.ee10.servlet.HttpOutput] [] - complete(Callback@74831062{NON_BLOCKING, org.eclipse.jetty.ee10.servlet.ServletChannel$$Lambda/0x00000000a11239f8@6d954f64,org.eclipse.jetty.ee10.servlet.ServletChannel$$Lambda/0x00000000a1123e58@1e06679f}) s=CLOSING,api=BLOCKED,sc=false,e=null s=false e=null, c=HeapByteBuffer@3b90258d[p=0,l=0,c=0,r=0]={<<<>>>}
[2025-12-09 11:26:15,747] [DEBUG] [] [o.e.j.server.handler.EventsHandler] [] - onResponseBegin of @1582a761{POST@22588103 http://localhost:8080/test-product/v1/persistence/scenarios/persist_up_to HTTP/1.1} status=0 headers=Vary: Accept-Encoding
Set-Cookie: rememberMe=deleteMe; Path=/; Max-Age=0; Expires=Mon, 08-Dec-2025 11:26:14 GMT; SameSite=lax
[2025-12-09 11:26:15,747] [DEBUG] [] [o.e.j.s.internal.ResponseHttpFields] [] - org.eclipse.jetty.server.internal.ResponseHttpFields@796ea5b3 committed
[2025-12-09 11:26:15,747] [DEBUG] [] [o.e.j.s.internal.HttpChannelState] [] - writing last=true HeapByteBuffer@3b90258d[p=0,l=0,c=0,r=0]={<<<>>>} ChannelResponse@3ec73b95{200,POST@22588103 http://localhost:8080/test-product/v1/persistence/scenarios/persist_up_to HTTP/1.1}
[2025-12-09 11:26:15,747] [DEBUG] [] [o.e.j.server.internal.HttpConnection] [] - generate: NEED_HEADER for SendCallback@13d0894d[PROCESSING][i=HTTP/1.1{s=200,h=3,cl=0},cb=ChannelResponse@3ec73b95{200,POST@22588103 http://localhost:8080/test-product/v1/persistence/scenarios/persist_up_to HTTP/1.1}] (null,[p=0,l=0,c=0,r=0],true)@start
[2025-12-09 11:26:15,747] [DEBUG] [] [o.eclipse.jetty.http.HttpGenerator] [] - generateHeaders HTTP/1.1{s=200,h=3,cl=0} last=true content=HeapByteBuffer@3b90258d[p=0,l=0,c=0,r=0]={<<<>>>}
[2025-12-09 11:26:15,747] [DEBUG] [] [o.eclipse.jetty.http.HttpGenerator] [] - org.eclipse.jetty.server.internal.ResponseHttpFields@796ea5b3
[2025-12-09 11:26:15,747] [DEBUG] [] [o.eclipse.jetty.http.HttpGenerator] [] - endOfContent CONTENT_LENGTH content-Length 0
`
Logs with Jersey 3.1.11:
[2025-12-09 11:34:38,211] [DEBUG] [] [o.e.j.e.servlet.ServletChannelState] [] - onError s=HANDLING rs=ASYNC os=OPEN is=IDLE awp=false se=false i=false al=0 org.eclipse.jetty.io.EofException: null at org.eclipse.jetty.server.internal.HttpChannelState.onClose(HttpChannelState.java:525) at org.eclipse.jetty.server.internal.HttpConnection.close(HttpConnection.java:628) at org.eclipse.jetty.util.IO.close(IO.java:615) at org.eclipse.jetty.util.IO.close(IO.java:630) at org.eclipse.jetty.io.ManagedSelector$CloseConnections.update(ManagedSelector.java:1000) at org.eclipse.jetty.io.ManagedSelector$SelectorProducer.processUpdates(ManagedSelector.java:577) at org.eclipse.jetty.io.ManagedSelector$SelectorProducer.produce(ManagedSelector.java:544) at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.produceTask(AdaptiveExecutionStrategy.java:526) at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.tryProduce(AdaptiveExecutionStrategy.java:251) at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.run(AdaptiveExecutionStrategy.java:204) at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:311) at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:981) at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.doRunJob(QueuedThreadPool.java:1211) at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1166) at java.base/java.lang.Thread.run(Thread.java:1474) [2025-12-09 11:34:38,211] [DEBUG] [] [o.e.j.e.servlet.ServletChannelState] [] - unhandle ServletChannelState@2bb6d405{s=HANDLING rs=ASYNC os=OPEN is=IDLE awp=false se=false i=false al=0} [2025-12-09 11:34:38,211] [DEBUG] [] [o.e.j.e.servlet.ServletChannelState] [] - nextAction(false) WAIT ServletChannelState@2bb6d405{s=WAITING rs=ASYNC os=OPEN is=IDLE awp=false se=false i=false al=0} [2025-12-09 11:34:38,211] [DEBUG] [] [o.e.j.ee10.servlet.ServletChannel] [] - action WAIT ServletChannel@32f3e7ad{s=ServletChannelState@2bb6d405{s=WAITING rs=ASYNC os=OPEN is=IDLE awp=false se=false i=false al=0},r=0,c=false/false,a=WAITING,uri=http://localhost:8080/test-product/v1/persistence/scenarios/persist_up_to,age=11483} [2025-12-09 11:34:38,211] [DEBUG] [] [o.e.j.ee10.servlet.ServletChannel] [] - !handle WAIT ServletChannel@32f3e7ad{s=ServletChannelState@2bb6d405{s=WAITING rs=ASYNC os=OPEN is=IDLE awp=false se=false i=false al=0},r=0,c=false/false,a=WAITING,uri=http://localhost:8080/test-product/v1/persistence/scenarios/persist_up_to,age=11483} [2025-12-09 11:34:38,211] [DEBUG] [] [o.e.j.util.thread.SerializedInvoker] [] - Next link is null, execution is over in HttpChannelSerializedInvoker@200f2038{name=HttpChannelState_readInvoker,tail=null,invoker=null} [2025-12-09 11:34:38,211] [DEBUG] [] [o.eclipse.jetty.io.AbstractEndPoint] [] - close SocketChannelEndPoint@a181e42[{l=/127.0.0.1:8080,r=/127.0.0.1:44324,OPEN,fill=-,flush=-,to=11485/34321}{io=0/0,kio=0,kro=1}]->[HttpConnection@1dd4f3c2[p=HttpParser{s=END,166 of 166},g=HttpGenerator@2a44130f{s=START}]=>HttpChannelState@2491e80f{handling=null, handled=true, send=SENDING, completed=false, request=POST@511c9a13 http://localhost:8080/test-product/v1/persistence/scenarios/persist_up_to HTTP/1.1}] [2025-12-09 11:34:38,211] [DEBUG] [] [o.eclipse.jetty.io.AbstractEndPoint] [] - close(null) SocketChannelEndPoint@a181e42[{l=/127.0.0.1:8080,r=/127.0.0.1:44324,OPEN,fill=-,flush=-,to=11485/34321}{io=0/0,kio=0,kro=1}]->[HttpConnection@1dd4f3c2[p=HttpParser{s=END,166 of 166},g=HttpGenerator@2a44130f{s=START}]=>HttpChannelState@2491e80f{handling=null, handled=true, send=SENDING, completed=false, request=POST@511c9a13 http://localhost:8080/test-product/v1/persistence/scenarios/persist_up_to HTTP/1.1}] [2025-12-09 11:34:38,211] [DEBUG] [] [o.e.j.io.SelectableChannelEndPoint] [] - doClose SocketChannelEndPoint@a181e42[{l=/127.0.0.1:8080,r=/127.0.0.1:44324,CLOSED,fill=-,flush=-,to=11485/34321}{io=0/0,kio=0,kro=1}]->[HttpConnection@1dd4f3c2[p=HttpParser{s=END,166 of 166},g=HttpGenerator@2a44130f{s=START}]=>HttpChannelState@2491e80f{handling=null, handled=true, send=SENDING, completed=false, request=POST@511c9a13 http://localhost:8080/test-product/v1/persistence/scenarios/persist_up_to HTTP/1.1}] [2025-12-09 11:34:38,211] [DEBUG] [] [org.eclipse.jetty.io.FillInterest] [] - onClose FillInterest@1e6145bc{null}