Skip to content

Prevent WebSocket traffic from starving FileReader completion tasks #287

Description

@wieslawsoltes

Completed — 21 September 2026

The shared scheduler/protocol implementation and WebScene PR #891 now satisfy the current installed-package proof that kept this issue open. On unchanged Code OSS 645f29cc, tested WebScene change 1412283 (merged without code changes as d3c030f), and AppScene cd0a02e, 20/20 launches retained the exact remote root, registered provider, five resolved children, five Explorer-model children, five visible rows, and 64-node DOM bound.

Resolve is 751.61 ms p50 / 762.64 ms p95 / 797.49 ms maximum. First-child paint is 1828.19 ms p50 / 1860.12 ms p95 / 1870.24 ms maximum; every launch satisfies the 2-second gate. Routed selector invalidation behavior remains covered by the focused native regressions, and the direct-subject optimization has an explicit A/B escape hatch.

The remaining workspace-file/multi-root, interaction, dependent-service, visual, and repeated lifecycle matrix stays in #252. No duplicate scheduler implementation remains scheduled.

Parent: #280
Product acceptance: #252
Related completed API contract: #73
Prior socket wake fix: #284 / #285

Problem

WebScene's browser task arbitration drains every ready Worker, MessagePort, or WebSocket event before it considers any due timer. Its FileReader compatibility implementation intentionally uses a zero-delay timer both before reading a Blob and before publishing progress/load/loadend.

Code OSS's unchanged remote protocol receives binary WebSocket frames as Blob values and feeds them through a persistent FileReader. Under the remote-workspace startup stream, the WebSocket source therefore starves the FileReader timers needed to consume those same responses. The provider stays correct but waits seconds for stat/readdir promises.

This is distinct from #284: the runtime now wakes promptly for an empty-to-nonempty socket queue and rotates fairly among the three asynchronous message sources, but that arbitration tier still precedes due timers unconditionally.

Retained evidence

Exact inputs:

  • WebScene aa06172c92a60324b1f2e5fa2d94a00bd1e15214
  • AppScene 1420e227e52579a097e7ae52a2cadb41cf073e4d
  • VS Code OSS 645f29cc3176500b4b5762ba887cf2a7f0ffdf2c
  • Node 24.18.1
  • local query-gated observer commit 74b3b94 (not pushed)
  • log /private/tmp/vscode-252-product-navigation-280-attribution.log

One bounded, no-host-poll product trace retained the exact selected vscode-remote URI, registered provider, exact five resolved/model children, five Explorer rows, and 64 Explorer DOM nodes. Its protocol measurements were:

  • 151 native WebSocket events, 13,118,749 bytes, maximum queue depth 27
  • native receive-to-runtime-dispatch: 25,322.5 ms aggregate across events, 3,563.26 ms maximum
  • WebSocket JS callbacks: 200.777 ms aggregate, 4.916 ms maximum
  • callback microtask checkpoints: 1.890 ms aggregate, 1.100 ms maximum
  • 146 FileReader reads, 13,115,590 bytes
  • underlying Blob.arrayBuffer: 1.532 ms aggregate, 0.041 ms maximum
  • FileReader call-to-loadend: 658,518.7 ms aggregate across overlapping reads, 14,940.7 ms maximum
  • exact-root provider stat calls in the first wave: about 5,416 ms
  • exact-root provider readdir calls in the next wave: about 2,299 ms
  • scene publication samples remained bounded individually (observed maximum 64.35 ms)

The byte counts align the WebSocket/Blob/FileReader path. Copying and callbacks are small; the multi-second boundary appears while FileReader waits for its scheduled tasks. Source ordering confirms that ready async-message sources return before has_due_timer() is serviced.

Scope

Make task arbitration fair between due timers and continuously ready asynchronous message sources. Preserve FIFO ordering within each source and the browser-observable asynchronous FileReader event sequence. Do not add a Code OSS/provider special case.

Acceptance

  • A product-neutral native/browser fixture feeds at least 256 consecutive binary WebSocket Blob frames through one FileReader queue and verifies exact bytes and loadstart → progress → load → loadend order.
  • With Worker, MessagePort, and WebSocket sources continuously refilling, due zero-delay timers have p95 ≤ 25 ms and maximum ≤ 100 ms; no source waits behind an unbounded competing backlog.
  • Socket callbacks and promise/microtask continuations settle once and preserve FIFO message order.
  • Abort, cancellation, disconnect/reconnect, close, malformed input, and navigation teardown release timers, callbacks, Blobs, sockets, and task queues without stale delivery.
  • Queue depth/bytes, task counts, scene publications, worker wakeups, V8 heap, and RSS remain bounded over repeated cold/warm cycles.
  • Wake native runtime for queued WebSocket events #284's 100-cycle socket wake/fairness gate and adjacent Worker/MessagePort/idle-platform gates remain green.
  • Unchanged Code OSS preserves the exact remote root/provider/five children/five rows and completes first resolve plus first-child paint within Remove fixed delay from remote filesystem provider responses #280/Qualify remote workspace bootstrap, Explorer contents, and watcher refresh #252's 2 s bound.

Activity

  1. added
    bugSomething isn't working
    vscode-oss/plannedPlanned for the AppScene/WebScene VS Code OSS integration
    on Sep 17, 2026
  2. wieslawsoltes commented on Sep 17, 2026

    @wieslawsoltes
    CollaboratorAuthor

    Local candidate 0f92cf47 (branch fix/timer-async-task-fairness-287, rebased on current main aa786c0e) alternates due timers with the Worker/MessagePort/WebSocket source group. It changes only runtime task state/arbitration plus the focused WebSocket/FileReader test.

    Direct baseline with the new oracle fails to complete the browser WebSocket lifecycle. The candidate passes repeated runs with:

    • 256 consecutive exact binary Blob → FileReader frames on one socket
    • exact loadstart → progress → load → loadend ordering
    • FileReader p95 0.119–0.198 ms; maximum 0.272–0.716 ms
    • at most 20 competing self-refilling MessagePort deliveries before a FileReader completion
    • existing 100-cycle WebSocket p95 0.111–0.204 ms; at most 24 competing MessagePort deliveries
    • 514/514 bounded timers; at most 4,482 microtask checkpoints; 2 scene builds; at most 319 signalled wakes
    • cancellation/reconnect/close once; stable V8 heap; 47.6 MB maximum RSS
    • adjacent worker configuration, postMessage batching, and idle V8 platform filters pass

    The unchanged Code OSS product rerun remains functionally exact but does not meet the parent latency gate:

    • selected URI == only workspace root; provider registered
    • exact five resolved/model children; five rendered rows; 64 Explorer DOM nodes
    • resolve 7,749.84 ms
    • first child paint 11,788.09 ms
    • sampling maximum 48.46 ms
    • peak child-process RSS 860,160,000 bytes

    Log: /private/tmp/vscode-252-product-navigation-287-candidate.log.

    Therefore this candidate proves and fixes the focused generic starvation contract, but it is not sufficient for #280/#252 and remains local/unpushed. The next attribution must identify which runtime source or non-task phase accounts for the remaining delay before widening scheduler scope.

  3. wieslawsoltes commented on Sep 17, 2026

    @wieslawsoltes
    CollaboratorAuthor

    Rebased investigation on exact merged-#245 main 4040058e74d76b4485961d65dad74a77c46072fb and reduced the corrected product boundary to task arbitration.

    A 20-cycle product-neutral protocol oracle now uses the actual 13-byte framing plus a 1,071,425-byte initialization body, coalesces the write behind setTimeout(..., 0), and keeps Worker, MessagePort, WebSocket, and Blob/FileReader work ready. The first cycle uses a calibrated backlog to retain the unchanged product's multi-second shape; warm cycles retain the same sources with bounded work.

    Unchanged main fails specifically at the due timer:

    • protocol enqueue → deferred flush: 3,581.35 ms max, 112.286 ms p95
    • before the flush: Worker 235,792, MessagePort 700,000, WebSocket 62, FileReader completion 0
    • WebSocket queue HWM 66; FileReader queue HWM 67
    • actual size-only/product-shaped control remains fast: flush p95 0.0218 ms, outbound receipt p95 1 ms, Initialized p95 13.97 ms

    The same oracle with timer-vs-async alternation passes:

    • deferred flush 0.1539 ms max, 0.0475 ms p95
    • at most one Worker and one MessagePort task before the due timer in that retained run
    • Initialized p95 12.27 ms; outbound receipt p95 1 ms
    • final bounded run: 340 timers, 585 microtask checkpoints, 47 signalled wakes, 2 scene builds, 655,100-byte post-low-memory V8 heap, 121,028,608-byte process maximum RSS
    • Worker configuration, postMessage batching, and idle-platform filters pass
    • Chromium 151 direct control passes 45/45, with flush p95/max about 0.1 ms

    Local implementation/test commit: 26694871 on fix/remote-extension-handshake-289 (not pushed). Main failure log SHA-256: 90a26f5b40cde9bdf34f8bd1df84ef18235b6b2953b40e6d9972e286d6d236d7; candidate log: b5258114164972b33f26931bc4aa7964cf76b9e49240f8bb504b054a97f0dc30.

    This proves #287 is the generic owner of the 3.542 s product enqueue→timer→WebSocket.send delay. It is not a wire delay: the retained product send call took 0.743 ms and Node received the frame 5 ms later.

    The branch remains local because rebased PR #281 extends this same async-source rotation with ServiceWorker. After #281 merges, the fix must rebase on the new main and preserve all four sources before final direct and unchanged-product qualification.

  4. wieslawsoltes commented on Sep 17, 2026

    @wieslawsoltes
    CollaboratorAuthor

    Post-#281 rebase validation on exact WebScene 1bd8596e3dc07a3281204504acad379eb1f6bc78:

    • Local observer/fix commit: b75d37958ef7ce3f73a5b08de6b0516b0f8f57eb (unpushed).
    • Exact-main reduced multi-source oracle: protocol-flush max 3617.66 ms, p95 122.523 ms under the calibrated 1,071,425-byte protocol workload.
    • Candidate: max 0.204 ms, p95 0.157 ms; adjacent Worker ordering, message batching, idle platform, and ServiceWorker client gates pass. The four-source Worker/ServiceWorker/MessagePort/WebSocket rotation from Add service worker client messaging and navigation lifecycle #281 is preserved.
    • Chromium control remains 45/45, with timer p95/max about 0.1 ms.

    The unchanged packaged Code OSS trace rejects this candidate as sufficient for the product delay: protocol send was requested at 1789661804067, while native WebSocket.send was not entered until 1789661807765 (+3698 ms). Once entered, send returned in 0.783 ms, its microtask ran in 0.834 ms, and bufferedAmount remained 0.

    Therefore this commit proves and fixes the reduced timer-vs-async fairness defect, but another product task tier still delays the actual send. It remains local and must not be proposed as the complete #289/#252 fix. Draft #292 currently collides in webscene_v8_runtime_tasks.inc; its intended DOM-listener retirement is semantically separate, but it must rebase without regressing #281's four-source rotation before this lane can publish.

    Evidence: /private/tmp/webscene-289-main-1bd8596e-multisource-oracle.log, /private/tmp/webscene-289-b75d3795-direct-rebuilt.log, /private/tmp/webscene-289-b75d3795-adjacent-gates.log, /private/tmp/vscode-252-product-b75d3795.log (SHA-256 f58b40413fe5dd30567d0d6a3d207b668fd07bea96b594aae9c5568509a38252).

  5. wieslawsoltes commented on Sep 18, 2026

    @wieslawsoltes
    CollaboratorAuthor

    The generic scheduler fix for this reduced starvation class has now landed through PR #347 at dbd7351a88415d369ea322c692153474fb7a933c.

    Its product-shaped gate includes concurrent WebSocket and FileReader work alongside Worker, MessagePort, and window-message pressure. On exact-base validation, the 1.07 MiB protocol flush completed in 0.157 ms p95 / 0.274 ms max, no more than 2 competing tasks ran first, queue high-water stayed at 4, and V8 heap was flat. This issue remains open until unchanged packaged Code OSS #252 confirms the downstream product timing.

  6. wieslawsoltes commented on Sep 18, 2026

    @wieslawsoltes
    CollaboratorAuthor

    The current exact-package #280 trace exposes a second, narrower FileReader scheduling defect after the generic async-source fairness work merged in #347.

    On AppScene d4a73888, WebScene dd39f118, and unchanged Code OSS 645f29cc, the functional workspace path is exact (selected root, provider, five model children, five rows), but 149 FileReader operations over 13,209,295 bytes take 88,463.629 ms in overlapping call-to-loadend time with a 2,219.394 ms maximum. The same 149 Blob.arrayBuffer() operations total 1.111 ms with a 0.040 ms maximum. FileReader still uses two zero-delay timers and therefore inherits the complete application timer backlog.

    PR #423 gives FileReader a bounded independent task source while preserving asynchronous delivery, exact bytes, event order, timer fairness, queue bounds, navigation/disposal cleanup, exception handling, inspector lifecycle, and microtask checkpoints.

    Direct evidence on current main 2f0ae988:

    • test-only control: all 4,096 application timers run before load, 57.847 ms, gate fails;
    • candidate: 2 timers before load, 0.405 ms, gate passes;
    • native/Chrome WPT-style contract: 48/48 in both engines; Chrome independently completes the same timer-backlog control in 3.8 ms;
    • 100-cycle WebSocket gate and 20 product-shaped protocol cycles pass; FileReader p95 1.984 ms, protocol flush p95/max 0.107/0.117 ms, bounded queues/tasks/wakes/scenes, flat settled V8 heap;
    • Node 24 compatibility tests pass 8/8.

    Detailed evidence: docs/validation/file-reader-task-source-20260918.md on PR #423. This issue remains open after the focused merge until the unchanged packaged #280/#252 workspace rerun meets the two-second first-paint gate.

  7. wieslawsoltes commented on Sep 21, 2026

    @wieslawsoltes
    CollaboratorAuthor

    Exact merged-package closure evidence — 21 September 2026

    The current installed-SDK Release now passes the shared unchanged-product gate that this issue was waiting for.

    Exact inputs:

    • AppScene cd0a02ecd15f0a635bccc242cdd657888db39e25
    • WebScene a99eaf23aef5e5525b0a58c5635fa8a431b604f1
    • unchanged Code OSS 645f29cc3176500b4b5762ba887cf2a7f0ffdf2c
    • SDK manifest SHA-256 475c5652aed411cb98867ad79074e75096534adce6f607cbe1a11f5b2b39ab9b
    • executable SHA-256 9c3404b01537cca336717492030f548b15180fc5c3d1f684185963808d430b4f
    • product log SHA-256 c78d19651bf5615b9db7595ea2aa16bc252ad1395d19b83b610088639c864fc2

    Unchanged-product result:

    • selected URI equals the only workspace root;
    • stock remote provider registered;
    • exact resolved/model/rendered child set: .hidden.txt, readme-link, README.md, subdir, unicodé.txt;
    • resolved/model/visible counts: 5/5/5;
    • maximum Explorer DOM nodes: 64;
    • provider resolve: 757.40 ms;
    • first-child paint: 1,880.02 ms, inside the 2-second product budget;
    • observer sampling maximum: 15.37 ms;
    • protocol: 79 FileReader reads / 11,801,046 bytes, 47.41 ms maximum FileReader completion, 0.067 ms maximum Blob conversion;
    • remote transport → Ready: 939 ms; Ready → Initialized: 295 ms;
    • after bounded termination, no AppScene host, bundled server, extension-host, or helper process remained.

    The closing implementation chain is merged: shared task-source/protocol fairness, dedicated FileReader scheduling, per-socket WebSocket fairness (#888), metadata-only diagnostics (#889), and lazy binary Blob compatibility-string expansion (#890, merge a99eaf23). The 12 MiB focused Blob gate measured 0.867 ms construction without requested text expansion versus 55.79 ms with explicit expansion (~64.4×), preserved the exact snapshot/string result, retained cross-socket ordering, and finished with flat settled heap.

    The wider workspace/watcher/dependent-service matrix remains tracked by #252. This issue's shared implementation and exact-product latency gate are complete.

  8. wieslawsoltes commented on Sep 21, 2026

    @wieslawsoltes
    CollaboratorAuthor

    Reopened after repeated exact-package run — 21 September 2026

    The first exact merged-package run passed at 1,880.02 ms, but a second independent cold run on the same AppScene cd0a02e / WebScene a99eaf2 / unchanged Code OSS 645f29cc package painted at 2,179.19 ms. Provider resolve remained bounded at 1,110.87 ms, the exact root/provider/five resolved/model/rendered children remained correct, and maximum Explorer DOM nodes remained 64.

    Because this issue explicitly requires the unchanged-product first-child result within two seconds across repeated cold/warm qualification, one passing run is insufficient. The issue is reopened pending a multi-cycle p50/p95 gate and attribution of the remaining approximately 179 ms breach. The already merged direct scheduler/Blob regressions remain valid and are not reverted.

  9. wieslawsoltes commented on Sep 21, 2026

    @wieslawsoltes
    CollaboratorAuthor

    Completed by the shared merged scheduler/protocol chain plus WebScene PR #891.

    The exact unchanged-product qualification passed 20/20 launches with the requested root, provider, five resolved/model/rendered children, and first-child paint under 2 seconds. Resolve p95 is 762.64 ms and paint p95 is 1860.12 ms. Broader workspace-file, multi-root, interaction, visual, dependent-service, and lifecycle acceptance remains tracked in #252.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    bugSomething isn't workingvscode-oss/plannedPlanned for the AppScene/WebScene VS Code OSS integration

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions