Skip to content

SYNC_STREAM frame loss never converges — a layout area stays on its placeholder forever, and a re-snapshot does not recover it #2654

Closed

Description

@rbuergi

Summary

A layout area's synchronization stream loses patch frames in transport and never converges. The client asks for a fresh snapshot, receives another lossy chain, and repeats — so the page stays on its unrendered placeholder indefinitely. Every retry hits it identically, so it presents as a test timeout rather than an error.

Measured on MeshWeaver.Education's disposable-mesh e2e, run 33238349875 (job 99063579613), portal log from the run's own mesh-diagnostics/portal.log:

[SYNC_STREAM] Frame loss detected for 3_EIXhSwc0eWbdGFUxNGZg: incoming Patch v9 chains onto v8
but the last applied frame is v7 — a frame was lost in transport;
requesting fresh snapshot from e2e-admin/Packages

112 such events across 40 distinct streams, spanning 06:30:07 → 06:48:57 — the entire 19-minute window, across both the first attempt and its retry. The immediately preceding main run (33234257081) shows 120 events over the same 40 streams.

The gap is never one frame. It is consistently two or three:

incoming Patch v9  chains onto v8  but the last applied frame is v7
incoming Patch v17 chains onto v16 but the last applied frame is v14
incoming Patch v20 chains onto v19 but the last applied frame is v17
incoming Patch v22 chains onto v21 but the last applied frame is v19

What the user sees

The page renders the control's ToString() instead of the control — the patch that would have replaced the placeholder never applies:

- generic [ref=f19e45]: "NamedAreaControl { Id = , Style = , Readonly = , Skins = …,
    Area = Overview, ShowProgress = , ProgressMessage = , SpinnerType = Ring }"

Not an error dialog, not a spinner that eventually resolves — a permanent placeholder on a page whose breadcrumb, banner, search box and menus all render fine. Only the streamed area is stuck.

Why this is worth a separate issue from #2543

Same family — "a message was lost between two hubs" — and quite possibly the same root cause. But the mechanism and the surface differ, and merging them would bury the blast radius:

#2543 this
what is lost a reply to a request (RESPONSE_POSTED … callback STILL pending) a patch frame on a synchronization stream
detection [STALE-CALLBACK], after a 30 s ticker [SYNC_STREAM] Frame loss detected, immediately, by version chain
recovery attempted none — the caller waits yes — a fresh snapshot is requested, and it does not help
surface a NodeType's Tests probe never created a page permanently unrendered

The recovery leg is the part I would look at first: the stream detects the loss correctly and asks for a fresh snapshot, and the next chain is lossy again. Whatever drops frames is still dropping them during the re-snapshot, or the re-snapshot is itself delivered as a chain that can be lost.

Blast radius — this is currently the fleet's last-mile blocker

MeshWeaver.Education is the only producer of the education bundle source. Its publish-bake job is gated (needs: mesh-gate → needs: [e2e-install, e2e-mesh, …]) on the very install this defect fails. So:

  • Education has published no bundles since 2026-08-27 15:07:50Z;
  • its courses are installed on memex-cloud;
  • the self-updater holds a roll unless every installed package has a sealed bake for the target identity.

So this stream defect, via a CI gate, is what is holding the fleet's roll.

Correlation worth checking (not proven)

The affected page is a PluginCatalog whose available-package list grew from 13 to 42 packages on 2026-08-27 19:03Z (Education#221 swapped a four-package sparse checkout of MeshWeaver.Plugins for its whole sealed publication). The blocking install passed on 5/5 main runs before that commit and has failed on 6/6 runs that executed it since.

That is consistent with the loss being payload/frame-count driven rather than random. I could not run the control: e2e artifacts have 1-day retention, so every green run's portal.log has expired and I cannot say whether green runs also logged frame loss at a lower rate. Could not establish — offered as a lead, not a conclusion.

Education/#228 narrows that catalog back to the 3 packages the courses actually require, which should remove the trigger. It does not address this defect, and a payload-sized-dependent loss will resurface on any other large area.

Repro

Both runs' e2e-install-report artifacts contain the full mesh-diagnostics/portal.log and the Playwright page snapshot. grep -c 'Frame loss' portal.log reproduces the counts directly. (Retention is 1 day — grab them promptly or re-run the Education workflow.)

Activity

  1. rbuergi commented on Aug 30, 2026

    @rbuergi
    ContributorAuthor

    This ticket now owns the whole frame-loss question — plus three things from source

    #2641 reported the same log line in production (847 in 30 min on memex-cloud). Its frame-loss half
    is closed against this issue: this one asks the question that matters (does the resync
    converge?
    ) and has the evidence to answer it — per-stream counts, both attempts, the artifacts, and
    the user-visible surface. The full per-symptom disposition is
    on #2641.

    Three things I derived from source while settling it. None is a fix for this ticket; the first is a
    correction to a premise here, and the other two are where I would look next.

    1 · "The gap is never one frame" is not evidence of multi-frame loss

    The body reads the consistent 2–3 frame gaps as "consistent with the loss being payload/frame-count
    driven rather than random"
    . The recovery's own shape produces that pattern from single-frame
    losses, so the observation does not discriminate:

    SynchronizationStream.RequestFreshSnapshot nulls the cached JSON and latches _resyncInFlight.
    Every Patch that arrives before the fresh Full lands therefore takes the "Patch before base Full"
    branch — logged at Debug, RequestFreshSnapshot no-ops on the latch, and the frame is dropped.
    So the next Frame loss detected at Warning is measured across the whole resync round-trip, and the
    gap it reports is "however many frames flew while we waited", not "how many the wire ate". One lost
    frame plus a 2-frame round-trip prints v20 chains onto v19 but the last applied frame is v17.

    That does not rule the Education#221 13→42 package correlation out — it removes the gap width as
    support for it. The controls that would discriminate are the per-stream count and whether a Full
    follows each detection ([SYNC_STREAM] Processing Full change for {StreamId}, Debug).

    2 · The two upstream drivers to rule out before suspecting the chain

    Anything that repeatedly ends and re-establishes a subscriber's server-side stream costs one gap per
    cycle. Both were live in the #2641 window and both are cheap to check in a portal.log:

    3 · Where a resync can fail to converge by construction

    Two seams, both from reading RequestFreshSnapshot / GetClientSubscription, offered as leads —
    I have not reproduced either:

    • The re-ask has no failure arm. _resyncInFlight is cleared by exactly one thing: a Full
      landing. There is no NACK path, no OnError, no deadline. The SubscribeRequest rides the same
      owner↔subscriber leg that lost the frame, so if it is lost, or the re-assert Full is, the mirror
      latches silently forever: every later Patch enters "Patch before base Full" at Debug and is
      swallowed. That is a permanent placeholder with no error anywhere — this ticket's symptom exactly.
      (Same mechanism RCA'd on Six of the last ten CI failures were unrelated single integration tests — a flake population taxing every second PR #1384 for the in-process case.)
    • A hit that re-asserts nothing. On a re-subscribe the owner re-asserts only when
      alreadyServing.Current is { Value: not null }; otherwise it returns the existing stream and sends
      no Full at all. The comment there reasons that the initial subscribe's own first Full is
      already in flight — true during hydration, but the mirror has by then nulled its cache and latched,
      so anything that makes that in-flight Full not arrive leaves the same silent latch.

    Both suggest the same shape of fix, and it is not a timer or a retry: the resync needs a
    bounded, event-driven failure arm — a gap-proving patch that arrives after a resync with no
    intervening Full is proof the re-ask was lost, and that should surface (OnError / a Warning naming
    the stream), not be swallowed at Debug.

    Also landed: an amplifier of this storm — #2744

    AcceptsStringSplice was declared on the initial subscribe and on neither re-subscribe, so the
    first eviction/recycle/resync cycle silently downgraded a mirror to whole-string replace frames for
    the rest of its life — more bytes per frame, per subscriber, on exactly the path that fires here.
    Fixed by minting every SubscribeRequest in one place. It is an amplifier, not the cause; this
    ticket's residual is unchanged.

    🤖 Generated with Claude Code

  2. added a commit that references this issue on Aug 30, 2026
  3. added 2 commits that reference this issue on Aug 30, 2026
  4. rbuergi commented on Aug 30, 2026

    @rbuergi
    ContributorAuthor

    Fixed in #2754 (merged be39fc607e) — the convergence contract

    The durable write-up is Doc/Architecture/DataSyncAndCrdt §6 → "The convergence contract — what re-opens the resync gate" (get Doc/Architecture/DataSyncAndCrdt). This comment is a pointer and a disposition of the two seams the handover named.

    Seam 1 — HELD. It is the root cause.

    RequestFreshSnapshot was the third SubscribeRequest post site and the only one with no arm on its answer (the initial subscribe and Resubscribe have always used hub.Observe). It posted fire-and-forget behind a latch whose only release was a Full landing — so every way the answer could fail to arrive shut the mirror permanently and silently: each later Patch took the Patch before base Full branch, RequestFreshSnapshot no-opped on the latch, and the frame was dropped at Debug.

    Three defects, one per way the answer fails:

    1. The re-ask is now Observed (inside Observable.Defer, so a synchronous post throw reaches the same arm instead of escaping UpdateStream with the gate shut). Verdicts are classified by the same policy the stream's own DeliveryFailure handler applies.
    2. The gate is released by the round trip — the Full, the owner's ack, or a verdict. Releasing it asks for nothing: only the next frame that proves the mirror still has no base drives a new re-ask. No timer, no poll, no retry.
    3. A mirror holding no cached JSON accepts a Full at any frame version. An owner that had to rebuild the server-side stream to answer stamps its first Full on a reset clock, and the monotonicity guard was throwing away the very snapshot the mirror had asked for.

    Plus: the gate used to be latched before discovering there was nothing to post (Reference not a WorkspaceReference) — permanent by construction.

    🚨 The premise correction that mattered most: classify on ErrorType, never on TargetUnserved

    #2745 merged while this was in flight, and it makes the router stamp TargetUnserved on both of its "nobody serves that address" verdicts — the terminal no-live-subscriber refusal (RefuseNoSubscriber, NotFound) and the transient pod-hub refusal a rolling deploy produces while a silo's claim has not landed (AnswerPodHubNotHere, ShuttingDown). My first draft keyed the tear-down on the stamp; that would have faulted every mirror in a rolling deploy's overlap window — a worse defect than this one. RoutingGrain states the contract: the stamp is the owner-side eviction gate, the ErrorType beside it says whether the sender keeps its recovery armed, and the two are independent. #2758 is the owner-side half of the same correction.

    The measured finding: the frame chain cannot detect a lost fresh snapshot

    BuildReassertFrame carries the version of the state it re-asserts (#945), not a new one — so the re-assert Full shares a version with the frame before it and the chain reads

    v4(basedOn 3) → Full v4(basedOn 4) → v5(basedOn 4)
    

    exactly like v4 → v5(basedOn 4). An earlier draft of the fix watched the seen-chain through the resync window; the repro proved it blind, and it was dropped rather than shipped. BasedOnVersion is a content clock, not a frame sequence — worth knowing before anyone else reaches for it.

    Seam 2 — does NOT hold

    "a re-subscribe hit whose Current.Value is null re-asserts nothing, so the mirror waits forever for a base Full that will never come"

    The premise is false, from source: Current is set only by SetCurrent, which is also the only thing that emits; ToDataChanged's outbound cursor is set on that same emission; and ToDataChanged's currentJson is null branch makes the first frame a Full. So Current is null ⇒ empty cursor ⇒ the stream's own first frame is a Full by construction. The subscriber is always answered; the Full is not "never coming".

    The one real residual is that the alreadyServing guard reads Current out of turn. It was deliberately not changed: making the Update unconditional queues a redundant whole-snapshot Full per re-subscribe for the duration of a hydration, on exactly the load-sensitive path this ticket is about. Documented as the contract instead (§6, "What a re-subscribe is owed by the owner").

    The operator signal

    [SYNC_STREAM] Resync has not converged for {StreamId}: asking {Owner} for a fresh snapshot again (attempt N) at Warning. Attempt 1 is ordinary recovery and stays Debug; anything above 1 is a mirror that asked and was not answered. That is the line that separates "gaps that were answered" (healthy) from "a stream that keeps asking and never converges" — the state this ticket lived in with a stuck layout area as its only outward sign.

    Tests

    StreamResyncConvergenceTest — four cases, all driving the real resync with the deterministic wire-loss pipeline: the answer lost in transport, the answer on a rebased clock, the re-ask refused terminally, and the re-ask refused transiently with the identical TargetUnserved stamp. All four fail on the pre-fix tree (verified by checking out origin/main's SynchronizationStream.cs and re-running: 4/4 red there, 4/4 green with the fix).

    What this does not close

    The upstream drivers of the storm volume are unchanged and were never this ticket's residual: #2633/#2692's attach latch (fixed by #2645) and the eviction cycle of #2620/#2756. This fixes the part that made a detected gap permanent.

  5. rbuergi commented on Aug 30, 2026

    @rbuergi
    ContributorAuthor

    Closing: this ticket's own scope is fixed and merged, and its stated residuals belong to other issues that are themselves closed.

    Fixed by #2754 (merged be39fc607). Per that PR's disposition on this issue:

    • Seam 1 held and was the root cause — RequestFreshSnapshot was the third SubscribeRequest post site and the only one with no arm on its answer.
    • Seam 2 did not hold — refuted from source rather than assumed (Current is set only by SetCurrent, which is also the only emitter).
    • StreamResyncConvergenceTest drives the real resync through a deterministic wire-loss pipeline, so the fix is pinned rather than argued.
    • An operator signal was added at Warning for a non-converging resync, with attempt 1 left at Debug so ordinary recovery stays quiet.

    The named residuals are elsewhere and are all closed: the attach latch (#2633, #2692 — fixed by #2645) and the eviction cycle (#2620, #2756). They were explicitly "never this ticket's residual".

    The durable write-up is Doc/Architecture/DataSyncAndCrdt §6 — "The convergence contract" — so the reasoning outlives this thread.

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

    No labels
    No labels

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions