jetty.project icon indicating copy to clipboard operation
jetty.project copied to clipboard

Failed to serve resource java.lang.IllegalStateException: s=HANDLING rs=ASYNC os=OPEN is=IDLE awp=false se=false i=true al=0

Open kohlschuetter opened this issue 1 year ago • 9 comments
trafficstars

Jetty version(s) 12.0.8 onwards

Jetty Environment ee10

Java version/vendor (use: java -version) any

OS type/version any, macOS

Description

While trying to serve a path that redirects to an "index.html" file, jetty 12.0.8 or newer fails with an IllegalStateException. Apparently, the "RequestState" was already ASYNC, and so the test in startAsync fails.

4279 [qtp592617454-62] WARN org.eclipse.jetty.server.ResourceService - Failed to serve resource: /posts/some/path/
java.lang.IllegalStateException: s=HANDLING rs=ASYNC os=OPEN is=IDLE awp=false se=false i=true al=0
	at org.eclipse.jetty.ee10.servlet.ServletChannelState.startAsync(ServletChannelState.java:576)
	at org.eclipse.jetty.ee10.servlet.ServletApiRequest.startAsync(ServletApiRequest.java:1362)
	at jakarta.servlet.ServletRequestWrapper.startAsync(ServletRequestWrapper.java:350)
	at org.eclipse.jetty.ee10.servlet.ResourceServlet.doGet(ResourceServlet.java:496)
	at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:527)
	at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:614)
	at org.eclipse.jetty.ee10.servlet.ServletHolder.handle(ServletHolder.java:736)
	at org.eclipse.jetty.ee10.servlet.ServletHandler$ChainEnd.doFilter(ServletHandler.java:1614)
	at org.eclipse.jetty.ee10.servlet.ServletHandler$MappedServlet.handle(ServletHandler.java:1547)
	at org.eclipse.jetty.ee10.servlet.Dispatcher.forward(Dispatcher.java:126)
	at org.eclipse.jetty.ee10.servlet.ResourceServlet$ServletResourceService.serveWelcome(ResourceServlet.java:691)
	at org.eclipse.jetty.server.ResourceService.handleWelcomeAction(ResourceService.java:527)
	at org.eclipse.jetty.server.ResourceService.welcome(ResourceService.java:516)
	at org.eclipse.jetty.server.ResourceService.sendWelcome(ResourceService.java:468)
	at org.eclipse.jetty.server.ResourceService.doGet(ResourceService.java:169)
	at org.eclipse.jetty.ee10.servlet.ResourceServlet.doGet(ResourceServlet.java:498)
	at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:527)
	at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:614)
	at org.eclipse.jetty.ee10.servlet.ServletHolder.handle(ServletHolder.java:736)
	at org.eclipse.jetty.ee10.servlet.ServletHandler$ChainEnd.doFilter(ServletHandler.java:1614)
	at org.eclipse.jetty.ee10.websocket.servlet.WebSocketUpgradeFilter.doFilter(WebSocketUpgradeFilter.java:195)
	at org.eclipse.jetty.ee10.servlet.FilterHolder.doFilter(FilterHolder.java:205)
	at org.eclipse.jetty.ee10.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1586)
	at org.eclipse.jetty.ee10.servlet.ServletHandler$MappedServlet.handle(ServletHandler.java:1547)
	at org.eclipse.jetty.ee10.servlet.ServletChannel.dispatch(ServletChannel.java:824)
	at org.eclipse.jetty.ee10.servlet.ServletChannel.handle(ServletChannel.java:436)
	at org.eclipse.jetty.ee10.servlet.ServletHandler.handle(ServletHandler.java:464)
	at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:575)
	at org.eclipse.jetty.ee10.servlet.SessionHandler.handle(SessionHandler.java:703)
	at org.eclipse.jetty.server.handler.ContextHandler.handle(ContextHandler.java:1060)
	at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:181)
	at org.eclipse.jetty.server.Server.handle(Server.java:181)
	at org.eclipse.jetty.server.internal.HttpChannelState$HandlerInvoker.run(HttpChannelState.java:648)
	at org.eclipse.jetty.server.internal.HttpConnection.onFillable(HttpConnection.java:403)
	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:322)
	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:99)
	at org.eclipse.jetty.io.SelectableChannelEndPoint$1.run(SelectableChannelEndPoint.java:53)
	at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.runTask(AdaptiveExecutionStrategy.java:478)
	at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.consumeTask(AdaptiveExecutionStrategy.java:441)
	at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.tryProduce(AdaptiveExecutionStrategy.java:293)
	at org.eclipse.jetty.util.thread.strategy.AdaptiveExecutionStrategy.run(AdaptiveExecutionStrategy.java:201)
	at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:311)
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:979)
	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.doRunJob(QueuedThreadPool.java:1209)
	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1164)
	at java.base/java.lang.Thread.run(Thread.java:1589)

How to reproduce? This is from an embedded setup I can't currently share, but I hope the stacktrace above is sufficient (notice the absence of any application-specific stacktrace elements)

However, allowing the existing requestState == ASYNC fixes the issue:

in ServletChannelState.startAsync:

            if (_state != State.HANDLING || (_requestState != RequestState.BLOCKING
                && _requestState != RequestState.ASYNC && _requestState != RequestState.ERRORING))
                throw new IllegalStateException(this.getStatusStringLocked());

kohlschuetter avatar Aug 09 '24 15:08 kohlschuetter

There's something missing from this.

Is this the result of a RequestDispatch to index.html?

joakime avatar Aug 09 '24 16:08 joakime

What is your DefaultServlet (or ResourceServlet) configuration? Can you do a WebAppContext.dump() and report the results? (do not delete lines, but feel free to XXXX out any sensitive information inside of a line)

joakime avatar Aug 09 '24 16:08 joakime

WebAppContext.dump (redacted)

