Skip to content

ThreadAgentIntegrationTest flakes on shard 4 again — now AddressRecyclingException, not the #1362 timeout #2025

Closed

Description

@rbuergi

MeshWeaver.AI.Test.ThreadAgentIntegrationTest.FullFlow_CreateThread_SendMessage_StreamResponse_SaveReply is intermittently failing shard 4 again. The symptom has changed since #1362 was closed, so this is a separate defect rather than that one reopening.

Then vs now — same test, same line, same node, different failure

#1362 (closed 2026-08-13) Today (2026-08-21)
Exception TimeoutException: GetMeshNode('ACME/ProductLaunch') timed out after 60.0s AddressRecyclingException: GetMeshNode('ACME/ProductLaunch'): the owning hub was still recycling (ShuttingDown) after 110 probes
Inner — DeliveryFailureException: Hub ACME/ProductLaunch is shutting down (RunLevel=Dead) — cannot process RawJson
Reads as the hub never activated here the hub is going away while a read is in flight

Both fail at ThreadAgentIntegrationTest.cs:191 (StartChatWithOwnAgent → ReadNode(AgentContextPath)), from :266.

Read together, #1362's fix looks like it did its job — a silent 60s hang became a diagnosable, promptly-thrown error naming the run level. What it did not remove is the race underneath: a per-node hub can be recycling/dead exactly when this read arrives, and the read fails rather than waiting for or re-activating the successor. 110 probes is not a slow activation; it is a hub that stays ShuttingDown for the whole probe budget.

Occurrences (both today, both reproducible from the logs)

Why it is worth fixing rather than re-running

It reds PRs whose diffs cannot reach it, and the honest diagnosis costs a full cycle each time: you have to pull the annotations, find the same test on a main run to clear your own change, then re-run. That happened twice today on unrelated work.

Relates to #1362 (same test and shard; different failure mode).

