[spring-projects/spring-boot]Tomcat:java.lang.IllegalStateException:调用 [asyncError()] 对于异步状态 [MUST_DISPATCH] 的请求无效

2018-11-01 894 views

回答

6

查看该框架问题后,我们发现它是 Tomcat 中的一个错误。您没有说明您是从哪个版本的 Boot 升级的,但您可能已经选择了新版本的 Tomcat 作为包含回归的升级的一部分。然而,基于如此少的信息,不可能有任何程度的确定性。

如果您希望我们花更多时间查看此问题,请花时间提供重现该问题的最小示例。鉴于之前的类似问题是 Tomcat 中的一个错误,我认为这不太可能是 Spring Boot 错误,但一旦我们有了重现该问题的示例,我们就可以相应地解决该问题。

7

@wilkinsona 之前的版本是 2.0.x,据我了解,2.1 带来了主要的 Tomcat (9) 更新作为依赖项。链接的 Tomcat 票证提及Fixed in 8.0.x for 8.0.0 and 7.0.x for 7.0.51.但未提及 9,因此这可能确实是他们的问题。我确实从 Spring Boot 跟踪器开始指出最近依赖项更新的问题,并且可能的临时解决方案可能会降级回 8.x。我会尝试提供更多信息/示例。

3

Tomcat 错误的最小示例

要查看错误:localhost:8080在浏览器中打开,点击“刷新”

切换到 Undertow使日志变得干净

1

感谢您提供样品。我已经重现了该问题,但只能通过终止连接到事件流的客户端来做到这一点,例如使用curl 和 CTRL+C。这样做后,我在日志中看到以下内容:

2018-11-02 11:43:33.016 ERROR 17152 --- [nio-8080-exec-2] o.a.catalina.connector.CoyoteAdapter     : Exception while processing an asynchronous request

java.lang.IllegalStateException: Calling [asyncError()] is not valid for a request with Async state [MUST_DISPATCH]
    at org.apache.coyote.AsyncStateMachine.asyncError(AsyncStateMachine.java:440) ~[tomcat-embed-core-9.0.12.jar:9.0.12]
    at org.apache.coyote.AbstractProcessor.action(AbstractProcessor.java:494) [tomcat-embed-core-9.0.12.jar:9.0.12]
    at org.apache.coyote.Request.action(Request.java:430) ~[tomcat-embed-core-9.0.12.jar:9.0.12]
    at org.apache.catalina.core.AsyncContextImpl.setErrorState(AsyncContextImpl.java:382) ~[tomcat-embed-core-9.0.12.jar:9.0.12]
    at org.apache.catalina.connector.CoyoteAdapter.asyncDispatch(CoyoteAdapter.java:239) ~[tomcat-embed-core-9.0.12.jar:9.0.12]
    at org.apache.coyote.AbstractProcessor.dispatch(AbstractProcessor.java:241) [tomcat-embed-core-9.0.12.jar:9.0.12]
    at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:53) [tomcat-embed-core-9.0.12.jar:9.0.12]
    at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:770) [tomcat-embed-core-9.0.12.jar:9.0.12]
    at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1415) [tomcat-embed-core-9.0.12.jar:9.0.12]
    at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) [tomcat-embed-core-9.0.12.jar:9.0.12]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_181]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_181]
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) [tomcat-embed-core-9.0.12.jar:9.0.12]
    at java.lang.Thread.run(Thread.java:748) [na:1.8.0_181]

使用调试器,我可以看到触发要设置的错误状态的故障是由于管道损坏而导致的 IO 异常。

如果我将 Tomcat 降级到 8.5.34,则会发生故障,但情况有所不同,并且更明显是由损坏的管道引起的:

