spring-projects / spring-framework

Spring Framework
https://spring.io/projects/spring-framework
Apache License 2.0
56.75k stars 38.15k forks source link

SseEmitter IOException on HTTP2 Connection Close #33832

Open alex-vukov opened 3 weeks ago

alex-vukov commented 3 weeks ago

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 commented 2 weeks ago

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 commented 1 week ago

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 commented 1 week ago

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.