Repository navigation
fix: a pooled-I/O residual NAMES the leaf that would not unwind - #2770
Conversation
A dirty teardown reported an anonymous 'AgentStore=1' — enough to know a pool did not drain, never enough to fix it. Measured 2026-08-30 on MeshWeaver.AI.Test under load: 3 of 20 runs ended in a dirty teardown naming AgentStore, Query and FileSystem on three different runs, each burning the full 30 s drain budget, and not one of them could be chased any further. #2480 added the POOL NAME for exactly this reason and stopped one level short. IoPool now keeps each in-flight leaf's work BY REFERENCE (no stack capture, no string built on the hot path) and formats it only when a drain reports a residual. A lambda's compiler-generated name carries its ENCLOSING method, so the residual becomes AgentStore=1 [MeshWeaver.AI.Stores.MeshNodeAgentFileStore+<>c__DisplayClass..<WriteCore>b__0] All four entry points are instrumented (Invoke, InvokeStream, InvokeBlocking, SubscribeThroughPool — the last has no delegate, so it reports the source observable's type). PoolResidual carries the sites; both the drain warning and the pools=[...] phase trace the test base prints now include them. Pinned by IoPoolTest: a leaf that ignores its token MUST be nameable, and a pool that drains clean reports no sites (so the diagnostic is not noise). Co-Authored-By: Claude Fable 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01HWc8YSndL2gpW2i9wRUQWt
There was a problem hiding this comment.
Pull request overview
This PR improves pooled I/O teardown diagnostics by capturing and surfacing the “site” (delegate/observable identity) of in-flight IoPool leaves so residual drain reports point to the specific operation that failed to unwind.
Changes:
- Track in-flight IoPool leaves (by reference) and expose
PendingLeafSitesfor residual reporting. - Extend
IoPoolRegistry.DrainAllto include residual leaf sites in both returned residuals and warning logs. - Add tests ensuring (a) a residual is nameable and (b) a clean pool reports no sites.
Reviewed changes
Copilot reviewed 3 out of 3 changed files in this pull request and generated 4 comments.
| File | Description |
|---|---|
| test/MeshWeaver.Hosting.Test/IoPoolTest.cs | Adds coverage to pin residual leaf site naming and “no-noise on clean drain”. |
| src/MeshWeaver.Mesh.Contract/Threading/IoPoolRegistry.cs | Propagates and logs per-pool residual sites alongside residual counts. |
| src/MeshWeaver.Mesh.Contract/Threading/IoPool.cs | Tracks in-flight leaves and formats diagnostic “site” strings for residual reporting. |
Suppressed comments (2)
src/MeshWeaver.Mesh.Contract/Threading/IoPool.cs:315
- EnterLeaf(source) is outside the try/finally that releases the gate permit; if EnterLeaf throws, the leaf will leak _inFlight and the permit, potentially wedging Drain()/Dispose(). Move ticket acquisition inside the guarded region (initialize to 0) so ReleaseGate always runs.
await _gate.WaitAsync(ct).ConfigureAwait(false);
Interlocked.Increment(ref _inFlight);
var leaf = EnterLeaf(source);
src/MeshWeaver.Mesh.Contract/Threading/IoPool.cs:490
- EnterLeaf(source) is evaluated before the try/finally that releases the gate permit; if it throws, the permit and _inFlight increment are leaked and the pooled subscribe setup can wedge teardown. Acquire the ticket inside the guarded region (initialize to 0) so ReleaseGate always runs.
await _gate.WaitAsync(ct).ConfigureAwait(false);
Interlocked.Increment(ref _inFlight);
var subLeaf = EnterLeaf(source);
💡 Add a code-review agent skill or configure MCP servers for context-aware, tailored reviews. Learn more in the docs.
| await _gate.WaitAsync(ct).ConfigureAwait(false); | ||
| Interlocked.Increment(ref _inFlight); | ||
| var leaf = EnterLeaf(io); |
| @@ -174,7 +178,10 @@ public int DrainAll(out IReadOnlyList<PoolResidual> byPool) | |||
| _logger?.LogWarning( | |||
| "IoPoolDrain: pool '{PoolName}' did not finish {Residual} leaf(es) within " | |||
| + "the drain budget — a leaf ignored its cancellation token; fix the leaf, do not " | |||
| + "widen the budget.", kvp.Key, residual); | |||
| + "widen the budget. Still running: {Sites}", kvp.Key, residual, | |||
| kvp.Value.PendingLeafSites.Count == 0 | |||
| ? "(no site captured)" | |||
| : string.Join(" | ", kvp.Value.PendingLeafSites)); | |||
| // Read the sites BEFORE the drain returns nothing to name: Drain() joins, so by the | ||
| // time it hands back a residual the surviving leaves are exactly the ones still | ||
| // registered — but a leaf that unwinds during the join must not be reported, so this | ||
| // is read after Drain and reflects what is genuinely still running. |
| Interlocked.Increment(ref _inFlight); | ||
| var blockingLeaf = EnterLeaf(work); | ||
| if (Interlocked.Increment(ref _blockingInFlight) == 1) | ||
| _blockingIdle.Reset(); |
|
The red is this PR's own new test, not an inherited or flaky one — and it is a hang, not an assertion failure, which changes what to look for. The Test Results annotation reports the trx as Two consequences worth stating explicitly:
Given the subject, the most likely shapes, in order:
Worth checking whether the test's wait has its own bound and a positive success signal, rather than relying on the 30 s method timeout to end it — a timeout is not an assertion, and a test that can only fail by timing out reports the same thing whether the feature works or the harness stalled. |
Root cause — the test cannot fit inside the harness's method timeout, and its
|
Measured, from the trx — 30 s → 0.28 sYou asked whether CI actually waits that long. It did, and the trx is the place the per-test number lives. Branch Against the current branch, CI reports the same test as What changed.
🚨 The speed-up exposed a real defect the timeout was hidingIt now fails in 0.28 s on a genuine mismatch in this PR's own diff:
Worth noting what this says about the original: a 30 s timeout kill and a one-line format mismatch are indistinguishable from the outside. The test could only ever report "something went wrong", at a cost of 30 s of shard time per run. Cherry-pick |
… assertion onto the extended contract
IoPoolResidualNamesItsPoolTest pinned ToString() to exactly 'Query=1'. That exactness was the
contract until this PR, whose whole point is that a residual also NAMES the leaf still running
('Query=1 [Namespace.Type.Method]'), because a bare pool name sent the reader into every Query
caller in the process. The assertion now checks the pool-and-count prefix unchanged, that the
bracketed site names THIS test's lambda (a residual naming anyone else's code would be worse
than none), and that one leaked leaf yields exactly one site.
Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01HWc8YSndL2gpW2i9wRUQWt
|
Shard 2 red was this PR's own test pinning the OLD wire format ( Process note for the record: my first push of this fix landed on |
The ratchet caught real drift on its first exposure to a moving main — IoPoolTest.cs 30 -> 32, from #2770 (`a pooled-I/O residual NAMES the leaf that would not unwind`) landing after this branch took its seed. Re-seeded rather than argued with: the allow file's own header says to seed against main's TIP, not the branch point, precisely because CI checks out the merge ref. TotalBudget 79 -> 81, with the reason recorded in the guard's remarks so the next reader does not read 81 as the original measurement. 🚨 This is the ratchet working, not a concession. Those two sites come back out in the IoPool drain-budget change, which lowers the budget to 79 again — the mechanism the file documents (delete a line, lower the budget by exactly that amount, in the same change). Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
…leaking a pool thread #2770 merged without these. On main the test now: * cannot pass at all — a residual is only observable by letting IoPool's drain budget EXPIRE, DrainTimeout is 30s and Drain() spends it THREE times (cancel join, each gate slot, blocking-idle join), while test/xunit.runner.json caps every method at methodTimeout: 30000. CI recorded it as `[took 30s]`, killed at exactly the budget with no assertion message; * LEAKS on that path — `release.Set()` sits after `await drain.WaitAsync(..., TestContext.Current.CancellationToken)`, and that token IS the method-timeout token. On timeout the await throws, the release never runs, the deliberately-blocked leaf holds a pool thread for its full two minutes, and `using` disposes over live work. The test written to prove residuals are reported was leaking one into the next test. Fixes, in the order they matter: 1. IoPool gains an `(int maxConcurrency, TimeSpan drainTimeout)` overload and IoPoolOptions a `DrainTimeout`, threaded through IoPoolRegistry.Get. The default is UNCHANGED at 30s and is now pinned by its own test, so making it injectable cannot quietly move the teardown contract. 2. The test drives a 250ms budget and still calls the REAL registry.DrainAll(out byPool) — the subject is "the residual is reported and NAMES its pool", not the numeric budget. 3. The release is UNCONDITIONAL, in a `finally`. 4. Both ManualResetEventSlim gates become AsyncSubject<Unit>, per /async: a hand-woven gate is the same defect class as await on a turn-based scheduler. The one remaining block IS the subject (a leaf ignoring its token) and is now bounded at 30s so a failing run cannot wedge the shard. Measured from the trx, where per-test duration actually lives: DrainAll_reportsTheResidual… 00:00:00.279 (was: killed at 30s) TheDefaultDrainBudget… 00:00:00.0004 DrainAll_reportsNoPool… 00:00:00.0007 This also removes 2 of the 81 hand-woven gates the ratchet in #2782 seeds; the one merged second should lower TotalBudget 81 -> 79 and drop IoPoolTest.cs's count accordingly. A seed HIGHER than actual only leaves slack, so either merge order is safe. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
…ion and ratcheted in tests (#2782) * feat(guard): hand-woven concurrency gates are held at zero in production and ratcheted in tests A SemaphoreSlim / ManualResetEventSlim / AutoResetEvent / CountdownEvent / Monitor.Wait parks a thread. On a hub action block or a grain turn that is the deadlock the mesh cannot recover from — the class /async names alongside await on a hub. AGENTS.md states the rule; nothing enforced it. Two tiers, the shape #2762 established: - ProductionRoots (src, tools, samples, clients, memex) — ZERO, no allow file. The only permitted gates are SanctionedGates entries, VERIFIED not listed: each must still exist and still contain a gate, so an entry cannot outlive its subject. - RatchetedRoots (test) — a seeded inventory that may only shrink. Measured on main's tip: 79 sites across 24 files, every one a ManualResetEventSlim, 30 of them in IoPoolTest.cs. TotalBudget 79. 🚨 The guard found a production violation on its first run that a src/-only grep had missed: tools/MeshWeaver.ThumbnailGenerator. Registered rather than converted, with the premise VERIFIED rather than asserted in prose — its csproj is an Exe referencing Microsoft.Playwright, SixLabors.ImageSharp and System.CommandLine and NOT ONE MeshWeaver assembly, so there is no hub, no grain turn and no IIoPool in that process and the defect cannot occur. The register re-reads that csproj on every run and FAILS if a MeshWeaver ProjectReference ever appears: an exemption whose PREMISE silently stops holding is worse than one whose subject moved, because the subject's absence at least fails loudly. `tools` stays in scope rather than being dropped, so a gate added to a tool that DOES reference the mesh still fails. The self-test plants a real tree and runs the REAL scan over it — .cs, .csx, prose, a string literal and bin/ — rather than matching the regex against strings. That distinction is the defect this repo found in three separate guards today. Verified by MUTATION, each arm proven able to fail and then restored: A new gate in src/ -> RED (production zero) A new file in test/ not in the allow list -> RED (NEW SITE) A listed test file's count grows -> RED (may only shrink) restored -> GREEN 4/4 Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> * re-seed against main's tip: #2770 added two gates while this PR was open The ratchet caught real drift on its first exposure to a moving main — IoPoolTest.cs 30 -> 32, from #2770 (`a pooled-I/O residual NAMES the leaf that would not unwind`) landing after this branch took its seed. Re-seeded rather than argued with: the allow file's own header says to seed against main's TIP, not the branch point, precisely because CI checks out the merge ref. TotalBudget 79 -> 81, with the reason recorded in the guard's remarks so the next reader does not read 81 as the original measurement. 🚨 This is the ratchet working, not a concession. Those two sites come back out in the IoPool drain-budget change, which lowers the budget to 79 again — the mechanism the file documents (delete a line, lower the budget by exactly that amount, in the same change). Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> --------- Co-authored-by: Claude Opus 5 (1M context) <noreply@anthropic.com>
…leaking a pool thread (#2786) * test(iopool): the residual test costs 0.28s instead of 30s+ — and now shows its real failure IoPoolResidualNamesItsPoolTest was killed at exactly 30s in CI with no assertion message. It could not have passed: a residual is only observable by letting IoPool's drain budget EXPIRE, DrainTimeout is 30s, and Drain() spends it THREE times (the cancel join, each gate slot, the blocking-idle join) — while test/xunit.runner.json caps every method at methodTimeout: 30000. Worse, `release.Set()` sat after `await drain.WaitAsync(..., TestContext. Current.CancellationToken)`. That token IS the method-timeout token, so on the timeout the await threw and the release never ran: the deliberately-blocked leaf held a pool thread for its full 2 minutes and `using` disposed over live work. The test written to prove residuals are reported was leaking one. - IoPool gains an `(int maxConcurrency, TimeSpan drainTimeout)` overload; IoPoolOptions gains `DrainTimeout`, threaded through IoPoolRegistry.Get. The default is UNCHANGED at 30s and now pinned by its own test, so making it injectable cannot quietly move the teardown contract. - The test drives a 250ms budget and calls the REAL registry.DrainAll(out byPool) — the subject is "the residual is reported and NAMES its pool", not the numeric budget. - `release.Set()` moves into a `finally`. Measured from the trx, which is where per-test duration actually lives: DrainAll_reportsTheResidual… 00:00:00.28 (was: killed at 30s) TheDefaultDrainBudget… 00:00:00.0006 DrainAll_reportsNoPool… 00:00:00.0013 whole class: 300 ms. 🚨 And the speed-up EXPOSED a real defect the timeout was hiding. The test now fails in 0.28s on a genuine mismatch in this PR's own diff: expected "Query=1" found "Query=1 [MeshWeaver.Hosting.Test.IoPoolResidual…b__0]" PoolResidual.ToString() appends the pending leaf SITES, but the test asserts the older `{pool}={n}` and calls it "the wire format the teardown traces embed, so it is part of the contract". One of the two is wrong — left failing deliberately rather than papered over, because which one is the author's call. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> * fix(iopool): the residual test costs 0.28s instead of 30s, and stops leaking a pool thread #2770 merged without these. On main the test now: * cannot pass at all — a residual is only observable by letting IoPool's drain budget EXPIRE, DrainTimeout is 30s and Drain() spends it THREE times (cancel join, each gate slot, blocking-idle join), while test/xunit.runner.json caps every method at methodTimeout: 30000. CI recorded it as `[took 30s]`, killed at exactly the budget with no assertion message; * LEAKS on that path — `release.Set()` sits after `await drain.WaitAsync(..., TestContext.Current.CancellationToken)`, and that token IS the method-timeout token. On timeout the await throws, the release never runs, the deliberately-blocked leaf holds a pool thread for its full two minutes, and `using` disposes over live work. The test written to prove residuals are reported was leaking one into the next test. Fixes, in the order they matter: 1. IoPool gains an `(int maxConcurrency, TimeSpan drainTimeout)` overload and IoPoolOptions a `DrainTimeout`, threaded through IoPoolRegistry.Get. The default is UNCHANGED at 30s and is now pinned by its own test, so making it injectable cannot quietly move the teardown contract. 2. The test drives a 250ms budget and still calls the REAL registry.DrainAll(out byPool) — the subject is "the residual is reported and NAMES its pool", not the numeric budget. 3. The release is UNCONDITIONAL, in a `finally`. 4. Both ManualResetEventSlim gates become AsyncSubject<Unit>, per /async: a hand-woven gate is the same defect class as await on a turn-based scheduler. The one remaining block IS the subject (a leaf ignoring its token) and is now bounded at 30s so a failing run cannot wedge the shard. Measured from the trx, where per-test duration actually lives: DrainAll_reportsTheResidual… 00:00:00.279 (was: killed at 30s) TheDefaultDrainBudget… 00:00:00.0004 DrainAll_reportsNoPool… 00:00:00.0007 This also removes 2 of the 81 hand-woven gates the ratchet in #2782 seeds; the one merged second should lower TotalBudget 81 -> 79 and drop IoPoolTest.cs's count accordingly. A seed HIGHER than actual only leaves slack, so either merge order is safe. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> * review: satisfying one ratchet by violating another is not a fix My own conversion traded a hand-woven gate for a blocking bridge: ManualResetEventSlim -> AsyncSubject + .Wait(). That cleared HandWovenGateRatchetGuard and tripped BlockingBridgeInTestRatchetGuard (`NoNewTestBridgesAnObservableToABlockingWait`), which is not progress — it is moving the same defect between two guards' jurisdictions. What the test actually needs is (a) to know the leaf started and (b) for the leaf to outlive the drain budget. Neither needs a signal back INTO the leaf, so the whole release channel is gone: * the precondition goes through the sanctioned test bridge — `await entered.Timeout(10s).Await(ct)`; no .Wait(), no gate; * the leaf sleeps. The SUBJECT of this test is a leaf that ignores its cancellation token, and sleeping IS ignoring it. With a 250 ms budget a 1 s sleep outlives it four times over, and the drain returns without waiting for the leaf, so the suite pays nothing for it. Also lowers the gate inventory by exactly what this deletes: the IoPoolResidualNamesItsPoolTest entry is removed from HandWovenGateSites.allow and TotalBudget goes 81 -> 79, which is the mechanism that file documents. Verified: IoPoolResidualNamesItsPoolTest 3/3, residual case 00:00:00.279 BlockingBridgeInTestRatchetGuard + HandWovenGateRatchetGuard 6/6 together Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> --------- Co-authored-by: Claude Opus 5 (1M context) <noreply@anthropic.com>
Why
A dirty teardown reports
teardown DIRTY — 1 pooled I/O leaf(s) still runningand, since #2480, which pool. It does not report which leaf — so the failure is unactionable.Measured 2026-08-30,
MeshWeaver.AI.Test(1,630 tests) under load (DOTNET_PROCESSOR_COUNT=4+ CPU burners), 20 runs:MeshNodeAgentFileStoreTestAgentStore=1PluginCatalogTestQuery=1MeshPluginTestFileSystem=1Three pools, three tests, always the full budget — and nothing to act on. #2480 added the pool name for this exact reason and stopped one level short.
How
IoPoolkeeps each in-flight leaf's work by reference — no stack capture, no string built on the hot path — and formats only when a drain reports a residual. A lambda's compiler-generated name carries its enclosing method, so the residual reads:All four entry points instrumented (
Invoke,InvokeStream,InvokeBlocking,SubscribeThroughPool— the last has no delegate, so it reports the source observable's type).PoolResidual.Sitesflows into both the drain warning and thepools=[…]phase traceMonolithMeshTestBasealready prints, so a CItest-evidence-*artifact carries it with no further change.Verification
IoPoolTest25/25, including two new pins: a leaf that ignores its token must be nameable, and a clean pool reports no sites (the diagnostic must not become noise).Note: on current
mainthis class did not reproduce in 24 further loaded runs (P ≈ 0.02 under the measured 15 % rate), so something in the intervening commits — most plausibly the continuingToTasksweep — has largely fixed it. The diagnostic is worth landing regardless: the next occurrence names itself instead of restarting this investigation.