Skip to content

Plugin-install hub disposed via direct Dispose() discards a deferred SubscribeRequest behind closed init gates #4888

Closed as not planned

Description

@systemorph-com

What is failing

The hub for iris/_Install/Systemorph-MeshWeaver.Plugins was torn down by a direct Dispose() (no routed DisposeRequest, no stated reason) while it still held an accepted SubscribeRequest — id KUJHV11BQk2TQYsY3DubYA, sent from the cache hub — deferred behind its not-yet-open initialization gates [DataContextInit, MeshNodeInit]. At RunLevel=ShutDown the deferred message was discarded; the cache sender was answered ShuttingDown, so a cache-side subscriber never received its subscription.

Probable cause — medium-low confidence

The teardown was invoked externally on a hub that had not finished initializing (both init gates still closed at the moment of disposal). Either (a) a plugin install/recycle flow disposes the install hub before initialization completes — the same "work accepted, gates closed, hub taken down" shape the teardown report was built to name — or (b) the dispose raced the hub's own initialization. The log cannot say which, because the caller did not route a DisposeRequest and stated no reason; the attribution line in the report ("that attribution is who to ask why this hub went down with work still parked behind its gates") is exactly the open question. I could not find the direct-dispose caller in the mesh sources; identifying it is the first task.

Impact

Low. One occurrence on one pod (memex-portal-deployment-69956b6dbc-gx6z6), 2026-09-19 08:59 UTC. One discarded subscription for the cache sender, answered ShuttingDown so the sender can resubscribe on a fresh activation. But the discard means the deferred work is gone for good — if the dispose-instead-of-recycle is deliberate, the cache client's subscription silently never lands.

Where to look

  • Start from the MessageService [DISPOSE-DISCARD] report site (MeshWeaver.Messaging.MessageService, event 7301) — it records the deferral gates and the absence of a routed DisposeRequest.
  • Find the caller of the direct Dispose() on the install hub for Systemorph-MeshWeaver.Plugins under the iris mesh — a plugin install/recycle path is the likely owner; have it either route a DisposeRequest with a reason or wait for the init gates to open before disposing.
  • Background: Teardown Layers, Hub Disposal Model, and Refused replies during teardown for the drain-before-dispose contract this violates.

Evidence

Fingerprint 03a2bc711f5e4501
Category MeshWeaver.Messaging.MessageService
Severity Error
Namespace memex-cloud
Pods memex-portal-deployment-69956b6dbc-gx6z6
Occurrences 1
First seen 2026-09-19 08:59:08Z
Last seen 2026-09-19 08:59:08Z
Recent log lines
2026-09-19 08:59:08Z memex-portal-deployment-69956b6dbc-gx6z6 fail: MeshWeaver.Messaging.MessageService[7301]
      [DISPOSE-DISCARD] Hub iris/_Install/Systemorph-MeshWeaver.Plugins is disposing with SubscribeRequest (id=KUJHV11BQk2TQYsY3DubYA, from cache/TE-NTdwZF0a2kvW15BoYlA) still deferred; initialization gates closed at deferral: [DataContextInit,MeshNodeInit] — the message is NOT processed; the sender is answered ShuttingDown. RunLevel=ShutDown. This teardown was requested by a direct Dispose() (no routed DisposeRequest); why: reason not stated by the caller. Accepted work must be drained before a hub goes down — that attribution is who to ask why this hub went down with work still parked behind its gates.

