The RTM client silently disconnects after a few hours

[gaspardpetit]

Issue Type

• Bug
• Enhancement / Feature request
• Question
• Documentation

Description

The RTM client will silently disconnect after a few hours. There does not seem to be any callback being triggered or easy ways to check the status of the websocket from the RTM api.

I have produced PR #459 to support ping/pong messages and events, and was hoping that pinging every 30 seconds would help but it did not. At the end, I can see a ping never being answered back.

It could be that the solution is to timeout on a ping event and force a reconnect when the pong response is not heard back within a reasonable amount of time (ex. 15 seconds?)

Is there another way to test if the websocket is still active with the RTM client? or a way to obtain a callback when the websocket connection drops?

Requirements (place an x in each of the [ ])

• I've read and understood the Contributing guidelines and have done my best effort to follow them.
• I've read and agree to the Code of Conduct.
• I've searched for any related issues and avoided creating a duplicate issue.

[seratch]

It seems we need to implement this logic in RTMClient#connect() method.

[gaspardpetit]

I'll try it out and report, but I am suspicious. The websocket link Slack provides is only valid for 30 seconds:

The Websocket URLs provided by rtm.connect are single-use and are only valid for 30 seconds, so make sure to connect quickly.

So I would think that letting Tyrus automatically reconnect to the same URL would fail. I'll try it and report back my findings. Otherwise, we can at least trigger an event and let the application manually call reconnect on the RTMClient

[gaspardpetit]

So that was interesting.

06:15:49.317 [Grizzly(2)] WARN  com.slack.api.rtm.RTMClient - ### Reconnecting... (reconnect count: 3)
06:15:50.389 [Grizzly(2)] DEBUG com.slack.api.rtm.RTMClient - session opened: f5f1af89-83dd-4665-9ba3-eb1dcbdd2e19
06:15:50.389 [Grizzly(2)] DEBUG com.slack.api.rtm.RTMClient - message: {"type":"error","error":{"msg":"Socket URL has expired","code":1,"source":"gs-iad-1b6o"}}
06:15:50.389 [Grizzly(2)] DEBUG com.slack.api.rtm.RTMEventsDispatcherImpl - No event handler registered for type: error
06:15:55.385 [Grizzly(2)] DEBUG com.slack.api.rtm.RTMClient - session closed: f5f1af89-83dd-4665-9ba3-eb1dcbdd2e19, reason: Closed abnormally.

It tried three time (I had that configured) and each time failed because of Socket URL has expired as I expected. However, it ended up triggering the session closed and my app picked that up and was able to reconnect (I had reconnect logic outside of the websocket, but was not getting this session closed event before.

So, I would say partial success. A quick fix would be to implement this with no retry so it immediately fails and the app has a chance to reconnect. A better fix would be to handle this within the RTM client, such that the RMT client calls reconnect to fetch a new URL from slack and performs the reconnection under the hood.

Would you be comfortable with me sending a pull request for the quick fix first and later when you (or I) have time we can look at the better solution? At least for now we would be able to tell people that the work around is to monitor session closed and to reconnect if desired.

[seratch]

I'm still not sure about what your "quick fix" is yet but I'd love to know what it is. Could you make a WIP pull request?

When it comes to consistency among 1st party Slack API SDKs, node-slack-sdk and python-slackclient have the concept - autoReconnect: boolean while this library doesn't. I'm keen to have the option and make it the default behavior as with those SDKs.

[gaspardpetit]

I'll still investigating. I tried a few things - the last "disconnect" I had looked like this:

07:43:14.618 [Grizzly(1)] DEBUG com.slack.api.rtm.RTMClient - message: {"type":"pong","time":{"seconds":1590219794,"nanos":599871000},"reply_to":998}
07:43:44.619 [Grizzly(2)] DEBUG com.slack.api.rtm.RTMClient - message: {"type":"pong","time":{"seconds":1590219824,"nanos":600550000},"reply_to":999}
07:43:56.938 [Grizzly(1)] DEBUG com.slack.api.rtm.RTMClient - message: {"type": "goodbye", "source": "gateway_server"}
07:43:56.938 [Grizzly(1)] DEBUG com.slack.api.rtm.RTMEventsDispatcherImpl - No event handler registered for type: goodbye
07:44:14.620 [Grizzly(2)] DEBUG com.slack.api.rtm.RTMClient - message: {"type":"pong","time":{"seconds":1590219854,"nanos":601300000},"reply_to":1000}

So it looks like we have to handle that one as well (https://api.slack.com/events/goodbye)

[seratch]

Thanks for sharing this! Indeed, this library doesn't provide an automatic-reconnect feature when receiving goodbye events yet. As GoodbyeHandler interface already exists, all we need to do is implement GoodbyeHandler which acquires a new WebSocket endpoint and reconnects to the server-side + enable it as a built-in one.

[gaspardpetit]

Hi again,

So good news is that my bot has been able to survive the 8h disconnect from Slack by handling the goodbye event. However I am not sure how this should be handled by the java sdk.

My existential concern is the following: I see two ways of handling the loss of the websocket:

1. Handled internally by the Slack SDK - this is the most convenient approach for anyone who's expecting the sdk to just "work". However, getting it right requires a bit of refactoring for the case when Slack is not available. As it is now, I can attempt a reconnect when we lose the websocket or when Slack says goodbye, but what if the reconnect fails (ex. Slack is down)? Then we'd need a thread that retries periodically, but also we would probably to inform the app that we are offline, and then notify when we are back online.

2. Let the app handle this - in the main loop, check when we get disconnected and attempt to reconnect. If re-connection fails, the main loop can just sleep 30 seconds and retry, and retry and retry until Slack is back online.

It would be possible to do something in-between by providing a reconnect policy - some kind of "restart recipe" that does the logic of #2 but is readily available so that whoever is creating a new bot using RTM does not have to worry about implementing it themselves.

I'll try to present such policy object in a PR so you can tell me what you think.

[seratch]

Thanks for sharing your well-considered resolution for this.

For the cases that the auto-reconnect logic should consider are:

• 1️⃣ rtm.connect/rtm.start failures due to Slack outage
• 2️⃣ rtm.connect/rtm.start failures due to rate_limited errors (rtm.* are Tier1)

Regarding 1️⃣, as you mentioned, waiting for the recovery a bit longer than usual and showing the status in info-level logs may be helpful for some apps. We can provide the default policy suitable for 80+% use cases but if it is customizable, that'll be great.

As for 2️⃣, the implementation should have a great consideration of Retry-After response header. I don't think we should use AsyncMethodsClient for this as it brings a bit more complexity in this case but checking the code would be helpful for learning how to handle rate_limited errors: https://github.com/slackapi/java-slack-sdk/blob/v1.0.7/slack-api-client/src/main/java/com/slack/api/methods/impl/AsyncRateLimitExecutor.java#L160-L162

Also, I think onClose is triggered right after your app receives goodbye messages from Slack. Based on the assumption, implementing this logic as RTMCloseHandler looks better as it can cover any other patterns the RTMClient needs to reconnect to Slack (e.g., disconnected without receiving a goodbye message).
https://github.com/slackapi/java-slack-sdk/blob/v1.0.7/slack-api-client/src/main/java/com/slack/api/rtm/RTMClient.java#L141-L149

Let the app handle this - in the main loop, check when we get disconnected and attempt to reconnect. If re-connection fails, the main loop can just sleep 30 seconds and retry, and retry and retry until Slack is back online.

If we can implement the above as RTMCloseHandler, I don't think we should manage another thread on our own (please correct me if I misunderstand).

[gaspardpetit]

Sorry for the radio silence. I tried a few things and each time it's a 8+ hour wait to validate :)

It turns out that catching GoodbyeEvent and calling disconnect on the client when it happens is sufficient to keep the bot running. The disconnect then correctly calls the close callback and the bot gets a chance to reconnect.

What I still don't understand, is why the close event does not get sent when we don't manually disconnect on Goodbye and the web socket is closed a few minutes after from the other end.

This is much less urgent now thatI have a workaround, so I guess we can close the issue and I'll come back if I have an improvement to offer.

Cheers,

Gaspard

[seratch]

@gaspardpetit Thanks for the response and I'm glad to hear that your app has been working well. I would like to know more details about your code with goodbye events. Does it look like this?
seratch@292339c

Also, if my implementation is valid (I haven't done any tests yet though), what do you think about having this implementation as the built-in message listener since the next version?