Slackbot is down with java.lang.IllegalStateException: Message will not be sent because the WebSocket session has been closed

[lavanyachadga]

hi, Slack bot is continuously toggles (going on and off) with below error since yesterday. It tries to ping and comes up for some time and then after couple of times it goes down permanently ( never comes up until i deploy the app again) . Could you please look into this websocket issue

2021-01-05 18:47:43.904 ERROR 1 --- [pool-2-thread-1] me.ramswaroop.jbot.core.slack.Bot        : Error pinging Slack. Slack bot may go offline when not active. Exception: 

java.lang.IllegalStateException: Message will not be sent because the WebSocket session has been closed
	at org.apache.tomcat.websocket.WsRemoteEndpointImplBase.writeMessagePart(WsRemoteEndpointImplBase.java:425) ~[tomcat-embed-websocket-9.0.24.jar!/:9.0.24]
	at org.apache.tomcat.websocket.WsRemoteEndpointImplBase.sendMessageBlock(WsRemoteEndpointImplBase.java:309) ~[tomcat-embed-websocket-9.0.24.jar!/:9.0.24]
	at org.apache.tomcat.websocket.WsRemoteEndpointImplBase.sendMessageBlock(WsRemoteEndpointImplBase.java:250) ~[tomcat-embed-websocket-9.0.24.jar!/:9.0.24]
	at org.apache.tomcat.websocket.WsRemoteEndpointImplBase.sendPartialString(WsRemoteEndpointImplBase.java:223) ~[tomcat-embed-websocket-9.0.24.jar!/:9.0.24]
	at org.apache.tomcat.websocket.WsRemoteEndpointBasic.sendText(WsRemoteEndpointBasic.java:49) ~[tomcat-embed-websocket-9.0.24.jar!/:9.0.24]
	at org.springframework.web.socket.adapter.standard.StandardWebSocketSession.sendTextMessage(StandardWebSocketSession.java:213) ~[spring-websocket-5.1.9.RELEASE.jar!/:5.1.9.RELEASE]
	at org.springframework.web.socket.adapter.AbstractWebSocketSession.sendMessage(AbstractWebSocketSession.java:106) ~[spring-websocket-5.1.9.RELEASE.jar!/:5.1.9.RELEASE]
	at me.ramswaroop.jbot.core.slack.Bot$PingTask.run(Bot.java:361) ~[jbot-4.1.2-rc.3-SNAPSHOT.jar!/:4.1.2-rc.3-SNAPSHOT]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [na:1.8.0_111-internal]
	at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [na:1.8.0_111-internal]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [na:1.8.0_111-internal]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [na:1.8.0_111-internal]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [na:1.8.0_111-internal]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [na:1.8.0_111-internal]
	at java.lang.Thread.run(Thread.java:745) [na:1.8.0_111-internal]

2021-01-05 18:47:43.906  INFO 1 --- [pool-2-thread-1] o.s.w.s.c.WebSocketConnectionManager     : Stopping WebSocketConnectionManager

[lavanyachadga]

And I see that it usually happens at IST night hours 1.00 am ( say currently my slackbot is turning off and on with this web socket issue its ) . @rampatra , can you please suggest a fix to it...

[lavanyachadga]

hi, @kojilin , @rampatra
Just wanted to know if jbot support is still active.
My slackbot is constantly going down with this issue.
Let me know with any suggestions/fix for the same!

[rampatra]

@lavanyachadga since when are you using JBot? Was it working fine all the time before you reported this bug? If yes, I would like to know any changes you made recently.

[lavanyachadga]

hi @rampatra, thanks for responding.
Even earlier couple of times bot would go off due to socket connection close issue. And I had to restart the bot.
But after slack outage (which happened recently) it was going off pretty frequently i.e. toggle on and off and then permanently switch off and this was happening repeatedly for about two days.
Now, after enabling debug log level and restarting the bot again I see bot is up and running.
Unsure if slack had some issues.

In future, for such websocket connection close issues what is the suggested steps/solutions that has to be taken from my end?
By the way great work on the bot itself thanks for that !

Regards,
Lavanya

[lavanyachadga]

Hi @rampatra, actually the bot went down again 2 hours back (after bot being up for 3 days since I saw the toggle issue) with same websocket connection close issue.
So, how could I raise the frequency of ping pong? I guess, if the slack response is idle for sometime then this websocket connection issue is being seen.

[rampatra]

You can modify the frequency here:

pingScheduledExecutorService.scheduleAtFixedRate(pingTask, 1L, 30L, TimeUnit.SECONDS);

in the file: src/main/java/me/ramswaroop/jbot/core/slack/Bot.java.

Also, may I ask where are you hosting the bot? Is it a free server like Heroku or something else or is it a paid server?

[lavanyachadga]

Thank you.
And, no its not Heroku server, it is something else that we use internally here to run in our workplace.
Would that matter here in this case?

[rampatra]

Yes maybe, as the free servers become inactive when there are no requests to the application (even if we have the ping at regular intervals). You can quickly test whether it's an issue with your server by deploying a sample spring-boot application there and see if it goes down after a while if it receives no requests.

[lavanyachadga]

hmm.. ok pods were up and running but yeah will give this a try and check it out.
Thanks for the input!

[kojilin]

I also met this problem before.
My bot is host internally(not public cloud). And sometimes there is no error log or disconnection log, but the slack bot in the slack APP shows offline.

I tried to wrap the bot class with automatic ping and check if pong comebacks, if there is no pong message back, I make bot reconnect.

[lavanyachadga]

Thanks @kojilin for responding. Will try doing the same if I see the issue again.
I think I have fixed the current issue which was actually causing due to lengthy messages ( say longer thread messages in the channel which the bot is part of). So when there are lengthy thread messages then websocket would close.
So I have added below code to overide text Message Size post that it seems to be up and running. Was waiting for few days to monitor before putting it up here.
@Override public void afterConnectionEstablished(WebSocketSession session) { Assert.state(session != null, "WebSocketSession not yet initialized"); session.setTextMessageSizeLimit(50000); logger.info("websocketSession setTextMessageSizeLimit : "+session.getTextMessageSizeLimit()); }
Thanks @kojilin and @rampatra