Skip to content

A package root is disposed mid-install under a reconcile — Chess, then Hosting, then Chess again; main-cd cannot seal #3499

Closed

Description

@rbuergi

A package's ROOT hub is disposed mid-install, and every write under it then dies on the owner bound

Three independent occurrences in six hours, on three different heads, hitting two different packages. It is not a package's content and it is not any one pull request.

run head when package that wedged
core main-cd #7937 (34058018897) 85ab1dfbe 20:26Z Chess — GATE FAILED — install: Chess
core main-cd #7941 (34061838257) b8accc2b2 after #3475 Hosting (144 files) — same shape; Chess adopted 3/3 and passed
Plugins #1422 gate (34059652860, job 101564568189) — 22:08Z Chess again

#7938 in between sealed fine. So it is a race that lands on whichever package's root recycles under a reconcile at the wrong moment.

🚨 #7937 predates the merge of #3475 and carries unstripped content — that is the control. It rules out the operational-strip work as the cause; #1422 is a victim of this, not its origin.

The sequence, from the Plugins gate shard

22:08:20-25  bake-seed: Prebuilt assembly ADOPTED for Chess/GambitHunt|Game|History at version 0
             — no compile needed; bundle Chess.zip: adopted 3/3          ← no Roslyn ran
22:08:29     [QUIESCE-TIMEOUT] Chess: 1 callback(s) still pending after 2s — forcibly cancelling.
             Pending: CreateOrUpdateNodeRequest…
             [PluginGating] reconcile failed for Chess: Hub Chess was disposed before the
             response arrived
~22:09:00    VERDICT_TIMEOUT / OwnerUnreachable at ~31s on Chess/History, GambitHunt, Game,
             _Policy, _Access/Anonymous_Access, GambitHunt/_Activity/compile-state
~22:09:21    MeshNode Unknown … TimeoutException (~20s)
22:09:38     idempotence: re-install failed: Install of 'Chess/_Policy' failed:
             Inner UpdateNode faulted: TimeoutException
             GATE FAILED — idempotence: Chess — 1 new failure(s)

Everything downstream is consequence: the root is gone, so every write under Chess/** waits out the owner bound. The types themselves were fine — compile=Ok render=ok tests=ok on all three, and 1/1 content asset(s) served.

The likely mechanism, and what would confirm it

The Chess root is a Store/Plugin instance (PluginContent), so this is not the installer's retyped-root recycle. Something disposes the root while PluginGating's reconcile is in flight — the shape reads like a rebind recycle (a hub activated before its node was visible, then retyped by the install's root write). The recycler logs at Debug in that tester, so the log does not name it.

🚨 The pending item is a CreateOrUpdateNodeRequest — correlated work — and there is a MEASURED mechanism that produces exactly one of those, unanswerable, at teardown. From #3261 (DanglingNodeTypeUpdateTest, MESHWEAVER_MSG_TRACE=1 + MeshWeaver.Messaging: Debug):

A hub that has already logged [QUIESCE-OK] still accepts new correlated requests, and even creates hosted hubs for them — the intake gate only refuses from DisposeHostedHubs onward. A request taken on in that window can never be answered.

11.928 [QUIESCE-START] TestData/dnt…: 0 pending callbacks at dispose entry: <none>
11.928 [QUIESCE-OK]    TestData/dnt…: drained 0 callback(s) in 0ms
11.968 Start processing SubscribeRequest (ID: p2qsFux3…, cache/iIN4… -> TestData/dnt…)
11.969 Creating new hosted hub for address sync/4wzOafy… in host TestData/dnt…

Stated as a fit, not a diagnosis — that trace shows [QUIESCE-OK] then late intake, while this shows [QUIESCE-TIMEOUT] with something already pending. They may be two bugs. What the intake window does explain is how a request that can never be answered comes to be pending at all, which is the part the gate log does not show.

The discriminator: whether the CreateOrUpdateNodeRequest was accepted before or after [QUIESCE-START]. That needs MeshWeaver.Messaging at Debug in the tester image, alongside the recycler, so the intake timestamp can be read against the quiesce line.

🚨 Not the fix: widening the 2s quiesce budget

That is the explicit conclusion from #3261's measurement and it holds independently of whether the two shapes are one bug: a bigger budget converts a leaked callback into a slower leaked callback. The same goes for the 31s owner bound and the install timeout — those are reporting a root that is gone, not a bound that is too tight.

Why it matters now

main-cd cannot produce a sealed set. The last one is #7938 (aa4075832), which predates #3475; every post-merge run since has either failed the seal on this wedge or skipped it behind a module-test flake (#7946, MeshWeaver.AI FullCrudWorkflow timeout). So this race is currently the thing standing between a merged core fix and any deployable wave — Education's pin bump and every downstream instance wait on it.

Acceptance

  • A package root is not disposed while a reconcile addressed to it is in flight; or, if it must be, the requester is told (a NACK) rather than left to time out.
  • The tester image logs the recycler and MeshWeaver.Messaging at a level that names which recycle fired, so the next occurrence is attributed in one read.
  • No quiesce, owner or install bound is widened.

Provenance

Gate-shard analysis and the three-run attribution by the session working MeshWeaver.Education; the #3261 intake-window measurement and the acceptance framing by this one. Filed jointly so neither half is lost.

Activity

  1. added a commit that references this issue on Sep 6, 2026
  2. rbuergi commented on Sep 6, 2026

    @rbuergi
    ContributorAuthor

    Root-caused, fixed, and the issue's own hypothesis falsified by its own control

    PR: #3505. The durable write-up is the doc page
    Doc/Architecture/WriteVerdictTotality
    → "Totality is not enough — the verdict's CODE decides whether the write survives"; this comment is
    a pointer to it.

    The discriminator, answered: BOTH — and the run that wedged the seal was BEFORE

    No new instrumentation was needed: the [QUIESCE-TIMEOUT] trails already carry
    RECEIVED runLevel=<level>@<issuing hub>.

    run hub runLevel at intake
    #7937 Cornerstone, Publish, RemoteControl, Voice Quiescing
    #7937 Chess (the one that failed the gate) Started
    #7941 RolePlay Started
    #7941 Video, Essentials Quiescing
    Plugins #1422 Chess Quiescing

    Six of nine are #3261's intake window. They are two bugs, and the intake window is benign in
    every occurrence measured — the requester gets a typed HubDisposedBeforeResponseException. Filed
    separately as #3506.

    🚨 The base rate falsifies the framing

    Counting all four bake jobs, each with per-request tracing on (handler-side fate present in every
    one, so no count below is a missing denominator):

    bake job verdict [QUIESCE-TIMEOUT] reconcile failed VERDICT_TIMEOUT
    core #7937 FAILED install: Chess 6 10 5
    core #7938 SEALED 10 12 0
    core #7941 FAILED install: Hosting 5 8 0
    Plugins #1422 FAILED idempotence: Chess 3 7 10

    A package root disposed under an in-flight reconcile is at its MAXIMUM in the run that sealed. It
    is normal and it is answered. What separates a seal from a failure is the third column.

    The actual root (#7937 + Plugins #1422)

    Ten of ten VERDICT_TIMEOUT trails on the gate run — and thirteen on #7937 per #2543's own
    measurement — show the patch had already committed:

    PATCH_MERGE_STAMPED v=2 refused=0 → PATCH_ECHO_SEEN  ⇒ (nothing, 31s)
    

    Only the durability leg was owed, and it faulted on a lifetime scope that was closing. That fault
    reaches ClassifyPatchException — the ONE funnel every owner-side patch fault passes through — and
    fell out of its _ => arm as MeshNodeErrorCode.Unknown, which is TERMINAL by the enum's own
    contract. The writer reported a lost write for a patch that had committed, and the install failed.

    #2543 (merged 21:49Z, after all three runs) caught the escaping throw so the writer is no longer
    left in 31 s of silence — and then hands it a prompt Unknown. Same failed install, 31 s sooner. Its
    own test's because says "a NACK the writer can retry on"; the verdict could not be retried. #3505
    makes that assertion true and enforceable.

    The rule was already written down one layer over, in HubDisposingException.IsDisposedContainer:
    "a hub whose scope has been closed cannot serve anything, so a delivery that faults this way must be
    answered as RETRYABLE (the address reactivates) rather than as a result."
    ClassifyPatchException
    now consults it first and answers OwnerDisposing, which MeshNodeStreamExtensions already
    re-enqueues against the fresh activation, capped and re-diffing. No bound moves.

    #7941 is a THIRD mechanism, and not this one

    Zero unanswered write verdicts; instead two JsonSynchronizationStream … resubscribe failed lines —
    zero in the sealed control — whose parked stream leaves the outer CreateOrUpdateNodeRequest
    with no terminal one layer above the verdict watcher. That is #3498's shape. Classification cannot
    seal that run; both fixes are needed.

    Acceptance

    • ✅ the requester is told, truthfully, in the verdict its own machinery acts on;
    • ✅ mw-plugin-test now raises MeshWeaver.Graph.Configuration,
      MeshWeaver.PluginCatalog.PackageInstaller and MeshWeaver.Messaging.MessageHub to Information,
      so the recycle names itself and [QUIESCE-START] answers the discriminator in one read;
    • ✅ no quiesce, owner or install bound widened.

    Falsified: with the classification reverted, three pins fail with
    Expected value to be OwnerDisposing …, but found Unknown.

  3. added a commit that references this issue on Sep 6, 2026
  4. rbuergi commented on Sep 7, 2026

    @rbuergi
    ContributorAuthor

    Closed by hand — #3505 merged as 155b4fa17, verified an ancestor of origin/main

    The merge queue does not fire Closes links, so this is manual and the ancestry was measured.

    🚨 This issue's stated cause was falsified by its own control, and the fix is for something else.

    What the control said

    Counting all four bake jobs, tracing on in every one so no count is a missing denominator:

    bake job verdict [QUIESCE-TIMEOUT] reconcile failed VERDICT_TIMEOUT
    core #7937 FAILED install: Chess 6 10 5
    core #7938 SEALED 10 12 0
    core #7941 FAILED install: Hosting 5 8 0
    Plugins #1422 FAILED idempotence: Chess 3 7 10

    A root recycled under an in-flight reconcile is at its MAXIMUM in the run that sealed. Read across
    the three failures alone it looks causal; the control turns it into a correlate of load. The
    discriminating column is the one the title did not point at.

    And it splits the failures across two bugs. #7941 has zero unanswered write verdicts and two
    JsonSynchronizationStream … resubscribe failed lines, zero in the sealed control — that is #3498,
    fixed by #3501 (99bafdc10). #7937 and Plugins#1422 are this one.

    The actual root

    In ten of ten VERDICT_TIMEOUT trails the patch had already committed —
    PATCH_MERGE_STAMPED v=2 refused=0 → PATCH_ECHO_SEEN ⇒ nothing. Only the durability leg was owed; it
    faulted on a closing lifetime scope; ClassifyPatchException dropped it out of its _ => arm as
    MeshNodeErrorCode.Unknown, terminal by the enum's own contract. The writer reported a lost write
    for a patch that had landed, and the installer failed the package.

    🚨 #2543 merged at 21:49Z — after all three runs — so it reads like the answer and is not. It
    converts 31 s of silence into a prompt Unknown. Same failed install, 31 seconds sooner.

    The fix changes classification only: HubDisposingException.IsDisposedContainer already stated
    the rule one layer over, and ClassifyPatchException now consults it first, over the exception
    graph rather than an InnerException loop. No bound moved, no watchdog, no new retry — the
    re-enqueue already existed, is capped, and re-diffs each attempt.

    The discriminator this issue asked for

    Answered without new instrumentation: the [QUIESCE-TIMEOUT] trails already carry
    RECEIVED runLevel=<level>@<hub>. Both shapes are live. Six of nine intakes are Quiescing —
    #3261's window — and every one is benign (the requester gets a typed answer). Chess in #7937, the one
    that failed the gate, is Started. The intake window is filed as #3506 rather than described as
    covered.

    Known residual, recorded rather than left implicit

    A review of this PR established that the arm it feeds is selected for, not merely shared with,
    #3477: the closed-scope fault occurs after HostedHubsCollection closes the hosted hub's scope,
    at which point the hub is past DisposeHostedHubs, its own Post is refused, and the verdict routes
    through ILatePatchVerdictSink by construction — the late half, which is the half #3477
    measured going dark. So the cost of a false "retryable" is a capped idempotent re-diff plus whatever
    #3477 is
    , which is silent today. The asymmetry claim was replaced, not softened, in both its homes;
    #3477 carries the instrumentation design that would make that case loud.

    Follow-ups left open on purpose: #3506 (the intake window), #3477 (the silent re-enqueue).

  5. rbuergi commented on Sep 7, 2026

    @rbuergi
    ContributorAuthor

    Control measured, and it sharpens the framing: the recycle is deterministic; only the collision is a race.

    Plugins main's own run 34063118498 (head 83d399127, 22:08Z — before #1422 merged, so unstripped Chess content; same tester as #1422's red run) shows the identical sequence during the Chess install and PASSES:

    23:22:46 bake-seed: Prebuilt assembly ADOPTED for Chess/GambitHunt at version 1 …
    23:22:49 bake-seed: Prebuilt assembly ADOPTED for Chess/Game at version 0 …
    23:22:52 bake-seed: Prebuilt assembly ADOPTED for Chess/History at version 1 …
    23:22:57 [QUIESCE-TIMEOUT] Chess: 0 callback(s) still pending after 2s — forcibly cancelling
    23:23:06 ── Chess: installed (34 written, 0 unchanged); checking 3 NodeType(s)…
    23:26:45 [PASS] Chess (34 node(s), 3 type(s)) [1/1 content asset(s) served]
    

    versus #1422's red run (job 101564568189, stripped content):

    22:08:25 bake-seed: bundle Chess.zip: adopted 3/3 prebuilt assembly(ies)
    22:08:29 [QUIESCE-TIMEOUT] Chess: 1 callback(s) still pending after 2s — forcibly cancelling. Pending: …CreateOrUpdateNodeRequest…
    22:08:29 [PluginGating] reconcile failed for Chess: Hub Chess was disposed before the response arrived
    22:09:00 VERDICT_TIMEOUT … bound=31s on Chess/History, GambitHunt, Game, _Policy, _Access/Anonymous_Access, GambitHunt/_Activity/compile-state
    

    Same root (Chess, a Store/Plugin instance), same moment (a few seconds after the three in-package types adopt), same [QUIESCE-TIMEOUT] dispose of the root mid-install — on stripped and unstripped content alike. The only difference is 0 versus 1 pending callback: whether PluginGating's CreateOrUpdateNodeRequest to the root happened to be in flight when the recycle fired. So the discriminator is not the content and not the package; it is the reconcile's timing against a recycle that always happens. That also says where the fix is not: nothing about Chess or Hosting, and nothing #1422 changed.

  6. rbuergi commented on Sep 7, 2026

    @rbuergi
    ContributorAuthor

    🚨 Correcting this closure: the count-based falsification is narrower than I wrote it

    Amending rather than editing, because the overstatement was acted on and the record should show both.

    I wrote that this issue's stated cause was "falsified by its own control". That is true of one
    proposition and not of another, and the distinction turns out to matter within the hour.

    What the control DOES falsify: "how many roots recycle under an in-flight reconcile" as the
    discriminator. [QUIESCE-TIMEOUT] at its maximum (10) in the run that SEALED settles that
    decisively, and it is what split #7941 out as #3498's shape.

    What it does NOT falsify: "the root of the package BEING INSTALLED was disposed under its own
    install."
    That is this issue's original sentence, and the count says nothing about it — the
    discriminator there is not how many roots recycle, but whether the recycled root is the one
    installing
    . Those are different claims and only the first was tested.

    The second one is live, and is now filed as #3510 (found by the release session on core CD 7950,
    f55b9f4ab — #3480 in, neither fix):

    The open measurement, and it was deferred here rather than answered: who disposed Hosting?
    Not in the log at that level — no [QUIESCE-START] Hosting, no dispose source. Hypothesis (2) from
    this issue's own body, the rebind recycle, is the leading candidate and was never measured,
    because hypothesis (1) was found first.
    That is the honest state of it.

    This issue stays closed: the defect it names — a committed patch reported as a lost write — is real,
    fixed and falsified in both directions. But it should not be read as having closed the installing
    root's own disposal
    , which #3510 now carries.

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