Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Deadlock between SseEmitter and StandardServletAsyncWebRequest when clients disconnect #33421

Closed
dmngb opened this issue Aug 23, 2024 · 9 comments
Closed

Deadlock between SseEmitter and StandardServletAsyncWebRequest when clients disconnect #33421

dmngb opened this issue Aug 23, 2024 · 9 comments
Assignees
@rstoyanchev
Labels
in: web Issues in web modules (web, webmvc, webflux, websocket) type: bug A general bug
Milestone
6.1.13

Comments

@dmngb
Copy link

dmngb commented Aug 23, 2024 •
edited
Loading

We have been tracking rather strange & random failures in our application: eventually, after many browser closed (and/or page refresh), our SSE event flux would not be sending anything anymore to new clients.

We identified that threads used for async tasks execution (AsyncSupportConfigurer) may deadlock due to a timing-dependant ABBA deadlock between SseEmitter sending and error handling on connection closed.
If using the the default SimpleAsyncTaskExecutor which fires up a new Thread for each task, no user visible effect (except that some deadlocked unused threads are consumming resources on the server).
But, if using a fixed number of threads (as we do in our application), the system may finally come to a halt (when all worker threads have been deadlocked).

What we think is going on (see example jstack trace captured):

  • The client is connected to the SSE endpoint:
  • For an object to be written to the sse flux:
    • the SseEmitter locks itself (synchronized on super.send(...))
    • then the Object is serialized (Jackson)
    • eventually, writing/flushing on the output stream will require StandardServletAsyncWebRequest to aquire its stateLock ReentrantLock
  • The client disconnects abruptly (browser closed), while the object is being serialized:
    • the server "sees" that the connection has been closed (probably because another object is sent concurrently on the SseEmitter)
    • this triggers StandardServletAsyncWebRequest.onError handling process that first locks the stateLock ReentrantLock and then calls SseEmitter.completeWithError which wants to lock itself (synchronized)
      So, we think that there's a potential ABBA deadlock between SSE error handling and concurrent SSE sending.

Things are highly timing dependent, but we have been able to reproduce (with high probablity) our observed deadlocks:
the idea is to emit big JSON objects (increasing the concurrency window) and normal objects concurrenty on the flux, while closing the browser

Reproduced with spring boot 3.3.2 (springframework 6.1.11) and also 3.3.3 (springframework 6.1.12)

Steps to reproduce:

See the minimalist example attached, with the following steps to reproduce:

  • Launch the main class
    • note the process PID for further reference
  • Using a browser as an http client, go to the index.html via url : http://localhost:8080
  • Refresh the browser
  • Run the "jstack $PID" command
    • You should notice 1 deadlock (varying probability, but still very likely)
  • For each additional refresh, an additional deadlock may appear

Example of deadlock captured using jstack:

Found one Java-level deadlock:
=============================
"http-nio-8080-exec-3":
  waiting to lock monitor 0x000001dfe2866ac0 (object 0x0000000614fc1408, a org.springframework.web.servlet.mvc.method.annotation.SseEmitter),
  which is held by "task-4"

"task-4":
  waiting for ownable synchronizer 0x0000000614e998c0, (a java.util.concurrent.locks.ReentrantLock$NonfairSync),
  which is held by "http-nio-8080-exec-3"

Java stack information for the threads listed above:
===================================================
"http-nio-8080-exec-3":
	at org.springframework.web.servlet.mvc.method.annotation.ResponseBodyEmitter.completeWithError(ResponseBodyEmitter.java:264)
	- waiting to lock <0x0000000614fc1408> (a org.springframework.web.servlet.mvc.method.annotation.SseEmitter)
	at org.springframework.web.servlet.mvc.method.annotation.ReactiveTypeHandler$AbstractEmitterSubscriber$$Lambda/0x000001df9d4acaf0.accept(Unknown Source)
	at org.springframework.web.servlet.mvc.method.annotation.ResponseBodyEmitter$ErrorCallback.accept(ResponseBodyEmitter.java:396)
	at org.springframework.web.servlet.mvc.method.annotation.ResponseBodyEmitter$ErrorCallback.accept(ResponseBodyEmitter.java:383)
	at org.springframework.web.context.request.async.DeferredResult$1.handleError(DeferredResult.java:319)
	at org.springframework.web.context.request.async.DeferredResultInterceptorChain.triggerAfterError(DeferredResultInterceptorChain.java:99)
	at org.springframework.web.context.request.async.WebAsyncManager.lambda$startDeferredResultProcessing$6(WebAsyncManager.java:451)
	at org.springframework.web.context.request.async.WebAsyncManager$$Lambda/0x000001df9d4b0220.accept(Unknown Source)
	at org.springframework.web.context.request.async.StandardServletAsyncWebRequest.lambda$onError$0(StandardServletAsyncWebRequest.java:193)
	at org.springframework.web.context.request.async.StandardServletAsyncWebRequest$$Lambda/0x000001df9d4c1970.accept(Unknown Source)
	at java.util.ArrayList.forEach(java.base@21.0.3/ArrayList.java:1596)
	at org.springframework.web.context.request.async.StandardServletAsyncWebRequest.onError(StandardServletAsyncWebRequest.java:193)
	at org.apache.catalina.core.AsyncListenerWrapper.fireOnError(AsyncListenerWrapper.java:49)
	at org.apache.catalina.core.AsyncContextImpl.setErrorState(AsyncContextImpl.java:415)
	at org.apache.catalina.connector.CoyoteAdapter.asyncDispatch(CoyoteAdapter.java:155)
	at org.apache.coyote.AbstractProcessor.dispatch(AbstractProcessor.java:243)
	at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:57)
	at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:904)
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1741)
	at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:52)
	at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1190)
	at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659)
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:63)
	at java.lang.Thread.runWith(java.base@21.0.3/Thread.java:1596)
	at java.lang.Thread.run(java.base@21.0.3/Thread.java:1583)
"task-4":
	at jdk.internal.misc.Unsafe.park(java.base@21.0.3/Native Method)
	- parking to wait for  <0x0000000614e998c0> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)
	at java.util.concurrent.locks.LockSupport.park(java.base@21.0.3/LockSupport.java:221)
	at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(java.base@21.0.3/AbstractQueuedSynchronizer.java:754)
	at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(java.base@21.0.3/AbstractQueuedSynchronizer.java:990)
	at java.util.concurrent.locks.ReentrantLock$Sync.lock(java.base@21.0.3/ReentrantLock.java:153)
	at java.util.concurrent.locks.ReentrantLock.lock(java.base@21.0.3/ReentrantLock.java:322)
	at org.springframework.web.context.request.async.StandardServletAsyncWebRequest$LifecycleHttpServletResponse.obtainLockAndCheckState(StandardServletAsyncWebRequest.java:306)
	at org.springframework.web.context.request.async.StandardServletAsyncWebRequest$LifecycleServletOutputStream.write(StandardServletAsyncWebRequest.java:373)
	at org.springframework.util.StreamUtils$NonClosingOutputStream.write(StreamUtils.java:261)
	at com.fasterxml.jackson.core.json.UTF8JsonGenerator._flushBuffer(UTF8JsonGenerator.java:2210)
	at com.fasterxml.jackson.core.json.UTF8JsonGenerator.close(UTF8JsonGenerator.java:1234)
	at org.springframework.http.converter.json.AbstractJackson2HttpMessageConverter.writeInternal(AbstractJackson2HttpMessageConverter.java:452)
	at org.springframework.http.converter.AbstractGenericHttpMessageConverter.writeInternal(AbstractGenericHttpMessageConverter.java:123)
	at org.springframework.http.converter.AbstractHttpMessageConverter.write(AbstractHttpMessageConverter.java:235)
	at org.springframework.web.servlet.mvc.method.annotation.ResponseBodyEmitterReturnValueHandler$HttpMessageConvertingHandler.sendInternal(ResponseBodyEmitterReturnValueHandler.java:221)
	at org.springframework.web.servlet.mvc.method.annotation.ResponseBodyEmitterReturnValueHandler$HttpMessageConvertingHandler.send(ResponseBodyEmitterReturnValueHandler.java:212)
	at org.springframework.web.servlet.mvc.method.annotation.ResponseBodyEmitter.sendInternal(ResponseBodyEmitter.java:223)
	at org.springframework.web.servlet.mvc.method.annotation.ResponseBodyEmitter.send(ResponseBodyEmitter.java:214)
	- locked <0x0000000614fc1408> (a org.springframework.web.servlet.mvc.method.annotation.SseEmitter)
	at org.springframework.web.servlet.mvc.method.annotation.SseEmitter.send(SseEmitter.java:135)
	at org.springframework.web.servlet.mvc.method.annotation.ReactiveTypeHandler$SseEmitterSubscriber.send(ReactiveTypeHandler.java:389)
	at org.springframework.web.servlet.mvc.method.annotation.ReactiveTypeHandler$AbstractEmitterSubscriber.run(ReactiveTypeHandler.java:332)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@21.0.3/ThreadPoolExecutor.java:1144)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@21.0.3/ThreadPoolExecutor.java:642)
	at java.lang.Thread.runWith(java.base@21.0.3/Thread.java:1596)
	at java.lang.Thread.run(java.base@21.0.3/Thread.java:1583)

Found 1 deadlock.

demodeadlock.zip
@spring-projects-issues spring-projects-issues added the status: waiting-for-triage An issue we've not yet triaged or decided on label Aug 23, 2024
@bclozel bclozel added the in: web Issues in web modules (web, webmvc, webflux, websocket) label Aug 23, 2024
@rstoyanchev rstoyanchev self-assigned this Sep 6, 2024
@rstoyanchev
Copy link
Contributor

Thank you for the investigation. This looks like a valid issue.

@rstoyanchev rstoyanchev added type: bug A general bug and removed status: waiting-for-triage An issue we've not yet triaged or decided on labels Sep 6, 2024
@rstoyanchev rstoyanchev added this to the 6.1.13 milestone Sep 6, 2024
@rstoyanchev rstoyanchev changed the title SSE: potential deadlocks of async tasks threads on connection closed Deadlock between SseEmitter and StandardServletAsyncWebRequest when clients disconnect Sep 6, 2024
@rstoyanchev
Copy link
Contributor

I pushed a fix 3d1bf28, but I was not able to reproduce the condition with the demo. Possibly related, after the index page loads, this appears in the logs:

reactor.core.Exceptions$OverflowException: Could not emit tick 32 due to lack of requests (interval doesn't support small downstream requests that replenish slower than the ticks)

If you could give it a try with 6.1.13-SNAPSHOT to confirm the fix that would be very helpful.

@dmngb
Copy link
Author

dmngb commented Sep 16, 2024

I tried with 6.1.13-SNAPSHOT and can not reproduce anymore with the demo (and reloading quickly many times in a row)
(note: I think adding onBackpressureLatest() on the 2 fluxes avoids the OverflowException).

Still, there's this scary warning in the logs:

2024-09-16T15:14:59.016+02:00  WARN 24584 --- [io-8080-exec-10] .w.s.m.s.DefaultHandlerExceptionResolver : Resolved [org.springframework.web.context.request.async.AsyncRequestNotUsableException: ServletOutputStream failed to write: java.io.IOException: An established connection was aborted by the software in your host machine]
Exception in thread "task-21" java.lang.IllegalStateException: A non-container (application) thread attempted to use the AsyncContext after an error had occurred and the call to AsyncListener.onError() had returned. This is not allowed to avoid race conditions.
	at org.apache.catalina.core.AsyncContextImpl.check(AsyncContextImpl.java:537)
	at org.apache.catalina.core.AsyncContextImpl.getRequest(AsyncContextImpl.java:211)
	at org.apache.catalina.core.AsyncContextImpl.dispatch(AsyncContextImpl.java:201)
	at org.apache.catalina.core.AsyncContextImpl.dispatch(AsyncContextImpl.java:176)
	at org.apache.catalina.core.AsyncContextImpl.dispatch(AsyncContextImpl.java:170)
	at org.springframework.web.context.request.async.StandardServletAsyncWebRequest.dispatch(StandardServletAsyncWebRequest.java:170)
	at org.springframework.web.context.request.async.WebAsyncManager.setConcurrentResultAndDispatch(WebAsyncManager.java:411)
	at org.springframework.web.context.request.async.WebAsyncManager.lambda$startDeferredResultProcessing$8(WebAsyncManager.java:489)
	at org.springframework.web.context.request.async.DeferredResult.setResultInternal(DeferredResult.java:272)
	at org.springframework.web.context.request.async.DeferredResult.setErrorResult(DeferredResult.java:287)
	at org.springframework.web.servlet.mvc.method.annotation.ResponseBodyEmitterReturnValueHandler$HttpMessageConvertingHandler.completeWithError(ResponseBodyEmitterReturnValueHandler.java:241)
	at org.springframework.web.servlet.mvc.method.annotation.ResponseBodyEmitter.completeWithError(ResponseBodyEmitter.java:267)
	at org.springframework.web.servlet.mvc.method.annotation.ReactiveTypeHandler$AbstractEmitterSubscriber.run(ReactiveTypeHandler.java:340)
	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)

