@slack/bolt is throwing errors and reconnecting in websocket mode

[karl-run]

What version of Bun is running?

1.0.0+822a00c4d508b54f650933a73ca5f4a3af9a7983

What platform is your computer?

Linux 6.4.6-76060406-generic x86_64 x86_64

What steps can reproduce the bug?

Using @slack/bolt in socketMode like this:

import { App } from "@slack/bolt";

const app = new App({
  token: process.env.BOT_TOKEN,
  appToken: process.env.APP_TOKEN,
  socketMode: true,
});

What is the expected behavior?

@slack/bolt should work like it does in Node.

What do you see instead?

Internally in @slack/bolt it is unable to parse messages from the websocket payload:

[INFO]  socket-mode:SocketModeClient:0 Now connected to Slack
[ERROR]  socket-mode:SocketModeClient:0 Unable to parse an incoming WebSocket message: JSON Parse error: Unexpected identifier "data"
[INFO]  socket-mode:SocketModeClient:0 Reconnecting to Slack ...
[INFO]  socket-mode:SocketModeClient:0 Going to establish a new connection to Slack ...
[INFO]  socket-mode:SocketModeClient:0 Now connected to Slack
[ERROR]  socket-mode:SocketModeClient:0 Unable to parse an incoming WebSocket message: JSON Parse error: Unexpected identifier "data"
[INFO]  socket-mode:SocketModeClient:0 Reconnecting to Slack ...
[INFO]  socket-mode:SocketModeClient:0 Going to establish a new connection to Slack ...
[INFO]  socket-mode:SocketModeClient:0 Now connected to Slack

Additional information

No response

[karl-run]

Here are some logs from bolt with LogLevel.DEBUG:

[0.01ms] ".env"
[DEBUG]  web-api:WebClient:0 initialized
[DEBUG]  bolt-app Initializing SocketModeReceiver
[DEBUG]  web-api:WebClient:1 initialized
[DEBUG]  socket-mode:SocketModeClient:0 Transitioning to state: disconnected
[DEBUG]  socket-mode:SocketModeClient:0 The Socket Mode client is successfully initialized
[DEBUG]  web-api:WebClient:0 apiCall('auth.test') start
[DEBUG]  web-api:WebClient:0 http request url: https://slack.com/api/auth.test
[DEBUG]  web-api:WebClient:0 http request body: {"token":"[[REDACTED]]"}
[DEBUG]  web-api:WebClient:0 http request headers: {"Authorization":"[[REDACTED]]"}
[DEBUG]  socket-mode:SocketModeClient:0 Starting a Socket Mode client ...
[DEBUG]  socket-mode:SocketModeClient:0 Transitioning to state: connecting
[INFO]  socket-mode:SocketModeClient:0 Going to establish a new connection to Slack ...
[DEBUG]  socket-mode:SocketModeClient:0 Transitioning to state: connecting:authenticating
[DEBUG]  socket-mode:SocketModeClient:0 Going to retrieve a new WSS URL ...
[DEBUG]  web-api:WebClient:1 apiCall('apps.connections.open') start
[DEBUG]  web-api:WebClient:1 http request url: https://slack.com/api/apps.connections.open
[DEBUG]  web-api:WebClient:1 http request body: {}
[DEBUG]  web-api:WebClient:1 http request headers: {}
[DEBUG]  web-api:WebClient:1 http response received
[DEBUG]  web-api:WebClient:1 http request result: {"ok":true,"url":"wss://wss-primary.slack.com/link/?ticket=<snip>","response_metadata":{"scopes":["connections:write"],"acceptedScopes":["connections:write"]}}
[DEBUG]  web-api:WebClient:1 apiCall('apps.connections.open') end
[DEBUG]  socket-mode:SocketModeClient:0 Transitioning to state: connecting:authenticated
⚡️ Bolt app is running!
[DEBUG]  web-api:WebClient:0 http response received
[DEBUG]  web-api:WebClient:0 http request result: {"ok":true,"url":"https://systekkompis.slack.com/","team":"<snip>","user":"13372","team_id":"T04251BM1","user_id":"<snip>","bot_id":"<snip>","is_enterprise_install":false,"response_metadata":{"scopes":[<snip>]}}
[DEBUG]  web-api:WebClient:0 apiCall('auth.test') end
[DEBUG]  socket-mode:SocketModeClient:0 Transitioning to state: connecting:handshaking
[DEBUG]  socket-mode:SocketModeClient:0 Received a message on the WebSocket: {"type":"hello","num_connections":3,"debug_info":{"host":"applink-4","build_number":38,"approximate_connection_time":18060},"connection_info":{"app_id":"<snip>"}}
[DEBUG]  socket-mode:SocketModeClient:0 Transitioning to state: connected
[INFO]  socket-mode:SocketModeClient:0 Now connected to Slack
[DEBUG]  socket-mode:SocketModeClient:0 Transitioning to state: connected:preparing
[DEBUG]  socket-mode:SocketModeClient:0 Started running a new heart beat job
[DEBUG]  socket-mode:SocketModeClient:0 Transitioning to state: connected:ready
[DEBUG]  socket-mode:SocketModeClient:0 Received a message on the WebSocket: data frame using reserved opcode 3
[ERROR]  socket-mode:SocketModeClient:0 Unable to parse an incoming WebSocket message: JSON Parse error: Unexpected identifier "data"
[DEBUG]  socket-mode:SocketModeClient:0 Cancelled the job waiting for ping from Slack
[DEBUG]  socket-mode:SocketModeClient:0 Terminated the heart beat job
[DEBUG]  socket-mode:SocketModeClient:0 Transitioning to state: reconnecting
[INFO]  socket-mode:SocketModeClient:0 Reconnecting to Slack ...
``

[Aschen]

Same problem here ✋ (switching back to Node in the meantime)

For the maintainers, you can reproduce the bug in 5 min by following https://slack.dev/bolt-js/tutorial/getting-started

[devinjpmitch]

im facing the same issue, would love to find a solution while using socket mode.

[karl-run]

Just verified this in 1.0.3+25e69c71e70ac8a0a88f9cf15b4057bd7b2a633a as well!

[karl-run]

Verified in 1.0.4+745b6b94ee56cad24d475799690cc9a89957d15b as well. 😅

Edit: Verified still a bug in 1.0.6+969da088f5db3258a803ec186012e30f992829b4

[Electroid]

We need to test our WebSocket client using the Autobahn test suite to fix these bugs, including this one. For updates, please upvote and subscribe to this issue: #6686

[karl-run]

Isn't closing all these issues as "not planned" sending the wrong message? Close them as "duplicate", so people don't get emails saying "Closed #XXXX as not planned". 🥲

[Jarred-Sumner]

They are definitely planned! It’s a duplicate. GitHub just has not good copy here