Websocket connection_init message not send when using spring-graphql with spring-webmvc and undertow

[fheinic]

Dependencies

org.springframework.boot:spring-boot-starter-undertow:3.3.5
org.springframework.boot:spring-boot-starter-web:3.3.5
org.springframework.boot:spring-boot-starter-websocket:3.3.5
org.springframework.boot:spring-boot-starter-graphql:3.3.5

Description

When executing a subscription using spring graphql with spring-webmvc, spring-websocket and an undertow server, the server throws an error because the ACK message during connection init cannot be sent. During connection init, in org.springframework.graphql.server.webmvc.GraphQlWebSocketHandler the method session.sendMessage(outputmessage) does not return until an timeout Exception is thrown.

java.lang.IllegalStateException: Timeout on blocking read for 10000000000 NANOSECONDS
   at reactor.core.publisher.BlockingSingleSubscriber.blockingGet(BlockingSingleSubscriber.java:129) ~[reactor-core-3.6.11.jar:3.6.11]
   at reactor.core.publisher.Mono.block(Mono.java:1807) ~[reactor-core-3.6.11.jar:3.6.11]
   at org.springframework.graphql.server.webmvc.GraphQlWebSocketHandler.handleInternal(GraphQlWebSocketHandler.java:284) ~[spring-graphql-1.3.3.jar:1.3.3]
   at org.springframework.graphql.server.webmvc.GraphQlWebSocketHandler.handleTextMessage(GraphQlWebSocketHandler.java:210) ~[spring-graphql-1.3.3.jar:1.3.3]
   at org.springframework.web.socket.handler.AbstractWebSocketHandler.handleMessage(AbstractWebSocketHandler.java:43) ~[spring-websocket-6.1.14.jar:6.1.14]
   at org.springframework.web.socket.handler.WebSocketHandlerDecorator.handleMessage(WebSocketHandlerDecorator.java:75) ~[spring-websocket-6.1.14.jar:6.1.14]
   at org.springframework.web.socket.handler.LoggingWebSocketHandlerDecorator.handleMessage(LoggingWebSocketHandlerDecorator.java:56) ~[spring-websocket-6.1.14.jar:6.1.14]
   at org.springframework.web.socket.handler.ExceptionWebSocketHandlerDecorator.handleMessage(ExceptionWebSocketHandlerDecorator.java:58) ~[spring-websocket-6.1.14.jar:6.1.14]
   at org.springframework.web.socket.adapter.standard.StandardWebSocketHandlerAdapter.handleTextMessage(StandardWebSocketHandlerAdapter.java:113) ~[spring-websocket-6.1.14.jar:6.1.14]
   at org.springframework.web.socket.adapter.standard.StandardWebSocketHandlerAdapter$3.onMessage(StandardWebSocketHandlerAdapter.java:84) ~[spring-websocket-6.1.14.jar:6.1.14]
   at org.springframework.web.socket.adapter.standard.StandardWebSocketHandlerAdapter$3.onMessage(StandardWebSocketHandlerAdapter.java:81) ~[spring-websocket-6.1.14.jar:6.1.14]
   at io.undertow.websockets.jsr.FrameHandler$7.run(FrameHandler.java:288) ~[undertow-websockets-jsr-2.3.17.Final.jar:2.3.17.Final]
   at io.undertow.websockets.jsr.ServerWebSocketContainer$1.call(ServerWebSocketContainer.java:170) ~[undertow-websockets-jsr-2.3.17.Final.jar:2.3.17.Final]
   at io.undertow.websockets.jsr.ServerWebSocketContainer$1.call(ServerWebSocketContainer.java:167) ~[undertow-websockets-jsr-2.3.17.Final.jar:2.3.17.Final]
   at io.undertow.servlet.core.ContextClassLoaderSetupAction$1.call(ContextClassLoaderSetupAction.java:43) ~[undertow-servlet-2.3.17.Final.jar:2.3.17.Final]
   at io.undertow.websockets.jsr.ServerWebSocketContainer.invokeEndpointMethod(ServerWebSocketContainer.java:618) ~[undertow-websockets-jsr-2.3.17.Final.jar:2.3.17.Final]
   at io.undertow.websockets.jsr.ServerWebSocketContainer.invokeEndpointMethod(ServerWebSocketContainer.java:608) ~[undertow-websockets-jsr-2.3.17.Final.jar:2.3.17.Final]
   at io.undertow.websockets.jsr.FrameHandler.invokeTextHandler(FrameHandler.java:268) ~[undertow-websockets-jsr-2.3.17.Final.jar:2.3.17.Final]
   at io.undertow.websockets.jsr.FrameHandler.onFullTextMessage(FrameHandler.java:319) ~[undertow-websockets-jsr-2.3.17.Final.jar:2.3.17.Final]
   at io.undertow.websockets.core.AbstractReceiveListener$2.complete(AbstractReceiveListener.java:156) ~[undertow-core-2.3.17.Final.jar:2.3.17.Final]
   at io.undertow.websockets.core.AbstractReceiveListener$2.complete(AbstractReceiveListener.java:152) ~[undertow-core-2.3.17.Final.jar:2.3.17.Final]
   at io.undertow.websockets.core.BufferedTextMessage.read(BufferedTextMessage.java:105) ~[undertow-core-2.3.17.Final.jar:2.3.17.Final]
   at io.undertow.websockets.core.AbstractReceiveListener.readBufferedText(AbstractReceiveListener.java:152) ~[undertow-core-2.3.17.Final.jar:2.3.17.Final]
   at io.undertow.websockets.core.AbstractReceiveListener.bufferFullMessage(AbstractReceiveListener.java:90) ~[undertow-core-2.3.17.Final.jar:2.3.17.Final]
   at io.undertow.websockets.jsr.FrameHandler.onText(FrameHandler.java:184) ~[undertow-websockets-jsr-2.3.17.Final.jar:2.3.17.Final]
   at io.undertow.websockets.core.AbstractReceiveListener.handleEvent(AbstractReceiveListener.java:44) ~[undertow-core-2.3.17.Final.jar:2.3.17.Final]
   at io.undertow.websockets.core.AbstractReceiveListener.handleEvent(AbstractReceiveListener.java:33) ~[undertow-core-2.3.17.Final.jar:2.3.17.Final]
   at org.xnio.ChannelListeners.invokeChannelListener(ChannelListeners.java:92) ~[xnio-api-3.8.16.Final.jar:3.8.16.Final]
   at io.undertow.server.protocol.framed.AbstractFramedChannel$FrameReadListener.handleEvent(AbstractFramedChannel.java:974) ~[undertow-core-2.3.17.Final.jar:2.3.17.Final]
   at io.undertow.server.protocol.framed.AbstractFramedChannel$FrameReadListener.handleEvent(AbstractFramedChannel.java:954) ~[undertow-core-2.3.17.Final.jar:2.3.17.Final]
   at org.xnio.ChannelListeners.invokeChannelListener(ChannelListeners.java:92) ~[xnio-api-3.8.16.Final.jar:3.8.16.Final]
   at org.xnio.conduits.ReadReadyHandler$ChannelListenerHandler.readReady(ReadReadyHandler.java:66) ~[xnio-api-3.8.16.Final.jar:3.8.16.Final]
   at org.xnio.nio.NioSocketConduit.handleReady(NioSocketConduit.java:89) ~[xnio-nio-3.8.16.Final.jar:3.8.16.Final]
   at org.xnio.nio.WorkerThread.run(WorkerThread.java:603) ~[xnio-nio-3.8.16.Final.jar:3.8.16.Final]
Caused by: java.util.concurrent.TimeoutException: Timeout on blocking read for 10000000000 NANOSECONDS
   ... 34 common frames omitted

However, when removing .publishOn(state.getScheduler()), everything works fine and the ACK message is send.

Reproduce

To reproduce the issue i added a minimal sample project :

1. start DemoApplication
2. got to http://localhost:8080/graphiql
3. execute

subscription MySubscription {
  stockQuotes(symbol: "ABC") {
    stockPrice
    stockCode
    dateTime
  }
}

[bclozel]

Sorry for the delayed response.

I had a look at this and I found that:

• this is still a problem with Spring Boot 3.4.5
• this works with Tomcat
• this works with Jetty

It looks like there is a concurrent call to io.undertow.servlet.spec.ServletOutputStreamImpl#close and io.undertow.websockets.jsr.WebSocketSessionRemoteEndpoint.BasicWebSocketSessionRemoteEndpoint#sendText(java.lang.String, boolean) and that they both call org.xnio.channels.Channels#flushBlocking(SuspendableWriteChannel), locking each other out possibly?

We're using the standard WebSocket API here, but you've found out that this is also caused by the fact that we schedule this work on a different thread. I'm not super familiar with scheduling semantics in the WebSocket API so we'll have to discuss this more within the team.