diff --git a/.changeset/socket-mode-refresh-gap.md b/.changeset/socket-mode-refresh-gap.md new file mode 100644 index 000000000..76f3d3aff --- /dev/null +++ b/.changeset/socket-mode-refresh-gap.md @@ -0,0 +1,5 @@ +--- +"@slack/socket-mode": patch +--- + +fix(socket-mode): reconnect immediately on Slack `disconnect` without a connection gap ([#2767](https://github.com/slackapi/node-slack-sdk/issues/2767)). If the replacement socket never receives `hello`, abort the refresh and recover with the usual reconnect backoff. diff --git a/packages/socket-mode/src/SocketModeClient.test.ts b/packages/socket-mode/src/SocketModeClient.test.ts index e68ff270f..fb30ef938 100644 --- a/packages/socket-mode/src/SocketModeClient.test.ts +++ b/packages/socket-mode/src/SocketModeClient.test.ts @@ -388,6 +388,323 @@ describe('SocketModeClient', () => { }); }); + describe('server-requested disconnect (issue #2767)', () => { + it('should open a new connection immediately and keep the old socket until it is connected', async () => { + const client = new SocketModeClient({ + appToken: 'xapp-', + logLevel: LogLevel.ERROR, + clientPingTimeout: 5000, + }); + const oldWs = { + disconnect: sandbox.stub(), + isActive: () => true, + }; + client.websocket = oldWs as unknown as SlackWebSocket; + + let resolveStart: ((value: unknown) => void) | undefined; + const startStub = sandbox.stub(client, 'start').callsFake(() => { + // Real start() replaces `websocket` with the new connection before hello. + client.websocket = { + disconnect: sandbox.stub(), + isActive: () => true, + } as unknown as SlackWebSocket; + return new Promise((resolve) => { + resolveStart = resolve; + }); + }); + + client.emit( + 'ws_message', + JSON.stringify({ type: 'disconnect', reason: 'refresh_requested' }), + false /* isBinary */, + ); + await sleep(30); + + sinon.assert.calledOnce(startStub); + sinon.assert.notCalled(oldWs.disconnect); + + resolveStart?.({}); + await sleep(30); + + sinon.assert.calledOnce(oldWs.disconnect); + }); + + it('new socket closes before hello', async () => { + const client = new SocketModeClient({ + appToken: 'xapp-', + logLevel: LogLevel.ERROR, + clientPingTimeout: 50, + }); + const oldWs = { + disconnect: sandbox.stub(), + isActive: () => true, + }; + client.websocket = oldWs as unknown as SlackWebSocket; + const newWs = { + disconnect: sandbox.stub(), + isActive: () => false, + }; + const startStub = sandbox.stub(client, 'start').callsFake(() => { + client.websocket = newWs as unknown as SlackWebSocket; + return new Promise((resolve, reject) => { + client.once('connected', resolve); + client.once('disconnected', reject); + }); + }); + + client.emit( + 'ws_message', + JSON.stringify({ type: 'disconnect', reason: 'refresh_requested' }), + false /* isBinary */, + ); + await sleep(20); + + sinon.assert.calledOnce(startStub); + sinon.assert.notCalled(oldWs.disconnect); + + client.emit('close'); + await sleep(20); + + sinon.assert.called(oldWs.disconnect); + sinon.assert.calledOnce(startStub); + + await sleep(80); + sinon.assert.calledTwice(startStub); + }); + + it('old socket closes while the refresh is pending', async () => { + const client = new SocketModeClient({ + appToken: 'xapp-', + logLevel: LogLevel.ERROR, + clientPingTimeout: 50, + }); + const oldWs = { + disconnect: sandbox.stub(), + isActive: () => true, + }; + client.websocket = oldWs as unknown as SlackWebSocket; + const newWs = { + disconnect: sandbox.stub(), + isActive: () => false, + }; + const startStub = sandbox.stub(client, 'start').callsFake(() => { + client.websocket = newWs as unknown as SlackWebSocket; + return new Promise((resolve, reject) => { + client.once('connected', resolve); + client.once('disconnected', reject); + }); + }); + + client.emit( + 'ws_message', + JSON.stringify({ type: 'disconnect', reason: 'refresh_requested' }), + false /* isBinary */, + ); + await sleep(20); + + sinon.assert.calledOnce(startStub); + + oldWs.isActive = () => false; + client.emit('close'); + await sleep(20); + + sinon.assert.calledOnce(startStub); + + await sleep(80); + sinon.assert.calledTwice(startStub); + }); + + it('should acknowledge on the retiring socket while the replacement is connecting', async () => { + const client = new SocketModeClient({ + appToken: 'xapp-', + logLevel: LogLevel.ERROR, + clientPingTimeout: 5000, + }); + const oldSend = sandbox.stub(); + const oldWs = { + disconnect: sandbox.stub(), + isActive: () => true, + readyState: 1, + send: (data: string, cb: (err: Error | undefined) => void) => { + oldSend(data); + cb(undefined); + }, + }; + client.websocket = oldWs as unknown as SlackWebSocket; + sandbox.stub(client, 'start').callsFake(() => { + client.websocket = { + disconnect: sandbox.stub(), + isActive: () => false, + readyState: 0, + send: sandbox.stub(), + } as unknown as SlackWebSocket; + return new Promise(() => {}); + }); + + client.emit( + 'ws_message', + JSON.stringify({ type: 'disconnect', reason: 'refresh_requested' }), + false /* isBinary */, + ); + await sleep(20); + + let ackError: unknown; + client.on('slash_commands', async ({ ack }) => { + try { + await ack({}); + } catch (error) { + ackError = error; + } + }); + client.emit( + 'ws_message', + JSON.stringify({ + envelope_id: 'ack-during-refresh', + type: 'slash_commands', + payload: { command: '/hello-socket-mode' }, + }), + false /* isBinary */, + ); + await sleep(20); + + assert.equal(ackError, undefined); + sinon.assert.calledOnce(oldSend); + }); + + it('should acknowledge on the old socket while the new socket is OPEN but has not received hello', async () => { + const client = new SocketModeClient({ + appToken: 'xapp-', + logLevel: LogLevel.ERROR, + clientPingTimeout: 5000, + }); + const oldSend = sandbox.stub(); + const newSend = sandbox.stub(); + const oldWs = { + disconnect: sandbox.stub(), + isActive: () => true, + readyState: 1, + send: (data: string, cb: (err: Error | undefined) => void) => { + oldSend(data); + cb(undefined); + }, + }; + client.websocket = oldWs as unknown as SlackWebSocket; + sandbox.stub(client, 'start').callsFake(() => { + // Real WebSocket is OPEN well before Slack sends `hello`. + client.websocket = { + disconnect: sandbox.stub(), + isActive: () => true, + readyState: 1, + send: (data: string, cb: (err: Error | undefined) => void) => { + newSend(data); + cb(undefined); + }, + } as unknown as SlackWebSocket; + return new Promise(() => {}); + }); + + client.emit( + 'ws_message', + JSON.stringify({ type: 'disconnect', reason: 'refresh_requested' }), + false /* isBinary */, + ); + await sleep(20); + + let ackError: unknown; + client.on('slash_commands', async ({ ack }) => { + try { + await ack({}); + } catch (error) { + ackError = error; + } + }); + client.emit( + 'ws_message', + JSON.stringify({ + envelope_id: 'ack-before-hello', + type: 'slash_commands', + payload: { command: '/hello-socket-mode' }, + }), + false /* isBinary */, + ); + await sleep(20); + + assert.equal(ackError, undefined); + sinon.assert.calledOnce(oldSend); + sinon.assert.notCalled(newSend); + }); + + it('should emit disconnected once if disconnect() is called during a refresh', async () => { + const client = new SocketModeClient({ + appToken: 'xapp-', + logLevel: LogLevel.ERROR, + clientPingTimeout: 5000, + }); + const disconnected = sandbox.stub(); + client.on('disconnected', disconnected); + + const oldWs = { + isActive: () => true, + disconnect: sandbox.stub().callsFake(() => { + oldWs.isActive = () => false; + client.emit('close'); + }), + }; + client.websocket = oldWs as unknown as SlackWebSocket; + + const newWs = { + isActive: () => true, + disconnect: sandbox.stub().callsFake(() => { + newWs.isActive = () => false; + client.emit('close'); + }), + }; + sandbox.stub(client, 'start').callsFake(() => { + client.websocket = newWs as unknown as SlackWebSocket; + return new Promise((resolve, reject) => { + client.once('connected', resolve); + client.once('disconnected', reject); + }); + }); + + client.emit( + 'ws_message', + JSON.stringify({ type: 'disconnect', reason: 'refresh_requested' }), + false /* isBinary */, + ); + await sleep(20); + + await client.disconnect(); + await sleep(20); + + sinon.assert.calledOnce(disconnected); + }); + + it('should close the current socket immediately when auto-reconnect is disabled', async () => { + const client = new SocketModeClient({ + appToken: 'xapp-', + logLevel: LogLevel.ERROR, + autoReconnectEnabled: false, + }); + const oldWs = { + disconnect: sandbox.stub(), + isActive: () => true, + }; + client.websocket = oldWs as unknown as SlackWebSocket; + const startStub = sandbox.stub(client, 'start').resolves(undefined as never); + + client.emit( + 'ws_message', + JSON.stringify({ type: 'disconnect', reason: 'refresh_requested' }), + false /* isBinary */, + ); + await sleep(30); + + sinon.assert.calledOnce(oldWs.disconnect); + sinon.assert.notCalled(startStub); + }); + }); + describe("reconnection on 'close' (issue #2709)", () => { it('should not reconnect on a stale close event while the current connection is still active', () => { const client = new SocketModeClient({ appToken: 'xapp-', logLevel: LogLevel.ERROR }); diff --git a/packages/socket-mode/src/SocketModeClient.ts b/packages/socket-mode/src/SocketModeClient.ts index 93bf8c7c0..12ca0bc25 100644 --- a/packages/socket-mode/src/SocketModeClient.ts +++ b/packages/socket-mode/src/SocketModeClient.ts @@ -104,6 +104,31 @@ export class SocketModeClient extends EventEmitter { */ private reconnectionTimer: ReturnType | undefined; + /** + * True while a Slack-requested disconnect is being served by opening a replacement connection + * before the previous socket is closed. Unexpected closes during this window abort the refresh + * so a hung `start()` cannot leave the client unable to reconnect. + */ + private refreshInProgress = false; + + /** + * The still-open socket being replaced during a Slack-requested refresh. Used so acks can be + * written to a live connection while the replacement is still connecting, and so we can close + * it if the replacement fails. + */ + private retiringWebsocket?: SlackWebSocket; + + /** + * Timer that aborts a Slack-requested refresh if the replacement socket never receives `hello`. + */ + private refreshHelloTimeout: ReturnType | undefined; + + /** + * Incremented to cancel an in-flight `start()` (for example after a failed refresh) so a late + * `apps.connections.open` response cannot attach a new WebSocket after we have already recovered. + */ + private connectionAttemptId = 0; + public constructor( { logger = undefined, @@ -159,6 +184,11 @@ export class SocketModeClient extends EventEmitter { // Underlying WebSocket connection was closed, possibly reconnect. if (this.websocket?.isActive()) return; if (this.reconnectionTimer) return; + if (this.refreshInProgress) { + // Replacement failed before hello, or the old socket died while we were still connecting. + this.abortRefreshAndReconnect(); + return; + } if (!this.shuttingDown && this.autoReconnectEnabled) { this.delayReconnectAttempt(this.start); } else { @@ -180,10 +210,15 @@ export class SocketModeClient extends EventEmitter { public async start(): Promise { // python equiv: SocketModeClient.connect this.shuttingDown = false; + const attemptId = this.connectionAttemptId; this.logger.debug('Starting Socket Mode session ...'); + const url = await this.retrieveWSSURL(); + if (this.shuttingDown || attemptId !== this.connectionAttemptId) { + throw new Error('Socket Mode connection attempt was cancelled'); + } // create a socket connection using SlackWebSocket this.websocket = new SlackWebSocket({ - url: await this.retrieveWSSURL(), + url, // web socket events relevant to this client will be emitted into the instance of this class // see bottom of constructor for where we bind to these events client: this, @@ -194,6 +229,9 @@ export class SocketModeClient extends EventEmitter { serverPingTimeoutMS: this.serverPingTimeoutMS, pingPongLoggingEnabled: this.pingPongLoggingEnabled, }); + if (this.refreshInProgress) { + this.armRefreshHelloTimeout(); + } // Return a promise that resolves with the connection information return new Promise((resolve, reject) => { @@ -262,6 +300,107 @@ export class SocketModeClient extends EventEmitter { }); } + /** + * Handles a Slack `type: disconnect` message by opening a replacement WebSocket first. + * The previous connection stays up until the new one has completed the `hello` handshake, + * so interactive payloads are not dropped during a routine connection refresh. + */ + private async refreshConnection(): Promise { + if (this.refreshInProgress || this.shuttingDown) { + return; + } + this.refreshInProgress = true; + this.retiringWebsocket = this.websocket; + this.emit(State.Reconnecting); + try { + await this.start(); + this.finishSuccessfulRefresh(); + } catch (error) { + this.logger.error( + `Failed to open a replacement Socket Mode connection after Slack requested a disconnect: ${error}`, + ); + this.abortRefreshAndReconnect(); + } + } + + private armRefreshHelloTimeout(): void { + this.clearRefreshHelloTimeout(); + this.refreshHelloTimeout = setTimeout(() => { + this.logger.warn( + `Replacement Socket Mode connection did not receive hello before the timeout of ${this.clientPingTimeoutMS}ms`, + ); + this.abortRefreshAndReconnect(); + }, this.clientPingTimeoutMS); + } + + private clearRefreshHelloTimeout(): void { + clearTimeout(this.refreshHelloTimeout); + this.refreshHelloTimeout = undefined; + } + + /** + * Completes a Slack-requested refresh after the replacement socket has received `hello`. + */ + private finishSuccessfulRefresh(): void { + this.clearRefreshHelloTimeout(); + this.refreshInProgress = false; + const retiring = this.retiringWebsocket; + this.retiringWebsocket = undefined; + if (retiring && retiring !== this.websocket) { + retiring.disconnect(); + } + } + + /** + * Tears down a Slack-requested refresh that did not reach `hello`, settles the in-flight `start()`, + * and reconnects with the usual consecutive-failure backoff. + */ + private abortRefreshAndReconnect(): void { + if (!this.refreshInProgress) { + return; + } + this.refreshInProgress = false; + this.clearRefreshHelloTimeout(); + this.connectionAttemptId += 1; + const retiring = this.retiringWebsocket; + const incoming = this.websocket !== retiring ? this.websocket : undefined; + this.retiringWebsocket = undefined; + if (this.shuttingDown) { + // User `disconnect()` already closed `this.websocket` and is waiting on `disconnected`. + // Close the other socket if needed; do not emit here so that event fires once from `close`. + if (retiring && retiring !== this.websocket) { + retiring.disconnect(); + } else { + this.emit(State.Disconnected); + } + return; + } + // Reject the in-flight start() waiter (Connected / Disconnected). + this.emit(State.Disconnected); + if (this.autoReconnectEnabled && !this.reconnectionTimer) { + this.delayReconnectAttempt(this.start); + } + retiring?.disconnect(); + incoming?.disconnect(); + } + + /** + * During a Slack-requested refresh the replacement socket can be WebSocket OPEN long before + * Slack sends `hello`. Keep writing acks to the old socket until that handshake completes. + */ + private socketForSend(): SlackWebSocket | undefined { + if (this.refreshInProgress && this.retiringWebsocket?.isActive()) { + return this.retiringWebsocket; + } + if (this.websocket?.isActive()) { + return this.websocket; + } + if (this.retiringWebsocket?.isActive()) { + return this.retiringWebsocket; + } + return this.websocket; + } + /** * Retrieves a new WebSocket URL to connect to. */ @@ -347,7 +486,13 @@ export class SocketModeClient extends EventEmitter { this.logger.debug( `Received "${event.type}" (${event.reason}) message - disconnecting.${this.autoReconnectEnabled ? ' Will reconnect.' : ''}`, ); - this.websocket?.disconnect(); + if (this.autoReconnectEnabled && !this.shuttingDown) { + // Open the next connection before closing the current one, and do not treat this as a failure. + // See https://github.com/slackapi/node-slack-sdk/issues/2767 + await this.refreshConnection(); + } else { + this.websocket?.disconnect(); + } return; } @@ -406,14 +551,15 @@ export class SocketModeClient extends EventEmitter { const message = { envelope_id: id, payload: { ..._body } }; return new Promise((resolve, reject) => { - const wsState = this.websocket?.readyState; + const socket = this.socketForSend(); + const wsState = socket?.readyState; this.logger.debug( `send() method was called (WebSocket state: ${wsState ? WS_READY_STATES[wsState] : 'uninitialized'})`, ); - if (this.websocket === undefined) { + if (socket === undefined) { this.logger.error('Failed to send a message as the client is not connected'); reject(new SMSendWhileDisconnectedError()); - } else if (!this.websocket.isActive()) { + } else if (!socket.isActive()) { this.logger.error('Failed to send a message as the client has no active connection'); reject(new SMSendWhileNotReadyError()); } else { @@ -421,7 +567,7 @@ export class SocketModeClient extends EventEmitter { const flatMessage = JSON.stringify(message); this.logger.debug(`Sending a WebSocket message: ${flatMessage}`); - this.websocket.send(flatMessage, (error) => { + socket.send(flatMessage, (error) => { if (error) { this.logger.error(`Failed to send a WebSocket message (error: ${error})`); return reject(new SMWebsocketError(error));