First reported as bug on Spring Boot(https://github.com/spring-projects/spring-boot/issues/36803). After some investigation I've been redirected by the spring team to post the bug here. Reproduction steps with spring boot(tested on version 3.0.0 and 3.1.2): - Create spring initializr project with Kotlin and spring-boot-starter-web - Add org.jetbrains.kotlinx:kotlinx-coroutines-reactor dependency - Run following (Kotlin) code --- @SpringBootApplication class DemoApplication fun main(args: Array<String>) { runApplication<DemoApplication>(*args) } @RestController class Controller { @GetMapping("suspend") suspend fun errorScenario() { throw IllegalStateException("Double exception handling") } } @ControllerAdvice class ExceptionHandler : ResponseEntityExceptionHandler() { @ExceptionHandler(Exception::class) fun handleUnexpectedException( ex: Exception, request: WebRequest ): ResponseEntity<Any>? { return handleException( ErrorResponseException( HttpStatus.INTERNAL_SERVER_ERROR, ProblemDetail.forStatus(500), ex ), request ) } } --- When calling the /suspend endpoint (with postman) spring will catch the exception and create a response. If that response is has status 500 it will also set "jakarta.servlet.error.exception" with the caught exception. Because of this, this code in org.apache.catalina.connector.CoyoteAdapter.asyncDispatch(...) will trigger a second exception handling. --- if (request.isAsyncDispatching()) { connector.getService().getContainer().getPipeline().getFirst().invoke(request, response); Throwable t = (Throwable) request.getAttribute(RequestDispatcher.ERROR_EXCEPTION); if (t != null) { asyncConImpl.setErrorState(t, true); } } --- The result of this is that two response bodies, including body size, will be generated and returned. Postman will show that the request had a problem. This is because there is more data than the first body size reports, which is an invalid http response. Sniffing the response you can actually see the full response: --- HTTP/1.1 500 Content-Type: application/problem+json Transfer-Encoding: chunked Date: Tue, 08 Aug 2023 09:26:30 GMT Connection: close 59 {"type":"about:blank","title":"Internal Server Error","status":500,"instance":"/suspend"} 6c {"timestamp":"2023-08-08T09:26:30.705+00:00","status":500,"error":"Internal Server Error","path":"/suspend"} --- When calling the endpoint with chrome it will generate following error message, but only return a single response: s.e.ErrorMvcAutoConfiguration$StaticView : Cannot render error page for request [/suspend] as the response has already been committed. As a result, the response may have the wrong status code. This bug goes for me far too deep into the inner workings and I don't know if this is a tomcat bug or spring should just not set the the request attribute "jakarta.servlet.error.exception". It is however notable that when using another server(jetty, undertow) underneath spring this issue does not occur. And that is probably why the spring team send me here.
I am unable to reproduce this with Spring Boot 3.1.3 (Tomcat 10.1.12). This looks to have been fixed by the fix for BZ 66841. There are also additional fixes in 10.1.x for duplicate error handling. *** This bug has been marked as a duplicate of bug 66841 ***
With the exact same code I do still run into the same issue as before. You might have not included org.jetbrains.kotlinx:kotlinx-coroutines-reactor as dependency. If that dependency is not added then tomcat calls are not executed in async mode. Here is the log output for Spring Boot v3.1.3 and Tomcat 10.1.12 for the aforementioned code. . ____ _ __ _ _ /\\ / ___'_ __ _ _(_)_ __ __ _ \ \ \ \ ( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \ \\/ ___)| |_)| | | | | || (_| | ) ) ) ) ' |____| .__|_| |_|_| |_\__, | / / / / =========|_|==============|___/=/_/_/_/ :: Spring Boot :: (v3.1.3) 2023-09-25T14:28:52.231+02:00 INFO 41884 --- [ main] com.example.demo.DemoApplicationKt : Starting DemoApplicationKt using Java 18.0.2.1 with PID 41884 (...) 2023-09-25T14:28:52.233+02:00 INFO 41884 --- [ main] com.example.demo.DemoApplicationKt : No active profile set, falling back to 1 default profile: "default" 2023-09-25T14:28:52.848+02:00 INFO 41884 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat initialized with port(s): 8080 (http) 2023-09-25T14:28:52.854+02:00 INFO 41884 --- [ main] o.apache.catalina.core.StandardService : Starting service [Tomcat] 2023-09-25T14:28:52.855+02:00 INFO 41884 --- [ main] o.apache.catalina.core.StandardEngine : Starting Servlet engine: [Apache Tomcat/10.1.12] 2023-09-25T14:28:52.917+02:00 INFO 41884 --- [ main] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring embedded WebApplicationContext 2023-09-25T14:28:52.918+02:00 INFO 41884 --- [ main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 649 ms 2023-09-25T14:28:53.190+02:00 INFO 41884 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat started on port(s): 8080 (http) with context path '' 2023-09-25T14:28:53.194+02:00 INFO 41884 --- [ main] com.example.demo.DemoApplicationKt : Started DemoApplicationKt in 1.251 seconds (process running for 1.71) 2023-09-25T14:28:54.564+02:00 INFO 41884 --- [nio-8080-exec-1] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring DispatcherServlet 'dispatcherServlet' 2023-09-25T14:28:54.564+02:00 INFO 41884 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet : Initializing Servlet 'dispatcherServlet' 2023-09-25T14:28:54.564+02:00 INFO 41884 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet : Completed initialization in 0 ms 2023-09-25T14:28:54.821+02:00 ERROR 41884 --- [nio-8080-exec-1] s.e.ErrorMvcAutoConfiguration$StaticView : Cannot render error page for request [/suspend] as the response has already been committed. As a result, the response may have the wrong status code.
I have created a test case using the information provided including the org.jetbrains.kotlinx:kotlinx-coroutines-reactor dependency and am unable to recreate this issue. If you still see an issue then I suspect there are additional steps required to create the reproducible test case that have not been provided. I suggest you provide a minimal Spring Boot project that demonstrates the issue.
Here is a minimal project to reproduce it: https://github.com/nilskohrs/tomcat-bug-66875
I've updated the example to spring boot 3.1.4 and still get this error on calling the endpoint: 023-10-06T15:41:55.615+02:00 ERROR 53360 --- [nio-8080-exec-3] s.e.ErrorMvcAutoConfiguration$StaticView : Cannot render error page for request [/suspend] as the response has already been committed. As a result, the response may have the wrong status code.
It is indeed possible to reproduce it, here is the debug log: 2023-10-07T18:55:08.622+08:00 DEBUG 10702 --- [o-8080-Acceptor] o.apache.tomcat.util.threads.LimitLatch : Counting up[http-nio-8080-Acceptor] latch=1 2023-10-07T18:55:08.622+08:00 DEBUG 10702 --- [o-8080-Acceptor] o.apache.tomcat.util.threads.LimitLatch : Counting up[http-nio-8080-Acceptor] latch=2 2023-10-07T18:55:08.646+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.coyote.http11.Http11InputBuffer : Before fill(): parsingHeader: [true], parsingRequestLine: [true], parsingRequestLinePhase: [0], parsingRequestLineStart: [0], byteBuffer.position(): [0], byteBuffer.limit(): [0], end: [0] 2023-10-07T18:55:08.646+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.tomcat.util.net.SocketWrapperBase : Socket: [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@375c60d5:org.apache.tomcat.util.net.NioChannel@d287989:java.nio.channels.SocketChannel[connected local=/[0:0:0:0:0:0:0:1]:8080 remote=/[0:0:0:0:0:0:0:1]:63136]], Read from buffer: [0] 2023-10-07T18:55:08.646+08:00 DEBUG 10702 --- [nio-8080-exec-1] org.apache.tomcat.util.net.NioEndpoint : Socket: [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@375c60d5:org.apache.tomcat.util.net.NioChannel@d287989:java.nio.channels.SocketChannel[connected local=/[0:0:0:0:0:0:0:1]:8080 remote=/[0:0:0:0:0:0:0:1]:63136]], Read direct from socket: [706] 2023-10-07T18:55:08.646+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.coyote.http11.Http11InputBuffer : Received [GET /suspend HTTP/1.1 Host: localhost:8080 Connection: keep-alive Cache-Control: max-age=0 sec-ch-ua: "Google Chrome";v="117", "Not;A=Brand";v="8", "Chromium";v="117" sec-ch-ua-mobile: ?0 sec-ch-ua-platform: "macOS" Upgrade-Insecure-Requests: 1 User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/117.0.0.0 Safari/537.36 Accept: text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3;q=0.7 Sec-Fetch-Site: none Sec-Fetch-Mode: navigate Sec-Fetch-User: ?1 Sec-Fetch-Dest: document Accept-Encoding: gzip, deflate, br Accept-Language: zh-CN,zh;q=0.9,zh-TW;q=0.8 ] 2023-10-07T18:55:08.660+08:00 DEBUG 10702 --- [nio-8080-exec-1] org.apache.tomcat.util.http.Parameters : Set query string encoding to UTF-8 2023-10-07T18:55:08.661+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.authenticator.AuthenticatorBase : Security checking request GET /suspend 2023-10-07T18:55:08.662+08:00 DEBUG 10702 --- [nio-8080-exec-1] org.apache.catalina.realm.RealmBase : No applicable constraints defined 2023-10-07T18:55:08.664+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.a.jaspic.AuthConfigFactoryImpl : Loading persistent provider registrations from [/private/var/folders/mf/5hx78jfj1s12c3tnbk5vr0_c0000gn/T/tomcat.8080.3148371716981476226/conf/jaspic-providers.xml] 2023-10-07T18:55:08.664+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.authenticator.AuthenticatorBase : Not subject to any constraint 2023-10-07T18:55:08.666+08:00 INFO 10702 --- [nio-8080-exec-1] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring DispatcherServlet 'dispatcherServlet' 2023-10-07T18:55:08.666+08:00 INFO 10702 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet : Initializing Servlet 'dispatcherServlet' 2023-10-07T18:55:08.666+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet : Detected StandardServletMultipartResolver 2023-10-07T18:55:08.666+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet : Detected AcceptHeaderLocaleResolver 2023-10-07T18:55:08.666+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet : Detected FixedThemeResolver 2023-10-07T18:55:08.666+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet : Detected org.springframework.web.servlet.view.DefaultRequestToViewNameTranslator@e39dfa6 2023-10-07T18:55:08.666+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet : Detected org.springframework.web.servlet.support.SessionFlashMapManager@56b2037f 2023-10-07T18:55:08.667+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet : enableLoggingRequestDetails='false': request parameters and headers will be masked to prevent unsafe logging of potentially sensitive data 2023-10-07T18:55:08.667+08:00 INFO 10702 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet : Completed initialization in 1 ms 2023-10-07T18:55:08.673+08:00 DEBUG 10702 --- [nio-8080-exec-1] org.apache.tomcat.util.http.Parameters : Set encoding to UTF-8 2023-10-07T18:55:08.673+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet : GET "/suspend", parameters={} 2023-10-07T18:55:08.683+08:00 DEBUG 10702 --- [nio-8080-exec-1] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped to bug.example.Controller#other(Continuation) 2023-10-07T18:55:08.746+08:00 DEBUG 10702 --- [nio-8080-exec-1] reactor.util.Loggers : Using Slf4j logging framework 2023-10-07T18:55:08.787+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.apache.catalina.core.AsyncContextImpl : Req: null CReq: null RP: null Stage: - Thread: http-nio-8080-exec-1 State: N/A Method: Constructor URI: N/A 2023-10-07T18:55:08.787+08:00 DEBUG 10702 --- [nio-8080-exec-1] org.apache.coyote.AsyncStateMachine : Changing async state from [DISPATCHED] to [STARTING] 2023-10-07T18:55:08.787+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.apache.catalina.core.AsyncContextImpl : Firing onStartAsync() event for any AsyncListeners 2023-10-07T18:55:08.787+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.s.w.c.request.async.WebAsyncManager : Started async request 2023-10-07T18:55:08.788+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.s.w.c.request.async.WebAsyncManager : Async error, dispatch to /suspend 2023-10-07T18:55:08.788+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.apache.catalina.core.AsyncContextImpl : Req: 5844338c CReq: 4f70376c RP: 5acae348 Stage: 3 Thread: http-nio-8080-exec-1 State: N/A Method: dispatch URI: /suspend 2023-10-07T18:55:08.789+08:00 DEBUG 10702 --- [nio-8080-exec-1] org.apache.coyote.AsyncStateMachine : Changing async state from [STARTING] to [MUST_DISPATCH] 2023-10-07T18:55:08.790+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet : Exiting but response remains open for further handling 2023-10-07T18:55:08.790+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.apache.coyote.http11.Http11Processor : Socket: [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@375c60d5:org.apache.tomcat.util.net.NioChannel@d287989:java.nio.channels.SocketChannel[connected local=/[0:0:0:0:0:0:0:1]:8080 remote=/[0:0:0:0:0:0:0:1]:63136]], Status in: [OPEN_READ], State out: [LONG] 2023-10-07T18:55:08.790+08:00 DEBUG 10702 --- [nio-8080-exec-1] org.apache.coyote.AsyncStateMachine : Changing async state from [MUST_DISPATCH] to [DISPATCHING] 2023-10-07T18:55:08.790+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.apache.coyote.http11.Http11Processor : Socket: [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@375c60d5:org.apache.tomcat.util.net.NioChannel@d287989:java.nio.channels.SocketChannel[connected local=/[0:0:0:0:0:0:0:1]:8080 remote=/[0:0:0:0:0:0:0:1]:63136]], State after async post processing: [ASYNC_END] 2023-10-07T18:55:08.791+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.authenticator.AuthenticatorBase : Security checking request GET /suspend 2023-10-07T18:55:08.791+08:00 DEBUG 10702 --- [nio-8080-exec-1] org.apache.catalina.realm.RealmBase : No applicable constraints defined 2023-10-07T18:55:08.791+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.authenticator.AuthenticatorBase : Not subject to any constraint 2023-10-07T18:55:08.791+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.apache.catalina.core.AsyncContextImpl : Req: 5844338c CReq: 4f70376c RP: 5acae348 Stage: 3 Thread: http-nio-8080-exec-1 State: N/A Method: intDispatch URI: /suspend 2023-10-07T18:55:08.791+08:00 DEBUG 10702 --- [nio-8080-exec-1] org.apache.coyote.AsyncStateMachine : Changing async state from [DISPATCHING] to [DISPATCHED] 2023-10-07T18:55:08.793+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet : "ASYNC" dispatch for GET "/suspend", parameters={} 2023-10-07T18:55:08.794+08:00 DEBUG 10702 --- [nio-8080-exec-1] s.w.s.m.m.a.RequestMappingHandlerAdapter : Resume with async result [java.lang.IllegalStateException: This returns double error response] 2023-10-07T18:55:08.796+08:00 DEBUG 10702 --- [nio-8080-exec-1] .m.m.a.ExceptionHandlerExceptionResolver : Using @ExceptionHandler bug.example.ExceptionHandler#handleUnexpectedTechnicalException(Exception, WebRequest) 2023-10-07T18:55:08.988+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.s.w.s.m.m.a.HttpEntityMethodProcessor : Using 'application/problem+json;q=0.8', given [text/html, application/xhtml+xml, image/avif, image/webp, image/apng, application/xml;q=0.9, */*;q=0.8, application/signed-exchange;v=b3;q=0.7] and supported [application/problem+json] 2023-10-07T18:55:08.992+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.s.w.s.m.m.a.HttpEntityMethodProcessor : Writing [ProblemDetail[type='about:blank', title='Internal Server Error', status=500, detail='null', instance (truncated)...] 2023-10-07T18:55:09.003+08:00 DEBUG 10702 --- [nio-8080-exec-1] .m.m.a.ExceptionHandlerExceptionResolver : Resolved [java.lang.IllegalStateException: This returns double error response] 2023-10-07T18:55:09.005+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet : Exiting from "ASYNC" dispatch, status 500 2023-10-07T18:55:09.005+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.apache.catalina.core.AsyncContextImpl : Firing onComplete() event for any AsyncListeners 2023-10-07T18:55:09.005+08:00 DEBUG 10702 --- [nio-8080-exec-1] org.apache.coyote.AsyncStateMachine : Starting to process call to asyncError() 2023-10-07T18:55:09.005+08:00 DEBUG 10702 --- [nio-8080-exec-1] org.apache.coyote.AsyncStateMachine : Changing async state from [DISPATCHED] to [ERROR] 2023-10-07T18:55:09.006+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.apache.catalina.core.AsyncContextImpl : Firing onError() event for any AsyncListeners 2023-10-07T18:55:09.006+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.c.C.[Tomcat].[localhost] : Processing ErrorPage[errorCode=0, location=/error] 2023-10-07T18:55:09.007+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet : "INCLUDE" dispatch for GET "/error", parameters={} 2023-10-07T18:55:09.009+08:00 DEBUG 10702 --- [nio-8080-exec-1] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped to org.springframework.boot.autoconfigure.web.servlet.error.BasicErrorController#errorHtml(HttpServletRequest, HttpServletResponse) 2023-10-07T18:55:09.010+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : findClass(freemarker.template.Configuration) 2023-10-07T18:55:09.011+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : --> Returning ClassNotFoundException 2023-10-07T18:55:09.011+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : findClass(freemarker.template$Configuration) 2023-10-07T18:55:09.011+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : --> Returning ClassNotFoundException 2023-10-07T18:55:09.012+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : findClass(com.samskivert.mustache.Template) 2023-10-07T18:55:09.012+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : --> Returning ClassNotFoundException 2023-10-07T18:55:09.012+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : findClass(com.samskivert.mustache$Template) 2023-10-07T18:55:09.013+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : --> Returning ClassNotFoundException 2023-10-07T18:55:09.013+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : findClass(groovy.text.TemplateEngine) 2023-10-07T18:55:09.013+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : --> Returning ClassNotFoundException 2023-10-07T18:55:09.014+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : findClass(groovy.text$TemplateEngine) 2023-10-07T18:55:09.014+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : --> Returning ClassNotFoundException 2023-10-07T18:55:09.014+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : findClass(org.thymeleaf.spring6.SpringTemplateEngine) 2023-10-07T18:55:09.015+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : --> Returning ClassNotFoundException 2023-10-07T18:55:09.015+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : findClass(org.thymeleaf.spring6$SpringTemplateEngine) 2023-10-07T18:55:09.015+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : --> Returning ClassNotFoundException 2023-10-07T18:55:09.015+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : findClass(org.apache.jasper.compiler.JspConfig) 2023-10-07T18:55:09.016+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : --> Returning ClassNotFoundException 2023-10-07T18:55:09.016+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : findClass(org.apache.jasper.compiler$JspConfig) 2023-10-07T18:55:09.016+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : --> Returning ClassNotFoundException 2023-10-07T18:55:09.016+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : getResource(META-INF/resources/error/500.html) 2023-10-07T18:55:09.017+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : Delegating to parent classloader jdk.internal.loader.ClassLoaders$AppClassLoader@4e0e2f2a 2023-10-07T18:55:09.017+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : --> Resource not found, returning null 2023-10-07T18:55:09.017+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : getResource(resources/error/500.html) 2023-10-07T18:55:09.017+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : Delegating to parent classloader jdk.internal.loader.ClassLoaders$AppClassLoader@4e0e2f2a 2023-10-07T18:55:09.017+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : --> Resource not found, returning null 2023-10-07T18:55:09.017+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : getResource(static/error/500.html) 2023-10-07T18:55:09.017+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : Delegating to parent classloader jdk.internal.loader.ClassLoaders$AppClassLoader@4e0e2f2a 2023-10-07T18:55:09.017+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : --> Resource not found, returning null 2023-10-07T18:55:09.017+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : getResource(public/error/500.html) 2023-10-07T18:55:09.018+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : Delegating to parent classloader jdk.internal.loader.ClassLoaders$AppClassLoader@4e0e2f2a 2023-10-07T18:55:09.018+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : --> Resource not found, returning null 2023-10-07T18:55:09.018+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : findClass(freemarker.template.Configuration) 2023-10-07T18:55:09.019+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : --> Returning ClassNotFoundException 2023-10-07T18:55:09.019+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : findClass(freemarker.template$Configuration) 2023-10-07T18:55:09.019+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : --> Returning ClassNotFoundException 2023-10-07T18:55:09.020+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : findClass(com.samskivert.mustache.Template) 2023-10-07T18:55:09.020+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : --> Returning ClassNotFoundException 2023-10-07T18:55:09.021+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : findClass(com.samskivert.mustache$Template) 2023-10-07T18:55:09.021+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : --> Returning ClassNotFoundException 2023-10-07T18:55:09.021+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : findClass(groovy.text.TemplateEngine) 2023-10-07T18:55:09.022+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : --> Returning ClassNotFoundException 2023-10-07T18:55:09.022+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : findClass(groovy.text$TemplateEngine) 2023-10-07T18:55:09.022+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : --> Returning ClassNotFoundException 2023-10-07T18:55:09.022+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : findClass(org.thymeleaf.spring6.SpringTemplateEngine) 2023-10-07T18:55:09.023+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : --> Returning ClassNotFoundException 2023-10-07T18:55:09.023+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : findClass(org.thymeleaf.spring6$SpringTemplateEngine) 2023-10-07T18:55:09.023+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : --> Returning ClassNotFoundException 2023-10-07T18:55:09.023+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : findClass(org.apache.jasper.compiler.JspConfig) 2023-10-07T18:55:09.023+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : --> Returning ClassNotFoundException 2023-10-07T18:55:09.024+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : findClass(org.apache.jasper.compiler$JspConfig) 2023-10-07T18:55:09.024+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : --> Returning ClassNotFoundException 2023-10-07T18:55:09.024+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : getResource(META-INF/resources/error/5xx.html) 2023-10-07T18:55:09.024+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : Delegating to parent classloader jdk.internal.loader.ClassLoaders$AppClassLoader@4e0e2f2a 2023-10-07T18:55:09.024+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : --> Resource not found, returning null 2023-10-07T18:55:09.024+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : getResource(resources/error/5xx.html) 2023-10-07T18:55:09.025+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : Delegating to parent classloader jdk.internal.loader.ClassLoaders$AppClassLoader@4e0e2f2a 2023-10-07T18:55:09.025+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : --> Resource not found, returning null 2023-10-07T18:55:09.025+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : getResource(static/error/5xx.html) 2023-10-07T18:55:09.025+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : Delegating to parent classloader jdk.internal.loader.ClassLoaders$AppClassLoader@4e0e2f2a 2023-10-07T18:55:09.025+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : --> Resource not found, returning null 2023-10-07T18:55:09.025+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : getResource(public/error/5xx.html) 2023-10-07T18:55:09.025+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : Delegating to parent classloader jdk.internal.loader.ClassLoaders$AppClassLoader@4e0e2f2a 2023-10-07T18:55:09.025+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.a.c.loader.WebappClassLoaderBase : --> Resource not found, returning null 2023-10-07T18:55:09.029+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.s.w.s.v.ContentNegotiatingViewResolver : Selected 'text/html' given [text/html, text/html;q=0.8] 2023-10-07T18:55:09.029+08:00 ERROR 10702 --- [nio-8080-exec-1] s.e.ErrorMvcAutoConfiguration$StaticView : Cannot render error page for request [/suspend] as the response has already been committed. As a result, the response may have the wrong status code. 2023-10-07T18:55:09.029+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.s.web.servlet.DispatcherServlet : Exiting from "INCLUDE" dispatch, status 500 2023-10-07T18:55:09.029+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.apache.coyote.http11.Http11Processor : Error state [CLOSE_NOW] reported while processing request org.springframework.web.ErrorResponseException: 500 INTERNAL_SERVER_ERROR, ProblemDetail[type='about:blank', title='Internal Server Error', status=500, detail='null', instance='/suspend', properties='null'] at bug.example.ExceptionHandler.handleUnexpectedTechnicalException(SupendErrorHandlingError.kt:38) ~[classes/:na] at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103) ~[na:na] at java.base/java.lang.reflect.Method.invoke(Method.java:580) ~[na:na] at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:205) ~[spring-web-6.0.12.jar:6.0.12] at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:150) ~[spring-web-6.0.12.jar:6.0.12] at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:118) ~[spring-webmvc-6.0.12.jar:6.0.12] at org.springframework.web.servlet.mvc.method.annotation.ExceptionHandlerExceptionResolver.doResolveHandlerMethodException(ExceptionHandlerExceptionResolver.java:413) ~[spring-webmvc-6.0.12.jar:6.0.12] at org.springframework.web.servlet.handler.AbstractHandlerMethodExceptionResolver.doResolveException(AbstractHandlerMethodExceptionResolver.java:74) ~[spring-webmvc-6.0.12.jar:6.0.12] at org.springframework.web.servlet.handler.AbstractHandlerExceptionResolver.resolveException(AbstractHandlerExceptionResolver.java:141) ~[spring-webmvc-6.0.12.jar:6.0.12] at org.springframework.web.servlet.handler.HandlerExceptionResolverComposite.resolveException(HandlerExceptionResolverComposite.java:80) ~[spring-webmvc-6.0.12.jar:6.0.12] at org.springframework.web.servlet.DispatcherServlet.processHandlerException(DispatcherServlet.java:1341) ~[spring-webmvc-6.0.12.jar:6.0.12] at org.springframework.web.servlet.DispatcherServlet.processDispatchResult(DispatcherServlet.java:1152) ~[spring-webmvc-6.0.12.jar:6.0.12] at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1098) ~[spring-webmvc-6.0.12.jar:6.0.12] at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:974) ~[spring-webmvc-6.0.12.jar:6.0.12] at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1011) ~[spring-webmvc-6.0.12.jar:6.0.12] at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:903) ~[spring-webmvc-6.0.12.jar:6.0.12] at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:564) ~[tomcat-embed-core.jar:6.0] at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:885) ~[spring-webmvc-6.0.12.jar:6.0.12] at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:658) ~[tomcat-embed-core.jar:6.0] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:205) ~[tomcat-embed-core.jar:10.1.14-dev] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149) ~[tomcat-embed-core.jar:10.1.14-dev] at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100) ~[spring-web-6.0.12.jar:6.0.12] at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116) ~[spring-web-6.0.12.jar:6.0.12] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:174) ~[tomcat-embed-core.jar:10.1.14-dev] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149) ~[tomcat-embed-core.jar:10.1.14-dev] at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:101) ~[spring-web-6.0.12.jar:6.0.12] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:174) ~[tomcat-embed-core.jar:10.1.14-dev] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149) ~[tomcat-embed-core.jar:10.1.14-dev] at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:101) ~[spring-web-6.0.12.jar:6.0.12] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:174) ~[tomcat-embed-core.jar:10.1.14-dev] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149) ~[tomcat-embed-core.jar:10.1.14-dev] at org.apache.catalina.core.ApplicationDispatcher.invoke(ApplicationDispatcher.java:642) ~[tomcat-embed-core.jar:10.1.14-dev] at org.apache.catalina.core.ApplicationDispatcher.doDispatch(ApplicationDispatcher.java:570) ~[tomcat-embed-core.jar:10.1.14-dev] at org.apache.catalina.core.ApplicationDispatcher.dispatch(ApplicationDispatcher.java:541) ~[tomcat-embed-core.jar:10.1.14-dev] at org.apache.catalina.core.AsyncContextImpl$AsyncRunnable.run(AsyncContextImpl.java:570) ~[tomcat-embed-core.jar:10.1.14-dev] at org.apache.catalina.core.AsyncContextImpl.doInternalDispatch(AsyncContextImpl.java:340) ~[tomcat-embed-core.jar:10.1.14-dev] at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:165) ~[tomcat-embed-core.jar:10.1.14-dev] at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:90) ~[tomcat-embed-core.jar:10.1.14-dev] at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:482) ~[tomcat-embed-core.jar:10.1.14-dev] at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:115) ~[tomcat-embed-core.jar:10.1.14-dev] at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:93) ~[tomcat-embed-core.jar:10.1.14-dev] at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74) ~[tomcat-embed-core.jar:10.1.14-dev] at org.apache.catalina.connector.CoyoteAdapter.asyncDispatch(CoyoteAdapter.java:235) ~[tomcat-embed-core.jar:10.1.14-dev] at org.apache.coyote.AbstractProcessor.dispatch(AbstractProcessor.java:243) ~[tomcat-embed-core.jar:10.1.14-dev] at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:57) ~[tomcat-embed-core.jar:10.1.14-dev] at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:896) ~[tomcat-embed-core.jar:10.1.14-dev] at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1744) ~[tomcat-embed-core.jar:10.1.14-dev] at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:52) ~[tomcat-embed-core.jar:10.1.14-dev] at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191) ~[tomcat-embed-core.jar:10.1.14-dev] at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659) ~[tomcat-embed-core.jar:10.1.14-dev] at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) ~[tomcat-embed-core.jar:10.1.14-dev] at java.base/java.lang.Thread.run(Thread.java:1583) ~[na:na] Caused by: java.lang.IllegalStateException: This returns double error response at bug.example.Controller.other$suspendImpl(SupendErrorHandlingError.kt:26) ~[classes/:na] at bug.example.Controller.other(SupendErrorHandlingError.kt) ~[classes/:na] at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103) ~[na:na] at java.base/java.lang.reflect.Method.invoke(Method.java:580) ~[na:na] at kotlin.reflect.jvm.internal.calls.CallerImpl$Method.callMethod(CallerImpl.kt:97) ~[kotlin-reflect-1.8.22.jar:1.8.22-release-407(1.8.22)] at kotlin.reflect.jvm.internal.calls.CallerImpl$Method$Instance.call(CallerImpl.kt:113) ~[kotlin-reflect-1.8.22.jar:1.8.22-release-407(1.8.22)] at kotlin.reflect.jvm.internal.KCallableImpl.call(KCallableImpl.kt:107) ~[kotlin-reflect-1.8.22.jar:1.8.22-release-407(1.8.22)] at kotlin.reflect.full.KCallables.callSuspend(KCallables.kt:56) ~[kotlin-reflect-1.8.22.jar:1.8.22-release-407(1.8.22)] at org.springframework.core.CoroutinesUtils.lambda$invokeSuspendingFunction$2(CoroutinesUtils.java:108) ~[spring-core-6.0.12.jar:6.0.12] at kotlin.coroutines.intrinsics.IntrinsicsKt__IntrinsicsJvmKt$createCoroutineUnintercepted$$inlined$createCoroutineFromSuspendFunction$IntrinsicsKt__IntrinsicsJvmKt$4.invokeSuspend(IntrinsicsJvm.kt:205) ~[kotlin-stdlib-1.8.22.jar:1.8.22-release-407(1.8.22)] at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33) ~[kotlin-stdlib-1.8.22.jar:1.8.22-release-407(1.8.22)] at kotlinx.coroutines.internal.DispatchedContinuationKt.resumeCancellableWith(DispatchedContinuation.kt:367) ~[kotlinx-coroutines-core-jvm-1.6.4.jar:na] at kotlinx.coroutines.intrinsics.CancellableKt.startCoroutineCancellable(Cancellable.kt:30) ~[kotlinx-coroutines-core-jvm-1.6.4.jar:na] at kotlinx.coroutines.intrinsics.CancellableKt.startCoroutineCancellable$default(Cancellable.kt:25) ~[kotlinx-coroutines-core-jvm-1.6.4.jar:na] at kotlinx.coroutines.CoroutineStart.invoke(CoroutineStart.kt:110) ~[kotlinx-coroutines-core-jvm-1.6.4.jar:na] at kotlinx.coroutines.AbstractCoroutine.start(AbstractCoroutine.kt:126) ~[kotlinx-coroutines-core-jvm-1.6.4.jar:na] at kotlinx.coroutines.reactor.MonoKt.monoInternal$lambda-2(Mono.kt:90) ~[kotlinx-coroutines-reactor-1.6.4.jar:na] at reactor.core.publisher.MonoCreate.subscribe(MonoCreate.java:58) ~[reactor-core-3.5.10.jar:3.5.10] at reactor.core.publisher.Mono.subscribe(Mono.java:4495) ~[reactor-core-3.5.10.jar:3.5.10] at org.springframework.web.servlet.mvc.method.annotation.ReactiveTypeHandler$DeferredResultSubscriber.connect(ReactiveTypeHandler.java:462) ~[spring-webmvc-6.0.12.jar:6.0.12] at org.springframework.web.servlet.mvc.method.annotation.ReactiveTypeHandler.handleValue(ReactiveTypeHandler.java:178) ~[spring-webmvc-6.0.12.jar:6.0.12] at org.springframework.web.servlet.mvc.method.annotation.ResponseBodyEmitterReturnValueHandler.handleReturnValue(ResponseBodyEmitterReturnValueHandler.java:154) ~[spring-webmvc-6.0.12.jar:6.0.12] at org.springframework.web.method.support.HandlerMethodReturnValueHandlerComposite.handleReturnValue(HandlerMethodReturnValueHandlerComposite.java:78) ~[spring-web-6.0.12.jar:6.0.12] at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:136) ~[spring-webmvc-6.0.12.jar:6.0.12] at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:884) ~[spring-webmvc-6.0.12.jar:6.0.12] at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:797) ~[spring-webmvc-6.0.12.jar:6.0.12] at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87) ~[spring-webmvc-6.0.12.jar:6.0.12] at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1081) ~[spring-webmvc-6.0.12.jar:6.0.12] at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:974) ~[spring-webmvc-6.0.12.jar:6.0.12] at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1011) ~[spring-webmvc-6.0.12.jar:6.0.12] at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:903) ~[spring-webmvc-6.0.12.jar:6.0.12] at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:564) ~[tomcat-embed-core.jar:6.0] at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:885) ~[spring-webmvc-6.0.12.jar:6.0.12] at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:658) ~[tomcat-embed-core.jar:6.0] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:205) ~[tomcat-embed-core.jar:10.1.14-dev] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149) ~[tomcat-embed-core.jar:10.1.14-dev] at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:51) ~[tomcat-embed-websocket-10.1.13.jar:10.1.13] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:174) ~[tomcat-embed-core.jar:10.1.14-dev] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149) ~[tomcat-embed-core.jar:10.1.14-dev] at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100) ~[spring-web-6.0.12.jar:6.0.12] at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116) ~[spring-web-6.0.12.jar:6.0.12] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:174) ~[tomcat-embed-core.jar:10.1.14-dev] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149) ~[tomcat-embed-core.jar:10.1.14-dev] at org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93) ~[spring-web-6.0.12.jar:6.0.12] at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116) ~[spring-web-6.0.12.jar:6.0.12] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:174) ~[tomcat-embed-core.jar:10.1.14-dev] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149) ~[tomcat-embed-core.jar:10.1.14-dev] at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201) ~[spring-web-6.0.12.jar:6.0.12] at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116) ~[spring-web-6.0.12.jar:6.0.12] at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:174) ~[tomcat-embed-core.jar:10.1.14-dev] at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149) ~[tomcat-embed-core.jar:10.1.14-dev] at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:167) ~[tomcat-embed-core.jar:10.1.14-dev] at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:90) ~[tomcat-embed-core.jar:10.1.14-dev] at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:482) ~[tomcat-embed-core.jar:10.1.14-dev] at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:115) ~[tomcat-embed-core.jar:10.1.14-dev] at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:93) ~[tomcat-embed-core.jar:10.1.14-dev] at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74) ~[tomcat-embed-core.jar:10.1.14-dev] at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:340) ~[tomcat-embed-core.jar:10.1.14-dev] at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:391) ~[tomcat-embed-core.jar:10.1.14-dev] at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:63) ~[tomcat-embed-core.jar:10.1.14-dev] ... 7 common frames omitted 2023-10-07T18:55:09.030+08:00 DEBUG 10702 --- [nio-8080-exec-1] org.apache.coyote.AsyncStateMachine : Starting to process call to asyncError() 2023-10-07T18:55:09.030+08:00 DEBUG 10702 --- [nio-8080-exec-1] org.apache.coyote.AsyncStateMachine : Ignoring call to asyncError() as it has already been called since async processing started 2023-10-07T18:55:09.031+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.apache.catalina.core.AsyncContextImpl : Req: 5844338c CReq: 4f70376c RP: 5acae348 Stage: 3 Thread: http-nio-8080-exec-1 State: N/A Method: complete URI: /suspend 2023-10-07T18:55:09.031+08:00 DEBUG 10702 --- [nio-8080-exec-1] org.apache.coyote.AsyncStateMachine : Changing async state from [ERROR] to [COMPLETING] 2023-10-07T18:55:09.031+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.apache.catalina.core.AsyncContextImpl : Firing onComplete() event for any AsyncListeners 2023-10-07T18:55:09.031+08:00 DEBUG 10702 --- [nio-8080-exec-1] org.apache.coyote.AsyncStateMachine : Changing async state from [COMPLETING] to [DISPATCHED] 2023-10-07T18:55:09.031+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.apache.catalina.core.AsyncContextImpl : Req: 5844338c CReq: 4f70376c RP: 5acae348 Stage: 3 Thread: http-nio-8080-exec-1 State: N/A Method: recycle URI: /suspend 2023-10-07T18:55:09.031+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.apache.coyote.http11.Http11Processor : Error state [CLOSE_NOW] reported while processing request 2023-10-07T18:55:09.031+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.apache.coyote.http11.Http11Processor : Socket: [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@375c60d5:org.apache.tomcat.util.net.NioChannel@d287989:java.nio.channels.SocketChannel[connected local=/[0:0:0:0:0:0:0:1]:8080 remote=/[0:0:0:0:0:0:0:1]:63136]], Status in: [OPEN_READ], State out: [CLOSED] 2023-10-07T18:55:09.031+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.apache.coyote.http11.Http11Processor : Socket: [org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@375c60d5:org.apache.tomcat.util.net.NioChannel@d287989:java.nio.channels.SocketChannel[connected local=/[0:0:0:0:0:0:0:1]:8080 remote=/[0:0:0:0:0:0:0:1]:63136]], Status in: [OPEN_READ], State out: [CLOSED] 2023-10-07T18:55:09.031+08:00 DEBUG 10702 --- [nio-8080-exec-1] o.apache.tomcat.util.threads.LimitLatch : Counting down[http-nio-8080-exec-1] latch=2 2023-10-07T18:55:09.031+08:00 DEBUG 10702 --- [nio-8080-exec-1] org.apache.tomcat.util.net.NioEndpoint : Calling [org.apache.tomcat.util.net.NioEndpoint@43f55f91].closeSocket([org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper@375c60d5:org.apache.tomcat.util.net.NioChannel@d287989:java.nio.channels.SocketChannel[connected local=/[0:0:0:0:0:0:0:1]:8080 remote=/[0:0:0:0:0:0:0:1]:63136]])
The original bug report was for two JSON responses in a single HTTP response. Is that still an issue? Is the error message regarding the response already being committed in addition to the multiple JSON bodies or instead of the mutliple JSON bodies?
(In reply to Mark Thomas from comment #7) > The original bug report was for two JSON responses in a single HTTP > response. Is that still an issue? > > Is the error message regarding the response already being committed in > addition to the multiple JSON bodies or instead of the mutliple JSON bodies? Hmm, I don't think it's a matter of how many JSON responses in a signle HTTP response, but of exception handling. I dug a little deeper and have written a simple unit test[1] to simulate this scenario. To put it simply, Spring encapsulates the exception into JSON and responds normally, and at the same time sets the RequestDispatcher.ERROR_EXCEPTION attribute. I am not sure whether this behavior is reasonable, but I don't think it's a tomcat problem, the way I see it the handling is very reasonable. On the other hand, spring's behavior is very odd. There is a simple way to fix this issue, we can see whether the response is committed, if true, do not deal with RequestDispatcher.ERROR_EXCEPTION. --- if (request.isAsyncDispatching()) { connector.getService().getContainer().getPipeline().getFirst().invoke(request, response); Throwable t = (Throwable) request.getAttribute(RequestDispatcher.ERROR_EXCEPTION); if (t != null && !response.isCommitted()) { <-------- here asyncConImpl.setErrorState(t, true); } } --- Since I am not familiar with this specification, still need Mark to judge... Hope this helps! ; ) [1].https://gist.github.com/aooohan/b4fd3e1bce5ddda09b51e45173b5ed33
The simpler test case behaves as desired if the response buffer is flushed after the application provided error response is written. I'm not convinced that the test case completely reproduces the reported issue. I'm going to go back to the original reproducer and do some more debugging.
(In reply to Nils Kohrs from comment #4) > Here is a minimal project to reproduce it: > https://github.com/nilskohrs/tomcat-bug-66875 Thanks. This reproduces the issue as originally described with Tomcat 10.1.13. I need to set up some debugging to figure out what is going on.
I think there are two separate issues here. 1. When Spring sets jakarta.servlet.error.exception that triggers Tomcat's internal error handling. Whether Spring should do that and whether that should have the effect it has are the first issue. 2. Tomcat's error handling triggers the onError event. As per SRV.2.3.3.3 (search for "error dispatch") if no listeners call complete() or dispatch() this triggers another error dispatch. It is this second error dispatch that is generating the second error message. Spring and/or the application should be calling complete() or dispatch() as a result of the onError() event. This is the second issue. Next steps are to do some more research on the first issue.
Fixed in: - 11.0.x for 11.0.0-M14 onwards - 10.1.x for 10.1.16 onwards - 9.0.x for 9.0.83 onwards - 8.5.x for 8.5.96 onwards Comment #8 identifies the right place for the fix but I think a slightly different fix is called for.