Skip to content

AsyncRequestNotUsableException thrown and logged after upgrade from Spring Boot 3.2.3 to Spring Boot 3.2.4 #32509

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.

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

Closed
vap78 opened this issue Mar 21, 2024 · 22 comments
Assignees
Labels
in: web Issues in web modules (web, webmvc, webflux, websocket)

Comments

@vap78
Copy link

vap78 commented Mar 21, 2024

Hi

after upgrading to spring boot 3.2.4 from 3.2.3 our applications start logging this exception over and over (I suspect on every request):

org.springframework.web.context.request.async.AsyncRequestNotUsableException: ServletOutputStream failed to write: java.io.IOException: Connection reset by peer
        at org.springframework.web.context.request.async.StandardServletAsyncWebRequest$LifecycleHttpServletResponse.handleIOException(StandardServletAsyncWebRequest.java:320)
        at org.springframework.web.context.request.async.StandardServletAsyncWebRequest$LifecycleServletOutputStream.write(StandardServletAsyncWebRequest.java:378)
        at org.springframework.util.StreamUtils$NonClosingOutputStream.write(StreamUtils.java:264)
        at com.fasterxml.jackson.core.json.UTF8JsonGenerator._flushBuffer(UTF8JsonGenerator.java:2203)
        at com.fasterxml.jackson.core.json.UTF8JsonGenerator.writeString(UTF8JsonGenerator.java:526)
        at nl.collectcar.api.book.model.dto.serialize.JsonUuidSerializer.serialize(JsonUuidSerializer.java:15)
        at nl.collectcar.api.book.model.dto.serialize.JsonUuidSerializer.serialize(JsonUuidSerializer.java:12)
        at com.fasterxml.jackson.databind.ser.BeanPropertyWriter.serializeAsField(BeanPropertyWriter.java:732)
        at com.fasterxml.jackson.databind.ser.std.BeanSerializerBase.serializeFields(BeanSerializerBase.java:772)
        at com.fasterxml.jackson.databind.ser.BeanSerializer.serialize(BeanSerializer.java:178)
        at com.fasterxml.jackson.databind.ser.std.CollectionSerializer.serializeContents(CollectionSerializer.java:145)
        at com.fasterxml.jackson.databind.ser.std.CollectionSerializer.serialize(CollectionSerializer.java:107)
        at com.fasterxml.jackson.databind.ser.std.CollectionSerializer.serialize(CollectionSerializer.java:25)
        at com.fasterxml.jackson.databind.ser.BeanPropertyWriter.serializeAsField(BeanPropertyWriter.java:732)
        at com.fasterxml.jackson.databind.ser.std.BeanSerializerBase.serializeFields(BeanSerializerBase.java:772)
        at com.fasterxml.jackson.databind.ser.BeanSerializer.serialize(BeanSerializer.java:178)
        at com.fasterxml.jackson.databind.ser.std.CollectionSerializer.serializeContents(CollectionSerializer.java:145)
        at com.fasterxml.jackson.databind.ser.std.CollectionSerializer.serialize(CollectionSerializer.java:107)
        at com.fasterxml.jackson.databind.ser.std.CollectionSerializer.serialize(CollectionSerializer.java:25)
        at com.fasterxml.jackson.databind.ser.BeanPropertyWriter.serializeAsField(BeanPropertyWriter.java:732)
        at com.fasterxml.jackson.databind.ser.std.BeanSerializerBase.serializeFields(BeanSerializerBase.java:772)
        at com.fasterxml.jackson.databind.ser.BeanSerializer.serialize(BeanSerializer.java:178)
        at com.fasterxml.jackson.databind.ser.std.CollectionSerializer.serializeContents(CollectionSerializer.java:145)
        at com.fasterxml.jackson.databind.ser.std.CollectionSerializer.serialize(CollectionSerializer.java:107)
        at com.fasterxml.jackson.databind.ser.std.CollectionSerializer.serialize(CollectionSerializer.java:25)
        at com.fasterxml.jackson.databind.ser.DefaultSerializerProvider._serialize(DefaultSerializerProvider.java:479)
        at com.fasterxml.jackson.databind.ser.DefaultSerializerProvider.serializeValue(DefaultSerializerProvider.java:399)
        at com.fasterxml.jackson.databind.ObjectWriter$Prefetch.serialize(ObjectWriter.java:1568)
        at com.fasterxml.jackson.databind.ObjectWriter.writeValue(ObjectWriter.java:1061)
        at org.springframework.http.converter.json.AbstractJackson2HttpMessageConverter.writeInternal(AbstractJackson2HttpMessageConverter.java:483)
        at org.springframework.http.converter.AbstractGenericHttpMessageConverter.write(AbstractGenericHttpMessageConverter.java:114)
        at org.springframework.web.servlet.mvc.method.annotation.AbstractMessageConverterMethodProcessor.writeWithMessageConverters(AbstractMessageConverterMethodProcessor.java:297)
        at org.springframework.web.servlet.mvc.method.annotation.HttpEntityMethodProcessor.handleReturnValue(HttpEntityMethodProcessor.java:245)
        at org.springframework.web.method.support.HandlerMethodReturnValueHandlerComposite.handleReturnValue(HandlerMethodReturnValueHandlerComposite.java:78)
        at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:136)
        at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:925)
        at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:830)
        at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87)
        at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1089)
        at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:979)
        at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1014)
        at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:903)
        at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:564)
        at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:885)
        at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:658)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:205)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149)
        at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:51)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:174)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149)
        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:101)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:174)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149)
        at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100)
        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:174)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149)
        at org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93)
        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:174)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149)
        at org.springframework.web.servlet.v6_0.OpenTelemetryHandlerMappingFilter.doFilter(OpenTelemetryHandlerMappingFilter.java:76)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:174)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149)
        at org.springframework.web.filter.ServerHttpObservationFilter.doFilterInternal(ServerHttpObservationFilter.java:109)
        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:174)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149)
        at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201)
        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:174)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:149)
        at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:167)
        at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:90)
        at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:482)
        at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:115)
        at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:93)
        at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74)
        at org.apache.catalina.valves.RemoteIpValve.invoke(RemoteIpValve.java:735)
        at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:344)
        at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:391)
        at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:63)
        at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:896)
        at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1744)
        at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:52)
        at java.base/java.lang.VirtualThread.run(VirtualThread.java:309)
        Suppressed: org.springframework.web.context.request.async.AsyncRequestNotUsableException: Response not usable after response errors.
                at org.springframework.web.context.request.async.StandardServletAsyncWebRequest$LifecycleHttpServletResponse.obtainLockAndCheckState(StandardServletAsyncWebRequest.java:314)
                at org.springframework.web.context.request.async.StandardServletAsyncWebRequest$LifecycleServletOutputStream.write(StandardServletAsyncWebRequest.java:373)
                at org.springframework.util.StreamUtils$NonClosingOutputStream.write(StreamUtils.java:264)
                at com.fasterxml.jackson.core.json.UTF8JsonGenerator._flushBuffer(UTF8JsonGenerator.java:2203)
                at com.fasterxml.jackson.core.json.UTF8JsonGenerator.close(UTF8JsonGenerator.java:1227)
                at org.springframework.http.converter.json.AbstractJackson2HttpMessageConverter.writeInternal(AbstractJackson2HttpMessageConverter.java:452)
                ... 56 common frames omitted
Caused by: org.apache.catalina.connector.ClientAbortException: java.io.IOException: Connection reset by peer
        at org.apache.catalina.connector.OutputBuffer.realWriteBytes(OutputBuffer.java:344)
        at org.apache.catalina.connector.OutputBuffer.flushByteBuffer(OutputBuffer.java:773)
        at org.apache.catalina.connector.OutputBuffer.append(OutputBuffer.java:676)
        at org.apache.catalina.connector.OutputBuffer.writeBytes(OutputBuffer.java:379)
        at org.apache.catalina.connector.OutputBuffer.write(OutputBuffer.java:357)
        at org.apache.catalina.connector.CoyoteOutputStream.write(CoyoteOutputStream.java:97)
        at org.springframework.web.context.request.async.StandardServletAsyncWebRequest$LifecycleServletOutputStream.write(StandardServletAsyncWebRequest.java:375)
        ... 84 common frames omitted
Caused by: java.io.IOException: Connection reset by peer
        at java.base/sun.nio.ch.SocketDispatcher.write0(Native Method)
        at java.base/sun.nio.ch.SocketDispatcher.write(SocketDispatcher.java:62)
        at java.base/sun.nio.ch.IOUtil.writeFromNativeBuffer(IOUtil.java:137)
        at java.base/sun.nio.ch.IOUtil.write(IOUtil.java:102)
        at java.base/sun.nio.ch.IOUtil.write(IOUtil.java:58)
        at java.base/sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:542)
        at org.apache.tomcat.util.net.NioChannel.write(NioChannel.java:118)
        at org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper.doWrite(NioEndpoint.java:1381)
        at org.apache.tomcat.util.net.SocketWrapperBase.doWrite(SocketWrapperBase.java:764)
        at org.apache.tomcat.util.net.SocketWrapperBase.writeBlocking(SocketWrapperBase.java:589)
        at org.apache.tomcat.util.net.SocketWrapperBase.write(SocketWrapperBase.java:533)
        at org.apache.coyote.http11.Http11OutputBuffer$SocketOutputBuffer.doWrite(Http11OutputBuffer.java:540)
        at org.apache.coyote.http11.filters.ChunkedOutputFilter.doWrite(ChunkedOutputFilter.java:112)
        at org.apache.coyote.http11.Http11OutputBuffer.doWrite(Http11OutputBuffer.java:193)
        at org.apache.coyote.Response.doWrite(Response.java:616)
        at org.apache.catalina.connector.OutputBuffer.realWriteBytes(OutputBuffer.java:331)
        ... 90 common frames omitted

this did not happen with the 3.2.3 version and after a rollback the exceptions are no longer logged.

The exceptions themselves do not seem to have any functional impact.

Used JVM: Amazon Corretto JDK 21.0.2

Best regards
Vasil

@spring-projects-issues spring-projects-issues added the status: waiting-for-triage An issue we've not yet triaged or decided on label Mar 21, 2024
@wilkinsona
Copy link
Member

The change in behavior is due to #32340. We'll transfer this to Spring Framework so that they can investigate further.

@bclozel bclozel transferred this issue from spring-projects/spring-boot Mar 21, 2024
@snicoll snicoll added the in: web Issues in web modules (web, webmvc, webflux, websocket) label Mar 21, 2024
@rstoyanchev
Copy link
Contributor

What's actually logging the exception?

Previously, this would have been org.apache.catalina.connector.ClientAbortException. It is now wrapped with AsyncRequestNotUsableException, and that should be handled in DefaultHandlerExceptionResolver by marking it resolved without further handling.

@vap78
Copy link
Author

vap78 commented Mar 23, 2024

Hi

looks like this is traced in a custom exception handler annotated with @ControllerAdvice.

What is the recommendation here?

I could simply ignore this specific exception, but what would be the performance impact of exceptions being generated/thrown on every request?

Best regards
Vasil

@rstoyanchev
Copy link
Contributor

In this case the exception only wraps the IOException from the Servlet response. In other words there is already an exception, and such exceptions should be raised only when something goes wrong with the network, not for every request.

The exception implies the response is no longer usable, and you can't send any more data. You can treat it in the same way that you would the underlying ClientAbortException or any IOException from the response.

I'm closing as there is nothing for us to do, but feel free to comment if necessary.

@rstoyanchev rstoyanchev closed this as not planned Won't fix, can't repro, duplicate, stale Mar 25, 2024
@rstoyanchev rstoyanchev removed the status: waiting-for-triage An issue we've not yet triaged or decided on label Mar 25, 2024
@hw207165
Copy link

Hi

looks like this is traced in a custom exception handler annotated with @ControllerAdvice.

What is the recommendation here?

I could simply ignore this specific exception, but what would be the performance impact of exceptions being generated/thrown on every request?

Best regards Vasil

How did you solve it?I am facing the same problem. Thanks.

@danwashusen
Copy link

danwashusen commented Apr 28, 2024

We are also seeing this error after an upgrade, it doesn't seem to happen for every request, just those that have used response.sendRedirect(...). In our case we just see 'Response not usable after response errors.' logged with a nasty error message (no IO errors)... the client gets the redirect, so the issue is only server side...

@vap78
Copy link
Author

vap78 commented May 17, 2024

Hi
looks like this is traced in a custom exception handler annotated with @ControllerAdvice.
What is the recommendation here?
I could simply ignore this specific exception, but what would be the performance impact of exceptions being generated/thrown on every request?
Best regards Vasil

How did you solve it?I am facing the same problem. Thanks.

We didn't .

The only solution I see is to suppress the exception in the custom exception handler.
But I don't understand, why is it being thrown as we did not changes, except the Spring boot upgrade.

@vap78
Copy link
Author

vap78 commented May 17, 2024

From what I see what has changed is the exception type thrown.

Before spring-web:6.1.5 a ClientAbortException was thrown. Since 6.1.5 a AsyncRequestNotUsableException.

So adding AsyncRequestNotUsableException to the exception handler will restore the old state.

@namannigam
Copy link

We faced a similar issue. From this thread, I am taking away that we would either have to handle the AsyncRequestNotUsableException similar to other exceptions in the ControllerAdvice or have to live with it and look for resolution as any other IOException. Is that right @vap78 @rstoyanchev ?

@vap78
Copy link
Author

vap78 commented Jun 3, 2024

@namannigam never tried it. Sounds reasonable for APIs that are not async by nature. But I'm not the expert here.

@rstoyanchev
Copy link
Contributor

rstoyanchev commented Jun 4, 2024

@namannigam yes. The main change is that AsyncRequestNotUsableExcepton wraps the underlying IOException that came from the Servlet container either while trying to use the response or as an onError callback in an async request. If you check what the wrapped exception is, e.g. ClientAbortException, you probably have handling for it already.

@mauriciogeneroso
Copy link

mauriciogeneroso commented Jun 25, 2024

@rstoyanchev I got the same issue after upgrading Spring for a higher version than 3.2.3.

If this is a wrapper only and a change from ClientAbortException to AsyncRequestNotUsableExcepton, why won't we able to see ClientAbortException before? We were not handling ClientAbortException and I don't think is correct to make clients of the framework to start handling AsyncRequestNotUsableExcepton

@rstoyanchev
Copy link
Contributor

It's difficult to say without more details. The exception can occur in a wide range of scenarios, writing to the response. Also, check the cause, if it is a different exception perhaps. Tomcat may raise one of several IOException's. Or maybe you have handling for IOException.

@SiwyDym
Copy link

SiwyDym commented Jul 15, 2024

I encountered issue with 3.2.6, there is some mitigation for that?

@EAlf91
Copy link

EAlf91 commented Jul 17, 2024

@SiwyDym saw some mitigations using a controller advice ignoring it. just leave the method empty and it won't log anything

@ControllerAdvice
public class CustomAdvice {

    @ExceptionHandler(AsyncRequestNotUsableException.class)
    void handleAsyncRequestNotUsableException(AsyncRequestNotUsableException e) { }
}

@rstoyanchev
Copy link
Contributor

rstoyanchev commented Jul 17, 2024

We do have handling for AsyncRequestNotUsableException in DefaultHandlerExceptionResolver. I am guessing however that you have an @ExceptionHandler method that handles any Exception or IOException, and that is called before DefaultHandlerExceptionResolver has had a chance.