@rstoyanchev
Copy link
Contributor

rstoyanchev commented Sep 16, 2024 •
edited
Loading

Thanks for the feedback and by the way 6.1.13 was released in the mean time.

For the new stacktrace, I have looked at the source code and cannot understand why or how this can happen. On the original stacktrace, the "task-4" thread is on line 332 of ReactiveTypeHandler trying to send the message, but gets stuck waiting on the state lock of StandardServletAsyncWebRequest. After the fix, it no longer waits indefinitely but keeps checking if the state changed and indicates an onError notification (in progress). That should result in AsyncRequestNotUsableException being thrown, eventually making its way to line 340 in ReactiveTypeHandler in the new stacktrace where the exception is handled by completing the SseEmitter.

In order for the dispatch on line 411 of WebAsyncManager in the new stacktrace to occur, it would have to pass the state check on line 388, which is protected with a synchronized block on WebAsyncManager.this and there should be only one such instance per request. The onError handling also passes through this method, so if it had passed first as the IllegalStateException says, it would have changed the state to RESULT_SET, and therefore the next thread to pass should exit early and not call dispatch. I don't see how this protection can fail, and therefore whether there is an issue at the level of Tomcat with how it makes this determination.

For the AsyncRequestNotUsableException on Servlet container thread "io-8080-exec-10", do you have any idea whether that's for the same request as the IllegalStateException? If so that would imply the onError handling called dispatch first and reached DefaultHandlerExceptionResolver. However, I would expect in that case the exception to be a Tomcat specific IOException. A more likely explanation is that it is for a different request where the AsyncRequestNotUsableException from SseEmitter succeeded in calling dispatch first.

I will try the example again to see if I have better luck, but it would help to see a full stacktrace for the exception. You could try DEBUG level logging for org.springframework.web, or an @ExceptionHandler to log it.

@dmngb
Copy link
Author

dmngb commented Sep 17, 2024

Below the full stacktrace (with 6.6.13, a similar one was also reproduced with 6.6.12 - so, this is not something new):

2024-09-17T09:07:03.010+02:00 ERROR 11316 --- [nio-8080-exec-3] o.a.c.c.C.[.[.[/].[dispatcherServlet]    : Servlet.service() for servlet [dispatcherServlet] threw exception

java.lang.IllegalStateException: Cannot start async: [ERROR]
	at org.springframework.util.Assert.state(Assert.java:76) ~[spring-core-6.1.13.jar:6.1.13]
	at org.springframework.web.context.request.async.StandardServletAsyncWebRequest.startAsync(StandardServletAsyncWebRequest.java:156) ~[spring-web-6.1.13.jar:6.1.13]
	at org.springframework.web.context.request.async.WebAsyncManager.startAsyncProcessing(WebAsyncManager.java:508) ~[spring-web-6.1.13.jar:6.1.13]
	at org.springframework.web.context.request.async.WebAsyncManager.startDeferredResultProcessing(WebAsyncManager.java:483) ~[spring-web-6.1.13.jar:6.1.13]
	at org.springframework.web.servlet.mvc.method.annotation.ResponseBodyEmitterReturnValueHandler.handleReturnValue(ResponseBodyEmitterReturnValueHandler.java:177) ~[spring-webmvc-6.1.13.jar:6.1.13]
	at org.springframework.web.method.support.HandlerMethodReturnValueHandlerComposite.handleReturnValue(HandlerMethodReturnValueHandlerComposite.java:78) ~[spring-web-6.1.13.jar:6.1.13]
	at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:136) ~[spring-webmvc-6.1.13.jar:6.1.13]
	at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:926) ~[spring-webmvc-6.1.13.jar:6.1.13]
	at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:831) ~[spring-webmvc-6.1.13.jar:6.1.13]
	at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87) ~[spring-webmvc-6.1.13.jar:6.1.13]
	at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1089) ~[spring-webmvc-6.1.13.jar:6.1.13]
	at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:979) ~[spring-webmvc-6.1.13.jar:6.1.13]
	at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1014) ~[spring-webmvc-6.1.13.jar:6.1.13]
	at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:903) ~[spring-webmvc-6.1.13.jar:6.1.13]
	at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:564) ~[tomcat-embed-core-10.1.28.jar:6.0]
	at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:885) ~[spring-webmvc-6.1.13.jar:6.1.13]
	at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:658) ~[tomcat-embed-core-10.1.28.jar:6.0]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:195) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:140) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100) ~[spring-web-6.1.13.jar:6.1.13]
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116) ~[spring-web-6.1.13.jar:6.1.13]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:164) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:140) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:101) ~[spring-web-6.1.13.jar:6.1.13]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:164) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:140) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:101) ~[spring-web-6.1.13.jar:6.1.13]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:164) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:140) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.apache.catalina.core.ApplicationDispatcher.invoke(ApplicationDispatcher.java:632) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.apache.catalina.core.ApplicationDispatcher.doDispatch(ApplicationDispatcher.java:560) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.apache.catalina.core.ApplicationDispatcher.dispatch(ApplicationDispatcher.java:531) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.apache.catalina.core.AsyncContextImpl$AsyncRunnable.run(AsyncContextImpl.java:601) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.apache.catalina.core.AsyncContextImpl.doInternalDispatch(AsyncContextImpl.java:344) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:165) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:90) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:483) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:115) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:93) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.apache.catalina.connector.CoyoteAdapter.asyncDispatch(CoyoteAdapter.java:239) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.apache.coyote.AbstractProcessor.dispatch(AbstractProcessor.java:243) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:57) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:904) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1741) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:52) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1190) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:63) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at java.base/java.lang.Thread.run(Thread.java:1583) ~[na:na]

2024-09-17T09:07:03.033+02:00 ERROR 11316 --- [nio-8080-exec-3] o.a.c.c.C.[.[.[/].[dispatcherServlet]    : Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception [Request processing failed: java.lang.IllegalStateException: Cannot start async: [ERROR]] with root cause

java.lang.IllegalStateException: Cannot start async: [ERROR]
	at org.springframework.util.Assert.state(Assert.java:76) ~[spring-core-6.1.13.jar:6.1.13]
	at org.springframework.web.context.request.async.StandardServletAsyncWebRequest.startAsync(StandardServletAsyncWebRequest.java:156) ~[spring-web-6.1.13.jar:6.1.13]
	at org.springframework.web.context.request.async.WebAsyncManager.startAsyncProcessing(WebAsyncManager.java:508) ~[spring-web-6.1.13.jar:6.1.13]
	at org.springframework.web.context.request.async.WebAsyncManager.startDeferredResultProcessing(WebAsyncManager.java:483) ~[spring-web-6.1.13.jar:6.1.13]
	at org.springframework.web.servlet.mvc.method.annotation.ResponseBodyEmitterReturnValueHandler.handleReturnValue(ResponseBodyEmitterReturnValueHandler.java:177) ~[spring-webmvc-6.1.13.jar:6.1.13]
	at org.springframework.web.method.support.HandlerMethodReturnValueHandlerComposite.handleReturnValue(HandlerMethodReturnValueHandlerComposite.java:78) ~[spring-web-6.1.13.jar:6.1.13]
	at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:136) ~[spring-webmvc-6.1.13.jar:6.1.13]
	at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:926) ~[spring-webmvc-6.1.13.jar:6.1.13]
	at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:831) ~[spring-webmvc-6.1.13.jar:6.1.13]
	at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87) ~[spring-webmvc-6.1.13.jar:6.1.13]
	at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1089) ~[spring-webmvc-6.1.13.jar:6.1.13]
	at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:979) ~[spring-webmvc-6.1.13.jar:6.1.13]
	at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1014) ~[spring-webmvc-6.1.13.jar:6.1.13]
	at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:903) ~[spring-webmvc-6.1.13.jar:6.1.13]
	at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:564) ~[tomcat-embed-core-10.1.28.jar:6.0]
	at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:885) ~[spring-webmvc-6.1.13.jar:6.1.13]
	at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:658) ~[tomcat-embed-core-10.1.28.jar:6.0]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:195) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:140) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100) ~[spring-web-6.1.13.jar:6.1.13]
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116) ~[spring-web-6.1.13.jar:6.1.13]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:164) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:140) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:101) ~[spring-web-6.1.13.jar:6.1.13]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:164) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:140) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:101) ~[spring-web-6.1.13.jar:6.1.13]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:164) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:140) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.apache.catalina.core.ApplicationDispatcher.invoke(ApplicationDispatcher.java:632) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.apache.catalina.core.ApplicationDispatcher.doDispatch(ApplicationDispatcher.java:560) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.apache.catalina.core.ApplicationDispatcher.dispatch(ApplicationDispatcher.java:531) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.apache.catalina.core.AsyncContextImpl$AsyncRunnable.run(AsyncContextImpl.java:601) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.apache.catalina.core.AsyncContextImpl.doInternalDispatch(AsyncContextImpl.java:344) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:165) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:90) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:483) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:115) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:93) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.apache.catalina.connector.CoyoteAdapter.asyncDispatch(CoyoteAdapter.java:239) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.apache.coyote.AbstractProcessor.dispatch(AbstractProcessor.java:243) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:57) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:904) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1741) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:52) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1190) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:63) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
	at java.base/java.lang.Thread.run(Thread.java:1583) ~[na:na]

2024-09-17T09:07:03.777+02:00  WARN 11316 --- [nio-8080-exec-7] .w.s.m.s.DefaultHandlerExceptionResolver : Resolved [org.springframework.web.context.request.async.AsyncRequestNotUsableException: ServletOutputStream failed to write: java.io.IOException: An established connection was aborted by the software in your host machine]
Exception in thread "task-1" java.lang.IllegalStateException: A non-container (application) thread attempted to use the AsyncContext after an error had occurred and the call to AsyncListener.onError() had returned. This is not allowed to avoid race conditions.
	at org.apache.catalina.core.AsyncContextImpl.check(AsyncContextImpl.java:537)
	at org.apache.catalina.core.AsyncContextImpl.getRequest(AsyncContextImpl.java:211)
	at org.apache.catalina.core.AsyncContextImpl.dispatch(AsyncContextImpl.java:201)
	at org.apache.catalina.core.AsyncContextImpl.dispatch(AsyncContextImpl.java:176)
	at org.apache.catalina.core.AsyncContextImpl.dispatch(AsyncContextImpl.java:170)
	at org.springframework.web.context.request.async.StandardServletAsyncWebRequest.dispatch(StandardServletAsyncWebRequest.java:170)
	at org.springframework.web.context.request.async.WebAsyncManager.setConcurrentResultAndDispatch(WebAsyncManager.java:411)
	at org.springframework.web.context.request.async.WebAsyncManager.lambda$startDeferredResultProcessing$8(WebAsyncManager.java:489)
	at org.springframework.web.context.request.async.DeferredResult.setResultInternal(DeferredResult.java:272)
	at org.springframework.web.context.request.async.DeferredResult.setErrorResult(DeferredResult.java:287)
	at org.springframework.web.servlet.mvc.method.annotation.ResponseBodyEmitterReturnValueHandler$HttpMessageConvertingHandler.completeWithError(ResponseBodyEmitterReturnValueHandler.java:241)
	at org.springframework.web.servlet.mvc.method.annotation.ResponseBodyEmitter.completeWithError(ResponseBodyEmitter.java:267)
	at org.springframework.web.servlet.mvc.method.annotation.ReactiveTypeHandler$AbstractEmitterSubscriber.run(ReactiveTypeHandler.java:340)
	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)
2024-09-17T09:07:04.303+02:00  WARN 11316 --- [nio-8080-exec-4] .w.s.m.s.DefaultHandlerExceptionResolver : Resolved [org.springframework.web.context.request.async.AsyncRequestNotUsableException: ServletOutputStream failed to write: java.io.IOException: An established connection was aborted by the software in your host machine]
2024-09-17T09:07:04.477+02:00  WARN 11316 --- [nio-8080-exec-5] .w.s.m.s.DefaultHandlerExceptionResolver : Resolved [org.springframework.web.context.request.async.AsyncRequestNotUsableException: ServletOutputStream failed to flush: java.io.IOException: An established connection was aborted by the software in your host machine]

@micvm
Copy link

micvm commented Oct 2, 2024

Is this something that should be backported to 5.3.x or does it affect only higher versions?

@bclozel
Copy link
Member

bclozel commented Oct 2, 2024

@micvm older generations are only commercially supported at this point, see https://spring.io/projects/spring-framework#support

@micvm
Copy link

micvm commented Oct 2, 2024

@micvm older generations are only commercially supported at this point, see https://spring.io/projects/spring-framework#support

Oh thanks. I totally missed that deadline. That's why there is no backport then.

@bclozel
Copy link
Member

bclozel commented Oct 2, 2024

We announced this on our blog and since released a first set of commercial versions for a CVE fix.

You can learn more about our support offering here: https://spring.io/support

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@rstoyanchev rstoyanchev

Labels
in: web Issues in web modules (web, webmvc, webflux, websocket) type: bug A general bug
Projects
None yet
Milestone
6.1.13
Development

No branches or pull requests
5 participants
@bclozel @rstoyanchev @micvm @spring-projects-issues @dmngb