diff --git a/apps/playwright-browser-tunnel/src/PlaywrightBrowserTunnel.ts b/apps/playwright-browser-tunnel/src/PlaywrightBrowserTunnel.ts index db39d3d88f..6b5a084eab 100644 --- a/apps/playwright-browser-tunnel/src/PlaywrightBrowserTunnel.ts +++ b/apps/playwright-browser-tunnel/src/PlaywrightBrowserTunnel.ts @@ -11,7 +11,12 @@ import semver from 'semver'; import { TerminalProviderSeverity, TerminalStreamWritable, type ITerminal } from '@rushstack/terminal'; import { Executable, FileSystem, Async } from '@rushstack/node-core-library'; -import { getNormalizedErrorString } from './utilities'; +import { + getNormalizedErrorString, + getWebSocketCloseReason, + getWebSocketReadyStateString, + WebSocketCloseCode +} from './utilities'; import { LaunchOptionsValidator, type ILaunchOptionsValidationResult } from './LaunchOptionsValidator'; /** @@ -170,7 +175,7 @@ export class PlaywrightTunnel { this._pollInterval = undefined; } await this._initWsPromise?.finally(() => { - this._ws?.close(); + this._ws?.close(WebSocketCloseCode.NORMAL_CLOSURE, 'Tunnel stopped'); }); } @@ -448,37 +453,68 @@ export class PlaywrightTunnel { // ws1 is the tunnel websocket, ws2 is the browser server websocket private async _setupForwardingAsync(ws1: WebSocket, ws2: WebSocket): Promise { this._terminal.writeLine('Setting up message forwarding between ws1 and ws2'); + this._terminal.writeLine(` ws1 (tunnel) readyState: ${getWebSocketReadyStateString(ws1.readyState)}`); + this._terminal.writeLine(` ws2 (browser) readyState: ${getWebSocketReadyStateString(ws2.readyState)}`); + + const messageCount: { ws1ToWs2: number; ws2ToWs1: number } = { ws1ToWs2: 0, ws2ToWs1: 0 }; + ws1.on('message', (data) => { + messageCount.ws1ToWs2++; if (ws2.readyState === WebSocket.OPEN) { ws2.send(data); } else { - this._terminal.writeLine('ws2 is not open. Dropping message.'); + this._terminal.writeLine( + `ws2 not open (state: ${getWebSocketReadyStateString(ws2.readyState)}). Dropping message #${messageCount.ws1ToWs2}` + ); } }); ws2.on('message', (data) => { + messageCount.ws2ToWs1++; if (ws1.readyState === WebSocket.OPEN) { ws1.send(data); } else { - this._terminal.writeLine('ws1 is not open. Dropping message.'); + this._terminal.writeLine( + `ws1 not open (state: ${getWebSocketReadyStateString(ws1.readyState)}). Dropping message #${messageCount.ws2ToWs1}` + ); } }); - ws1.once('close', () => { + ws1.once('close', (code: number, reason: Buffer) => { + const reasonStr: string = reason.toString() || 'no reason provided'; + const codeDescription: string = getWebSocketCloseReason(code); + this._terminal.writeLine( + `ws1 (tunnel) closed - code: ${code} (${codeDescription}), reason: ${reasonStr}` + ); + this._terminal.writeLine( + ` Messages forwarded: ws1->ws2: ${messageCount.ws1ToWs2}, ws2->ws1: ${messageCount.ws2ToWs1}` + ); if (ws2.readyState === WebSocket.OPEN) { - ws2.close(); + this._terminal.writeLine(' Closing ws2 (browser) in response'); + ws2.close(WebSocketCloseCode.NORMAL_CLOSURE, 'Tunnel closed'); } }); - ws2.once('close', () => { + ws2.once('close', (code: number, reason: Buffer) => { + const reasonStr: string = reason.toString() || 'no reason provided'; + const codeDescription: string = getWebSocketCloseReason(code); + this._terminal.writeLine( + `ws2 (browser) closed - code: ${code} (${codeDescription}), reason: ${reasonStr}` + ); + this._terminal.writeLine( + ` Messages forwarded: ws1->ws2: ${messageCount.ws1ToWs2}, ws2->ws1: ${messageCount.ws2ToWs1}` + ); if (ws1.readyState === WebSocket.OPEN) { - ws1.close(); + this._terminal.writeLine(' Closing ws1 (tunnel) in response'); + ws1.close(WebSocketCloseCode.NORMAL_CLOSURE, 'Browser closed'); } }); ws1.once('error', (error) => { - this._terminal.writeLine(`WebSocket error: ${getNormalizedErrorString(error)}`); + this._terminal.writeErrorLine(`ws1 (tunnel) WebSocket error: ${getNormalizedErrorString(error)}`); + this._terminal.writeErrorLine(` ws1 readyState: ${getWebSocketReadyStateString(ws1.readyState)}`); }); ws2.once('error', (error) => { - this._terminal.writeLine(`WebSocket error: ${getNormalizedErrorString(error)}`); + this._terminal.writeErrorLine(`ws2 (browser) WebSocket error: ${getNormalizedErrorString(error)}`); + this._terminal.writeErrorLine(` ws2 readyState: ${getWebSocketReadyStateString(ws2.readyState)}`); }); } @@ -507,11 +543,21 @@ export class PlaywrightTunnel { this._terminal.writeLine(`WebSocket error occurred: ${getNormalizedErrorString(error)}`); }); - ws.on('close', async () => { + ws.on('close', async (code: number, reason: Buffer) => { + const reasonStr: string = reason.toString() || 'no reason provided'; + const codeDescription: string = getWebSocketCloseReason(code); this._initWsPromise = undefined; this.status = 'stopped'; - this._terminal.writeLine('WebSocket connection closed'); - await browserServer?.close(); + this._terminal.writeLine( + `WebSocket connection closed - code: ${code} (${codeDescription}), reason: ${reasonStr}` + ); + this._terminal.writeLine(` handshake received: ${handshake !== undefined}`); + this._terminal.writeLine(` browserServer active: ${browserServer !== undefined}`); + if (browserServer) { + this._terminal.writeLine(' Closing browser server...'); + await browserServer.close(); + this._terminal.writeLine(' Browser server closed'); + } }); return await new Promise((resolve, reject) => { @@ -531,7 +577,7 @@ export class PlaywrightTunnel { if (!shouldProceed) { terminal.writeLine('Browser server launch cancelled by user.'); ws.off('message', onMessageHandler); - ws.close(); + ws.close(WebSocketCloseCode.NORMAL_CLOSURE, 'Launch cancelled by user'); reject(new Error('Browser server launch cancelled by user')); return; } @@ -544,6 +590,20 @@ export class PlaywrightTunnel { client = browserServerProxy.client; browserServer = browserServerProxy.browserServer; + // Monitor browser server process for crashes + const browserProcess: ChildProcess | null = browserServer.process(); + if (browserProcess) { + browserProcess.on('exit', (code: number | null, signal: string | null) => { + terminal.writeErrorLine(`Browser server process exited - code: ${code}, signal: ${signal}`); + }); + browserProcess.on('error', (err: Error) => { + terminal.writeErrorLine(`Browser server process error: ${getNormalizedErrorString(err)}`); + }); + terminal.writeDebugLine(`Browser server process started with PID: ${browserProcess.pid}`); + } else { + terminal.writeDebugLine('Warning: Browser server process handle not available for monitoring'); + } + this.status = 'browser-server-running'; // Send ack so that the counterpart also knows to start forwarding messages. @@ -571,7 +631,7 @@ export class PlaywrightTunnel { // Cleanup and close connection on error ws.off('message', onMessageHandler); - ws.close(); + ws.close(WebSocketCloseCode.INTERNAL_ERROR, 'Handshake error'); reject(error); return; } @@ -579,7 +639,7 @@ export class PlaywrightTunnel { if (!client) { terminal.writeLine('Browser WebSocket client is not initialized.'); ws.off('message', onMessageHandler); - ws.close(); + ws.close(WebSocketCloseCode.INTERNAL_ERROR, 'Browser client not initialized'); return; } } diff --git a/apps/playwright-browser-tunnel/src/tunneledBrowserConnection.ts b/apps/playwright-browser-tunnel/src/tunneledBrowserConnection.ts index a08b6eeff7..9a32024768 100644 --- a/apps/playwright-browser-tunnel/src/tunneledBrowserConnection.ts +++ b/apps/playwright-browser-tunnel/src/tunneledBrowserConnection.ts @@ -10,6 +10,12 @@ import { type ITerminal, Terminal, ConsoleTerminalProvider } from '@rushstack/te import type { BrowserName } from './PlaywrightBrowserTunnel'; import { HttpServer } from './HttpServer'; +import { + getNormalizedErrorString, + getWebSocketCloseReason, + getWebSocketReadyStateString, + WebSocketCloseCode +} from './utilities'; const { version: playwrightVersion } = playwrightPackageJson; @@ -121,12 +127,12 @@ export async function tunneledBrowserConnection( logger.writeLine('Received handshakeAck from remote'); } else { logger.writeErrorLine('Invalid handshake ack message'); - ws.close(); + ws.close(WebSocketCloseCode.PROTOCOL_ERROR, 'Invalid handshake ack'); return; } } catch (e) { logger.writeErrorLine(`Failed parsing handshake ack: ${e}`); - ws.close(); + ws.close(WebSocketCloseCode.PROTOCOL_ERROR, 'Failed parsing handshake'); return; } // Resolve only once local proxy available and handshake acknowledged @@ -153,8 +159,21 @@ export async function tunneledBrowserConnection( } }); - ws.on('close', () => logger.writeLine('Remote websocket closed')); - ws.on('error', (err) => logger.writeErrorLine(`Remote websocket error: ${err}`)); + ws.on('close', (code: number, reason: Buffer) => { + const reasonStr: string = reason.toString() || 'no reason provided'; + const codeDescription: string = getWebSocketCloseReason(code); + logger.writeDebugLine( + `Remote websocket closed - code: ${code} (${codeDescription}), reason: ${reasonStr}` + ); + logger.writeDebugLine( + ` Connection state at close: handshakeSent=${handshakeSent}, handshakeAck=${handshakeAck}` + ); + logger.writeDebugLine(` Buffered messages pending: ${bufferedLocalMessages.length}`); + }); + ws.on('error', (err: Error) => { + logger.writeErrorLine(`Remote websocket error: ${getNormalizedErrorString(err)}`); + logger.writeErrorLine(` Socket readyState: ${getWebSocketReadyStateString(ws.readyState)}`); + }); }); localProxyWs.on('connection', (localWs, request) => { @@ -183,7 +202,7 @@ export async function tunneledBrowserConnection( if (!browserName) { const supportedBrowsersString: string = Array.from(SUPPORTED_BROWSER_NAMES).join('|'); logger.writeErrorLine(`browser query param required (${supportedBrowsersString})`); - localWs.close(); + localWs.close(WebSocketCloseCode.PROTOCOL_ERROR, 'Missing browser param'); return; } if (!launchOptions) { @@ -200,8 +219,20 @@ export async function tunneledBrowserConnection( bufferedLocalMessages.push(message); } }); - localWs.on('close', () => logger.writeLine('Local client websocket closed')); - localWs.on('error', (err) => logger.writeErrorLine(`Local client websocket error: ${err}`)); + localWs.on('close', (code: number, reason: Buffer) => { + const reasonStr: string = reason.toString() || 'no reason provided'; + const codeDescription: string = getWebSocketCloseReason(code); + logger.writeDebugLine( + `Local client websocket closed - code: ${code} (${codeDescription}), reason: ${reasonStr}` + ); + logger.writeDebugLine( + ` Remote socket state: ${remoteSocket ? getWebSocketReadyStateString(remoteSocket.readyState) : 'undefined'}` + ); + logger.writeDebugLine(` handshakeAck: ${handshakeAck}`); + }); + localWs.on('error', (err: Error) => { + logger.writeErrorLine(`Local client websocket error: ${getNormalizedErrorString(err)}`); + }); }); // Resolve immediately so caller can initiate local connection with query params (handshake completes later) diff --git a/apps/playwright-browser-tunnel/src/utilities.ts b/apps/playwright-browser-tunnel/src/utilities.ts index f186a6ffe6..31c8cda15a 100644 --- a/apps/playwright-browser-tunnel/src/utilities.ts +++ b/apps/playwright-browser-tunnel/src/utilities.ts @@ -41,3 +41,96 @@ export function getNormalizedErrorString(error: unknown): string { } return String(error); } + +/** + * WebSocket close codes as defined by RFC 6455. + * @see {@link https://datatracker.ietf.org/doc/html/rfc6455#section-11.7} + * @beta + */ +export const WebSocketCloseCode: { + /** Normal closure; the connection successfully completed. */ + readonly NORMAL_CLOSURE: 1000; + /** Endpoint is going away (e.g., server shutting down, browser navigating away). */ + readonly GOING_AWAY: 1001; + /** Protocol error encountered. */ + readonly PROTOCOL_ERROR: 1002; + /** Received data type that cannot be accepted (e.g., text-only endpoint received binary). */ + readonly UNSUPPORTED_DATA: 1003; + /** No status code was provided even though one was expected. */ + readonly NO_STATUS_RECEIVED: 1005; + /** Connection was closed abnormally (e.g., without sending a close frame). */ + readonly ABNORMAL_CLOSURE: 1006; + /** Received message data inconsistent with the message type. */ + readonly INVALID_PAYLOAD: 1007; + /** Received a message that violates policy. */ + readonly POLICY_VIOLATION: 1008; + /** Received a message that is too big to process. */ + readonly MESSAGE_TOO_BIG: 1009; + /** Server encountered an unexpected condition that prevented it from fulfilling the request. */ + readonly INTERNAL_ERROR: 1011; + /** Connection was closed due to TLS handshake failure. */ + readonly TLS_HANDSHAKE_FAILED: 1015; +} = { + NORMAL_CLOSURE: 1000, + GOING_AWAY: 1001, + PROTOCOL_ERROR: 1002, + UNSUPPORTED_DATA: 1003, + NO_STATUS_RECEIVED: 1005, + ABNORMAL_CLOSURE: 1006, + INVALID_PAYLOAD: 1007, + POLICY_VIOLATION: 1008, + MESSAGE_TOO_BIG: 1009, + INTERNAL_ERROR: 1011, + TLS_HANDSHAKE_FAILED: 1015 +}; + +/** + * Type for WebSocket close code values. + * @beta + */ +export type WebSocketCloseCodeValue = (typeof WebSocketCloseCode)[keyof typeof WebSocketCloseCode]; + +/** + * Human-readable descriptions for WebSocket close codes. + * @beta + */ +export const WebSocketCloseCodeDescriptions: Record = { + [WebSocketCloseCode.NORMAL_CLOSURE]: 'Normal Closure', + [WebSocketCloseCode.GOING_AWAY]: 'Going Away', + [WebSocketCloseCode.PROTOCOL_ERROR]: 'Protocol Error', + [WebSocketCloseCode.UNSUPPORTED_DATA]: 'Unsupported Data', + [WebSocketCloseCode.NO_STATUS_RECEIVED]: 'No Status Received', + [WebSocketCloseCode.ABNORMAL_CLOSURE]: 'Abnormal Closure (connection lost)', + [WebSocketCloseCode.INVALID_PAYLOAD]: 'Invalid Payload', + [WebSocketCloseCode.POLICY_VIOLATION]: 'Policy Violation', + [WebSocketCloseCode.MESSAGE_TOO_BIG]: 'Message Too Big', + [WebSocketCloseCode.INTERNAL_ERROR]: 'Internal Error', + [WebSocketCloseCode.TLS_HANDSHAKE_FAILED]: 'TLS Handshake Failed' +}; + +/** + * Returns a human-readable description for a WebSocket close code. + * @beta + */ +export function getWebSocketCloseReason(code: number): string { + return WebSocketCloseCodeDescriptions[code as WebSocketCloseCodeValue] || 'Unknown'; +} + +/** + * Returns a human-readable string for a WebSocket ready state. + * @beta + */ +export function getWebSocketReadyStateString(readyState: number): string { + switch (readyState) { + case 0: + return 'CONNECTING'; + case 1: + return 'OPEN'; + case 2: + return 'CLOSING'; + case 3: + return 'CLOSED'; + default: + return `UNKNOWN(${readyState})`; + } +} diff --git a/common/changes/@rushstack/playwright-browser-tunnel/feat-plbs-advanced-logging_2026-02-04-16-27.json b/common/changes/@rushstack/playwright-browser-tunnel/feat-plbs-advanced-logging_2026-02-04-16-27.json new file mode 100644 index 0000000000..b9f0efa28c --- /dev/null +++ b/common/changes/@rushstack/playwright-browser-tunnel/feat-plbs-advanced-logging_2026-02-04-16-27.json @@ -0,0 +1,10 @@ +{ + "changes": [ + { + "packageName": "@rushstack/playwright-browser-tunnel", + "comment": "Add advanced logging and websocket close codes", + "type": "patch" + } + ], + "packageName": "@rushstack/playwright-browser-tunnel" +} \ No newline at end of file diff --git a/vscode-extensions/playwright-local-browser-server-vscode-extension/package.json b/vscode-extensions/playwright-local-browser-server-vscode-extension/package.json index 802d17c690..9c6e601ab6 100644 --- a/vscode-extensions/playwright-local-browser-server-vscode-extension/package.json +++ b/vscode-extensions/playwright-local-browser-server-vscode-extension/package.json @@ -1,6 +1,6 @@ { "name": "playwright-local-browser-server", - "version": "0.1.0", + "version": "0.1.1", "repository": { "type": "git", "url": "https://github.com/microsoft/rushstack.git",