Websocket broker disconnects when client enable heartbeats

[rd-o]

After a spring boot websocket client connects to the websocket spring boot server, the server send some heartbeats, and then after some minutes in the trace logs shows "Connection to broker closed.". Removing setTaskScheduler() from the client seems to work without problems.

Websocket client with SockJsClient and heartbeats enabled.
Websocket server with enableStompBrokerRelay() (ActiveMQ) and withSockJS()

Here a POC with the client and server, it needs a ActiveMQ broker:
https://github.com/rd-o/websocket-spring-boot-bug

[rd-o]

2020-01-02 17:07:49.992 DEBUG 3329 --- [nboundChannel-6] org.springframework.web.SimpLogging      : Cleaning up connection state for session 81b3512603de443c92c3d65c63756df7
2020-01-02 17:07:49.992 TRACE 3329 --- [tboundChannel-8] org.springframework.web.SimpLogging      : Encoding STOMP ERROR, headers={message=[failed to forward heart-beat in session 81b3512603de443c92c3d65c63756df7]}
2020-01-02 17:07:49.993 DEBUG 3329 --- [nboundChannel-6] org.springframework.web.SimpLogging      : Closing TCP connection in session 81b3512603de443c92c3d65c63756df7
2020-01-02 17:07:49.993 DEBUG 3329 --- [ent-scheduler-2] org.springframework.web.SimpLogging      : Cleaning up connection state for session 81b3512603de443c92c3d65c63756df7
2020-01-02 17:07:49.994 TRACE 3329 --- [tboundChannel-8] s.w.s.s.t.s.WebSocketServerSockJsSession : Preparing to write SockJsFrame content='a["ERROR\nmessage:failed to forward heart-beat in session 81b3512603de443c92c3d6...(truncated)'
2020-01-02 17:07:49.994 TRACE 3329 --- [tboundChannel-8] s.w.s.s.t.s.WebSocketServerSockJsSession : Writing SockJsFrame content='a["ERROR\nmessage:failed to forward heart-beat in session 81b3512603de443c92c3d6...(truncated)'
2020-01-02 17:07:49.994 TRACE 3329 --- [tboundChannel-9] org.springframework.web.SimpLogging      : Encoding STOMP ERROR, headers={message=[Connection to broker closed.]}
2020-01-02 17:07:49.994 TRACE 3329 --- [tboundChannel-8] o.s.w.s.adapter.NativeWebSocketSession   : Sending TextMessage payload=[a["ERROR\n..], byteCount=120, last=true], StandardWebSocketSession[id=40594c37-39f4-75e0-9927-9216996c87d3, uri=ws://localhost:4321/gs-guide-websocket/236/81b3512603de443c92c3d65c63756df7/websocket]
2020-01-02 17:07:49.995 TRACE 3329 --- [tboundChannel-9] .s.h.ConcurrentWebSocketSessionDecorator : Another send already in progress: session id '81b3512603de443c92c3d65c63756df7':, "in-progress" send time 2 (ms), buffer size 62 bytes
2020-01-02 17:07:49.995 TRACE 3329 --- [tboundChannel-8] s.w.s.s.t.s.WebSocketServerSockJsSession : Preparing to write SockJsFrame content='a["ERROR\nmessage:Connection to broker closed.\ncontent-length:0\n\n\u0000"]'
2020-01-02 17:07:49.996 DEBUG 3329 --- [tboundChannel-9] s.w.s.s.t.s.WebSocketServerSockJsSession : Closing SockJS session 81b3512603de443c92c3d65c63756df7 with CloseStatus[code=1002, reason=null]

[wilkinsona]

This may be a symptom of AMQ-4710. @rd-o do you see the same problem with a different broker?

[spring-projects-issues]

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.

[spring-projects-issues]

Closing due to lack of requested feedback. If you would like us to look at this issue, please provide the requested information and we will re-open the issue.

[kandonorbert]

We are facing the same issue after updating the Spring Boot version from "1.5.12.RELEASE" to "2.1.9.RELEASE". ActiveMQ version is 5.15.3.
Randomly we get exception in the logs which states that the connection was lost (code 1002). The ActiveMQ is up and running, no error in the logs. Looks like only the SpringBoot application server restart fixes the connection, the connection is not reestablished without server restart.
We had no such problems in the past 2.5 years with the old SpringBoot version, and with the same ActiveMQ instance.
Now we are planning to go live with the new Spring Boot, however this issue looks like a very risky one.
Any feedback would be appreciated.

[wilkinsona]

1002 indicates that the connection was closed due to a protocol error. Without some more information, the code alone isn't enough to confirm that it's the same issue as was originally reported here. If you can capture the problem with debug or trace logging enabled, that may help to determine the nature of the error. If you manage to do that or you can provide a minimal sample that reproduces the problem, please open a new issue and we can investigate.

[lrozenblyum]

@kandonorbert, @rd-o were you able to localize the problem/apply some solution for it?
It looks like we're affected by a similar random 1002 issue after upgrading

Spring WebSocket: 4.3.17.Release -> 5.3.3

[rd-o]

@lrozenblyum

I couldn't find a solution for this

[jbakoc1]

@rd-o I have the same issue and I believe it is related to the Page Visibility functionality https://developer.mozilla.org/en-US/docs/Web/API/Page_Visibility_API
After some time the browser suspends the tab and the heartbeat is not processed.
But I don't know why we are getting 1002, instead of 1001.
@wilkinsona can we reopen the issue and provide you with all the info you need?

[wilkinsona]

But I don't know why we are getting 1002, instead of 1001

This sort of protocol level problem is unlikely to be caused by Spring Boot as it's only involved in configuring some of the components and not in their inter-communication. If your client is receiving a 1002, it's likely to be coming from the STOMP broker. Which broker are you using?

[jbakoc1]

RabbitMQ 3.8.16 with STOMP plugin

[jbakoc1]

But I don't know why we are getting 1002, instead of 1001

This sort of protocol level problem is unlikely to be caused by Spring Boot as it's only involved in configuring some of the components and not in their inter-communication. If your client is receiving a 1002, it's likely to be coming from the STOMP broker. Which broker are you using?

What kind of configurations you mean. There are no firewalls involved between spring host & the rabbit broker and the default tcp port 61613 is open between them. Can you point to the right direction?

[wilkinsona]

I mean the configuration of Spring Framework's STOMP support.

Can you reproduce the problem with debug or trace level logging enabled both in your Boot app and in the Rabbit broker? It's not yet clear to me why you think this is a Spring Boot problem rather than a problem in one of the other components that's involved. Seeing some logs that capture the problem occurring should help to narrow down the cause.