Re-addressed by the current identity function: this incident inherited d2249f800ffc2577 (Systemorph/MeshWeaver.Plugins#1796). Those nodes are superseded and will not fold, file or comment again.

Opened automatically from Admin/_LogIncident/03a2bc711f5e4501. Recurrences are folded into this issue rather than opening new ones.

Activity

  1. rbuergi commented on Sep 20, 2026

    @rbuergi
    Contributor

    The first task is answered: the caller is MessageHubGrain.OnDeactivateAsync

    "I could not find the direct-dispose caller in the mesh sources; identifying it is the first task."

    It is not in the mesh sources - it is in core, at src/MeshWeaver.Hosting.Orleans/MessageHubGrain.cs:

    logger.LogInformation("Grain {GrainId} deactivating: reason={Reason}", grainId, reason.ReasonCode);
    ...
    hub.CancelCurrentExecution();
    hub.Dispose();          // no routed DisposeRequest, no reason

    A per-node hub in Orleans is wrapped by a grain, and when Orleans deactivates that grain - idle collection, silo shutdown, rebalancing - it disposes the hub directly. That is the ordinary teardown path, not an exotic one, which is why the report could not attribute it: it is the same call for every reason Orleans might have.

    And the reason was available the whole time

    The grain logs reason.ReasonCode one line before disposing. At Information - a level the red-log pipeline never captures - so the [DISPOSE-DISCARD] Error that becomes a ticket could not see it. MessageHub.DisposalAttribution's own remarks already recorded what that cost, on Admin/_LogIncident/d2249f800ffc2577: 364 occurrences, 2026-09-08 to 2026-09-14, 13 pods, every one naming the discarded message, its sender and the gates it sat behind, and none naming the teardown.

    So the question this issue's report ends with had an answer a few microseconds and one log line away, and they never met.

    Fixed in #4960

    MessageHub.NoteDirectDisposalBy(requestedBy, reason) - the direct-dispose sibling of NoteCascadeFrom - and the grain now passes Orleans' ReasonCode and Description. First cause wins, so a hub already asked to recycle by name keeps that attribution when the deactivation catches up afterwards; and a disposer with genuinely nothing to say still reports as having stated nothing rather than leaving a blank clause.

    What stays open here

    Your second question - whether the plugin-install flow should route a DisposeRequest with a reason, or wait for its init gates, instead of the hub being disposed mid-initialization with [DataContextInit, MeshNodeInit] still closed.

    That is a behaviour change to the install path and needs the attribution to be decidable first, which is what #4960 provides: the next occurrence will name which deactivation reason took the hub down. If it reads as idle collection, the install hub is being reclaimed while it still holds accepted work and the remedy is on the lifetime side; if it names a shutdown or rebalance, it is the race in your option (b) and the remedy is different. Those two have opposite fixes, and until now the log could not tell them apart.

    2026-09-20, Claude Opus 5.

  2. added
    area:messagingCore subsystem: message hubs - delivery, disposal, lifecycle
    sev:MMedium - secondary path broken, or easy workaround
    on Sep 20, 2026
  3. rbuergi commented on Sep 21, 2026

    @rbuergi
    Contributor

    Consolidation 2026-09-21 — 8 tickets folded here

    Folded as duplicates: #5104 #5106 #5110 #5117 #5119 #5122 #5126 #5128.

    They split by what TRIGGERED the teardown, not by what is broken. One code path in MeshWeaver.Messaging.MessageService discards work it has already accepted while that work sits behind DataContextInit/MeshNodeInit gates, answering the sender ShuttingDown. Trigger set measured in a single day:

    trigger tickets occurrences
    direct Dispose() on a plugin-install hub this issue —
    operator MeshOperations.Recycle (Recycle tool / Compile button) #5106, #5119 6
    RecycleCascade from a NodeType (Hosting/TriageItem) #5104, #5110, #5117 102
    overlay self-heal DisposeRequest #5122, #5126 1 (filed twice)
    stale-build convergence self-recycle #5128 5

    The stale-build trigger matters most: Modules:AutoRecycleOnStaleBuild is off in code but set true fleet-wide by the AKS chart, so on every production portal this fires as a routine consequence of deploying.

    The measurement that decides the verdict — not yet taken

    #5122 frames it exactly: the deferred-work accounting works as designed (the message is attributed, not silently dropped) and the ShuttingDown answer is deliberate, so the protocol already supports client retry. Whether the cache/… sender re-subscribes on ShuttingDown is what no log shows, and it decides whether the fix is drain-before-teardown (framework) or re-subscribe-on-ShuttingDown (client). Until that is measured the user-visible impact is unproven, which is why the severity here stays sev:M rather than being raised.

    Precedent checked and found not to cover it: Doc/WhatsNew/2026-09-13-recycling-a-node-waits-for-an-install-writing-under-it added waiting for writes under a recycled node; accepted subscribe/unsubscribe work deferred behind init gates is not covered.

    🔗 Cross-group link: #5110's discarded client, cache/wpWb1fSJPUacoVxY6LnltQ, is the head-of-line destination in #5129–#5134 (folded into #5009) ~47 minutes later. See #5009 for that thread.

    Kept open separately: #4866 (the overlay self-heal recycling every Store/Plugin-bound hub at once — a scope defect, not a shedding defect) and #3986 (a discarded accepted click, user-visible, sev:H).

  4. rbuergi commented on Sep 21, 2026

    @rbuergi
    Contributor

    Cluster triage: this symptom has five distinct roots

    Reviewed together with #1540 #1547 #1548 #3243 #3593 #2833 #2480 #5064 #4859 #5136 #4847 #4883 #4888 #4961 — every one of them reports ObjectDisposedException with Autofac.Core.Lifetime.LifetimeScope.ThrowDisposedException() on top, or a teardown that did not finish. They are not one bug. The grouping, the discriminators and the evidence are committed as Doc/Architecture/DisposedScopeAndDyingHubs (added in #5159).

    Root: a direct Dispose() on a hub that had not finished initializing. Still open — the caller is not identified.

    Grouped in Doc/Architecture/DisposedScopeAndDyingHubs with #3593, #4847 and #4883.

    I could not find the direct-Dispose() caller either, and I want to record the one place I looked hardest
    so the next person does not repeat it: PackageInstaller.SettleRetypedRoot does tear down a package
    root mid-install, but it routes a proper DisposeRequest with a stated Reason
    (RetypedRootRecycleReason) off NodeOperationIssuingHub, and then holds the install on
    WaitForRootReady. That is the correct shape and is therefore not this report, whose [DISPOSE-DISCARD]
    line explicitly says no routed DisposeRequest, reason not stated by the caller.

    So the caller is elsewhere. The attribution line in the report is the open question, exactly as the issue
    says.

    What the framework contract already gives you, and what this violates: accepted work must be drained
    before a hub goes down. The remedy for whoever owns the caller is one of the two the issue names — route
    a DisposeRequest with a reason, or wait for the init gates to open — not a change at the discard
    site, which is reporting correctly.

    🚨 Not a candidate fix: making the discard silent, or replaying the deferred SubscribeRequest on a fresh
    activation. The first hides it; the second is a retry for a state that should not happen.

  5. rbuergi commented on Sep 22, 2026

    @rbuergi
    Contributor

    (Grouped with #4886 / #2833 / #2480 / #4847 — the five-issue grouping and the pairwise discriminators are on #2480. Short version: this one is NOT a duplicate of any of them; it is neither a budget expiry nor a starvation reading, and it shares only the 2026-09-19 teardown window.)

    The measurement this was waiting on is answerable from the CODE — and the answer changes the question

    The 2026-09-21 consolidation named the open measurement precisely:

    "the protocol already supports client retry. Whether the cache/… sender re-subscribes on
    ShuttingDown is what no log shows
    , and it decides whether the fix is drain-before-teardown
    (framework) or re-subscribe-on-ShuttingDown (client)."

    That is a question about src/, not about a running portal, so I traced it instead of waiting for a
    log.

    It does re-subscribe — and the recovery is one layer below the cache

    MeshNodeStreamCache has no re-subscribe logic at all; its DeliveryFailure handler is the
    late-write seam (LatePatchResponseRegistry) and nothing else. The recovery lives in
    JsonSynchronizationStream.CreateExternalClient, which treats ErrorType.ShuttingDown as a class
    of its own:

    if (ex is DeliveryFailureException { Failure.ErrorType: ErrorType.ShuttingDown })
    {
        ...
        rejectedByRecycle.OnNext(new RecycleRejection(
            "rejected our SubscribeRequest while shutting down",
            ShutdownNack.ExtractActivationTag(ex.Message)));
        return;          // deliberately NOT reduced.OnError(ex), NOT keepAlive.Dispose()
    }

    — then ChargeReArmBudget → OwnerReadyForReAsk (a JOIN on the rejecting instance's
    DisposalCompleted, not a poll) → Resubscribe with the same StreamId. So the discarded
    subscription is not lost by construction, and drain-before-teardown is not required to make this
    path whole.

    But the budget it is charged against was the wrong one, and that IS a defect in src/

    The ride-out bounds two different axes with two different budgets
    (Doc/Architecture/RidingOutAShuttingDownAddress): MaxRecycleReArms counts distinct owner
    activations
    that refused us, MaxSameActivationReAsks counts paced re-asks at one dying
    activation
    . Which one is charged is decided by ShutdownNack.ExtractActivationTag(ex.Message) —
    and this NACK carried no tag, because it was the one owner-side refusal that was hand-written
    instead of composed by ShutdownNack
    :

    $"Hub {Address} was disposed while {delivery.Message.GetType().Name} (id={delivery.Id}) was still
      deferred; initialization gates closed at deferral: [{gates}] — the message was never processed.
      The teardown was {disposal}. The address may reactivate (recycle / restart); retry to get the
      authoritative answer."

    It reads perfectly well — it had even copied the reactivation promise across by hand — and it is
    missing both machine-readable halves:

    missing read by consequence
    the banner Hub {address} is shutting down ShutdownNack.IsAnsweredByOwner, plus the three text classifiers MeshNodeStreamCache.IsTransientOwnerFailure, OrleansRoutingService.ClassifyRoutedFailure, AreaErrorClassifier.IsTransientHubFailure a TRANSIENT refusal read as terminal — the reader stops re-asking an address that is coming back
    the activation tag ChargeReArmBudget, GetMeshNodeOutcome's paced re-probe untagged ⇒ charged against the DISTINCT-ACTIVATION budget, so N discards by ONE activation exhaust a budget sized for N DIFFERENT ones, and the give-up line then reports a recycle storm that never happened

    That is exactly the drift ShutdownNack was factored to prevent (the #2376 review found two sites
    that had drifted in opposite directions), and this site had simply never been moved onto it.

    Fixed in #5272, not here

    Correction to this comment as first posted. I wrote this half as part of #5281. Another agent reached the identical root from #4866 about ten minutes earlier and opened #5272, which is narrower, carries a production measurement I did not have (105 discards in one sub-second window on one pod), and also extends OwnerAnswerRecognitionGuard — closing the enumeration blind spot that let this site stay unlisted as its SEVENTH terminal. #5272 owns the fix; I have removed the overlapping files from #5281, which now carries only an unrelated pooled-leaf fix. Two independent routes to the same root is good evidence the root is real.

    #5272 composes the discard NACK with
    ShutdownNack.RetryForTheAuthoritativeAnswer(Address, $"RunLevel={hub.RunLevel}, {ActivationTag()}", …)
    — whose own summary is this case in its own words: "work this hub ACCEPTED and can no longer
    finish — a queued turn that came too late, machinery that can no longer be created, a gate that
    can never open
    "
    . The gates and the teardown attribution ride in the what clause, so nothing the
    line already carried is traded away.

    Pinned by DeferredDeliveryNackedOnDisposeTest.ADiscardedDeferredDelivery_IsRecognisedAsTheOwnersAnswer (#5272),
    which asserts both halves through the producers (ShutdownNack.Banner,
    ShutdownNack.FormatActivationTag(theHub) — the exact tag for that activation, not merely "some hex
    is present") and asserts the owner predicate is FALSE for a different address so a trivially-true
    match cannot pass it. Control, on the unfixed build:

    Expected "Hub recognisable/1 was disposed while GatedRequest (id=…) was still deferred; …"
       to contain "Hub recognisable/1 is shutting down"
    total: 6  failed: 1
    

    What stays open here, and it is still a behaviour call

    Your second question, unchanged: whether the plugin-install flow should route a DisposeRequest
    with a reason, or wait for its init gates, rather than being disposed mid-initialization. My trace
    narrows it but does not decide it:

    • Drain-before-teardown is not needed to keep the SUBSCRIPTION, because the client re-asks.
    • It may still be wanted, because the re-ask budget is finite and the ride-out ends in an
      orphaned-but-not-faulted stream: past the budget the give-up is one Warning and the cache entry
      is never MarkFaulted, so nothing re-probes it and it leaves only on the 10-minute idle sweep —
      which a still-subscribed GUI reader keeps resetting.
    • And fix(messaging): a direct Dispose() can name its cause, and Orleans now does (#4888) #4960's attribution decides which of your (a)/(b) it is: the next occurrence names the Orleans
      ReasonCode. Idle collection and shutdown/rebalance have opposite remedies.

    So: not closing this. The discard's machine-readability is fixed; the lifetime question is not,
    and it needs the attribution reading you are already waiting for.

  6. rbuergi commented on Sep 23, 2026

    @rbuergi
    Contributor

    Addressed in #5609 (open; this comment will be updated at merge).

    This issue fires at the site shared by #4888, #5424 and #5589: [DISPOSE-DISCARD] for a SubscribeRequest from a cache/… sender, parked behind [DataContextInit,MeshNodeInit] of a hub that was torn down before its bring-up finished. The teardown here was an Orleans deactivation, directly or through DirectoryFailure.

    Why this was a false Error rather than a lost message:

    The change. A [ReaskedOnShutdown] marker goes on SubscribeRequest. A marked request's discard reports at Debug with the same facts (gate, sender, teardown attribution), following the rule #4178 set for self-addressed deliveries. An unmarked request from another sender stays Error, because that waiter may take the NACK as final. The NACK itself is unchanged.

    Test. DeferredDeliveryNackedOnDisposeTest.AReaskedRequestDiscardedByABringUpTeardown_IsTeardownNormal_NotAnError uses the production initiator (NoteDirectDisposalBy("Orleans deactivating grain …") + Dispose()). The existing unmarked case is the control. With the fix line disabled, the new test fails.

    What stays true after the roll. This fingerprint stops being filed for subscribes. A [DISPOSE-DISCARD] Error on a post-#5609 image means a NON-re-asked request was discarded, and that one deserves an issue.

    Not established: whether the teardowns themselves were avoidable. DirectoryFailure is Orleans deactivating activations whose directory owner silo is stopping, which is expected during a roll.

  7. rbuergi commented on Sep 23, 2026

    @rbuergi
    Contributor

    #5609 is merged: main at fe33e13a5b, through the merge queue, with the build and the review check both green. It is not yet running: memex.meshweaver.cloud serves 9a61fed964 and memex.systemorph.com serves 39f49494eb, neither of which contains it. It takes effect when an image containing it is rolled out (an owner step). No manual recycle is needed. Leaving this open until a post-roll reading shows the fingerprint has gone quiet on an image that contains fe33e13a5b.

  8. rbuergi commented on Sep 24, 2026

    @rbuergi
    Contributor

    Post-roll sweep 2026-09-24 ~06:50Z: the fix is not live on either portal yet

    What is running.

    • memex-cloud: /api/version returns 9a61fed964. Ops/Status/memex-cloud (06:42:00Z) shows 4/4 replicas on 3.0.0-ci.9263. CD run 9263 built core 9a61fed964 with Plugins 41bcfe968f.
    • memex: /api/version returns 39f49494eb. Ops/Status/memex shows the serving pods on 3.0.0-ci.9218, which is core 39f49494eb with Plugins e9d9283abe. A third pod, on ci.9260, is unready, so the roll is converged: false.

    This issue's fix: #5609 (fe33e13a5b). It is not an ancestor of either running build (git merge-base --is-ancestor, exit 1).

    Where it is. 3.0.0-ci.9287 (CD run 35956222018) is core bf5ac85526 with Plugins c4795a8d5b, and it contains this fix. The registry has sealed it. memex-cloud's self-updater logged [SelfUpdate] handing 3.0.0-ci.9287 to the control lane (https://memex.systemorph…) at 06:47Z. So the roll now waits on the control instance, which is an owner step and was not done here.

    Still open. It closes on a post-roll reading once a ci.9287-or-later image serves the namespace this fingerprint fires in.

  9. rbuergi commented on Sep 24, 2026

    @rbuergi
    Contributor

    Duplicate of #5424 — same log site MeshWeaver.Messaging.MessageService[7301]: [DISPOSE-DISCARD] Hub {hub} is disposing with {message} … still deferred behind [DataContextInit,MeshNodeInit]; consolidated.

    Read before closing: SubscribeRequest from a cache/… sender discarded behind the init gates of iris/_Install/Systemorph-MeshWeaver.Plugins; same shape and same fix as #5424 (#5609, fe33e13). The post-roll reading owed here is the one owed on #5424.

    The fix, verification and any recurrence are tracked on #5424.

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

    area:messagingCore subsystem: message hubs - delivery, disposal, lifecyclebugSomething isn't workingfeature:hub-disposalFeature: hub disposalsev:MMedium - secondary path broken, or easy workaround

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions