Skip to content

feat: buffer connection logs and flush them on failure - #1100

Merged
aqandrew merged 61 commits into
mainfrom
aqandrew/devex-669-vs-code-add-log-buffer
Sep 17, 2026
Merged

aqandrew merged 61 commits into
mainfrom
aqandrew/devex-669-vs-code-add-log-buffer

Conversation

@aqandrew

@aqandrew aqandrew commented Aug 26, 2026

Copy link
Copy Markdown
Contributor

Implements RFC requirement 13 / DEVEX-669: buffer connection debug logs in memory below the current log level and flush them on a genuine connection failure, so a support bundle captures the detail leading up to the failure without the user having enabled debug logging beforehand.

What this does

  • Adds a BufferingLogger decorator (src/logging/logBuffer.ts) that wraps the "Coder" output channel and keeps a bounded, in-memory ring of the entries that sit below the channel's current level, which it would otherwise drop. Only below-level entries are buffered, so nothing already written is duplicated. Entries are formatted (via safeStringify) at record time.
  • On a connection failure, flush(reason) re-emits the captured entries into the output channel at the least-verbose level the channel still persists. The first physical line of each entry carries a [buffered] marker with its original ISO timestamp and level; continuation lines carry the bare marker. Capture is best-effort — the channel writes on its own schedule — but a later failure flush replays anything a bundle missed.
    • Collecting a support bundle flushes the buffer (flush("support_bundle", { retain: true })) before the CLI runs, and retains the ring so a later failure flush still has the entries.
    • When the channel is at Off, flush keeps the entries buffered instead of discarding them.
  • The buffer is bounded by both entry count and characters (MAX_BUFFERED_CHARS = 2_000_000); trim() enforces both budgets with oldest-eviction, and flush() replays in chunks of 100 to avoid a single oversized write.
  • Wires the buffer into ServiceContainer and adds the coder.connectionLogBuffer.size setting (default 1000, capped at 10000, 0 disables). The setting readers live in src/settings/logger.ts and the container reads/watches the size through a single readSize() helper via watchConfigurationChanges. The setting is included in COLLECTED_SETTINGS.
  • Flushes only on genuine connection failures, gated by an explicit failure?: boolean on the connection-log reason (not on transient reconnects, a handshake 401, or intentional teardown):
    • a reconnecting WebSocket terminal failure (unrecoverable_close, unrecoverable_http where the status is not 401, or certificate_error);
    • a failure while opening a workspace (canceled build, missing agent, timeout, or CLI/certificate error), funnelled through Remote.closeRemote().
  • Connection-failure flushes are funnelled through BufferingLogger.onConnectionFailure(reason, route) (part of ConnectionLogBuffer), so the extension and remote paths flush ${reason} ${route} identically; the socket option defaults to a noop when no observer is supplied.
  • The flush reason carries the failing route for attribution; the route is seeded on the socket so even a first-connect failure logs a real route instead of unknown.
  • Handshake status is parsed by a shared handshakeStatus(error) (src/websocket/utils.ts) covering both ws (Unexpected server response: <code>) and eventsource (Non-200 status code (<code>)), so a host/port such as 127.0.0.1:4040 is no longer misread as HTTP 404 and the SSE path is handled. CoderApi.is404Error compares against HttpStatusCode.NOT_FOUND.
  • Redacts registration_access_token in HTTP body logging alongside the other sensitive fields.
  • Documents the behavior, config, hard-kill/OOM loss limitation, and SSH log scope in CONTRIBUTING.md.

WebSocket event fix

OneWayWebSocket now registers open/close/error via DOM-style addEventListener, so close consumers receive a real CloseEvent with .code/.reason. This makes unrecoverable_close reachable in production (message events still use ws.on("message", ...) for JSON parsing). Server-initiated normal closes (1000/1001) now go through scheduleReconnect rather than parking the socket, so the now-unreachable normal_close reason is dropped from the telemetry unions and EVENTS.md.

Scope notes

Testing

  • pnpm typecheck, pnpm format:check, and pnpm lint are clean.
  • Affected/dependent unit suites pass (logBuffer, settings/logger, formatters, reconnectingWebSocket, oneWayWebSocket, coderApi, workspaceMonitor, workspaceStateMachine, remote, commands.supportBundle, instrumentation/websocket).
Implementation plan & design decisions

Design

  • Buffer: bounded by entry count and characters; captures only calls whose severity is below the channel's current level; formats entries at record time; oldest-eviction; live-resizable via config; replays in chunks.
  • Flush target (D3): replay into the existing "Coder" output channel at a level that still persists, with a [buffered] marker plus original level/timestamp, chronologically next to the real failure logs. Support bundles already collect the on-disk VS Code logs and also trigger a flush before appending them, so no separate sink is needed. At Off, entries are retained rather than discarded.
  • Flush reasons (D4): genuine, surfaced connection failures only, gated by an explicit failure?: boolean — reconnecting-socket terminal failures (except a 401 handshake) and a workspace-open failure funnelled through closeRemote(). Never on transient retrying drops or intentional teardown (manual_disconnect, replaced, dispose/deactivate/reload). The callback carries the failing route.
  • SSH scope (D5): buffer extension SSH debug passing through the shared Logger; do not buffer CLI ProxyCommand file logs already handled via coder.proxyLogDirectory.

Decisions

  • D1: buffer all below-level session logs.
  • D2: bound by entry count (and a character budget to cap memory).
  • D3: replay into the existing Coder output channel at a persisted level with [buffered] marker/original level/timestamp; retain at Off; also flush on support-bundle collection.
  • D4: flush only on genuine connection failure; not transient, not a 401, and not intentional teardown.
  • D5: buffer extension SSH debug through the shared Logger; not CLI ProxyCommand file logs.

🤖 Generated with Coder Agents. Reviewed and authored on behalf of @aqandrew.

Wraps a Logger and keeps a bounded in-memory ring of entries below the sink's
current level (the ones it would drop). flush() replays them into the sink at a
level guaranteed to be written, so a connection failure can preserve the debug
detail leading up to it without the user having enabled debug logging.

Only below-level entries are buffered (no duplication of what the sink already
writes); flush is coalesced by a short suppression window.
@linear-code

linear-code Bot commented Aug 26, 2026

Copy link
Copy Markdown

DEVEX-669

@aqandrew
aqandrew marked this pull request as ready for review September 1, 2026 03:30
@aqandrew
aqandrew requested a review from EhabY September 1, 2026 03:30

@EhabY EhabY left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Please address the inline comments on remote-client failure wiring, the monitor's failure trigger, and flush suppression. The remaining comments cover simplification, test coverage, and naming.

Review generated with Coder Agents on behalf of @EhabY.

Comment thread src/extension.ts Outdated
Comment thread src/workspace/workspaceMonitor.ts Outdated
Comment thread test/unit/workspace/workspaceMonitor.test.ts Outdated
Comment thread src/logging/logBuffer.ts Outdated
Comment thread src/logging/logBuffer.ts Outdated
Comment thread src/websocket/reconnectingWebSocket.ts Outdated
Comment thread src/logging/logBuffer.ts Outdated
Comment thread src/core/container.ts Outdated
Comment thread src/logging/logBuffer.ts Outdated
Comment thread src/logging/logBuffer.ts Outdated
@aqandrew
aqandrew requested a review from EhabY September 9, 2026 19:53

@EhabY EhabY left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Two blocking items: the ws close event shape makes the unrecoverable_close flush unreachable in production, and the monitor test cannot fail. The rest covers trigger scope, where the settings reader lives, and trimming the buffer and its tests.

The PR description also needs a refresh: it still mentions the suppression window, the monitor trigger, isConnectionFailure, and four commits where there are twenty.

Comment thread src/websocket/reconnectingWebSocket.ts Outdated
Comment thread test/unit/workspace/workspaceMonitor.test.ts Outdated
Comment thread src/logging/logBuffer.ts Outdated
Comment thread src/core/container.ts Outdated
Comment thread src/logging/logBuffer.ts
Comment thread test/unit/logging/logBuffer.test.ts
Comment thread package.json Outdated
The exemption covers every 401, not only an OAuth-refreshable one, so say
so in the code comment, CONTRIBUTING, and the test name: a 401 explains
itself, and with OAuth a refresh reconnects the same socket.
Args are now formatted into each entry's text, so the [buffered] prefix
really does land on every physical line. Drop the over-claim from the test
name and assert on the joined replay text.
readConnectionLogBufferSize always returns a number, so the typeof guard
on the config-change callback was dead. Hoist a readSize() helper, use it
for the initial size and the watcher's getValue, and set the capacity
straight from it on change.
Combine the individual readConnectionLogBufferSize cases and the invalid-
value table into a single it.each<Case> with { name, value, expected }.
createMockWebSocket kept one handler per event and ignored the handler on
removal, so only the last of production's three close listeners survived;
use a Set per event with identity removal and drop the unused fire helpers.
Add a real OneWayWebSocket test that closes from a ws WebSocketServer with
1002 and asserts the callback receives the DOM CloseEvent code and reason.
The support-bundle flush change made Commands call
serviceContainer.getConnectionLogBuffer(), but the telemetry, netcheck,
and updateWorkspace Commands mocks did not provide it, so their suites
threw "getConnectionLogBuffer is not a function" in CI.
The strict `as ServiceContainer` cast requires each property to match
exactly, so annotate the getter's return as ConnectionLogBuffer to
restore comparability and fix the TS2352 typecheck error.
@aqandrew
aqandrew requested a review from EhabY September 15, 2026 21:47
Comment thread src/commands.ts Outdated
Comment thread src/logging/logBuffer.ts Outdated
Comment thread src/websocket/reconnectingWebSocket.ts
Comment thread src/websocket/oneWayWebSocket.ts Outdated
Comment thread src/websocket/utils.ts
Comment thread src/core/container.ts Outdated
Comment thread src/api/coderApi.ts Outdated
… CLI

A support bundle is a snapshot, so a missed entry should be recoverable by
the next bundle or failure: flush("support_bundle") now retains the ring
instead of clearing it. Move the flush above cliExec.supportBundle so the
CLI's runtime gives LogOutputChannel time to write the lines to disk.
Capture is still best-effort; the channel writes on its own schedule.
- Flush header reads "replaying N buffered entries (reason)"; the old
  "connection failure (reason)" was wrong for a support_bundle or a
  closeRemote() cancel.
- Relabel all four closeRemote() callers remote_closed; two of them are
  cancels, not workspace_open_failed.
- CONTRIBUTING: only the first physical line of an entry carries the
  timestamp and level; continuation lines carry the bare marker. Describe
  bundle capture as best-effort.
- package.json: describe bundle capture as best-effort.
- Drop the replaySink comment's "whatever the user's log level" claim;
  flush returns early at Off.
- Add an Unreleased changelog entry for the setting and normal-close
  reconnect.
Reconnecting after server-initiated normal closes made normal_close
unemittable, but it stayed in ConnectionStateReason and ConnectionDropCause
and in the EVENTS.md tables, so anyone filtering on it got a silent zero
rather than a signal the behavior changed. Remove it from both unions and
both tables, and give the double-emit test an emittable reason.
addEventListener and removeEventListener each spent a five-case switch on
non-message events that all do the same cast and call. The per-event
overloads force the cast either way, so one cast covers open/close/error.
handshakeStatus parses two libraries' internal error text, and neither is a
contract; the existing tests hand-build the strings, so a reword on a bump
would pass here and break in production. Drive a real ws client against a
server answering 404 on the upgrade and a real EventSource against one
answering 403, so a reword fails in CI instead. Reading the status from the
libraries' public event APIs is tracked in #1118.
The container was otherwise pure getters; the onConnectionFailure funnel is
behavior. Move the `<reason> <route>` arrow onto BufferingLogger and add it
to ConnectionLogBuffer, so the grep format sits next to the code that writes
the line. Call sites read getConnectionLogBuffer().onConnectionFailure.

Default the socket's onConnectionFailure option to a noop, so it lives in
#options and drops the #onConnectionFailure field, the optional-call at the
terminated funnel, and one member of the Required<Omit<...>>.
All three watch callers passed the route twice, and two duplicated a
template literal, so the createReconnectingSocket argument and the socket
init could drift. Hoist a single apiRoute per caller and pass it by
shorthand into the init.

Restore getLogLevel's explicit HttpClientLogLevel return type, and expand
the #lastRoute comment: it is not simply the seeded route, since the live
URL diverges after an SSE fallback and after a followRedirects redirect.
@aqandrew
aqandrew requested a review from EhabY September 16, 2026 19:38

@EhabY EhabY left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Code is solid: every thread from the last round checks out, and typecheck, lint, and the unit suites are clean. Approving, the three suggestions are wording only.

Description: Flush reasons (D4) still lists normal_close, which this PR deletes. The Off bullet still promises the context "survives until logging is turned back on", the phrasing we dropped from flush(), since nothing watches onDidChangeLogLevel.

Comment thread src/websocket/oneWayWebSocket.ts Outdated
Comment thread CHANGELOG.md Outdated
Comment thread CONTRIBUTING.md Outdated
aqandrew and others added 3 commits September 17, 2026 10:59
…correlated unions

Co-authored-by: Ehab Younes <ehab.alyounes@gmail.com>
Co-authored-by: Ehab Younes <ehab.alyounes@gmail.com>
…opens

Co-authored-by: Ehab Younes <ehab.alyounes@gmail.com>
@aqandrew

Copy link
Copy Markdown
Contributor Author

Updated the PR description to remove normal_close from D4's intentional teardown reasons + removed mention of turning logging back on from the Off channel description (per 544d143).

Thanks so much for the thorough reviews @EhabY! 🚀

@aqandrew
aqandrew merged commit c51f472 into main Sep 17, 2026
13 of 14 checks passed
@aqandrew
aqandrew deleted the aqandrew/devex-669-vs-code-add-log-buffer branch September 17, 2026 18:21
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants