Open fabianlinz opened 2 months ago
Indeed, when a connection is lost while writing, there is an inherent race between the Servlet container initiating error handling (to complete request handling and release resources), as well as the application trying to do the same because of the IOException
it got while from writing. There was plenty of work done in the issues you found to ensure only one of these goes through because if the Servlet container error handling goes through first, the request and response objects get recycled, and if application error sneaks through as well, it may end up operating on the recycled request and response that are now by then used for a different request.
There is not much we can do to ensure which goes first, and we cannot ensure that one is preferred over the other. Once we exit the Servlet container onError notification, it assumes the error is handled. We cannot hold it up indefinitely either, and there is no guarantee the application will propagate the IOException
(wrapped or not) or handle it and exit normally without further action.
In summary, you will need to be prepared to handle the root cause, which can also occur for non-streaming scenarios. We have the DisconnectedClientHelper
class that may be of help in recognizing such exceptions without introducing a dependency on a Servlet container class.
@rstoyanchev we encountered something similar, and I wonder if this is related to this issue. If that's not the case sorry for interrupting this issue.
We use the SseEmitter
and the code can be simplified to:
@GetMapping("/sse")
public SseEmitter sse() {
final var sse = new SseEmitter();
Runnable r = () -> {
try {
for (int i = 0; i < 5; i++) {
TimeUnit.SECONDS.sleep(5);
sse.send(SseEmitter.event().name("ping").data(i));
}
sse.complete();
} catch (Exception e) {
}
};
new Thread(r).start();
return sse;
}
Although we swallow the exception within the running thread when refreshing the page within the browser that connects to this SSE resource, the following error is logged (within Tomcat):
2024-09-10T22:20:07.632+02:00 ERROR 21670 --- [nio-8080-exec-4] o.a.c.c.C.[.[.[/].[dispatcherServlet] : Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception
java.io.IOException: Broken pipe
at java.base/sun.nio.ch.SocketDispatcher.write0(Native Method) ~[na:na]
at java.base/sun.nio.ch.SocketDispatcher.write(SocketDispatcher.java:62) ~[na:na]
at java.base/sun.nio.ch.IOUtil.writeFromNativeBuffer(IOUtil.java:137) ~[na:na]
at java.base/sun.nio.ch.IOUtil.write(IOUtil.java:102) ~[na:na]
at java.base/sun.nio.ch.IOUtil.write(IOUtil.java:58) ~[na:na]
at java.base/sun.nio.ch.SocketChannelImpl.implWrite(SocketChannelImpl.java:566) ~[na:na]
at java.base/sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:618) ~[na:na]
at org.apache.tomcat.util.net.NioChannel.write(NioChannel.java:122) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
at org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper.doWrite(NioEndpoint.java:1378) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
at org.apache.tomcat.util.net.SocketWrapperBase.doWrite(SocketWrapperBase.java:764) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
at org.apache.tomcat.util.net.SocketWrapperBase.flushBlocking(SocketWrapperBase.java:728) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
at org.apache.tomcat.util.net.SocketWrapperBase.flush(SocketWrapperBase.java:712) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
at org.apache.coyote.http11.Http11OutputBuffer$SocketOutputBuffer.flush(Http11OutputBuffer.java:574) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
at org.apache.coyote.http11.filters.ChunkedOutputFilter.flush(ChunkedOutputFilter.java:156) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
at org.apache.coyote.http11.Http11OutputBuffer.flush(Http11OutputBuffer.java:216) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
at org.apache.coyote.http11.Http11Processor.flush(Http11Processor.java:1252) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
at org.apache.coyote.AbstractProcessor.action(AbstractProcessor.java:408) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
at org.apache.coyote.Response.action(Response.java:208) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
at org.apache.catalina.connector.OutputBuffer.doFlush(OutputBuffer.java:299) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
at org.apache.catalina.connector.OutputBuffer.flush(OutputBuffer.java:265) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
at org.apache.catalina.connector.CoyoteOutputStream.flush(CoyoteOutputStream.java:136) ~[tomcat-embed-core-10.1.28.jar:10.1.28]
at org.springframework.web.context.request.async.StandardServletAsyncWebRequest$LifecycleServletOutputStream.flush(StandardServletAsyncWebRequest.java:389) ~[spring-web-6.1.12.jar:6.1.12]
at java.base/java.io.FilterOutputStream.flush(FilterOutputStream.java:155) ~[na:na]
at com.fasterxml.jackson.core.json.UTF8JsonGenerator.flush(UTF8JsonGenerator.java:1207) ~[jackson-core-2.17.2.jar:2.17.2]
at com.fasterxml.jackson.databind.ObjectWriter.writeValue(ObjectWriter.java:1063) ~[jackson-databind-2.17.2.jar:2.17.2]
at org.springframework.http.converter.json.AbstractJackson2HttpMessageConverter.writeInternal(AbstractJackson2HttpMessageConverter.java:483) ~[spring-web-6.1.12.jar:6.1.12]
at org.springframework.http.converter.AbstractGenericHttpMessageConverter.writeInternal(AbstractGenericHttpMessageConverter.java:123) ~[spring-web-6.1.12.jar:6.1.12]
at org.springframework.http.converter.AbstractHttpMessageConverter.write(AbstractHttpMessageConverter.java:235) ~[spring-web-6.1.12.jar:6.1.12]
at org.springframework.web.servlet.mvc.method.annotation.ResponseBodyEmitterReturnValueHandler$HttpMessageConvertingHandler.sendInternal(ResponseBodyEmitterReturnValueHandler.java:221) ~[spring-webmvc-6.1.12.jar:6.1.12]
at org.springframework.web.servlet.mvc.method.annotation.ResponseBodyEmitterReturnValueHandler$HttpMessageConvertingHandler.send(ResponseBodyEmitterReturnValueHandler.java:212) ~[spring-webmvc-6.1.12.jar:6.1.12]
at org.springframework.web.servlet.mvc.method.annotation.ResponseBodyEmitter.sendInternal(ResponseBodyEmitter.java:223) ~[spring-webmvc-6.1.12.jar:6.1.12]
at org.springframework.web.servlet.mvc.method.annotation.ResponseBodyEmitter.send(ResponseBodyEmitter.java:214) ~[spring-webmvc-6.1.12.jar:6.1.12]
at org.springframework.web.servlet.mvc.method.annotation.SseEmitter.send(SseEmitter.java:135) ~[spring-webmvc-6.1.12.jar:6.1.12]
at com.innoq.spring.sse.brokenpipe.RootController.lambda$sse$0(RootController.java:36) ~[classes/:na]
at java.base/java.lang.Thread.run(Thread.java:1575) ~[na:na]
I assume the only and required way to suppress this is by adding something like:
@ExceptionHandler(IOException.class)
void handle(IOException e) {
new DisconnectedClientHelper(RootController.class.getName()).checkAndLogClientDisconnectedException(e);
}
Right?
If that's not related to this problem, is there any chance of making this a bit more user-friendly or at least adding it to the documentation?
Affects: 6.1.11, 6.2.0-M7
When a
ClientAbortException
occurs within a Spring MVCStreamingResponseBody
sometimes the error handling is not called with the exception thrown by theStreamingResponseBody
, but for the root causejava.io.IOException: Broken pipe
. There seems to be a race condition, as this can be provoked reliably when throwing the exception from theStreamingResponseBody
is delayed by a few milliseconds (see test in example project). This might be only a problem for Tomcat, but I have not yet checked this.As the client aborted the connection the error handling will not be able to send anything to the client, but it can still log things or do other internal stuff. In our case this resulted in unexpected error log entries.
There are some issues that look very related (comments mention a race between Tomcat and the application), but they are closed and the issue still exists with Spring 6.2.0-M7 (I did not see something in the documentation or in a linked issue that this is a know issue for the time being; sorry if I missed it)
For the example project the expected behaviour would be that the error handling is called for the exception throws by the
StreamingResponseBody
:Unexpected is that the error handling is called for the root cause