I've created #33225 to add default handling in ResponseEntityExceptionHandler as well, which increases the chance that the exception will be handled out of the box as a no-op by default.

@SiwyDym
Copy link

SiwyDym commented Jul 17, 2024

Okay, thank You. I have a slightly different situation because I got these exceptions when using SSE so I also need to suppress IllegalStateException with specific error message in the AsyncTaskExecutor, quite clumsy but works.

@rstoyanchev
Copy link
Contributor

@SiwyDym could you elaborate on your scenario a little more? You shouldn't have to handle exceptions in SSE, and there isn't much you can do for handling. I'm also unsure how IllegalStateException relates to this. Perhaps a small code snippet that shows example handling.

@SiwyDym
Copy link

SiwyDym commented Jul 22, 2024

I try to make some demo repository, but without success. The setup is like

///config scheduler
    @Bean
    public ThreadPoolTaskScheduler threadPoolTaskScheduler() {
        ThreadPoolTaskScheduler threadPoolTaskScheduler = new ThreadPoolTaskScheduler();
        threadPoolTaskScheduler.setThreadNamePrefix("XXX-");
        threadPoolTaskScheduler.setErrorHandler(t -> {
            //FIXME: remove it  after SB fix it, probably this issue: https://github.com/spring-projects/spring-framework/issues/33225
            if (t instanceof IllegalStateException
                    && (t.getMessage().equals("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.")
                    || t.getMessage().equals("The request associated with the AsyncContext has already completed processing."))
            ) {
                log.debug("Please ignore below error, because it's inner issue in SB,", t);
            }
        });
        return threadPoolTaskScheduler;
    }
    
    ///// controller 
        @GetMapping(value = "/xxx/summary", produces = MediaType.TEXT_EVENT_STREAM_VALUE)
    public Flux<List<XXXSummary>> xxxSummaryFlux() {
        return fluxSink.asFlux().map(e -> xxxManager.getxxxSummary());
    }
 
    @ControllerAdvice
    @Slf4j
    static class CustomAdvice {
        @ExceptionHandler(AsyncRequestNotUsableException.class)
        void handleAsyncRequestNotUsableException(AsyncRequestNotUsableException e) { 
            //FIXME: remove it  after SB fix it, probably this issue: https://github.com/spring-projects/spring-framework/issues/33225
            log.debug("Please ignore below error, because it's inner issue in SB,", e);
        }
    }
    ///flux config
    @Configuration
    public class FluxConfig {

    @Bean
    Sinks.Many<Object> fluxSink() {
        return Sinks.many().multicast().directBestEffort();
    }

    @Bean
    FluxNotifier fluxNotifier(Sinks.Many<Object> fluxSink) { //used to trigger change
        return new FluxNotifier(fluxSink);
    }
}

It sometimes entered this new @ExceptionHandler(AsyncRequestNotUsableException.class), but it also throw in the executor ISE. During debugging the cause is the same as for @ExceptionHandler(AsyncRequestNotUsableException.class). Unfortunately I'm totally swamped, but in free time try to make demo-project for that

@rstoyanchev
Copy link
Contributor

Thanks for the extra context @SiwyDym. The change in #33225 is now in, and you should be able to remove your own @ExceptionHandler. I'm not sure that it will help with the IllegalStateException though, and I don't see from the snippet that how the ThreadPoolTaskScheduler is used. Feel free to try with 6.2.0-SNAPSHOT. If you manage to create a reproducer with the IllegalStateException, we'll take a look. You can also try upgrading to the latest Tomcat maintenance version to see if it helps.

@berkaygiris
Copy link

Is this fix available with a spring boot release?

@bclozel
Copy link
Member

bclozel commented Nov 7, 2024

@berkaygiris see #33225. This will be released with Framework 6.2 and Spring Boot 3.4.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
in: web Issues in web modules (web, webmvc, webflux, websocket)
Projects
None yet
Development

No branches or pull requests