SseEmitter IOException on HTTP Connection Close

[alex-vukov]

The crash happens on HTTP2 every time the browser issues an EventSource close() and can be reproduced with this repo:

https://github.com/alex-vukov/spring-sse-issue

You can test by starting the application, opening the following URL from the browser https://localhost:8080/sse and after you receive some data clicking on the browser's stop button. It can also be reproduced in JavaScript with EventSource close(). The error happens only with the integrated Tomcat server and only over HTTP2. It doesn't happen with Jetty (you can test by switching the pom.xml with pom-jetty.xml). This is the exception which breaks the app and it is unhandled even though in the code I have emitter.send wrapped in try-catch:

java.io.IOException: null
        at org.apache.coyote.http2.Stream$StandardStreamInputBuffer.receiveReset(Stream.java:1516) ~[tomcat-embed-core-10.1.31.jar:10.1.31]
        at org.apache.coyote.http2.Stream.receiveReset(Stream.java:224) ~[tomcat-embed-core-10.1.31.jar:10.1.31]
        at org.apache.coyote.http2.Http2UpgradeHandler.reset(Http2UpgradeHandler.java:1739) ~[tomcat-embed-core-10.1.31.jar:10.1.31]
        at org.apache.coyote.http2.Http2AsyncUpgradeHandler.reset(Http2AsyncUpgradeHandler.java:43) ~[tomcat-embed-core-10.1.31.jar:10.1.31]
        at org.apache.coyote.http2.Http2Parser.readRstFrame(Http2Parser.java:318) ~[tomcat-embed-core-10.1.31.jar:10.1.31]
        at org.apache.coyote.http2.Http2AsyncParser$FrameCompletionHandler.completed(Http2AsyncParser.java:260) ~[tomcat-embed-core-10.1.31.jar:10.1.31]
        at org.apache.coyote.http2.Http2AsyncParser$FrameCompletionHandler.completed(Http2AsyncParser.java:167) ~[tomcat-embed-core-10.1.31.jar:10.1.31]
        at org.apache.tomcat.util.net.SocketWrapperBase$VectoredIOCompletionHandler.completed(SocketWrapperBase.java:1103) ~[tomcat-embed-core-10.1.31.jar:10.1.31]
        at org.apache.tomcat.util.net.NioEndpoint$NioSocketWrapper$NioOperationState.run(NioEndpoint.java:1654) ~[tomcat-embed-core-10.1.31.jar:10.1.31]
        at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1190) ~[tomcat-embed-core-10.1.31.jar:10.1.31]
        at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659) ~[tomcat-embed-core-10.1.31.jar:10.1.31]
        at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:63) ~[tomcat-embed-core-10.1.31.jar:10.1.31]
        at java.base/java.lang.Thread.run(Thread.java:842) ~[na:na]

[zhuyuy]

Although there's a error log be printed, your code works as you want. But actually it should print some details message, not just java.io.IOException: null ('null' should be a detail message like Client reset the stream before the request was fully read, I think it will be added later). And why I said it's no bug:

1. sse is a async request/response, so this exception don't thorwn from emitter.send. Your try-catch code surround it can't catch this IOException.
2. your onError and onCompletion worked, but after that tomcat need know this IOException to close sse, the exception handled normally but just print an error log during catch code.

When the framework/tomcat is handling some exceptions, it will print error logs even if they are handled as expected. Don't worry, these logs are normal.

[alex-vukov]

This log doesn't show up on HTTP1.1 or on Jetty so it's a bug in the way the exception from Tomcat is handled. The user of the SseEmitter should be able to catch the exception in case any additional processing is needed. I am able to catch the IOException when on HTTP1.1 but I am not able to catch it using HTTP2.0 so it's definitely inconsistent.

[zhuyuy]

This log doesn't show up on HTTP1.1 or on Jetty

This log show in both HTTP1.1 and HTTP2.0 when using tomcat. In your example projcet, I disable http2, exception still be logged. Config is:

server.http2.enabled=false
spring.application.name=demo
#server.ssl.key-store-type=PKCS12
#server.ssl.key-store=classpath:localhost.p12
#server.ssl.key-store-password=
#server.ssl.key-alias=localhost

The user of the SseEmitter should be able to catch the exception in case any additional processing is needed.

This is a misnomer.
emitter.onError((ex) -> {System.out.println("Error BEEEE");});
In emitter.onError, we do our own business logic. After that, tomcat still need the exception to control request/response.

And I mean the tomcat code is like (It's actually a long processing chain, here I've simply represented as):

try {
} catch(IOException e) {
  // invoke developer's onError() method to process developer's business logic. This doesn't affect tomcat's exception handling processing
  log.error(e); // tomcat print log, but jetty not
  // close sse base on exception
}

In jetty, log was's show becaust it didn't print log, not your code catched it.
In my opinion, it's similar to IOException: Broken pipe when using GET/POST http method. Do you know this one?
The exception is correctly handled, and this log can be ignored as IOException: Broken pipe.

[sdeleuze]

With HTTP1.1 and Tomcat, the exception is different: java.io.IOException: Broken pipe, and have Spring mentioned in the stacktrace, but still can't be catched on user side indeed.

@rstoyanchev I am wondering if we could limit the annoyance by using DisconnectedClientHelper, for example in DeferredResult.java.DeferredResultProcessingInterceptor#handleError to just print a more compact log and skip setResultInternal(t) invocation for such case.

I think that would only work for HTTP1.1, not sure we have a solution for HTTP2 given the very generic IOException and lack of proper message.

Any thoughts?

[rstoyanchev]

IOException is a very broad exception that DisconnetedClientHelper can't help with. Also we need to keep the dispatch to allow applications to handle the error if necessary.

There is maybe room for improvement in Tomcat to include a message with the exception.

We recently started wrapping exceptions in the AsyncListener#onError callback, but only for disconnected client errors, see #34363. I think we can broaden the fix there to any IOException since any IOException reported there is related to the response.