Activity

  1. rbuergi commented on Aug 21, 2026

    @rbuergi
    ContributorAuthor

    Widening this with a day's evidence: it is not one test. Four distinct tests reddened PRs today, none reachable from the diff that carried them.

    PR Diff Failed test
    #2020 3 files, module static-asset provider AI.Test.ThreadAgentIntegrationTest.FullFlow_…
    #2021 view-pack lanes AI.Test.ThreadTokenUsageTest.CompletedRound_…
    #2028 Speech contract split Hosting.PostgreSql.Test.UserDirectoryCompletenessTests.AUserOutsideTheMostRecentlyModifiedPage_…
    #2029 one line — a version string in Directory.Build.props Content.Test.CommentDoneReactivityTest.EditingComment_DoneShowsEditedText_WithoutRefresh

    #2029 is the control, and it is about as clean as one gets

    Its entire diff is 3.0.0-rc6 → 3.0.0-rc7 in one property. There is no path from a version string to comment-editing reactivity. So that red is environmental with certainty, not inference — which means the baseline is "an arbitrary PR can go red on an unrelated test", and every such red costs a maintainer the same manual clearing ritual: pull the annotations, hunt the same test on a main run, re-run.

    Worth stating plainly because it cuts the other way too: on #2021 I read the first failing shard, recognised a known flake, and was reasoning toward "unrelated" — while the other failing shard held a genuine defect that would have shipped a broken framework identity. A noisy baseline is not just wasted cycles; it trains exactly the reflex that lets a real failure through.

    UserDirectoryCompletenessTests (#1936, added 2026-08-21) has no prior failure in the last 10 main runs and passes 2/2 locally on the branch that failed it, so it looks like a newly-landed test finding its own flake rather than a regression.

    No claim here about a single root cause — these span AI, PostgreSql and Content. Recording the rate as the thing to act on.

  2. rbuergi commented on Aug 25, 2026

    @rbuergi
    ContributorAuthor

    Not reproduced, and not observed in CI since — here is the measurement, and what it does NOT prove

    Swept the last 300 MeshWeaver Build and Test runs (2026-08-23 → 2026-08-25), pulling the
    [FAIL] lines out of every attempt of every run rather than only runs whose final conclusion was
    failure — a re-run-to-green otherwise hides the attempt that actually failed, which is exactly how
    this flake presents.

    MeshWeaver.AI.Test.ThreadAgentIntegrationTest.FullFlow_CreateThread_SendMessage_StreamResponse_SaveReply
    appears 0 times in that window. Two neighbours in the same assembly did fail
    (ThreadTokenUsageTest.CancelledRound_… ×3, AgentToolCancellationTest.GetVersions_ParkedOnAStalledStore_… ×3),
    so the assembly was being exercised and shard 4 was not skipped.

    🚨 That is not a clearance. The window starts 2026-08-23 and both occurrences in the issue are
    from 2026-08-21, so the sweep simply does not overlap them. A two-and-a-half-day quiet spell on a
    race that was seen twice in one day is weak evidence at best.

    What the failure is saying, for whoever picks this up

    The exception names its own mechanism precisely, and it is worth writing down because the surface
    has moved since #1362:

    AddressRecyclingException: GetMeshNode('ACME/ProductLaunch'): the owning hub was still recycling
                               (ShuttingDown) after 110 probes
    inner: DeliveryFailureException: Hub ACME/ProductLaunch is shutting down (RunLevel=Dead)
    

    GetMeshNodeOutcome's re-probe is not a fixed number of attempts — it re-probes for the whole
    caller budget, first NACK immediately and then on the pacing timer. 110 probes therefore means the
    address answered ShuttingDown for the entire budget: not a slow activation, and not a probe that
    gave up early. RunLevel=Dead on every one of them says the probes kept resolving to the same
    dead instance rather than to a fresh activation.

    Two candidates, neither confirmed:

    1. The overlay self-heal recycling the instance that a request just activated. This exact
      sequence is already written down as the cause of this test's earlier stall — see
      NodeTypeEnrichmentHelpers.IsRecompileSettled's remarks: "that fallback arms a
      WithOverlaySelfHeal watcher gated at the SAME version, so when the recompile we started lands a
      newer usable build the watcher immediately recycles the freshly-created instance hub — destroying
      the request that triggered the activation (the ThreadAgentIntegrationTest 60 s stall)"
      . ThreadAgentIntegrationTest blocks shard 4: a per-node hub's GetDataRequest handler runs and never answers #1362
      turned the silent 60 s hang into this diagnosable error; it did not remove the recycle underneath.
    2. A recycled hub that stays resolvable. In HostedHubsCollection, the removal of a hub from the
      registry on disposal is registered in Add(hub) — hub.RegisterForDisposal(h => messageHubs.TryRemove(h.Address, out _))
      — but the GetHub single-flight path publishes with a bare messageHubs[a] = newHub; and no such
      registration. Worth checking whether a hub created through that path is ever evicted, because if
      it is not, every probe after its disposal resolves to the dead instance and AddressRecyclingException
      is the guaranteed outcome rather than a race. (I did not chase this to a conclusion; recycle
      plainly works in the common case — SilentReadNackTest.GetMeshNode_WhenOwnerIsDisposedMidRead_RecoversOnTheReProbe
      passes — so there is something I have not found. Flagging it as the first thing to check.)

    Also relevant and merged since this issue was filed: #2252's author found that routing a message to
    a deactivating Orleans grain re-activates it
    , and #2270 closes the window where ApplicationStopping
    has fired while the membership oracle still reports Active. Either could have changed this test's
    behaviour without anyone attributing it here — which is another reason the quiet window above should
    not be read as "fixed".

    Leaving open.

  3. rbuergi commented on Aug 26, 2026

    @rbuergi
    ContributorAuthor

    Fresh occurrence with the full numbers (2026-08-26, shard 3)

    Still live, and now on shard 3 rather than 4 — so it is not shard-bound.

    AddressRecyclingException : GetMeshNode('ACME/ProductLaunch'): the owning hub was still recycling
    (ShuttingDown) after 109 probe(s) over 60.0s (budget 60s) — the address is recycling, NOT absent.
    ---- DeliveryFailureException : Hub ACME/ProductLaunch is shutting down (RunLevel=Dead) — cannot
         process RawJson; the address may reactivate (recycle / restart). Rejecting now.
      at ThreadAgentIntegrationTest.StartChatWithOwnAgent(…) line 191
    

    Test duration 60.45 s (09:26:22.173 → 09:27:22.626) — i.e. the entire budget, so a hang, not a wrong answer.

    What the numbers say

    Everything on the caller's side worked. The failure was classified ShuttingDown, the caller correctly read it as "ask again", and it asked again 109 times over 60 seconds. The hub was at RunLevel=Dead for all of them.

    So the bug is not the retry or the classification — it is that the address advertises itself as recoverable ("may reactivate") while sitting in a state it never actually leaves. 109 consecutive rejections is not a race being lost; it is a state that never changes.

    The shape worth checking first: the probe is what would normally cause reactivation, and the intake gate rejects it because the hub is Dead. If the dead instance stays registered, the thing that would heal the address is exactly the thing the address refuses — and no amount of retrying can converge. That would explain 109/109 rather than an occasional miss.

    I have not verified that mechanism; it is where I would start.

    Not the same bug as #2350

    I root-caused a different member of this flake family today (#2350 / #2351): the intake gate returned an unclassified failure, so a shutdown race reached the sender as Unavailable instead of ShuttingDown. That one fails in 2.3 s with a real assertion.

    This one is its mirror image — classification correct, recovery impossible — and fails in 60 s. Fixing #2350 will not fix this, and I have said so on #2346 so the two are not conflated.

  4. rbuergi commented on Aug 26, 2026

    @rbuergi
    ContributorAuthor

    A structural route to "Dead but still registered" — offered as analysis, not as the proven mechanism

    Chasing why the address never reactivates, I found a defect that would produce exactly this. I could not confirm it fired in the observed run — see the caveat at the end — so treat this as a lead with a cheap confirming experiment, not a diagnosis.

    Registry eviction is contingent on a path with three fault branches

    A hub removes itself from its parent's collection through a registered disposable:

    // HostedHubsCollection.cs:189
    hub.RegisterForDisposal(h => messageHubs.TryRemove(h.Address, out _));

    Registered disposables run in disposables.Dispose() — which is the last statement of DisposeImpl() (step 2, after the reactive dispose-action composition in step 1).

    Now look at what marks a hub Dead:

    path DisposeImpl() still sets Dead
    normal (MessageHub.cs:2181) called bare yes — and on the catch branch too
    normal catch skipped after the throw yes, then SignalDisposalFaulted
    normal finally — yes (backstop)
    force-teardown (:1789) try { DisposeImpl(); } catch { log warning } yes, regardless

    So if DisposeImpl throws anywhere before its final disposables.Dispose(), the hub is marked Dead and announces completion — while never being removed from the collection.

    The address is then owned by a dead instance: GetHub finds the existing entry rather than creating a new one, every probe routes to it, the intake gate rejects it with "is shutting down (RunLevel=Dead) — the address may reactivate", and it cannot. 109 consecutive rejections is what a permanently-poisoned address looks like, as opposed to a race being lost repeatedly.

    The fix this suggests

    Eviction should be tied to the Dead transition, which every path above reaches, rather than to a disposable that three of them can skip. RunLevelChanged already completes at Dead, so the collection can evict on that signal.

    Putting disposables.Dispose() in a finally inside DisposeImpl would also close it, but leaves eviction coupled to disposal succeeding far enough — the same shape, just narrower.

    🚨 The caveat, stated plainly

    I grepped the failing run for Error during shutdown of hub, [FORCE-TEARDOWN] and DISPOSAL DEADLOCK and found none. So there is no evidence DisposeImpl actually threw there.

    There is also a live alternative I have not excluded: ACME/ProductLaunch is a mesh NODE address, and those may be resolved through the node-hub registry rather than a plain HostedHubsCollection — in which case the eviction path that matters is a different one and this analysis is about the wrong registry.

    Cheapest confirming experiment: make DisposeImpl throw (a registered dispose action that throws is the obvious lever), then assert the address is re-creatable afterwards. That proves or kills the structural half deterministically, without needing the flake to reproduce.

  5. rbuergi commented on Aug 26, 2026

    @rbuergi
    ContributorAuthor

    Retracting most of my earlier hypothesis, and narrowing to what survives

    I proposed that DisposeImpl faulting before its final disposables.Dispose() would leave a hub marked Dead but still registered. Having read the code properly rather than reasoning from its shape, that is largely wrong and I want it off the table before someone spends time on it.

    Step 1 of DisposeImpl cannot throw. Every reactive dispose leg is wrapped twice —

    try { return action(this).Catch<Unit, Exception>(ex => { TryLog(...); return Observable.Return(Unit.Default); }); }
    catch (Exception ex) { TryLog(...); return Observable.Return(Unit.Default); }

    — a synchronous throw is caught, an observable fault is Catch-ed, and the Merge subscribe carries an onError. So step 2 is reached.

    And eviction precedes Dead on both paths. Normal: DisposeImpl() → messageService.Dispose() → RunLevel = Dead. Force-teardown: same order, with DisposeImpl in a swallowing try/catch. The registry removal registered at HostedHubsCollection.cs:189 runs inside disposables.Dispose(), i.e. before the hub is marked Dead — so there is no window of the shape I described.

    That leaves my hypothesis without a mechanism. Discard it.

    What does survive, as a separate observation

    GetHub's cached read has no liveness check:

    // HostedHubsCollection.cs:86
    if (messageHubs.TryGetValue(address, out var hub))
        return hub;

    Routing does reach this — MonolithRoutingService.cs:216 resolves node addresses through Mesh.GetHostedHub(address, …) — so whatever the reason a dead instance is in the map, every caller receives it, permanently, and the address can never reactivate. That matches 109/109 rejections better than any race does.

    🚨 But I want to be explicit: adding a liveness check there would be defence-in-depth, not a root-cause fix, and I am deliberately not shipping it. I have not established why a Dead hub was in the map, and hardening the read without knowing that is exactly the papering-over this repo's rules forbid. It would also convert a loud permanent wedge into a silent re-creation, which could hide the real defect rather than fix it.

    What I would do next

    Establish the why first. The cheapest evidence is a log line, and the failing run had none of Error during shutdown of hub, [FORCE-TEARDOWN], or DISPOSAL DEADLOCK. So the next step is to make the absence informative: log at eviction (messageHubs.TryRemove succeeded/failed, with the RunLevel) and at GetHub's cached-hit when the hub is past ShutDown. Either the eviction never ran — and the log says which path skipped it — or something re-registered the address after it, which is a different bug entirely and one I have no evidence for yet.

    Corrected rather than quietly amended, since the earlier comment reads as a diagnosis and someone could act on it.

  6. rbuergi commented on Aug 26, 2026

    @rbuergi
    ContributorAuthor

    Negative result: not reproducible through normal hub creation/disposal

    Retracting my second hypothesis too, by measurement rather than argument.

    I wrote two tests against baseline origin/main — one driving a hub whose disposal blocks mid-CompositeDisposable iteration until the 8 s watchdog force-tears-down, one a plain dispose — and asserted the contract that matters: a caller must never be handed the dead instance.

    fix markers in baseline file: 0
    BUILD EXIT=0 · TEST EXIT=0
    Passed! - Failed: 0, Passed: 2, Total: 2
    

    Baseline passes both. The address reactivates with a fresh hub, and no corpse is handed out.

    Where my earlier analysis was wrong

    I reported that HostedHubsCollection.Add() has no callers in src/ and concluded eviction was never wired on the live creation path. The observation is true; the conclusion is false. Eviction is wired through the hub CONSTRUCTOR:

    // MessageHub.cs:425
    foreach (var disposeAction in configuration.DisposeActions)
        RegisterForDisposal(disposeAction);

    I found one registration site, saw it unused, and stopped looking instead of asking how eviction demonstrably works. That is the same mistake as the DisposeImpl-faults hypothesis before it: reasoning from the shape of the code to a conclusion I never tested.

    Both proposed mechanisms are now ruled out:

    hypothesis verdict
    DisposeImpl faults before disposables.Dispose() step 1 is double-wrapped and cannot throw
    eviction never wired on the GetHub creation path wired via the constructor; baseline reactivates correctly

    I have shipped no fix and no documentation for either — a change to core hub routing based on a mechanism I could not demonstrate would be speculation, and the doc would have taught a hazard I never showed fires.

    What still stands, and where to look next

    GetHub's cached read genuinely has no liveness check (HostedHubsCollection.cs:86), so if a dead hub ever ends up in the map it is handed out forever. But nothing in ordinary creation/disposal puts one there.

    So the production condition involves something these tests do not recreate — Orleans routing, cross-silo activation, or a specific recycle path (the observed address, ACME/ProductLaunch, is an instance hub reached through routing, and DeferredDeliveryNackedOnDisposeTest records the same address self-disposing 13 ms after activation via the overlay self-heal watcher). That is where I would look, and I am explicitly not guessing further without evidence.

  7. added 2 commits that reference this issue on Aug 26, 2026
  8. rbuergi commented on Aug 26, 2026

    @rbuergi
    ContributorAuthor

    Re-triaged against origin/main @ 7bd82fa44 (post-#2376). Still open — and the four framework fixes that landed today are not it.

    #2376 merged at 15:03Z (after the comment above), and it is explicitly diagnostics, not a fix — its own body: "This PR does not claim to root-cause the flake." What it changes is what the next occurrence says:

    • MessageService now stamps the owner's activation identity onto the ShuttingDown NACK;
    • MeshNodeStreamExtensions' re-probe loop counts distinct owner activations across its probes;
    • AddressRecyclingException reports which of the two opposite shapes occurred (RecyclingShape, src/MeshWeaver.Mesh.Contract/MeshNodeStreamExtensions.cs:2389) — "every probe answered by the SAME owner activation" ⇒ look at that hub's disposal; "N DISTINCT owner activations" ⇒ look at whoever is asking for the recycles.

    So the concrete next step on this issue is no longer analysis: the next CI occurrence will name the shape, and that sentence picks which half to investigate. Until one lands, both hypotheses on this thread stay retracted-by-measurement (see the 12:18Z comment).

    Attribution: none of today's four deep fixes explains this, and I checked each

    Stating this explicitly because it would be easy — and wrong — to let a big fix day absorb an unrelated race.

    merged today why it does not explain this failure
    #2341 (#2390) — a test-side Catch().Repeat() 54 kHz busy-wait that wedged MeshWeaver.Threading.Test Wrong assembly and, decisively, wrong dates: that PR's own sweep puts the population at first 2026-08-25T23:24Z, 400 runs scanned back to 2026-08-22, none before. Both occurrences on this issue are 2026-08-21.
    #2377 (#2389) — a live query's scope walk queued on a foreign Rx trampoline Produces a stream that never emits — no error, no completion, no row. This failure is the opposite: 110 probes each got a prompt, explicit answer (ShuttingDown, RunLevel=Dead).
    #2008 (#2392) — a hub writing back its own activation seed The echo is "an equal-version rewrite and invisible" on a quiet node; it only becomes a version regression when a concurrent real write to the same node lands first, and there is no such writer to ACME/ProductLaunch in this test. It does not arm a version-gated self-heal watcher.
    #2339 (#2391) — the ack gate rebuilding the whole node per pending patch A throughput cost on the cross-hub patch path; it does not recycle a hub. #2376's own body reaches the same conclusion independently after investigating both together.

    I also checked that nothing merged since this issue's last comment touches the mechanism: git log origin/main --since=2026-08-25T18:00 -- src/MeshWeaver.Graph/Configuration/NodeTypeEnrichmentHelpers.cs src/MeshWeaver.Messaging.Hub/HostedHubsCollection.cs returns only commits from 2026-08-25 evening (#2202/#2084/#1701, #2245), all of which predate the 12:18Z negative result above. The overlay-self-heal recycle named as hypothesis 1 is untouched.

    Leaving open, on the criterion this thread already set: it closes on a fix or on a measured absence, and a quiet window is neither.

  9. rbuergi commented on Aug 26, 2026

    @rbuergi
    ContributorAuthor

    🚨 Correction to my own sweep: it has recurred — 2026-08-26, and on shard 3, not shard 4

    The 12:18Z comment reported "appears 0 times in that window" for a window starting 2026-08-23. That is wrong. Re-swept every MeshWeaver Build and Test run since 2026-08-21 (878 runs) at the shard-job annotation level, including re-run attempts, and found a fourth occurrence — inside that window and before the comment was written:

    run when (UTC) branch event shard
    32502056817 2026-08-21T16:16Z main push 4
    32511412348 2026-08-21T18:04Z main push 4
    32516795949 (attempt 1) 2026-08-21T19:07Z fix/module-stylesheet-fingerprinted-imports PR 4
    32952238195 2026-08-26T09:17Z refactor/content-test-drops-ai PR 3

    Verified independently rather than taken on trust — check-runs/98128127079/annotations carries Test failed (shard 3) :: MeshWeaver.AI.Test.ThreadAgentIntegrationTest.FullFlow_CreateThread_SendMessage_StreamResponse_SaveReply, and the job log carries the exception verbatim:

    MeshWeaver.Mesh.AddressRecyclingException : GetMeshNode('ACME/ProductLaunch'): the owning hub was still
    recycling (ShuttingDown) after 109 probe(s) over 60.0s (budget 60s) — the address is recycling, NOT absent.
      ThreadAgentIntegrationTest.cs(191,0): at StartChatWithOwnAgent(String threadPath, CancellationToken ct)
    

    Same defect, same node, same line — 109 probes rather than 110, so it is the identical shape and not a variant.

    Two consequences

    1. This is live, not a two-day-old ghost. The "quiet spell" reading in the 12:18Z comment was an artefact of the sweep, not of the defect. It was the only named failing test in that attempt, on a PR (refactor/content-test-drops-ai) whose diff is test-file moves — the unrelated-red pattern this issue was opened on, still costing cycles.
    2. 🚨 The title's "shard 4" is now stale and will mislead the next search. Shard assignment shifted; the 08-26 occurrence is on shard 3. Anyone grepping CI history for "shard 4" will conclude it stopped. That is exactly how the previous sweep produced a false negative.

    Rate, for scale: 1 occurrence in 653 run-attempts over 2026-08-23→08-26 — real, and roughly a twentieth the rate of the top flake in the same window.

    Because this occurrence predates #2376 (merged 15:03Z), it does not yet carry the new RecyclingShape sentence. The next one will, and it is what picks between "the address never reactivated — look at that hub's disposal" and "N distinct owner activations — look at whoever is asking for the recycles."

    (Not established, stated rather than glossed: 158 runs in the window concluded cancelled and were not inspected, so a shard could have failed inside one before the reporter ran. Four occurrences is a floor, not a ceiling.)

  10. rbuergi commented on Aug 30, 2026

    @rbuergi
    ContributorAuthor

    The test moved to MeshWeaver.Plugins with the AI engine (#2276), so this repo's CI can no longer produce it. Refile in MeshWeaver.Plugins on the next occurrence with the #2376 RecyclingShape diagnostics.

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