oeje10w.WebAppContext@74455848{/blog,/blog,b=[file:/private/var/folders/20/lqqqg9s974sg640km8nj3klm0000gn/T/dumbo-workdir160541941742846541/blog/webapp/, file:/redacted/workspace/redacted/target-eclipse/classes/redacted/webapp/, file:/redacted/workspace/dumbo/dumbo-core/target-eclipse/classes/redacted/jettydir-overlay/],a=AVAILABLE,h=oeje10s.SessionHandler@480aa870{STARTED}}{[file:/private/var/folders/20/lqqqg9s974sg640km8nj3klm0000gn/T/dumbo-workdir160541941742846541/blog/webapp/, file:/redacted/workspace/redacted/target-eclipse/classes/redacted/webapp/, file:/redacted/workspace/dumbo/dumbo-core/target-eclipse/classes/redacted/jettydir-overlay/]} - STARTED
+= SymlinkAllowedResourceAliasChecker@6c00236{base=[file:/private/var/folders/20/lqqqg9s974sg640km8nj3klm0000gn/T/dumbo-workdir160541941742846541/blog/webapp/, file:/redacted/workspace/redacted/target-eclipse/classes/redacted/webapp/, file:/redacted/workspace/dumbo/dumbo-core/target-eclipse/classes/redacted/jettydir-overlay/],protected=[/META-INF, /WEB-INF]} - STARTED
+- org.eclipse.jetty.util.DecoratedObjectFactory[decorators=3]
|  +: org.eclipse.jetty.ee10.plus.webapp.PlusDecorator@6807b4f9
|  +: org.eclipse.jetty.util.DeprecationWarning@118d57a4
|  +: org.eclipse.jetty.ee10.annotations.AnnotationDecorator@6e9e63ae
+= oeje10s.SessionHandler@480aa870{STARTED} - STARTED
|  += oeje10ss.ConstraintSecurityHandler@68490df9{STARTED} - STARTED
|  |  +- knownAuthenticatorFactories size=1
|  |  |  +> org.eclipse.jetty.security.DefaultAuthenticatorFactory@3dbcdc75
|  |  += oeje10s.ServletHandler@46f79c11{STARTED} - STARTED
|  |  |  +> listeners oeje10s.ServletHandler@46f79c11{STARTED} size=1
|  |  |  |  +> org.eclipse.jetty.ee10.servlet.listener.IntrospectorCleaner@5be90472{src=DESCRIPTOR:jar:file:/Users/redacted/.m2/repository/org/eclipse/jetty/ee10/jetty-ee10-webapp/12.0.12/jetty-ee10-webapp-12.0.12.jar!/org/eclipse/jetty/ee10/webapp/webdefault-ee10.xml} - STARTED
|  |  |  +> filters oeje10s.ServletHandler@46f79c11{STARTED} size=8
|  |  |  |  +> org.eclipse.jetty.ee10.websocket.servlet.WebSocketUpgradeFilter==org.eclipse.jetty.ee10.websocket.servlet.WebSocketUpgradeFilter@18131296{inst=true,async=true,src=EMBEDDED:<null>} - STARTED
|  |  |  |  |  +> org.eclipse.jetty.ee10.websocket.servlet.WebSocketUpgradeFilter@7beffc33
|  |  |  |  |     +> ConfigurationCustomizer@206bc84f{idleTimeout=null, writeTimeout=null, autoFragment=null, maxFrameSize=null, inputBufferSize=null, outputBufferSize=null, maxBinaryMessageSize=null, maxTextMessageSize=null, maxOutgoingFrames=null}
|  |  |  |  |     +> org.eclipse.jetty.websocket.core.server.WebSocketMappings@5a86cf47
|  |  |  |  |        +> PathMappings[size=0]
|  |  |  |  |           +> ju.TreeSet@0(size=0)
|  |  |  |  +> redacted.core.LFilter-49dc7102==redacted.core.LFilter@49dc7102{inst=true,async=true,src=EMBEDDED:<null>} - STARTED
|  |  |  |  |  +> redacted.core.LFilter@6a2ff509
|  |  |  |  +> redacted.core.CFilter-3a6bb9bf==redacted.core.CFilter@3a6bb9bf{inst=true,async=true,src=EMBEDDED:<null>} - STARTED
|  |  |  |  |  +> redacted.core.CFilter@854f0d0
|  |  |  |  +> redacted.core.LFilter-34f7cfd9==redacted.core.LFilter@34f7cfd9{inst=true,async=true,src=EMBEDDED:<null>} - STARTED
|  |  |  |  |  +> redacted.core.LFilter@28b8843b
|  |  |  |  +> redacted.core.LFilter-65f095f8==redacted.core.LFilter@65f095f8{inst=true,async=true,src=EMBEDDED:<null>} - STARTED
|  |  |  |  |  +> redacted.core.LFilter@64c68780
|  |  |  |  +> redacted.core.HtmlJspFilter-59af0466==redacted.core.HtmlJspFilter@59af0466{inst=true,async=true,src=EMBEDDED:<null>} - STARTED
|  |  |  |  |  +> redacted.core.HtmlJspFilter@71d4a1ac
|  |  |  |  +> redacted.core.SFilter-3e6ef8ad==redacted.core.SFilter@3e6ef8ad{inst=true,async=true,src=EMBEDDED:<null>} - STARTED
|  |  |  |  |  +> redacted.core.SFilter@5e290d36
|  |  |  |  +> com.kohlschutter.dumbo.JsFilter-62230c58==com.kohlschutter.dumbo.JsFilter@62230c58{inst=true,async=true,src=EMBEDDED:<null>} - STARTED
|  |  |  |     +> com.kohlschutter.dumbo.JsFilter@325cc394
|  |  |  +> filterMappings oeje10s.ServletHandler@46f79c11{STARTED} size=8
|  |  |  |  +> [/*]/[]/[REQUEST]=>org.eclipse.jetty.ee10.websocket.servlet.WebSocketUpgradeFilter
|  |  |  |  +> [*.xml]/[]/[REQUEST]=>redacted.core.LFilter-49dc7102
|  |  |  |  +> [*.css]/[]/[REQUEST]=>redacted.core.CFilter-3a6bb9bf
|  |  |  |  +> [*.json]/[]/[REQUEST]=>redacted.core.LFilter-34f7cfd9
|  |  |  |  +> [*.txt]/[]/[REQUEST]=>redacted.core.LFilter-65f095f8
|  |  |  |  +> [*.html]/[]/[REQUEST]=>redacted.core.HtmlJspFilter-59af0466
|  |  |  |  +> [*.scss]/[]/[REQUEST]=>redacted.core.SFilter-3e6ef8ad
|  |  |  |  +> [*.js]/[]/[REQUEST]=>com.kohlschutter.dumbo.JsFilter-62230c58
|  |  |  +> servlets oeje10s.ServletHandler@46f79c11{STARTED} size=7
|  |  |  |  +> org.eclipse.jetty.ee10.servlet.DefaultServlet-37858383==org.eclipse.jetty.ee10.servlet.DefaultServlet@8b29c469{jsp=null,order=-1,inst=true,async=true,src=EMBEDDED:<null>,STARTED} - STARTED
|  |  |  |  |  +> org.eclipse.jetty.ee10.servlet.DefaultServlet@367bbcfb
|  |  |  |  |  +> initParams size=3
|  |  |  |  |     +> useFileMappedBuffer=true
|  |  |  |  |     +> stylesheet=/css/jetty-dir.css
|  |  |  |  |     +> etags=true
|  |  |  |  +> com.kohlschutter.dumbo.JspCachingServlet-770d3326==com.kohlschutter.dumbo.JspCachingServlet@dd631d0c{jsp=null,order=0,inst=true,async=true,src=EMBEDDED:<null>,STARTED} - STARTED
|  |  |  |  |  +> com.kohlschutter.dumbo.JspCachingServlet@202d57bf
|  |  |  |  |  +> initParams size=1
|  |  |  |  |     +> scratchdir=/private/var/folders/20/lqqqg9s974sg640km8nj3klm0000gn/T/dumbo-workdir160541941742846541/blog/jetty.tmp/jsp
|  |  |  |  +> redacted.core.MarkdownServlet-4cc8eb05==redacted.core.MarkdownServlet@1fc2bee1{jsp=null,order=1,inst=true,async=true,src=EMBEDDED:<null>,STARTED} - STARTED
|  |  |  |  |  +> redacted.core.MarkdownServlet@7439604d
|  |  |  |  +> com.kohlschutter.dumbo.JspCachingServlet-51f116b8==com.kohlschutter.dumbo.JspCachingServlet@29918af6{jsp=null,order=0,inst=true,async=true,src=EMBEDDED:<null>,STARTED} - STARTED
|  |  |  |  |  +> com.kohlschutter.dumbo.JspCachingServlet@23de267a
|  |  |  |  |  +> initParams size=1
|  |  |  |  |     +> scratchdir=/private/var/folders/20/lqqqg9s974sg640km8nj3klm0000gn/T/dumbo-workdir160541941742846541/blog/jetty.tmp/jsp
|  |  |  |  +> com.kohlschutter.dumbo.JsonRpcServlet-cad498c==com.kohlschutter.dumbo.JsonRpcServlet@969af745{jsp=null,order=0,inst=true,async=true,src=EMBEDDED:<null>,STARTED} - STARTED
|  |  |  |  |  +> com.kohlschutter.dumbo.JsonRpcServlet@4829da9e
|  |  |  |  +> default==org.eclipse.jetty.ee10.servlet.DefaultServlet@5c13d641{jsp=null,order=0,inst=true,async=false,src=DESCRIPTOR:jar:file:/Users/redacted/.m2/repository/org/eclipse/jetty/ee10/jetty-ee10-webapp/12.0.12/jetty-ee10-webapp-12.0.12.jar!/org/eclipse/jetty/ee10/webapp/webdefault-ee10.xml,STARTED} - STARTED
|  |  |  |  |  +> NotAsync:org.eclipse.jetty.ee10.servlet.DefaultServlet@273ec8b
|  |  |  |  |  +> initParams size=9
|  |  |  |  |     +> dirAllowed=true
|  |  |  |  |     +> maxCacheSize=256000000
|  |  |  |  |     +> maxCachedFileSize=200000000
|  |  |  |  |     +> welcomeServlets=false
|  |  |  |  |     +> useFileMappedBuffer=true
|  |  |  |  |     +> acceptRanges=true
|  |  |  |  |     +> etags=false
|  |  |  |  |     +> maxCachedFiles=2048
|  |  |  |  |     +> redirectWelcome=false
|  |  |  |  +> jsp==org.eclipse.jetty.ee10.jsp.JettyJspServlet@19c47{jsp=null,order=0,inst=true,async=false,src=DESCRIPTOR:jar:file:/Users/redacted/.m2/repository/org/eclipse/jetty/ee10/jetty-ee10-webapp/12.0.12/jetty-ee10-webapp-12.0.12.jar!/org/eclipse/jetty/ee10/webapp/webdefault-ee10.xml,STARTED} - STARTED
|  |  |  |     +> NotAsync:org.eclipse.jetty.ee10.jsp.JettyJspServlet@3d77cf80
|  |  |  |     +> initParams size=4
|  |  |  |        +> compilerSourceVM=1.8
|  |  |  |        +> compilerTargetVM=1.8
|  |  |  |        +> scratchdir=/private/var/folders/20/lqqqg9s974sg640km8nj3klm0000gn/T/dumbo-workdir160541941742846541/blog/jetty.tmp/jsp
|  |  |  |        +> xpoweredBy=false
|  |  |  +> servletMappings oeje10s.ServletHandler@46f79c11{STARTED} size=6
|  |  |  |  +> [/]=>org.eclipse.jetty.ee10.servlet.DefaultServlet-37858383
|  |  |  |  +> [*.jsp]=>com.kohlschutter.dumbo.JspCachingServlet-770d3326
|  |  |  |  +> [*.md]=>redacted.core.MarkdownServlet-4cc8eb05
|  |  |  |  +> [*.jsp.js]=>com.kohlschutter.dumbo.JspCachingServlet-51f116b8
|  |  |  |  +> [/json]=>com.kohlschutter.dumbo.JsonRpcServlet-cad498c
|  |  |  |  +> [*.jspf, *.jspx, *.xsp, *.JSP, *.JSPF, *.JSPX, *.XSP]=>jsp
|  |  |  +> durable oeje10s.ServletHandler@46f79c11{STARTED} size=16
|  |  |     +> org.eclipse.jetty.ee10.websocket.servlet.WebSocketUpgradeFilter==org.eclipse.jetty.ee10.websocket.servlet.WebSocketUpgradeFilter@18131296{inst=true,async=true,src=EMBEDDED:<null>} - STARTED
|  |  |     |  +> org.eclipse.jetty.ee10.websocket.servlet.WebSocketUpgradeFilter@7beffc33
|  |  |     |     +> ConfigurationCustomizer@206bc84f{idleTimeout=null, writeTimeout=null, autoFragment=null, maxFrameSize=null, inputBufferSize=null, outputBufferSize=null, maxBinaryMessageSize=null, maxTextMessageSize=null, maxOutgoingFrames=null}
|  |  |     |     +> org.eclipse.jetty.websocket.core.server.WebSocketMappings@5a86cf47
|  |  |     |        +> PathMappings[size=0]
|  |  |     |           +> ju.TreeSet@0(size=0)
|  |  |     +> redacted.core.LFilter-49dc7102==redacted.core.LFilter@49dc7102{inst=true,async=true,src=EMBEDDED:<null>} - STARTED
|  |  |     |  +> redacted.core.LFilter@6a2ff509
|  |  |     +> redacted.core.CFilter-3a6bb9bf==redacted.core.CFilter@3a6bb9bf{inst=true,async=true,src=EMBEDDED:<null>} - STARTED
|  |  |     |  +> redacted.core.CFilter@854f0d0
|  |  |     +> redacted.core.LFilter-34f7cfd9==redacted.core.LFilter@34f7cfd9{inst=true,async=true,src=EMBEDDED:<null>} - STARTED
|  |  |     |  +> redacted.core.LFilter@28b8843b
|  |  |     +> redacted.core.LFilter-65f095f8==redacted.core.LFilter@65f095f8{inst=true,async=true,src=EMBEDDED:<null>} - STARTED
|  |  |     |  +> redacted.core.LFilter@64c68780
|  |  |     +> redacted.core.HtmlJspFilter-59af0466==redacted.core.HtmlJspFilter@59af0466{inst=true,async=true,src=EMBEDDED:<null>} - STARTED
|  |  |     |  +> redacted.core.HtmlJspFilter@71d4a1ac
|  |  |     +> redacted.core.SFilter-3e6ef8ad==redacted.core.SFilter@3e6ef8ad{inst=true,async=true,src=EMBEDDED:<null>} - STARTED
|  |  |     |  +> redacted.core.SFilter@5e290d36
|  |  |     +> com.kohlschutter.dumbo.JsFilter-62230c58==com.kohlschutter.dumbo.JsFilter@62230c58{inst=true,async=true,src=EMBEDDED:<null>} - STARTED
|  |  |     |  +> com.kohlschutter.dumbo.JsFilter@325cc394
|  |  |     +> org.eclipse.jetty.ee10.servlet.DefaultServlet-37858383==org.eclipse.jetty.ee10.servlet.DefaultServlet@8b29c469{jsp=null,order=-1,inst=true,async=true,src=EMBEDDED:<null>,STARTED} - STARTED
|  |  |     |  +> org.eclipse.jetty.ee10.servlet.DefaultServlet@367bbcfb
|  |  |     |  +> initParams size=3
|  |  |     |     +> useFileMappedBuffer=true
|  |  |     |     +> stylesheet=/css/jetty-dir.css
|  |  |     |     +> etags=true
|  |  |     +> com.kohlschutter.dumbo.JspCachingServlet-770d3326==com.kohlschutter.dumbo.JspCachingServlet@dd631d0c{jsp=null,order=0,inst=true,async=true,src=EMBEDDED:<null>,STARTED} - STARTED
|  |  |     |  +> com.kohlschutter.dumbo.JspCachingServlet@202d57bf
|  |  |     |  +> initParams size=1
|  |  |     |     +> scratchdir=/private/var/folders/20/lqqqg9s974sg640km8nj3klm0000gn/T/dumbo-workdir160541941742846541/blog/jetty.tmp/jsp
|  |  |     +> redacted.core.MarkdownServlet-4cc8eb05==redacted.core.MarkdownServlet@1fc2bee1{jsp=null,order=1,inst=true,async=true,src=EMBEDDED:<null>,STARTED} - STARTED
|  |  |     |  +> redacted.core.MarkdownServlet@7439604d
|  |  |     +> com.kohlschutter.dumbo.JspCachingServlet-51f116b8==com.kohlschutter.dumbo.JspCachingServlet@29918af6{jsp=null,order=0,inst=true,async=true,src=EMBEDDED:<null>,STARTED} - STARTED
|  |  |     |  +> com.kohlschutter.dumbo.JspCachingServlet@23de267a
|  |  |     |  +> initParams size=1
|  |  |     |     +> scratchdir=/private/var/folders/20/lqqqg9s974sg640km8nj3klm0000gn/T/dumbo-workdir160541941742846541/blog/jetty.tmp/jsp
|  |  |     +> com.kohlschutter.dumbo.JsonRpcServlet-cad498c==com.kohlschutter.dumbo.JsonRpcServlet@969af745{jsp=null,order=0,inst=true,async=true,src=EMBEDDED:<null>,STARTED} - STARTED
|  |  |     |  +> com.kohlschutter.dumbo.JsonRpcServlet@4829da9e
|  |  |     +> default==org.eclipse.jetty.ee10.servlet.DefaultServlet@5c13d641{jsp=null,order=0,inst=true,async=false,src=DESCRIPTOR:jar:file:/Users/redacted/.m2/repository/org/eclipse/jetty/ee10/jetty-ee10-webapp/12.0.12/jetty-ee10-webapp-12.0.12.jar!/org/eclipse/jetty/ee10/webapp/webdefault-ee10.xml,STARTED} - STARTED
|  |  |     |  +> NotAsync:org.eclipse.jetty.ee10.servlet.DefaultServlet@273ec8b
|  |  |     |  +> initParams size=9
|  |  |     |     +> dirAllowed=true
|  |  |     |     +> maxCacheSize=256000000
|  |  |     |     +> maxCachedFileSize=200000000
|  |  |     |     +> welcomeServlets=false
|  |  |     |     +> useFileMappedBuffer=true
|  |  |     |     +> acceptRanges=true
|  |  |     |     +> etags=false
|  |  |     |     +> maxCachedFiles=2048
|  |  |     |     +> redirectWelcome=false
|  |  |     +> jsp==org.eclipse.jetty.ee10.jsp.JettyJspServlet@19c47{jsp=null,order=0,inst=true,async=false,src=DESCRIPTOR:jar:file:/Users/redacted/.m2/repository/org/eclipse/jetty/ee10/jetty-ee10-webapp/12.0.12/jetty-ee10-webapp-12.0.12.jar!/org/eclipse/jetty/ee10/webapp/webdefault-ee10.xml,STARTED} - STARTED
|  |  |     |  +> NotAsync:org.eclipse.jetty.ee10.jsp.JettyJspServlet@3d77cf80
|  |  |     |  +> initParams size=4
|  |  |     |     +> compilerSourceVM=1.8
|  |  |     |     +> compilerTargetVM=1.8
|  |  |     |     +> scratchdir=/private/var/folders/20/lqqqg9s974sg640km8nj3klm0000gn/T/dumbo-workdir160541941742846541/blog/jetty.tmp/jsp
|  |  |     |     +> xpoweredBy=false
|  |  |     +> org.eclipse.jetty.ee10.servlet.listener.IntrospectorCleaner@5be90472{src=DESCRIPTOR:jar:file:/Users/redacted/.m2/repository/org/eclipse/jetty/ee10/jetty-ee10-webapp/12.0.12/jetty-ee10-webapp-12.0.12.jar!/org/eclipse/jetty/ee10/webapp/webdefault-ee10.xml} - STARTED
|  |  +- org.eclipse.jetty.security.DefaultIdentityService@6f48c3a2
|  |  +- org.eclipse.jetty.security.Authenticator$NoOp@69b319ff
|  |  +> roles size=0
|  |  +> constraints size=2
|  |     +> ConstraintMapping@74b9b7f6{TRACE,null / -> Constraint@77b17d2e{Disable TRACE,ANY,FORBIDDEN,[]}}
|  |     +> ConstraintMapping@5ecdf5a9{null,[TRACE] / -> Constraint@2f40636e{Enable everything but TRACE,ANY,ALLOWED,[]}}
|  += org.eclipse.jetty.session.DefaultSessionCache@16ff7777[evict=-1,removeUnloadable=false,saveOnCreate=false,saveOnInactiveEvict=false] - STARTED
|  |  += org.eclipse.jetty.session.NullSessionDataStore@6a5b208b[passivating=false,graceSec=3600] - STARTED
|  +~ oejs.DefaultSessionIdManager@5b0ae0d4{STARTED}[worker=node0] - STARTED
|  +- ju.ImmutableCollections$ListN@1(size=0)
+= oeje10s.ServletContextHandler$ServletContainerInitializerStarter@77fdb3c8{STARTED} - STARTED
|  += ContainerInitializer{org.eclipse.jetty.ee10.apache.jsp.JettyJasperInitializer,interested=[],applicable=[],annotated=[]} - STARTED
|  += ContainerInitializer{org.eclipse.jetty.ee10.apache.jsp.JettyJasperInitializer,interested=[],applicable=[],annotated=[]} - STARTED
|  += ContainerInitializer{org.eclipse.jetty.ee10.websocket.jakarta.server.config.JakartaWebSocketServletContainerInitializer,interested=[],applicable=[],annotated=[]} - STARTED
+- org.eclipse.jetty.server.handler.ErrorHandler@29380236
+= oejur.ResourceFactoryInternals$LifeCycle@3f41cf09{STARTED} - STARTED
|  +> newResourceReferences size=1
|     +> jar:file:/Users/redacted/.m2/repository/org/eclipse/jetty/ee10/jetty-ee10-webapp/12.0.12/jetty-ee10-webapp-12.0.12.jar!/
+- org.eclipse.jetty.util.resource.ResourceFactory$2@5583cdd
+- java:comp org.eclipse.jetty.jndi.NamingContext@49a7620[name=comp,parent=org.eclipse.jetty.jndi.NamingContext@6ddafd37,bindings.size=1]
|  +@ env = org.eclipse.jetty.jndi.NamingContext@a59f77a[name=env,parent=org.eclipse.jetty.jndi.NamingContext@49a7620,bindings.size=0]
+= oejwcs.WebSocketServerComponents@3bd148bf{STARTED} - STARTED
|  +~ InflaterPool@6cad0293{STARTED,size=0,capacity=200} - STARTED
|  +~ DeflaterPool@56a46974{STARTED,size=0,capacity=200} - STARTED
|  +~ org.eclipse.jetty.io.ArrayByteBufferPool@1383b6fd{min=0,max=65536,buckets=16,heap=0/2147483648,direct=86016/2147483648}
|  +- org.eclipse.jetty.websocket.core.WebSocketExtensionRegistry@22269082
|  |  +: class org.eclipse.jetty.websocket.core.internal.FragmentExtension
|  |  +: class org.eclipse.jetty.websocket.core.internal.FrameCaptureExtension
|  |  +: class org.eclipse.jetty.websocket.core.internal.IdentityExtension
|  |  +: class org.eclipse.jetty.websocket.core.internal.ValidationExtension
|  |  +: class org.eclipse.jetty.websocket.core.internal.PerMessageDeflateExtension
|  +~ org.eclipse.jetty.util.DecoratedObjectFactory[decorators=3]
|  +~ QueuedThreadPool[qtp592617454]@23529fee{STARTED,8<=21<=200,i=4,r=-1,t=58976ms,q=0}[ReservedThreadExecutor@261bb7cf{capacity=16,threads=ThreadIdPool@530185b1{capacity=16}}] - STARTED
+- WebSocketServerComponentsCleanupListener
+- WebSocketUpgradeFilterCleanupListener
+- org.eclipse.jetty.websocket.core.server.WebSocketMappings@5a86cf47
|  +> PathMappings[size=0]
|     +> ju.TreeSet@0(size=0)
+- org.eclipse.jetty.websocket.core.server.WebSocketMappings$1@5d3be572
+= oeje10wjs.JakartaWebSocketServerContainer@4b8fccd7{STARTED} - STARTED
|  += oeje10wjc.SessionTracker@3051afa6{STARTED} - STARTED
|  |  +> ju.Collections$SetFromMap@0(size=0)
|  +> ConfigurationCustomizer@6f228810{idleTimeout=null, writeTimeout=null, autoFragment=null, maxFrameSize=null, inputBufferSize=null, outputBufferSize=null, maxBinaryMessageSize=null, maxTextMessageSize=null, maxOutgoingFrames=null}
+- JakartaWebSocketServerContainerCleanupListener
+- org.eclipse.jetty.ee10.servlet.listener.IntrospectorCleaner@6db0e0f3
+- org.eclipse.jetty.server.AllowedResourceAliasChecker$AllowedResourceAliasCheckListener@586c60e6
+> WebAppClassLoader{/blog}@54208046
|  +> URLs size=0
|  +> parent(core): jdk.internal.loader.ClassLoaders$AppClassLoader@1698c449
+> Systemclasses /blog@74455848 size=16
|  +> jakarta.
|  +> java.
|  +> javax.
|  +> org.eclipse.jetty.ee10.jaas.
|  +> org.eclipse.jetty.ee10.jsp.
|  +> org.eclipse.jetty.ee10.servlet.DefaultServlet
|  +> org.eclipse.jetty.ee10.servlet.NoJspServlet
|  +> org.eclipse.jetty.ee10.servlet.StatisticsServlet
|  +> org.eclipse.jetty.ee10.websocket.jakarta.client.JakartaWebSocketClientContainerProvider
|  +> org.eclipse.jetty.ee10.websocket.jakarta.client.JakartaWebSocketShutdownContainer
|  +> org.eclipse.jetty.ee10.websocket.jakarta.server.config.
|  +> org.eclipse.jetty.ee10.websocket.servlet.
|  +> org.eclipse.jetty.jndi.
|  +> org.eclipse.jetty.security.jaas.
|  +> org.w3c.
|  +> org.xml.
+> Serverclasses /blog@74455848 size=16
|  +> -org.eclipse.jetty.ee10.apache.
|  +> -org.eclipse.jetty.ee10.jaas.
|  +> -org.eclipse.jetty.ee10.jsp.
|  +> -org.eclipse.jetty.ee10.servlet.DefaultServlet
|  +> -org.eclipse.jetty.ee10.servlet.NoJspServlet
|  +> -org.eclipse.jetty.ee10.servlet.StatisticsServlet
|  +> -org.eclipse.jetty.ee10.servlet.listener.
|  +> -org.eclipse.jetty.ee10.websocket.jakarta.client.JakartaWebSocketClientContainerProvider
|  +> -org.eclipse.jetty.ee10.websocket.jakarta.client.JakartaWebSocketShutdownContainer
|  +> -org.eclipse.jetty.ee10.websocket.jakarta.server.config.
|  +> -org.eclipse.jetty.ee10.websocket.servlet.
|  +> -org.eclipse.jetty.jndi.
|  +> -org.eclipse.jetty.security.jaas.
|  +> org.eclipse.jdt.
|  +> org.eclipse.jetty.
|  +> org.objectweb.asm.
+> Configurations /blog@74455848 size=13
|  +> org.eclipse.jetty.ee10.webapp.WebInfConfiguration@76e78cc7
|  +> org.eclipse.jetty.ee10.webapp.WebXmlConfiguration@2e70012a
|  +> org.eclipse.jetty.ee10.webapp.MetaInfConfiguration@7bb05605
|  +> org.eclipse.jetty.ee10.webapp.FragmentConfiguration@49edcf16
|  +> org.eclipse.jetty.ee10.webapp.JaasConfiguration@51d56c94
|  +> org.eclipse.jetty.ee10.webapp.JndiConfiguration@5b82ac99
|  +> org.eclipse.jetty.ee10.webapp.JspConfiguration@11c9929a
|  +> org.eclipse.jetty.ee10.websocket.jakarta.server.config.JakartaWebSocketConfiguration@694c112f
|  +> org.eclipse.jetty.ee10.webapp.WebAppConfiguration@f1eec60
|  +> org.eclipse.jetty.ee10.plus.webapp.EnvConfiguration@156d6b0b
|  +> org.eclipse.jetty.ee10.plus.webapp.PlusConfiguration@48ed6dce
|  +> org.eclipse.jetty.ee10.annotations.AnnotationConfiguration@645fffb
|  +> org.eclipse.jetty.ee10.webapp.JettyWebXmlConfiguration@21c9c5f8
+> Handler attributes /blog@74455848 size=10
|  +> org.eclipse.jetty.webapp.originalResourceBase=[file:/private/var/folders/20/lqqqg9s974sg640km8nj3klm0000gn/T/dumbo-workdir160541941742846541/blog/webapp/, file:/redacted/workspace/redacted/target-eclipse/classes/redacted/webapp/, file:/redacted/workspace/dumbo/dumbo-core/target-eclipse/classes/redacted/jettydir-overlay/]
|  +> org.eclipse.jetty.lifecyleCallbackCollection=org.eclipse.jetty.plus.annotation.LifeCycleCallbackCollection@44d9ad64
|  +> org.eclipse.jetty.injectionCollection=org.eclipse.jetty.plus.annotation.InjectionCollection@7f75348c
|  +> org.apache.catalina.jsp_classpath=
|  +> jakarta.servlet.context.tempdir=/private/var/folders/20/lqqqg9s974sg640km8nj3klm0000gn/T/dumbo-workdir160541941742846541/blog/jetty.tmp
|  +> jsonPath=/blog/json
|  +> dumborb.json.methods=["ConsoleService.requestNextChunk"]
|  +> com.kohlschutter.dumbo.DumboServerImpl=com.kohlschutter.dumbo.DumboServerImpl@40e26132
|  +> org.eclipse.jetty.websocket.core.server.WebSocketMappings=org.eclipse.jetty.websocket.core.server.WebSocketMappings@5a86cf47
|  +> org.eclipse.jetty.ee10.plus.webapp.PlusConfiguration.jndiKey=481627690
+> Context attributes /blog@74455848 size=20
|  +> org.eclipse.jetty.webapp.originalResourceBase=[file:/private/var/folders/20/lqqqg9s974sg640km8nj3klm0000gn/T/dumbo-workdir160541941742846541/blog/webapp/, file:/redacted/workspace/redacted/target-eclipse/classes/redacted/webapp/, file:/redacted/workspace/dumbo/dumbo-core/target-eclipse/classes/redacted/jettydir-overlay/]
|  +> org.eclipse.jetty.util.DecoratedObjectFactory=org.eclipse.jetty.util.DecoratedObjectFactory[decorators=3]
|  +> org.eclipse.jetty.lifecyleCallbackCollection=org.eclipse.jetty.plus.annotation.LifeCycleCallbackCollection@44d9ad64
|  +> org.apache.tomcat.InstanceManager=org.apache.tomcat.SimpleInstanceManager@4536e7f2
|  +> org.eclipse.jetty.injectionCollection=org.eclipse.jetty.plus.annotation.InjectionCollection@7f75348c
|  +> org.eclipse.jetty.server.Executor=QueuedThreadPool[qtp592617454]@23529fee{STARTED,8<=21<=200,i=4,r=-1,t=58976ms,q=0}[ReservedThreadExecutor@261bb7cf{capacity=16,threads=ThreadIdPool@530185b1{capacity=16}}]
|  +> org.apache.catalina.jsp_classpath=
|  +> org.eclipse.jetty.websocket.core.WebSocketComponents=oejwcs.WebSocketServerComponents@3bd148bf{STARTED}
|  +> jakarta.servlet.context.tempdir=/private/var/folders/20/lqqqg9s974sg640km8nj3klm0000gn/T/dumbo-workdir160541941742846541/blog/jetty.tmp
|  +> jsonPath=/blog/json
|  +> jakarta.websocket.server.ServerContainer=oeje10wjs.JakartaWebSocketServerContainer@4b8fccd7{STARTED}
|  +> org.apache.jasper.compiler.ELInterpreter=org.apache.jasper.compiler.ELInterpreterFactory$DefaultELInterpreter@4c0dd0bd
|  +> org.apache.jasper.compiler.TldCache=org.apache.jasper.compiler.TldCache@1a0a4ce4
|  +> com.kohlschutter.dumbo.ServerApp=com.kohlschutter.dumbo.ServerApp@49325566
|  +> dumborb.json.methods=["ConsoleService.requestNextChunk"]
|  +> com.kohlschutter.dumbo.DumboServerImpl=com.kohlschutter.dumbo.DumboServerImpl@40e26132
|  +> org.eclipse.jetty.websocket.core.server.WebSocketMappings=org.eclipse.jetty.websocket.core.server.WebSocketMappings@5a86cf47
|  +> org.apache.jasper.compiler.StringInterpreter=org.apache.jasper.compiler.StringInterpreterFactory$DefaultStringInterpreter@3bc932c5
|  +> org.eclipse.jetty.ee10.plus.webapp.PlusConfiguration.jndiKey=481627690
|  +> org.apache.jasper.runtime.JspApplicationContextImpl=org.apache.jasper.runtime.JspApplicationContextImpl@19e38539
+> EventListeners oeje10w.WebAppContext@74455848{/blog,/blog,b=[file:/private/var/folders/20/lqqqg9s974sg640km8nj3klm0000gn/T/dumbo-workdir160541941742846541/blog/webapp/, file:/redacted/workspace/redacted/target-eclipse/classes/redacted/webapp/, file:/redacted/workspace/dumbo/dumbo-core/target-eclipse/classes/redacted/jettydir-overlay/],a=AVAILABLE,h=oeje10s.SessionHandler@480aa870{STARTED}}{[file:/private/var/folders/20/lqqqg9s974sg640km8nj3klm0000gn/T/dumbo-workdir160541941742846541/blog/webapp/, file:/redacted/workspace/redacted/target-eclipse/classes/redacted/webapp/, file:/redacted/workspace/dumbo/dumbo-core/target-eclipse/classes/redacted/jettydir-overlay/]} size=9
|  +> org.eclipse.jetty.util.resource.ResourceFactory$2@5583cdd
|  +> WebSocketServerComponentsCleanupListener
|  +> WebSocketUpgradeFilterCleanupListener
|  +> org.eclipse.jetty.websocket.core.server.WebSocketMappings@5a86cf47
|  |  +> PathMappings[size=0]
|  |     +> ju.TreeSet@0(size=0)
|  +> org.eclipse.jetty.websocket.core.server.WebSocketMappings$1@5d3be572
|  +> oeje10wjs.JakartaWebSocketServerContainer@4b8fccd7{STARTED} - STARTED
|  |  += oeje10wjc.SessionTracker@3051afa6{STARTED} - STARTED
|  |  |  +> ju.Collections$SetFromMap@0(size=0)
|  |  +> ConfigurationCustomizer@6f228810{idleTimeout=null, writeTimeout=null, autoFragment=null, maxFrameSize=null, inputBufferSize=null, outputBufferSize=null, maxBinaryMessageSize=null, maxTextMessageSize=null, maxOutgoingFrames=null}
|  +> JakartaWebSocketServerContainerCleanupListener
|  +> org.eclipse.jetty.ee10.servlet.listener.IntrospectorCleaner@6db0e0f3
|  +> org.eclipse.jetty.server.AllowedResourceAliasChecker$AllowedResourceAliasCheckListener@586c60e6
+> Initparams /blog@74455848 size=0
key: +- bean, += managed, +~ unmanaged, +? auto, +: iterable, +] array, +@ map, +> undefined
JVM: Eclipse Adoptium OpenJDK 64-Bit Server VM 19.0.2+7; OS: Mac OS X aarch64 14.6.1; Jetty: 12.0.12; CPUs: 10; mem(free/total/max): 419/584/16,384 MiB
UTC: 2024-08-09T16:39:44.550697Z; Europe/Berlin: 2024-08-09T18:39:44.550697+02:00

kohlschuetter avatar Aug 09 '24 16:08 kohlschuetter

I have a HttpFilter that listens for URL paths ending with .html, which then uses a request dispatcher to some other resource (with a different suffix). Maybe that's what's tripping it (not that it should).

kohlschuetter avatar Aug 09 '24 16:08 kohlschuetter

Your LFilter on url-pattern *.txt is set to async=true that's where the async is coming from.

joakime avatar Aug 09 '24 16:08 joakime

What does that mean, and how can I disable it? These are simple HttpFilters that I add via ServletHandler.addFilterWithMapping(FilterHolder,String pathSpec,EnumSet(REQUEST))

Notably, calling FilterHolder.setAsyncSupported with either true or false has no effect.

Again, everything works fine with either 12.0.7 or by adding the above check.

kohlschuetter avatar Aug 09 '24 17:08 kohlschuetter

Calling setAsyncSupported(false); on the DefaultServlet I create lets me use 12.0.12, but I wonder why.

ServletHolder holderDefaultServlet = sh.addServletWithMapping(DefaultServlet.class.getName(),
        "/");
    holderDefaultServlet.setAsyncSupported(false); // without this, 12.0.8 or newer fail
    holderDefaultServlet.setInitParameter("etags", "true");
    holderDefaultServlet.setInitParameter("useFileMappedBuffer", "true");
    holderDefaultServlet.setInitParameter("stylesheet", "/css/jetty-dir.css");

kohlschuetter avatar Aug 09 '24 17:08 kohlschuetter

It's a useful finding, something isn't right. Smells like a bug.

joakime avatar Aug 09 '24 17:08 joakime

We ran into this too. Working around by disabling async seems to work.

2024-10-07T16:30:59.977Z [doc-server-59] WARN  o.e.jetty.server.ResourceService - Failed to serve resource: /
java.lang.IllegalStateException: s=HANDLING rs=ASYNC os=OPEN is=IDLE awp=false se=false i=true al=0
	at org.eclipse.jetty.ee10.servlet.ServletChannelState.startAsync(ServletChannelState.java:575)
	at org.eclipse.jetty.ee10.servlet.ServletApiRequest.startAsync(ServletApiRequest.java:1362)
	at jakarta.servlet.ServletRequestWrapper.startAsync(ServletRequestWrapper.java:350)
	at org.eclipse.jetty.ee10.servlet.ResourceServlet.doGet(ResourceServlet.java:496)
	at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:527)
	at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:614)

dump here: https://gist.github.com/stevenschlansker/478bbedfe1b59639783578b2bc1e41e0

stevenschlansker avatar Oct 07 '24 23:10 stevenschlansker

Between Jetty 12.0.7 and 12.0.8, cross-context dispatching was re-introduced. This changed touched a lot of code related to this issue so while I suspect it is the change that introduced this problem, I'm not yet sure of what's going on because there are too many lose ends, and I have too little data to narrow down the bug.

At the core of this problem, it seems that you have two DefaultServlets configured, and one is delegating a welcome file request to the other one.

I've created a PR that contains extra debug information that should report where the original startAsync call was made as this is unclear: it may be in Jetty's code, but it could be in yours too and I would like to understand how exactly this problem is triggered. I'd be glad if you could reproduce the problem against a build of this branch and report back the full stack trace as this information is going to help us better understand what's going on.

Once we do understand the problem, we'll be able to reproduce it and come up with a fix.

In the meantime, I suspect that we should simply check that the async context already is started and don't try to start it twice. It can be done by patching EE10 ResourceServlet.java:521 this way:

--- AsyncContext asyncContext = httpServletRequest.startAsync();
+++ AsyncContext asyncContext = httpServletRequest.isAsyncStarted() ? httpServletRequest.getAsyncContext() : httpServletRequest.startAsync();

Nevertheless, we need to be able to reproduce the issue you're facing before committing this fix.

Thanks!

lorban avatar Nov 25 '24 15:11 lorban