I recently faced and issue, unfortunately on production environment, when my Spring Boot Server was not sending response of CONNECT frame (i.e CONNECTED frame). It first started happening occasionally but later on all the CONNECT requests sent by the browser were not replied to.
On console I was able to see following log
After some investigating, I found out that inboundChannel queue was holding many requests at that time. I believe this was the reason.
2022-06-01 18:22:59,943 INFO Thread-id-74- springframework.web.socket.config.WebSocketMessageBrokerStats: WebSocketSession[130 current WS(129)-HttpStream(1)-HttpPoll(0), 225 total, 0 closed abnormally (0 connect failure, 0 send limit, 2 transport error)], stompSubProtocol[processed CONNECT(220)-CONNECTED(132)-DISCONNECT(0)], stompBrokerRelay[null], inboundChannel[pool size = 2, active threads = 2, queued tasks = 10774, completed tasks = 31806], outboundChannel[pool size = 2, active threads = 0, queued tasks = 0, completed tasks = 570895], sockJsScheduler[pool size = 1, active threads = 1, queued tasks = 134, completed tasks = 1985]
I was wondering what might be the cause of the issue, what can cause queuing in the inboundChannel queue?
here is my current STOMP config on my angular application.
const config: StompJS.StompConfig = {
brokerURL: this.serverUrl,
connectHeaders: {
ccid: this.cookieService.get('ccid'),
username: `${this.globalContext.get('me')['username']}`,
},
debug: (str) => {
this.loggerService.log(this.sessionId, ' | ', str);
},
webSocketFactory: () => {
return new SockJS(this.serverUrl);
},
logRawCommunication: true,
reconnectDelay: 3000,
heartbeatIncoming: 100,
heartbeatOutgoing: 100,
discardWebsocketOnCommFailure: true,
connectionTimeout: 4000
};
Finally I think I found the solution, so the problem was around queued-tasks
for inbound-channel
as can be seen in the log appended
2022-06-01 18:22:59,943 INFO Thread-id-74- springframework.web.socket.config.WebSocketMessageBrokerStats: WebSocketSession[130 current WS(129)-HttpStream(1)-HttpPoll(0), 225 total, 0 closed abnormally (0 connect failure, 0 send limit, 2 transport error)], stompSubProtocol[processed CONNECT(220)-CONNECTED(132)-DISCONNECT(0)], stompBrokerRelay[null], inboundChannel[pool size = 2, active threads = 2, queued tasks = 10774, completed tasks = 31806], outboundChannel[pool size = 2, active threads = 0, queued tasks = 0, completed tasks = 570895], sockJsScheduler[pool size = 1, active threads = 1, queued tasks = 134, completed tasks = 1985]
I was socked to say only 2 threads were allocated to the task through I was running on a 8 core machine. So I checked the code for TaskExecutor and found this.
this.taskExecutor.setCorePoolSize(Runtime.getRuntime().availableProcessors() * 2);
According to this my corePoolSize should had been around 8*2=16
and figured out there is some bug with Runtime.getRuntime().availableProcessors()
because of which it does not returns correct value in Java8, but has been fixed for newer version. Hence, i decided to fix this manually.
@Override
public void configureClientInboundChannel(ChannelRegistration registration) {
logger.debug("Configuring task executor for Client Inbound Channel");
if(inboundCoreThreads != null && inboundCoreThreads > 0) {
registration.taskExecutor().corePoolSize(inboundCoreThreads);
}
}
Now the question was why is it getting queued, so we started looking at the thread dump. And figured out that most of the threads are stuck in WAITING state due to cachelimit. And hence updated the cacheLimit to 4096 from 1024
@Override
public void configureMessageBroker(MessageBrokerRegistry config) {
config.setCacheLimit(messageBrokerCacheLimit);
}
ofcourse, inboundCoreThreads
and messageBrokerCacheLimit
are the variable names and have to put values in these.
After this, everything seems to working just fine. Thankyou @Ilya Lapitan for help.