2018-11-02 11:45:41.985 ERROR 17227 --- [nio-8080-exec-2] o.a.c.c.C.[.[.[/].[dispatcherServlet]    : Servlet.service() for servlet [dispatcherServlet] threw exception

java.io.IOException: Broken pipe
    at sun.nio.ch.FileDispatcherImpl.write0(Native Method) ~[na:1.8.0_181]
    at sun.nio.ch.SocketDispatcher.write(SocketDispatcher.java:47) ~[na:1.8.0_181]
    at sun.nio.ch.IOUtil.writeFromNativeBuffer(IOUtil.java:93) ~[na:1.8.0_181]
    at sun.nio.ch.IOUtil.write(IOUtil.java:65) ~[na:1.8.0_181]
    at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:471) ~[na:1.8.0_181]
    at org.apache.tomcat.util.net.NioChannel.write(NioChannel.java:134) ~[tomcat-embed-core-8.5.34.jar:8.5.34]
    at org.apache.tomcat.util.net.NioBlockingSelector.write(NioBlockingSelector.java:101) ~[tomcat-embed-core-8.5.34.jar:8.5.34]
    at org.apache.tomcat.util.net.NioSelectorPool.write(NioSelectorPool.java:157) ~[tomcat-embed-core-8.5.34.jar:8.5.34]
    at org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper.doWrite(NioEndpoint.java:1306) ~[tomcat-embed-core-8.5.34.jar:8.5.34]
    at org.apache.tomcat.util.net.SocketWrapperBase.doWrite(SocketWrapperBase.java:726) ~[tomcat-embed-core-8.5.34.jar:8.5.34]
    at org.apache.tomcat.util.net.SocketWrapperBase.flushBlocking(SocketWrapperBase.java:679) ~[tomcat-embed-core-8.5.34.jar:8.5.34]
    at org.apache.tomcat.util.net.SocketWrapperBase.flush(SocketWrapperBase.java:669) ~[tomcat-embed-core-8.5.34.jar:8.5.34]
    at org.apache.coyote.http11.Http11OutputBuffer$SocketOutputBuffer.flush(Http11OutputBuffer.java:646) ~[tomcat-embed-core-8.5.34.jar:8.5.34]
    at org.apache.coyote.http11.filters.ChunkedOutputFilter.flush(ChunkedOutputFilter.java:169) ~[tomcat-embed-core-8.5.34.jar:8.5.34]
    at org.apache.coyote.http11.Http11OutputBuffer.flush(Http11OutputBuffer.java:252) ~[tomcat-embed-core-8.5.34.jar:8.5.34]
    at org.apache.coyote.http11.Http11Processor.flush(Http11Processor.java:1561) ~[tomcat-embed-core-8.5.34.jar:8.5.34]
    at org.apache.coyote.AbstractProcessor.action(AbstractProcessor.java:380) ~[tomcat-embed-core-8.5.34.jar:8.5.34]
    at org.apache.coyote.Response.action(Response.java:173) ~[tomcat-embed-core-8.5.34.jar:8.5.34]
    at org.apache.catalina.connector.OutputBuffer.doFlush(OutputBuffer.java:317) ~[tomcat-embed-core-8.5.34.jar:8.5.34]
    at org.apache.catalina.connector.OutputBuffer.flush(OutputBuffer.java:284) ~[tomcat-embed-core-8.5.34.jar:8.5.34]
    at org.apache.catalina.connector.CoyoteOutputStream.flush(CoyoteOutputStream.java:118) ~[tomcat-embed-core-8.5.34.jar:8.5.34]
    at sun.nio.cs.StreamEncoder.implFlush(StreamEncoder.java:297) ~[na:1.8.0_181]
    at sun.nio.cs.StreamEncoder.flush(StreamEncoder.java:141) ~[na:1.8.0_181]
    at java.io.OutputStreamWriter.flush(OutputStreamWriter.java:229) ~[na:1.8.0_181]
    at org.springframework.util.StreamUtils.copy(StreamUtils.java:124) ~[spring-core-5.1.2.RELEASE.jar:5.1.2.RELEASE]
    at org.springframework.http.converter.StringHttpMessageConverter.writeInternal(StringHttpMessageConverter.java:106) ~[spring-web-5.1.2.RELEASE.jar:5.1.2.RELEASE]
    at org.springframework.http.converter.StringHttpMessageConverter.writeInternal(StringHttpMessageConverter.java:43) ~[spring-web-5.1.2.RELEASE.jar:5.1.2.RELEASE]
    at org.springframework.http.converter.AbstractHttpMessageConverter.write(AbstractHttpMessageConverter.java:227) ~[spring-web-5.1.2.RELEASE.jar:5.1.2.RELEASE]
    at org.springframework.web.servlet.mvc.method.annotation.ResponseBodyEmitterReturnValueHandler$HttpMessageConvertingHandler.sendInternal(ResponseBodyEmitterReturnValueHandler.java:191) ~[spring-webmvc-5.1.2.RELEASE.jar:5.1.2.RELEASE]
    at org.springframework.web.servlet.mvc.method.annotation.ResponseBodyEmitterReturnValueHandler$HttpMessageConvertingHandler.send(ResponseBodyEmitterReturnValueHandler.java:184) ~[spring-webmvc-5.1.2.RELEASE.jar:5.1.2.RELEASE]
    at org.springframework.web.servlet.mvc.method.annotation.ResponseBodyEmitter.sendInternal(ResponseBodyEmitter.java:189) ~[spring-webmvc-5.1.2.RELEASE.jar:5.1.2.RELEASE]
    at org.springframework.web.servlet.mvc.method.annotation.ResponseBodyEmitter.send(ResponseBodyEmitter.java:183) ~[spring-webmvc-5.1.2.RELEASE.jar:5.1.2.RELEASE]
    at org.springframework.web.servlet.mvc.method.annotation.SseEmitter.send(SseEmitter.java:133) ~[spring-webmvc-5.1.2.RELEASE.jar:5.1.2.RELEASE]
    at com.demo.DemoServer.lambda$0(DemoServer.java:27) ~[main/:na]
    at java.util.concurrent.CopyOnWriteArrayList.forEach(CopyOnWriteArrayList.java:891) ~[na:1.8.0_181]
    at com.demo.DemoServer.sendSseEvent(DemoServer.java:22) ~[main/:na]
    at com.demo.DemoServer.helloMessage(DemoServer.java:38) ~[main/:na]
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_181]
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_181]
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_181]
    at java.lang.reflect.Method.invoke(Method.java:498) ~[na:1.8.0_181]
    at org.springframework.scheduling.support.ScheduledMethodRunnable.run(ScheduledMethodRunnable.java:84) ~[spring-context-5.1.2.RELEASE.jar:5.1.2.RELEASE]
    at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54) ~[spring-context-5.1.2.RELEASE.jar:5.1.2.RELEASE]
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[na:1.8.0_181]
    at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) ~[na:1.8.0_181]
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) ~[na:1.8.0_181]
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) ~[na:1.8.0_181]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[na:1.8.0_181]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[na:1.8.0_181]
    at java.lang.Thread.run(Thread.java:748) [na:1.8.0_181]

如果我降级到 Spring Boot 2.0.6(使用 Tomcat 8.5.34),我会看到与使用 Tomcat 8.5.34 的 Spring Boot 2.1.0 相同的行为。

据我所知,这里唯一改变的是 Tomcat 的错误处理,8.5.x 和 9.0.x 记录的异常不同。但基本行为似乎是相同的。

@vitalyster 如果您观察到与我上面描述的不同的东西,您能否提供详细的说明来准确描述如何重现它?

3

是的,我在 Spring Boot 2.0.6 上看到了同样的情况,并且在 Spring JIRA 上也跟踪了该错误,我已经尝试过关闭已关闭的票证,但他们禁止这样做:)但是旧的异常看起来对我来说处理正确,只是登录了错误的级别,而在我开始找到问题之前,我并不清楚新的异常是否与相同的 sseemitter 问题相同。

7

解决SPR-16528的提交更改为异步超时的日志级别,但未更改为损坏管道的日志级别。如果您认为框架需要进一步完善,我建议打开一个新的框架问题,尽管@rstoyanchev 只更改一个而不更改另一个可能有充分的理由。

也就是说,框架中的更改不会对 Tomcat 9 有所帮助,因为在这种情况下是 Tomcat 记录错误消息,而不是框架。如果您想了解这方面的内容,我建议您打开 Tomcat 问题。

我将结束这一章,因为所有行为变化都不是由 Spring Boot 本身造成的,并且记录内容和级别的任何变化都必须在 Spring Framework 或 Tomcat 中进行。

3

拆下涡轮机流并检查

0

请停止评论多个项目,当它们明显不相关时,移除涡轮机流将有所帮助

6

我也出现这样的异常,请问如何解决?

6

@GarconX 请不要提问,尤其是关于已解决的问题。正如贡献指南中提到的,我们更喜欢仅使用 GitHub 问题来解决错误和增强功能。

5

此问题已结束,for: external-project有谁知道是否已提交 Tomcat 问题并有参考吗?

3

Tomcat 问题是56042

7

我今天遇到了这个问题,我可以确认将(嵌入式)tomcat 更新到版本 9.0.29 后,该错误不再发生。