spring-projects / spring-framework

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

The `isOpen()` method of `WebSocketSession` in springboot version 3.1.2 always returns true #30944

Closed NXY666 closed 1 year ago

NXY666 commented 1 year ago

I use TextWebSocketHandler to manage WebSocket sessions, but when the connection is obviously closed, the session.isOpen() method still returns true.

if (session.isOpen()) {
    System.out.println("Session is not closed. Session ID: " + session.getId());
    try {
        session.close();
    } catch (IOException e) {
        e.printStackTrace();
    }
    if (session.isOpen()) {
        System.out.println("Session is still not closed. Session ID: " + session.getId());
    }
}

Output:

Session is not closed. Session ID: 2e4f942c-e2a7-af86-edcf-fe70cfe4cfe7
Session is still not closed. Session ID: 2e4f942c-e2a7-af86-edcf-fe70cfe4cfe7

At this point, the frontend has already displayed Connection closed and afterConnectionClosed in TextWebSocketHandler has been triggered. When attempting to send a message in this situation, it will throw an error: java.lang.IllegalStateException: Message will not be sent because the WebSocket session has been closed.

This situation only exists in springboot version 3.1.2 (framwork version 6.0.11). I tested several previous versions, and this issue did not appear.

jhoeller commented 1 year ago

@rstoyanchev any specific changes in that area in 6.0.11 which could have caused a regression?

NXY666 commented 1 year ago

@rstoyanchev any specific changes in that area in 6.0.11 which could have caused a regression?

7775675ed7a119d6ff42da945c9f875 03eb95c328f76bf20cb3cdd12d5d689

Hmm, maybe I misunderstood. It seems that the implementation of session.isOpen() has been modified, so the behavior of the program has changed.

NXY666 commented 1 year ago

@rstoyanchev any specific changes in that area in 6.0.11 which could have caused a regression?

However, in this case, is it possible to expose the session.state? Simply calling session.isOpen() is no longer sufficient to accurately determine whether the session has been closed or triggered for closure.

rstoyanchev commented 1 year ago

I'm not sure which WebSocketSession implementation, depends on the server and if SockJS is involved. From the image it looks like it could be SockJS related, but it doesn't match very well. Links to the source code are much more useful than pasting images.

There aren't changes in 6.0.x maintenance releases that could be related. I'm wondering if it is related to a server dependency upgrade. You can try Boot 3.1.1 and change only Spring Framework to 6.0.11. If that works than try varying the server version independent of everything else.

NXY666 commented 1 year ago

I'm not sure which WebSocketSession implementation, depends on the server and if SockJS is involved. From the image it looks like it could be SockJS related, but it doesn't match very well. Links to the source code are much more useful than pasting images.

There aren't changes in 6.0.x maintenance releases that could be related. I'm wondering if it is related to a server dependency upgrade. You can try Boot 3.1.1 and change only Spring Framework to 6.0.11. If that works than try varying the server version independent of everything else.

Sorry, I didn't make it clear. I didn't enable SockJS, and I believe the change was caused by a dependency upgrade. The modified isOpen method appeared in org.apache.tomcat.websocket.WsSession.

This is the link to the commit with the changes: https://github.com/apache/tomcat/commit/ea6d9cdcb949fc2c910058b162fb2e382abdabd7

rstoyanchev commented 1 year ago

Thanks for clarifying. I'm not sure what we can do differently. Our implementation of isOpen() simply delegates to the one from the underlying WebSocket implementation. Are you suggesting anything specific for us to do?

spring-projects-issues commented 1 year ago

If you would like us to look at this issue, please provide the requested information. If the information is not provided within the next 7 days this issue will be closed.

NXY666 commented 1 year ago

Thanks for clarifying. I'm not sure what we can do differently. Our implementation of isOpen() simply delegates to the one from the underlying WebSocket implementation. Are you suggesting anything specific for us to do?

Perhaps you can deduce the current state by assessing the trigger status of the handler and the return result of isOpen:

While I could implement it on my own, I believe Spring Boot might offer a simplified development approach without imposing significant performance overhead.

My English is not very good, so I'm using machine translation, which may misinterpret the meaning of certain words.

rstoyanchev commented 1 year ago

This is unclear I'm afraid. The isOpen() method in Spring Framework's WebSocketSession returns boolean, and not some state. I'm closing for now, but if you have a concrete idea, feel free to submit a pull request that shows the exact changes you have in mind.

rstoyanchev commented 1 year ago

Also, consider whether your question is really for Tomcat's issue tracker since you referred to a change in Tomcat.

icguy commented 3 months ago

I have found this issue on the tomcat bug tracker.

https://bz.apache.org/bugzilla/show_bug.cgi?id=67293

It tackles the same issue from a different angle I suppose, but it's already closed as "invalid".

icguy commented 3 months ago

I took the time and made a minimal working example of the bug.

https://github.com/icguy/spring30944

See the reproduction in SocketHandler.kt:

override fun afterConnectionClosed(session: WebSocketSession, status: CloseStatus) {
    logger.info("afterConnectionClosed 1, isOpen=${session.isOpen}")
    try {
        session.sendMessage(TextMessage("hello"))
    }
    catch(ex: Exception) {
        logger.error("failed to send message", ex)
    }
    logger.info("afterConnectionClosed 2, isOpen=${session.isOpen}")
}

On my machine when connected to the WebSocket handler and disconnecting (e.g. by reloading the page) it prints:

2024-07-18T17:40:39.575+02:00  INFO 25572 --- [demo] [nio-8888-exec-4] socket                                   : afterConnectionClosed 1, isOpen=true
2024-07-18T17:40:39.575+02:00 ERROR 25572 --- [demo] [nio-8888-exec-4] socket                                   : failed to send message

java.lang.IllegalStateException: Message will not be sent because the WebSocket session has been closed
    at org.apache.tomcat.websocket.WsRemoteEndpointImplBase.writeMessagePart(WsRemoteEndpointImplBase.java:455) ~[tomcat-embed-websocket-10.1.25.jar:10.1.25]
    at org.apache.tomcat.websocket.WsRemoteEndpointImplBase.sendMessageBlockInternal(WsRemoteEndpointImplBase.java:313) ~[tomcat-embed-websocket-10.1.25.jar:10.1.25]
    at org.apache.tomcat.websocket.WsRemoteEndpointImplBase.sendMessageBlock(WsRemoteEndpointImplBase.java:266) ~[tomcat-embed-websocket-10.1.25.jar:10.1.25]
    at org.apache.tomcat.websocket.WsRemoteEndpointImplBase.sendMessageBlock(WsRemoteEndpointImplBase.java:250) ~[tomcat-embed-websocket-10.1.25.jar:10.1.25]
    at org.apache.tomcat.websocket.WsRemoteEndpointImplBase.sendPartialString(WsRemoteEndpointImplBase.java:223) ~[tomcat-embed-websocket-10.1.25.jar:10.1.25]
    at org.apache.tomcat.websocket.WsRemoteEndpointBasic.sendText(WsRemoteEndpointBasic.java:48) ~[tomcat-embed-websocket-10.1.25.jar:10.1.25]
    at org.springframework.web.socket.adapter.standard.StandardWebSocketSession.sendTextMessage(StandardWebSocketSession.java:217) ~[spring-websocket-6.1.10.jar:6.1.10]
    at org.springframework.web.socket.adapter.AbstractWebSocketSession.sendMessage(AbstractWebSocketSession.java:108) ~[spring-websocket-6.1.10.jar:6.1.10]
    at com.example.demo.SocketHandler.afterConnectionClosed(SocketHandler.kt:35) ~[main/:na]
    at org.springframework.web.socket.handler.WebSocketHandlerDecorator.afterConnectionClosed(WebSocketHandlerDecorator.java:85) ~[spring-websocket-6.1.10.jar:6.1.10]
    at org.springframework.web.socket.handler.LoggingWebSocketHandlerDecorator.afterConnectionClosed(LoggingWebSocketHandlerDecorator.java:72) ~[spring-websocket-6.1.10.jar:6.1.10]
    at org.springframework.web.socket.handler.ExceptionWebSocketHandlerDecorator.afterConnectionClosed(ExceptionWebSocketHandlerDecorator.java:78) ~[spring-websocket-6.1.10.jar:6.1.10]
    at org.springframework.web.socket.adapter.standard.StandardWebSocketHandlerAdapter.onClose(StandardWebSocketHandlerAdapter.java:144) ~[spring-websocket-6.1.10.jar:6.1.10]
    at org.apache.tomcat.websocket.WsSession.fireEndpointOnClose(WsSession.java:730) ~[tomcat-embed-websocket-10.1.25.jar:10.1.25]
    at org.apache.tomcat.websocket.WsSession.onClose(WsSession.java:638) ~[tomcat-embed-websocket-10.1.25.jar:10.1.25]
    at org.apache.tomcat.websocket.WsFrameBase.processDataControl(WsFrameBase.java:347) ~[tomcat-embed-websocket-10.1.25.jar:10.1.25]
    at org.apache.tomcat.websocket.WsFrameBase.processData(WsFrameBase.java:279) ~[tomcat-embed-websocket-10.1.25.jar:10.1.25]
    at org.apache.tomcat.websocket.WsFrameBase.processInputBuffer(WsFrameBase.java:130) ~[tomcat-embed-websocket-10.1.25.jar:10.1.25]
    at org.apache.tomcat.websocket.server.WsFrameServer.onDataAvailable(WsFrameServer.java:85) ~[tomcat-embed-websocket-10.1.25.jar:10.1.25]
    at org.apache.tomcat.websocket.server.WsFrameServer.doOnDataAvailable(WsFrameServer.java:184) ~[tomcat-embed-websocket-10.1.25.jar:10.1.25]
    at org.apache.tomcat.websocket.server.WsFrameServer.notifyDataAvailable(WsFrameServer.java:164) ~[tomcat-embed-websocket-10.1.25.jar:10.1.25]
    at org.apache.tomcat.websocket.server.WsHttpUpgradeHandler.upgradeDispatch(WsHttpUpgradeHandler.java:152) ~[tomcat-embed-websocket-10.1.25.jar:10.1.25]
    at org.apache.coyote.http11.upgrade.UpgradeProcessorInternal.dispatch(UpgradeProcessorInternal.java:60) ~[tomcat-embed-core-10.1.25.jar:10.1.25]
    at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:57) ~[tomcat-embed-core-10.1.25.jar:10.1.25]
    at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:904) ~[tomcat-embed-core-10.1.25.jar:10.1.25]
    at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1741) ~[tomcat-embed-core-10.1.25.jar:10.1.25]
    at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:52) ~[tomcat-embed-core-10.1.25.jar:10.1.25]
    at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1190) ~[tomcat-embed-core-10.1.25.jar:10.1.25]
    at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659) ~[tomcat-embed-core-10.1.25.jar:10.1.25]
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:63) ~[tomcat-embed-core-10.1.25.jar:10.1.25]
    at java.base/java.lang.Thread.run(Thread.java:833) ~[na:na]

2024-07-18T17:40:39.578+02:00  INFO 25572 --- [demo] [nio-8888-exec-4] socket                                   : afterConnectionClosed 2, isOpen=true

Note that even though the exception says the socket has been closed it the isOpen property is still returning true.

While I understand this is due to the change in behavior in Tomcat 10 I believe that one way or another this needs to be addressed on the Spring side as well because right now the public API of the socket object is returning false information about its state.

rstoyanchev commented 3 months ago

@icguy from the Javadoc of WebSocketHandler#afterConnectionClosed:

Although the session may technically still be open, depending on the underlying implementation, sending messages at this point is discouraged and most likely will not succeed.

Perhaps this could be phrased even more definitively. The underlying Jakarta EE onClose callback says:

The developer may take this last opportunity to retrieve session attributes such as the ID, or any application data it holds before it becomes unavailable after the completion of the method. Developers should not attempt to modify the session from within this method, or send new messages from this call as the underlying connection will not be able to send them at this stage.

In other words, you can check session attributes and take final actions, but not send messages. So the case in your example is not expected to work.

@NXY666 I'm not sure if your case is also from within afterConnectionClosed or not. If it is then as I explained you cannot send messages, and the session cannot be used. If it is not the same case, then I can imagine that isOpen() can return true in one thread while the connection is in the process of being closed in another with an onClose notificaiton invoked. To be clear, all we have from the underlying Jakarta WebSocket API is the isOpen() method and the onClose notification, so we can't do anything more. Even if were to detect this, simply exposing information about the current state along the lines of https://github.com/spring-projects/spring-framework/issues/30944#issuecomment-1675061175 would not be sufficient to guard sending against a race between message sending on one thread and an onClose callback on a container thread. You would still need to use some synchronization/locking.

icguy commented 3 months ago

@rstoyanchev I must admit the code is a bit contrived trying to send messages in afterConnectionClosed. But I think the issue persists that there is no way to tell beforehand whether the connection is open and sending should be even attempted. The example code could be called from any other place (unrelated to session lifecycle events), if the timing is right it will produce the same error. It is just a convenience for the sake of the example that i placed the code in the afterConnectionClosed callback.

I guess for now the best workaround is to wrap sendMessage calls into try-catch blocks and treat them as "best-effort".

rstoyanchev commented 3 months ago

As I explained in my last comment, even if you could check beforehand, by the time you attempt to do it (e.g. on the very next line) it may no longer be possible to do that. It's the nature of a race condition. The connection can get closed or lost at any point.