From 616ef86ce16b3a7a98090d38c04c57b5c2582dab Mon Sep 17 00:00:00 2001 From: Cacie Prins Date: Tue, 16 Apr 2024 16:12:46 -0400 Subject: [PATCH 01/10] fix: updates regex for websocket connection error to properly handle --- packages/server/lib/browsers/cri-client.ts | 2 +- packages/server/test/unit/browsers/cri-client_spec.ts | 11 +++++++++++ 2 files changed, 12 insertions(+), 1 deletion(-) diff --git a/packages/server/lib/browsers/cri-client.ts b/packages/server/lib/browsers/cri-client.ts index eaabd7522af4..0e3a4b18959a 100644 --- a/packages/server/lib/browsers/cri-client.ts +++ b/packages/server/lib/browsers/cri-client.ts @@ -16,7 +16,7 @@ const debugVerboseSend = debugModule('cypress-verbose:server:browsers:cri-client // debug using cypress-verbose:server:browsers:cri-client:recv:* const debugVerboseReceive = debugModule('cypress-verbose:server:browsers:cri-client:recv:[<--]') -const WEBSOCKET_NOT_OPEN_RE = /^WebSocket is (?:not open|already in CLOSING or CLOSED state)/ +const WEBSOCKET_NOT_OPEN_RE = /^WebSocket (?:connection closed|is (?:not open|already in CLOSING or CLOSED state))/ type QueuedMessages = { enableCommands: EnableCommand[] diff --git a/packages/server/test/unit/browsers/cri-client_spec.ts b/packages/server/test/unit/browsers/cri-client_spec.ts index 5918e56b8d19..b9958b773f83 100644 --- a/packages/server/test/unit/browsers/cri-client_spec.ts +++ b/packages/server/test/unit/browsers/cri-client_spec.ts @@ -130,6 +130,17 @@ describe('lib/browsers/cri-client', function () { expect(client.send('DOM.getDocument', { depth: -1 })).to.be.rejectedWith('DOM.getDocument will not run as browser CRI connection was reset') }) + + it(`when socket is closed mid send ('WebSocket connection closed' variant)`, async function () { + const err = new Error('WebSocket connection closed') + + send.onFirstCall().rejects(err) + const client = await getClient() + + await client.close() + + expect(client.send('DOM.getDocument', { depth: -1 })).to.be.rejectedWith('DOM.getDocument will not run as browser CRI connection was reset') + }) }) }) }) From 3ca7f5c3e9d1ff8333581740ef0511a5508962ad Mon Sep 17 00:00:00 2001 From: Cacie Prins Date: Tue, 16 Apr 2024 16:14:20 -0400 Subject: [PATCH 02/10] build binaries for this branch --- .circleci/workflows.yml | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/.circleci/workflows.yml b/.circleci/workflows.yml index 393cebfed786..84e1d2aea511 100644 --- a/.circleci/workflows.yml +++ b/.circleci/workflows.yml @@ -29,7 +29,7 @@ mainBuildFilters: &mainBuildFilters - develop - /^release\/\d+\.\d+\.\d+$/ # use the following branch as well to ensure that v8 snapshot cache updates are fully tested - - 'cacie/dep/electron-27' + - 'cacie/fix/websocket-closed' - 'feat/protocol_shadow_dom_support' - 'publish-binary' - 'em/circle2' @@ -43,7 +43,7 @@ macWorkflowFilters: &darwin-workflow-filters - equal: [ develop, << pipeline.git.branch >> ] # use the following branch as well to ensure that v8 snapshot cache updates are fully tested - equal: [ 'update-v8-snapshot-cache-on-develop', << pipeline.git.branch >> ] - - equal: [ 'cacie/dep/electron-27', << pipeline.git.branch >> ] + - equal: [ 'cacie/fix/websocket-closed', << pipeline.git.branch >> ] - equal: [ 'feat/protocol_shadow_dom_support', << pipeline.git.branch >> ] - equal: [ 'chore/move_off_circle_to_macstadium_amd64', << pipeline.git.branch >> ] - matches: @@ -56,7 +56,7 @@ linuxArm64WorkflowFilters: &linux-arm64-workflow-filters - equal: [ develop, << pipeline.git.branch >> ] # use the following branch as well to ensure that v8 snapshot cache updates are fully tested - equal: [ 'update-v8-snapshot-cache-on-develop', << pipeline.git.branch >> ] - - equal: [ 'cacie/dep/electron-27', << pipeline.git.branch >> ] + - equal: [ 'cacie/fix/websocket-closed', << pipeline.git.branch >> ] - equal: [ 'feat/protocol_shadow_dom_support', << pipeline.git.branch >> ] - equal: [ 'chore/move_off_circle_to_macstadium_amd64', << pipeline.git.branch >> ] - matches: From 207d235485d6544c96ecee0c54f1fc6086852d2d Mon Sep 17 00:00:00 2001 From: Cacie Prins Date: Fri, 19 Apr 2024 11:45:07 -0400 Subject: [PATCH 03/10] do not reconnect if reconnect in progress; treat websocket not connected errors as websocket in closing/closed state errors --- packages/server/lib/browsers/cri-client.ts | 65 +++++++++++++++++--- packages/server/test/integration/cdp_spec.ts | 17 ++--- 2 files changed, 67 insertions(+), 15 deletions(-) diff --git a/packages/server/lib/browsers/cri-client.ts b/packages/server/lib/browsers/cri-client.ts index 0e3a4b18959a..4c0776ecf666 100644 --- a/packages/server/lib/browsers/cri-client.ts +++ b/packages/server/lib/browsers/cri-client.ts @@ -11,10 +11,13 @@ import type { SendDebuggerCommand, OnFn, CdpCommand, CdpEvent } from './cdp_auto import type { ProtocolManagerShape } from '@packages/types' const debug = debugModule('cypress:server:browsers:cri-client') +const debugVerbose = debugModule('cypress-verbose:server:browsers:cri-client') // debug using cypress-verbose:server:browsers:cri-client:send:* -const debugVerboseSend = debugModule('cypress-verbose:server:browsers:cri-client:send:[-->]') +const debugVerboseSend = debugModule(`${debugVerbose.namespace}:send:[-->]`) // debug using cypress-verbose:server:browsers:cri-client:recv:* -const debugVerboseReceive = debugModule('cypress-verbose:server:browsers:cri-client:recv:[<--]') +const debugVerboseReceive = debugModule(`${debugVerbose.namespace}:recv:[<--]`) +// debug using cypress-verbose:server:browsers:cri-client:err:* +const debugVerboseLifecycle = debugModule(`${debugVerbose.namespace}:ws`) const WEBSOCKET_NOT_OPEN_RE = /^WebSocket (?:connection closed|is (?:not open|already in CLOSING or CLOSED state))/ @@ -136,6 +139,20 @@ const maybeDebugCdpMessages = (cri: CDPClient) => { return send.call(cri._ws, data, callback) } } + + if (debugVerboseLifecycle.enabled) { + cri._ws.addEventListener('open', (event) => { + debugVerboseLifecycle(`[OPEN] %o`, event) + }) + + cri._ws.addEventListener('close', (event) => { + debugVerboseLifecycle(`[CLOSE] %o`, event) + }) + + cri._ws.addEventListener('error', (event) => { + debugVerboseLifecycle(`[ERROR] %o`, event) + }) + } } type DeferredPromise = { resolve: Function, reject: Function } @@ -167,6 +184,7 @@ export const create = async ({ let closed = false // has the user called .close on this? let connected = false // is this currently connected to CDP? let crashed = false // has this crashed? + let reconnection: Promise | undefined = undefined let cri: CDPClient let client: CriClient @@ -195,8 +213,25 @@ export const create = async ({ // '*.enable' commands need to be resent on reconnect or any events in // that namespace will no longer be received - await Promise.all(enableCommands.map(({ command, params, sessionId }) => { - return cri.send(command, params, sessionId) + await Promise.all(enableCommands.map(async ({ command, params, sessionId }) => { + // these commands may have been enqueued, so we need to resolve those promises and remove + // them from the queue when we send here + const isInFlightCommand = (candidate: EnqueuedCommand) => { + return candidate.command === command && candidate.params === params && candidate.sessionId === sessionId + } + const enqueued = enqueuedCommands.find(isInFlightCommand) + + try { + const response = await cri.send(command, params, sessionId) + + enqueued?.p.resolve(response) + } catch (e) { + enqueued?.p.reject(e) + } finally { + enqueuedCommands = enqueuedCommands.filter((candidate) => { + return !isInFlightCommand(candidate) + }) + } })) enqueuedCommands.forEach((cmd) => { @@ -216,13 +251,23 @@ export const create = async ({ } const retryReconnect = async () => { + if (reconnection) { + debug('reconnection in progress; not starting new process, returning promise for in-flight reconnection attempt') + + return reconnection + } + debug('disconnected, starting retries to reconnect... %o', { closed, target }) const retry = async (retryIndex = 0) => { retryIndex++ try { - return await reconnect(retryIndex) + const attempt = await reconnect(retryIndex) + + reconnection = undefined + + return attempt } catch (err) { if (closed) { debug('could not reconnect because client is closed %o', { closed, target }) @@ -244,11 +289,14 @@ export const create = async ({ // If we cannot reconnect to CDP, we will be unable to move to the next set of specs since we use CDP to clean up and close tabs. Marking this as fatal cdpError.isFatalApiErr = true + reconnection = undefined onAsynchronousError(cdpError) } } - return retry() + reconnection = retry() + + return reconnection } const connect = async () => { @@ -358,6 +406,7 @@ export const create = async ({ // Keep track of '*.enable' commands so they can be resent when // reconnecting if (command.endsWith('.enable') || ['Runtime.addBinding', 'Target.setDiscoverTargets'].includes(command)) { + debug('registering enable command', command) const obj: EnableCommand = { command, } @@ -377,15 +426,17 @@ export const create = async ({ try { return await cri.send(command, params, sessionId) } catch (err) { + debug('Encountered error on send %o', { command, params, sessionId, err }) // This error occurs when the browser has been left open for a long // time and/or the user's computer has been put to sleep. The // socket disconnects and we need to recreate the socket and // connection if (!WEBSOCKET_NOT_OPEN_RE.test(err.message)) { + debug('error classified as not WEBSOCKET_NOT_OPEN_RE, rethrowing') throw err } - debug('encountered closed websocket on send %o', { command, params, sessionId, err }) + debug('error classified as WEBSOCKET_NOT_OPEN_RE; enqueuing and attempting to reconnect') const p = enqueue() as Promise diff --git a/packages/server/test/integration/cdp_spec.ts b/packages/server/test/integration/cdp_spec.ts index f2988d74445d..b42f0c71f5f2 100644 --- a/packages/server/test/integration/cdp_spec.ts +++ b/packages/server/test/integration/cdp_spec.ts @@ -2,12 +2,13 @@ process.env.NODE_TLS_REJECT_UNAUTHORIZED = '0' import Debug from 'debug' import _ from 'lodash' -import { Server as WebSocketServer } from 'ws' +import WebSocket from 'ws' import { CdpCommand, CdpEvent } from '../../lib/browsers/cdp_automation' import * as CriClient from '../../lib/browsers/cri-client' import { expect, nock } from '../spec_helper' -import type { SinonStub } from 'sinon' +import sinon from 'sinon' + // import Bluebird from 'bluebird' const debug = Debug('cypress:server:tests') @@ -29,14 +30,14 @@ type OnWSConnection = (wsClient: WebSocket) => void describe('CDP Clients', () => { require('mocha-banner').register() - let wsSrv: WebSocketServer + let wsSrv: WebSocket.Server let criClient: CriClient.CriClient let messages: object[] - let onMessage: SinonStub + let onMessage: sinon.SinonStub - const startWsServer = async (onConnection?: OnWSConnection): Promise => { + const startWsServer = async (onConnection?: OnWSConnection): Promise => { return new Promise((resolve, reject) => { - const srv = new WebSocketServer({ + const srv = new WebSocket.Server({ port: wsServerPort, }) @@ -209,7 +210,7 @@ describe('CDP Clients', () => { const send = (commands: CDPCommands[]) => { commands.forEach(({ command, params }) => { - criClient.send(command, params).catch(() => {}) + criClient.send(command, params) }) } @@ -319,7 +320,7 @@ describe('CDP Clients', () => { }) .then((stub) => { expect(criClient.closed).to.be.true - expect((stub as SinonStub).callCount).to.be.eq(3) + expect((stub as sinon.SinonStub).callCount).to.be.eq(3) }) }) }) From 04693afb0959fabd1e7a3692b6c4635ffcb2096a Mon Sep 17 00:00:00 2001 From: Cacie Prins Date: Fri, 19 Apr 2024 13:52:28 -0400 Subject: [PATCH 04/10] changelog --- cli/CHANGELOG.md | 8 ++++++++ 1 file changed, 8 insertions(+) diff --git a/cli/CHANGELOG.md b/cli/CHANGELOG.md index 82a432c0b850..f42b1da0264d 100644 --- a/cli/CHANGELOG.md +++ b/cli/CHANGELOG.md @@ -1,4 +1,12 @@ +## 13.8.1 + +_Released 4/23/2024 (PENDING) + +**Bufixes:** + +- Fixes a bug introduced in [`13.6.0`](https://docs.cypress.io/guides/references/changelog#13-6-0) where Cypress would occasionally exit with status code 1 even when the test run was successful, due to an unhandled WebSocket exception (`Error: WebSocket connection closed`). Addresses [#28523](https://github.com/cypress-io/cypress/issues/28523). + ## 13.8.0 _Released 4/18/2024_ From 83038b49607a7cd48cf72e528d61feb33dfd518c Mon Sep 17 00:00:00 2001 From: Cacie Prins Date: Fri, 19 Apr 2024 14:02:37 -0400 Subject: [PATCH 05/10] fix changelog --- cli/CHANGELOG.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/cli/CHANGELOG.md b/cli/CHANGELOG.md index f42b1da0264d..0ac550af714e 100644 --- a/cli/CHANGELOG.md +++ b/cli/CHANGELOG.md @@ -1,7 +1,7 @@ ## 13.8.1 -_Released 4/23/2024 (PENDING) +_Released 4/23/2024 (PENDING)_ **Bufixes:** From 59a1198c5c1b222d81f33131d680ca08009dde5b Mon Sep 17 00:00:00 2001 From: Cacie Prins Date: Fri, 19 Apr 2024 14:05:19 -0400 Subject: [PATCH 06/10] publish prerelease binaries for this branch --- .circleci/workflows.yml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/.circleci/workflows.yml b/.circleci/workflows.yml index 6bc4aafa8533..688d6d3b3c6b 100644 --- a/.circleci/workflows.yml +++ b/.circleci/workflows.yml @@ -151,7 +151,7 @@ commands: name: Set environment variable to determine whether or not to persist artifacts command: | echo "Setting SHOULD_PERSIST_ARTIFACTS variable" - echo 'if ! [[ "$CIRCLE_BRANCH" != "develop" && "$CIRCLE_BRANCH" != "release/"* && "$CIRCLE_BRANCH" != "publish-binary" && "$CIRCLE_BRANCH" != "feat/protocol_shadow_dom_support" && "$CIRCLE_BRANCH" != "feat/support_wds5" ]]; then + echo 'if ! [[ "$CIRCLE_BRANCH" != "develop" && "$CIRCLE_BRANCH" != "release/"* && "$CIRCLE_BRANCH" != "publish-binary" && "$CIRCLE_BRANCH" != "feat/psrotocol_shadow_dom_support" && "$CIRCLE_BRANCH" != "feat/support_wds5" && "$CIRCLE_BRANCH" != "cacie/fix/websocket-closed" ]]; then export SHOULD_PERSIST_ARTIFACTS=true fi' >> "$BASH_ENV" # You must run `setup_should_persist_artifacts` command and be using bash before running this command From e82de8c939a0d816d846c3617436328336ce407a Mon Sep 17 00:00:00 2001 From: Cacie Prins Date: Mon, 22 Apr 2024 10:33:22 -0400 Subject: [PATCH 07/10] build windows prerelease package --- .circleci/workflows.yml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/.circleci/workflows.yml b/.circleci/workflows.yml index 688d6d3b3c6b..3ef351c9fb5a 100644 --- a/.circleci/workflows.yml +++ b/.circleci/workflows.yml @@ -81,7 +81,7 @@ windowsWorkflowFilters: &windows-workflow-filters - equal: [ develop, << pipeline.git.branch >> ] # use the following branch as well to ensure that v8 snapshot cache updates are fully tested - equal: [ 'update-v8-snapshot-cache-on-develop', << pipeline.git.branch >> ] - - equal: [ 'cacie/dep/electron-27', << pipeline.git.branch >> ] + - equal: [ 'cacie/fix/websocket-closed', << pipeline.git.branch >> ] - equal: [ 'feat/protocol_shadow_dom_support', << pipeline.git.branch >> ] - equal: [ 'lerna-optimize-tasks', << pipeline.git.branch >> ] - equal: [ 'feat/support_wds5', << pipeline.git.branch >> ] From 2add9c20e9f9e443e21b2037b1007118ff763c24 Mon Sep 17 00:00:00 2001 From: Jennifer Shehane Date: Mon, 22 Apr 2024 10:46:04 -0400 Subject: [PATCH 08/10] Update cli/CHANGELOG.md --- cli/CHANGELOG.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/cli/CHANGELOG.md b/cli/CHANGELOG.md index 0ac550af714e..8489b529c3d1 100644 --- a/cli/CHANGELOG.md +++ b/cli/CHANGELOG.md @@ -3,7 +3,7 @@ _Released 4/23/2024 (PENDING)_ -**Bufixes:** +**Bugfixes:** - Fixes a bug introduced in [`13.6.0`](https://docs.cypress.io/guides/references/changelog#13-6-0) where Cypress would occasionally exit with status code 1 even when the test run was successful, due to an unhandled WebSocket exception (`Error: WebSocket connection closed`). Addresses [#28523](https://github.com/cypress-io/cypress/issues/28523). From 798f302c61af8ec060d2ae7a085bcaa9daf93a22 Mon Sep 17 00:00:00 2001 From: Cacie Prins Date: Mon, 22 Apr 2024 14:05:15 -0400 Subject: [PATCH 09/10] Update cli/CHANGELOG.md Co-authored-by: Bill Glesias --- cli/CHANGELOG.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/cli/CHANGELOG.md b/cli/CHANGELOG.md index 8489b529c3d1..c7c457a8b221 100644 --- a/cli/CHANGELOG.md +++ b/cli/CHANGELOG.md @@ -5,7 +5,7 @@ _Released 4/23/2024 (PENDING)_ **Bugfixes:** -- Fixes a bug introduced in [`13.6.0`](https://docs.cypress.io/guides/references/changelog#13-6-0) where Cypress would occasionally exit with status code 1 even when the test run was successful, due to an unhandled WebSocket exception (`Error: WebSocket connection closed`). Addresses [#28523](https://github.com/cypress-io/cypress/issues/28523). +- Fixes a bug introduced in [`13.6.0`](https://docs.cypress.io/guides/references/changelog#13-6-0) where Cypress would occasionally exit with status code 1, even when a test run was successfully, due to an unhandled WebSocket exception (`Error: WebSocket connection closed`). Addresses [#28523](https://github.com/cypress-io/cypress/issues/28523). ## 13.8.0 From a613bca09ada44aaf708e6e52cd8507e04272678 Mon Sep 17 00:00:00 2001 From: Cacie Prins Date: Mon, 22 Apr 2024 14:25:34 -0400 Subject: [PATCH 10/10] add comment for websocket error regex examples --- packages/server/lib/browsers/cri-client.ts | 8 ++++++++ 1 file changed, 8 insertions(+) diff --git a/packages/server/lib/browsers/cri-client.ts b/packages/server/lib/browsers/cri-client.ts index 4c0776ecf666..e75e661e8f61 100644 --- a/packages/server/lib/browsers/cri-client.ts +++ b/packages/server/lib/browsers/cri-client.ts @@ -19,6 +19,14 @@ const debugVerboseReceive = debugModule(`${debugVerbose.namespace}:recv:[<--]`) // debug using cypress-verbose:server:browsers:cri-client:err:* const debugVerboseLifecycle = debugModule(`${debugVerbose.namespace}:ws`) +/** + * There are three error messages we can encounter which should not be re-thrown, but + * should trigger a reconnection attempt if one is not in progress, and enqueue the + * command that errored. This regex is used in client.send to check for: + * - WebSocket connection closed + * - WebSocket not open + * - WebSocket already in CLOSING or CLOSED state + */ const WEBSOCKET_NOT_OPEN_RE = /^WebSocket (?:connection closed|is (?:not open|already in CLOSING or CLOSED state))/ type QueuedMessages = {