Skip to content

CrossHubPatchAtomicityTest flakes — MergeGuard refuses concurrent writes as stale/reordered #2339

Closed

Description

@rbuergi

MeshWeaver.AI.Test.CrossHubPatchAtomicityTest.ConcurrentCrossHubPatches_DoNotDropAQueuedMessage failed on PR #2334, whose entire diff is inside MeshWeaver.Connection.Orleans (a stream-teardown change).

Round 0: 17 of 288 concurrent cross-hub adds are not visible (present=271).
Missing: [r0-m3-i31, r0-m3-i32, r0-m3-i33, …]

[Warning] [MeshWeaver.Data.MergeGuard] TestData/CrossHubAtomicity/…:
          refused stale/reordered cross-hub write        (repeatedly)

Why the PR is ruled out as the cause

  • test/MeshWeaver.AI.Test/MeshWeaver.AI.Test.csproj has no reference to Connection.Orleans or Hosting.Orleans.
  • CrossHubPatchAtomicityTest derives from AITestBase (monolith), not OrleansTestBase.

The changed code is not in that test's graph, so it cannot be reached from this suite.

Why this is a ticket and not a re-run

observation value
shard 3 on main success, 3 most recent Build-and-Test runs
documented as flaky no — no mention anywhere in the repo
failure mode MergeGuard refusing writes as stale/reordered under concurrency
loss 17 of 288 (~6%), contiguous run i31… in one round

Per the standing rule, flakes are real races — re-running would hide it. The contiguity of the missing ids (a run within one round/member rather than a scatter) suggests a window where a batch of concurrent cross-hub writes is judged stale wholesale, rather than individual lost messages.

The test's own name is the invariant: concurrent cross-hub patches must not drop a queued message. It dropped 17.

Note

This is the second concurrency guard to flake within an hour on a PR that provably cannot touch it — see #2338 (LiveQueryHandoffDropTest, on a markdown-only PR). Both are guards for previously-fixed races. Worth considering whether they share a cause, or whether recent CI contention is simply making existing windows reachable.

Filed by the session that hit it; not re-run.

Activity

  1. rbuergi commented on Aug 26, 2026

    @rbuergi
    ContributorAuthor

    Possible shared cause with #2338 — both guards' subjects live in one file.

    MergeGuard (this issue) is implemented in src/MeshWeaver.Data/DataExtensions.cs. So is the early→live handoff whose guard is flaking in #2338 — b74277304 touched that same file.

    Recent commits to DataExtensions.cs, newest first:

    25a372d24  Merge PR #2297 — AI application folds in
    00795d6a6  The AI application folds into the engine
    0f5d8b7d7  Announce the end of a sync stream, so an open view stops freezing (#2191)
    a496723b4  Split DataContext.Initialize: type registration stays in Build, source start moves out
    

    Two of those are stream-lifecycle changes, and both flaking guards are about something lost across a lifecycle boundary:

    0f5d8b7d7 in particular changes when a sync stream announces its end, and a496723b4 moves when a source starts. Either could shift the window in which a write is considered early, late, or out of order — which would explain two independent guards for previously-fixed races both becoming reachable at once, on PRs that cannot touch either.

    Not a diagnosis — I have not reproduced either failure or bisected it. Recording the coincidence because "two unrelated flakes" and "one file, two symptoms" want very different investigations, and the second is cheap to rule in or out: run both suites against the commit before a496723b4 and after.

    The contiguity noted above (missing ids i31…i37 within one round rather than scattered) is consistent with a boundary shift rather than random message loss.

  2. rbuergi commented on Aug 26, 2026

    @rbuergi
    ContributorAuthor

    Narrowing — the merge DOES recurse, so the loss is at the recursion's precondition.

    The test's premise (its own doc): "K separate client mirrors each fire N concurrent stream.Update adds, each adding a UNIQUE key to a merge-safe ImmutableDictionary". Unique keys — so there is no logical conflict, and every add should survive.

    My first hypothesis was that MeshNodePatchMerge treats the whole dictionary as one scalar and refuses the second writer. That is wrong — src/MeshWeaver.Data/Serialization/MeshNodePatchMerge.cs:60:

    // Nested object on patch AND live → recurse (deep three-way merge).
    if (patchVal is JsonObject patchObj && liveVal is JsonObject liveObj)
        Apply(liveObj, patchObj, baseVal as JsonObject, onRefuse);

    Unique keys inside a dictionary that is an object on both sides merge cleanly.

    But the recursion is conditional on liveVal already being a JsonObject. When it is not — the dictionary absent from live, null, or not yet materialised as an object on the first concurrent write — control falls through to the scalar path:

    if (!hasBase || JsonNode.DeepEquals(liveVal, baseVal))  … apply …
    else onRefuse?.Invoke(key);   // "overlapping edits → resolve-by-version: keep newer live"

    and the whole dictionary-valued key is refused as a conflicting scalar — taking every entry in that patch with it.

    That shape fits the evidence: 17 of 288 lost (~6%) and the missing ids contiguous within one round/member (i31…i37) rather than scattered — one writer's batch refused wholesale, which is what a parent-key refusal looks like, versus per-entry loss which would scatter.

    Not proven. I have not reproduced it or instrumented onRefuse to record whether the refused key is the dictionary parent or an individual entry. That single instrumentation would settle it — if the refused key is the parent, this is the cause and the fix is to treat an absent/non-object liveVal as an empty object so the recursion still applies rather than falling to the scalar branch.

    Consistent with the precedent already in that file: RebaseMonotonicTriggers exists because the generic "refuse every conflicting scalar" rule was too blunt for a monotonically-increasing field. Concurrent adds to a set look like the same class of exception.

  3. rbuergi commented on Aug 26, 2026

    @rbuergi
    ContributorAuthor

    Correcting this issue's premise — no write is lost, and MergeGuard is not the mechanism

    I filed this, and both halves of the title are wrong. The run's own diagnostics say so; I hadn't read them past the first clause.

    1. MergeGuard never refuses a data key. All 286 refusals in the run are on one field:

    286  refused stale/reordered cross-hub write to 'lastModified'
    

    lastModified conflicts on every concurrent write by construction — each writer bumps it from its own base — so the refusal is benign and expected. No PendingUserMessages key is ever refused. And a benign refusal cannot sink a write anyway: the NACK at DataExtensions.cs:1277 fires only when DeepEquals(preMergeNode, currentNode) — i.e. when nothing landed — and an add of a unique key always changes the node.

    2. Nothing is lost. The test's OWNER-TRUTH probe (which exists precisely to split read-side from owner-side loss) reports:

    WRITE ERRORS (0): []
    OWNER-TRUTH probe: version=289 present=288 missing=[]
    MIRROR SEQUENCE (285 emissions), REGRESSIONS (0): []
    converged=NEVER
    tail=[279@v280(t38804ms), … ,284@v285(t39111ms)]
    

    The owner holds all 288 at version 289. The mirror had 284 and was still climbing monotonically — 0 regressions, so this is not the #945 stale-resubscribe re-assert. It was ~4 short and advancing when the 30 s settle bound expired at t≈39 s.

    By the decision tree the test prints in its own failure message, this is the last branch: owner-truth complete, no regression, mirror simply behind.

    What the real question is

    Not "why was a write dropped" but why does the mirror need ~39 s to deliver 288 frames — roughly 135 ms per frame, delivered one write at a time.

    I want to be explicit that raising the 30 s bound is not the fix and I am not proposing it. Either that cadence is a genuine throughput defect in the shared-cache mirror path worth measuring and fixing, or the test is asserting the wrong thing — its subject is DoNotDropAQueuedMessage, and by its own evidence nothing was dropped at either end, so a bound on mirror convergence latency is not the assertion that proves it.

    Caveat on scope: this is one CI observation. The per-frame cadence needs measuring on main across runs before anyone concludes it's a regression rather than the test's inherent shape (288 sequential cross-hub writes, each producing a frame).

    Retitle suggested: "CrossHubPatchAtomicityTest: mirror convergence exceeds the 30 s settle bound (no write loss)".

    Consequence for #2334: its red is this, and its diff is entirely inside MeshWeaver.Connection.Orleans — it cannot reach this path. That is an explanation, not a licence to re-run; the bound question above still needs an answer.

  4. rbuergi commented on Aug 26, 2026

    @rbuergi
    ContributorAuthor

    Root-caused and fixed in #2391 — it is not MergeGuard, and no write is dropped

    The correcting comment above was right that the title is wrong. Here is the mechanism, measured
    rather than inferred, and the reason the delivery lag it identified is a real framework defect
    rather than a slow box.

    (a) MergeGuard refusing a legitimate concurrent write — disproven

    Counted over 1 008 concurrent cross-hub writes in this test's shape:

    MergeGuard refusal keys: {'lastModified': 1001}
    

    Every refusal is on lastModified, which conflicts on every concurrent write by construction —
    each writer stamps it from its own base. Zero refusals on a data key, zero write errors, owner
    holding every entry. Per-field partial resolution behaves exactly as #2305 established it must, and
    the fix does not touch it. CrossHubPatchAtomicityTest is unmodified.

    The defect: the ack gate rebuilt the whole node to read two scalars

    DataExtensions.ChangeContainsStampedWrite is the write-identity gate every cross-hub
    stream.Update waits on. For each emission of the owner's reduced stream it asks "is this the
    state that contains my write?"
    — an entity id and a version number. To read those two values it
    serialized the entire node to a JsonNode.

    It runs once per still-pending patch on every emission, so a burst of K concurrent writes to
    one node runs it up to K(K+1)/2 times, against a node that grows with every write.

    It is self-amplifying, and that is why this presents as a stall rather than a slope: the further
    emissions lag the merges, the more patches are still pending, and the more full rebuilds every next
    emission must pay before it can be delivered.

    Instrumented on this test's own 6×48 burst:

    • the owner applied all 288 patches in 1.5 s (285 merge-turn log lines inside a 1 500 ms window);
    • both subscribers — the shared-cache mirror and a direct bypass mirror — stopped at v213/v214
      and saw a ~2.7 s gap with no frames at all, one still stranded when the owner-truth probe ran.

    That is the "why does the mirror need ~39 s" question from the comment above, answered: it is not
    the mirror, and it is not the box. It is work the owner does on its own emission path, once per
    waiting write, per frame.

    Numbers

    before after
    full-node rebuilds by the gate, per 288-write burst 9 455 0
    allocation over the burst 4 407 MB 2 896 MB
    mirror convergence 5 356 ms 2 537 ms

    Same instrumented harness both sides, same box, back to back. One rebuild costs 0.9 ms at 144
    entries, 1.9 ms at 288
    on this node shape — so 9 455 of them are seconds of CPU, serialised ahead
    of every frame. The 0 also proves the new path is live under the production hub's
    JsonSerializerOptions rather than silently falling back.

    The fix, and how it is pinned

    Read the two values off the serialization contract (JsonTypeInfo — the same effective JSON
    names and getters the serializer would use) and never build the document. Same answer, same ranked
    idKey ?? "Id" ?? "id" lookup, same version-absent-reads-as-0 rule; the document path stays as the
    fallback for a value whose contract the options cannot resolve. The identical waste at the handler's
    preReadId goes through the same helper.

    Pinned deterministically, with no timing assertion: PatchAckWriteIdentityTest counts document
    builds through a payload converter, so the count is the observation. 150 gate evaluations now
    build one document (the control that proves the instrument can fire) instead of 151. Verified
    both directions by reverting the source and rebuilding.

    On the settle bound

    Not raised, and worth recording as a separate observation rather than a change: Merge(writes)
    completing does not mean the writes landed — UpdateRemote emits optimistically after
    UpdateResponseWaitBound = 2 s when the owner is busy. So under load the "30 s after the burst"
    window is really "30 s from ~2 s in", i.e. a bound on the whole pipeline. That did not need
    touching, because the pipeline was doing avoidable quadratic work.

    Relationship to #2229

    Splitting it honestly, because the two halves differ:

    • A cross-hub write can genuinely fail to converge from this. UpdateRemote's conflict recovery
      (RebaseSource) waits up to ConflictRebaseBound = 5 s for the writer's own mirror to advance
      past the version the owner refused, then rebuilds against whatever it has. A stalled mirror has
      not advanced — STALE_MIRROR fires, the re-attempt is rebuilt from the same base and is refused
      identically. The stall that disarms that recovery is worst precisely when many concurrent writers
      hit one node, i.e. exactly when refusals cluster ("five in one burst"), and the measured stalls
      were 2.5–2.7 s on an idle 18-core box — a loaded 4-vCPU pod clears 5 s easily.
    • It does not explain the [AdoptedSourceStamp] … IsDirty=true line itself. That watcher writes
      via workspace.GetMeshNodeStream() with no path — the own-node path (UpdateOwn), which never
      goes through MergeGuard or UpdateRemote. The five refusals prove concurrent cross-hub writers
      were active on that node in that window (this defect's precondition), but that is co-occurrence,
      not a causal chain. Write lane degraded on memex-cloud: create chain dies on a NotFound stream, a finished Store/Provision storms compile-state, plus a permanent-silent import order bug and a 2/s identity-cache loop #2229's recurrence still needs its own owner for the own-write half.

    #2291 / #2305's Status=Completed with a placeholder Text is per-field merge resolution and is
    unaffected by this change — a separate problem.

    Suggested retitle

    "The cross-hub ack gate rebuilds the whole node per pending write per frame — delivery stalls under
    a concurrent burst"
    . The refusal in the current title is benign; the delivery lag behind it was not.

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