diff --git a/CHANGELOG.md b/CHANGELOG.md index b21c753eaa..3f5db64172 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -12,6 +12,10 @@ - Warn when the connected agent's startup scripts fail or time out, with **Show Logs** and **Open in Dashboard** actions. These failures used to appear only in the Coder output channel. +- Flush the buffered connection logs into the Coder output channel after several + consecutive failed reconnect attempts, so the detail leading up to a "hangs on + connecting" problem is captured even when the server is simply unreachable and + the socket never reaches a terminal failure. ## [v1.16.4](https://github.com/coder/vscode-coder/releases/tag/v1.16.4) 2026-09-23 diff --git a/src/instrumentation/EVENTS.md b/src/instrumentation/EVENTS.md index 9c5c5f42e5..766c6fadcb 100644 --- a/src/instrumentation/EVENTS.md +++ b/src/instrumentation/EVENTS.md @@ -16,7 +16,7 @@ new ones live in `CONVENTIONS.md`. | [Remote setup](#remote-setup) | `remote.setup` | | [SSH](#ssh) | `ssh.process.discovered`, `ssh.process.lost`, `ssh.process.recovered`, `ssh.process.replaced`, `ssh.process.disposed`, `ssh.network.sampled` | | [HTTP](#http) | `http.requests` | -| [WebSocket connections](#websocket-connections) | `connection.state_transitioned`, `connection.opened`, `connection.dropped`, `connection.reconnect_resolved` | +| [WebSocket connections](#websocket-connections) | `connection.state_transitioned`, `connection.opened`, `connection.dropped`, `connection.reconnect_resolved`, `connection.unreachable` | | [Workspace](#workspace) | `workspace.start.triggered`, `workspace.update.triggered`, `workspace.start.prompted`, `workspace.update.prompted`, `workspace.open`, `workspace.picker.prompted`, `workspace.dev_container.open`, `workspace.state_transitioned`, `workspace.agent.state_transitioned` | Signal kinds, which each category groups its events by: @@ -428,7 +428,7 @@ Emitted by `WebSocketTelemetry`. These events share one value set, **ConnectionStateReason**: `initial_connect`, `manual_reconnect`, `certificate_refresh`, `scheduled_reconnect`, `open`, `disconnect`, `dispose`, `unrecoverable_close`, `unrecoverable_http`, -`certificate_error`, `connection_error`, `unexpected_close`. +`certificate_error`, `connection_error`, `unexpected_close`, `unreachable`. ### Logs @@ -471,6 +471,17 @@ success or termination). | `max_backoff_ms` (measurement) | largest backoff scheduled | | `total_duration_ms` (measurement) | cycle wall time | +#### `connection.unreachable` + +Emitted once when the reconnect loop has failed enough consecutive times to +treat the server as unreachable (also flushes the connection log buffer). The +counter resets on a successful open, so a later outage emits again. + +| Attribute | Values | +| ------------------------ | ---------------------------------------- | +| `route` | normalized route | +| `attempts` (measurement) | consecutive failed attempts at the flush | + ## Workspace Emitted by `WorkspaceOperationTelemetry` (start and update), diff --git a/src/instrumentation/websocket.ts b/src/instrumentation/websocket.ts index 98c54bab6f..cc300e0b1c 100644 --- a/src/instrumentation/websocket.ts +++ b/src/instrumentation/websocket.ts @@ -16,7 +16,8 @@ export type ConnectionStateReason = | "unrecoverable_http" | "certificate_error" | "connection_error" - | "unexpected_close"; + | "unexpected_close" + | "unreachable"; export type ConnectionDropCause = | "manual_disconnect" @@ -127,6 +128,18 @@ export class WebSocketTelemetry { } } + /** + * The reconnect loop has failed enough consecutive times to treat the server + * as unreachable. Surfaced so Support can query sustained unreachability. + */ + public unreachable(route: string, attempts: number): void { + this.#telemetry.log( + "connection.unreachable", + { route: normalizeRoute(route) }, + { attempts }, + ); + } + public reset(): void { this.#connectStartedAtMs = undefined; this.#connectionOpenedAtMs = undefined; diff --git a/src/websocket/reconnectingWebSocket.ts b/src/websocket/reconnectingWebSocket.ts index f67a16d13e..d116baf100 100644 --- a/src/websocket/reconnectingWebSocket.ts +++ b/src/websocket/reconnectingWebSocket.ts @@ -114,6 +114,15 @@ export type SocketFactory = () => Promise>; /** Default failure callback for callers that do not observe connection failures. */ const NOOP_CONNECTION_FAILURE = (): void => undefined; +/** + * Consecutive failed reconnect attempts before the buffer is flushed once and + * the server is treated as unreachable. With the default backoff (250ms + * doubling to a 30s cap) the 6th attempt lands after ~15s of retrying: past a + * transient blip of one or two retries, before the 30s cap, and before a user + * reproducing a "hangs on connecting" issue would typically give up. + */ +const MAX_RECONNECT_FAILURES_BEFORE_FLUSH = 6; + export interface ReconnectingWebSocketOptions { initialBackoffMs?: number; maxBackoffMs?: number; @@ -152,6 +161,9 @@ export class ReconnectingWebSocket< #lastRoute: string; #backoffMs: number; #reconnectTimeoutId: NodeJS.Timeout | null = null; + // Consecutive failed connect attempts in the current outage. Reset on a + // successful open, so it only grows while the server stays unreachable. + #consecutiveConnectFailures = 0; #state: ConnectionState = ConnectionState.IDLE; #certRefreshAttempted = false; // Tracks if cert refresh was already attempted this connection cycle readonly #onDispose?: () => void; @@ -275,6 +287,7 @@ export class ReconnectingWebSocket< if (this.#state === ConnectionState.DISCONNECTED) { this.#backoffMs = this.#options.initialBackoffMs; this.#certRefreshAttempted = false; // User-initiated reconnect, allow retry + this.#consecutiveConnectFailures = 0; } if (this.#reconnectTimeoutId !== null) { @@ -375,6 +388,7 @@ export class ReconnectingWebSocket< // Reset backoff on successful connection this.#backoffMs = this.#options.initialBackoffMs; this.#certRefreshAttempted = false; + this.#consecutiveConnectFailures = 0; this.executeHandlers("open", event); }); @@ -450,6 +464,24 @@ export class ReconnectingWebSocket< if (!this.#dispatch({ type: "SCHEDULE_RETRY" }, reason)) { return; } + + // Each scheduled retry is one failed attempt. Once the loop has failed + // enough times against an unreachable server it never reaches a terminal + // reason, so flush the buffer once here; the `=== N` check keeps it to one + // flush per outage, and a successful open resets the counter. + this.#consecutiveConnectFailures += 1; + if ( + this.#consecutiveConnectFailures === MAX_RECONNECT_FAILURES_BEFORE_FLUSH + ) { + this.#logger.warn( + `Server unreachable after ${this.#consecutiveConnectFailures} reconnect attempts for ${this.#route}`, + ); + this.#telemetry.unreachable( + this.#route, + this.#consecutiveConnectFailures, + ); + this.#options.onConnectionFailure("unreachable", this.#route); + } const jitter = this.#backoffMs * this.#options.jitterFactor * (Math.random() * 2 - 1); const delayMs = Math.max(0, this.#backoffMs + jitter); diff --git a/test/unit/instrumentation/websocket.test.ts b/test/unit/instrumentation/websocket.test.ts index c461cc4f70..cf70885a00 100644 --- a/test/unit/instrumentation/websocket.test.ts +++ b/test/unit/instrumentation/websocket.test.ts @@ -30,6 +30,23 @@ describe("WebSocketTelemetry", () => { }); }); + describe("unreachable", () => { + it("emits connection.unreachable with the normalized route and attempts", () => { + const { ws, sink } = setup(); + + ws.unreachable( + "wss://coder.example.com/api/v2/workspaces/123e4567-e89b-12d3-a456-426614174000/watch-ws?token=secret", + 6, + ); + + const [event] = sink.eventsNamed("connection.unreachable"); + expect(event).toMatchObject({ + properties: { route: "/api/v2/workspaces/{id}/watch-ws" }, + measurements: { attempts: 6 }, + }); + }); + }); + describe("opened", () => { it("emits connection.opened with route and connect duration", () => { const { ws, sink } = setup(); diff --git a/test/unit/websocket/reconnectingWebSocket.test.ts b/test/unit/websocket/reconnectingWebSocket.test.ts index 7d841ba7c5..199e39aecb 100644 --- a/test/unit/websocket/reconnectingWebSocket.test.ts +++ b/test/unit/websocket/reconnectingWebSocket.test.ts @@ -880,6 +880,163 @@ describe("ReconnectingWebSocket", () => { ws.close(); }); }); + + describe("Unreachable server", () => { + // Mirrors MAX_RECONNECT_FAILURES_BEFORE_FLUSH in the implementation. + const FAILURES_BEFORE_FLUSH = 6; + // Pathname of the mock socket's URL, which becomes the logged route. + const ROUTE = "/api/test"; + + async function setupUnreachable( + options: { telemetry?: TelemetryReporter } = {}, + ) { + const sockets: MockSocket[] = []; + let failing = false; + const factory = vi.fn(() => { + if (failing) { + return Promise.reject(new Error("connect ECONNREFUSED")); + } + const socket = createMockSocket(); + sockets.push(socket); + return Promise.resolve(socket); + }); + const onConnectionFailure = + vi.fn<(reason: ConnectionStateReason, route: string) => void>(); + // Constant backoff and no jitter, so each timer advance is exactly one + // failed attempt. + const ws = await ReconnectingWebSocket.create( + factory, + createMockLogger(), + { + telemetry: options.telemetry ?? NOOP_TELEMETRY_REPORTER, + route: "/api/v2/test", + onCertificateRefreshNeeded: () => Promise.resolve(false), + onConnectionFailure, + initialBackoffMs: 100, + maxBackoffMs: 100, + jitterFactor: 0, + }, + ); + sockets[0].fireOpen(); + + // Drop the healthy socket and make every reconnect fail. The close is + // the first failed attempt; each advance is the next. + const startOutage = (): void => { + failing = true; + sockets.at(-1)?.fireClose({ + code: WebSocketCloseCode.ABNORMAL, + reason: "Connection lost", + }); + }; + const failNextAttempt = async (): Promise => { + await vi.advanceTimersByTimeAsync(100); + }; + const recover = async (): Promise => { + failing = false; + await vi.advanceTimersByTimeAsync(100); + sockets.at(-1)?.fireOpen(); + }; + return { + ws, + sockets, + onConnectionFailure, + startOutage, + failNextAttempt, + recover, + }; + } + + it("flushes once with the unreachable reason after N failed attempts", async () => { + const { ws, onConnectionFailure, startOutage, failNextAttempt } = + await setupUnreachable(); + + startOutage(); // attempt 1 + for (let i = 0; i < FAILURES_BEFORE_FLUSH - 2; i++) { + await failNextAttempt(); // through attempt N-1 + } + expect(onConnectionFailure).not.toHaveBeenCalled(); + + await failNextAttempt(); // attempt N + expect(onConnectionFailure).toHaveBeenCalledTimes(1); + expect(onConnectionFailure).toHaveBeenCalledWith("unreachable", ROUTE); + + ws.close(); + }); + + it("does not flush again while the server stays unreachable", async () => { + const { ws, onConnectionFailure, startOutage, failNextAttempt } = + await setupUnreachable(); + + startOutage(); + for (let i = 0; i < FAILURES_BEFORE_FLUSH - 1; i++) { + await failNextAttempt(); + } + expect(onConnectionFailure).toHaveBeenCalledTimes(1); + + for (let i = 0; i < 5; i++) { + await failNextAttempt(); + } + expect(onConnectionFailure).toHaveBeenCalledTimes(1); + + ws.close(); + }); + + it("flushes again after a successful open resets the counter", async () => { + const { ws, onConnectionFailure, startOutage, failNextAttempt, recover } = + await setupUnreachable(); + + startOutage(); + for (let i = 0; i < FAILURES_BEFORE_FLUSH - 1; i++) { + await failNextAttempt(); + } + expect(onConnectionFailure).toHaveBeenCalledTimes(1); + + await recover(); + + startOutage(); + for (let i = 0; i < FAILURES_BEFORE_FLUSH - 1; i++) { + await failNextAttempt(); + } + expect(onConnectionFailure).toHaveBeenCalledTimes(2); + + ws.close(); + }); + + it("does not flush a transient outage that recovers before N", async () => { + const { ws, onConnectionFailure, startOutage, failNextAttempt, recover } = + await setupUnreachable(); + + startOutage(); + await failNextAttempt(); + await failNextAttempt(); + await recover(); + + expect(onConnectionFailure).not.toHaveBeenCalled(); + ws.close(); + }); + + it("emits connection.unreachable once at the flush", async () => { + enableLocalTelemetry(); + const sink = new TestSink(); + const telemetry = createTestTelemetryService(sink); + const { ws, startOutage, failNextAttempt } = await setupUnreachable({ + telemetry, + }); + + startOutage(); + for (let i = 0; i < FAILURES_BEFORE_FLUSH - 1; i++) { + await failNextAttempt(); + } + + expect(sink.eventsNamed("connection.unreachable")).toMatchObject([ + { + properties: { route: ROUTE }, + measurements: { attempts: FAILURES_BEFORE_FLUSH }, + }, + ]); + ws.close(); + }); + }); }); type MockSocket = UnidirectionalStream & {