Skip to content

Fix the usage-satellite read and close #1029's second door (AI.Test parallel opt-in: measured no) - #1043

Closed
rbuergi wants to merge 2 commits into
mainfrom
fix/1040-ai-test-parallel-safety
Closed

rbuergi wants to merge 2 commits into
mainfrom
fix/1040-ai-test-parallel-safety

Conversation

@rbuergi

@rbuergi rbuergi commented Aug 9, 2026 •

Copy link
Copy Markdown
Contributor

Two defect fixes, and a measured "no" on parallelising AI.Test.

Does not close #1040 — see "The opt-in is backed out" below. Closes the half of #1029 that #1038
did not reach.

#1040's premise is wrong: AI.Test has no cross-class shared state

The issue attributes the parallel failures to state shared between test classes — 13 classes on one
rbuergi@systemorph.com, ~17 on the TestData partition — the #999 shape. The reproduction says
otherwise, and so does the structure.

MonolithMeshTestBase.ShareMeshClusterEnabled is false, so every ShareMeshAcrossTests
override in the assembly is ignored and every [Fact] builds its own mesh.
Two classes therefore
never share a workspace, a hub, a routing table, an IStorageAdapter (TryAddSingleton, per
service-provider) or an IMeshNodeStreamCache (likewise). TestData is a path inside each test's
private in-memory store; the shared test user is a claim on each test's private AccessService.
_sharedProviders, the one static collection the test base still declares, is never read or written
while that kill-switch is off, and NoStaticCollectionsTest reports zero remaining CACHE-class
statics.

The 502-call-site TestPartition refactor proposed in the issue thread would have made per-class
what is already per-test.

Defect 1 — the token-usage satellite (3 of the original 5 failures)

ThreadTokenUsageTest.WaitForUsage point-read {thread}/_Usage/{model}. TokenUsage.RecordUsage is
subscribed as an independent side effect, deliberately NOT chained before the round's terminal
status write — its own doc comment says so — so "terminal state reached" does not imply "satellite
exists". A point read of an absent node gets an authoritative routing NotFound, which
terminates the stream with an error; it cannot wait for a node to appear. Three tests failed
within a second: No node found at 'TestData/_Thread/…/_Usage/usage_model'.

Production never had this — ThreadTokenChip binds the live children query of {thread}/_Usage,
which starts from the (possibly empty) collection and re-emits when the node lands. WaitForUsage
now uses exactly that, so the test covers the read path the portal actually runs.

Negative control, verified: UsageWatchedFromBeforeTheRound_ArrivesWhenTheSatelliteIsCreated
opens the watch before submitting, when the thread has no _Usage namespace at all. Against the
point-read helper it fails in 2.6 s with the exact CI signature; against the children query it
passes.

Defect 2 — the second door into #1029, which #1038 did not close

#1038 forked deleted-vs-recycling in NackThroughParent — deliveries the hub abandons (intake
gate, disposal drain). There is a second site. A delivery can be accepted and then fault: the
handler runs while RunLevel still reads Started, reaches for machinery HostedHubsCollection
has already frozen (SynchronizationStream's ctor → Host.GetHostedHub), and throws
HubDisposingException. That lands in MessageService's execution Catch, which still hardcoded
ErrorType.ShuttingDown and echoed the raw exception text — whose wording is literally "Hub …
is shutting down"
, an IsTransientOwnerFailure marker. Both signals pointing the wrong way.

So the consumer rode it out awaiting a reactivation that can never come, the 5 s keep-alive
heartbeat drew the authoritative NotFound from routing with nobody left to hand it to, and the
reader burned its budget reporting "unavailable" for a node provably gone.

Measured with #1038 already merged in: MeshPluginTest.FullCrudWorkflow_CreateGetUpdateDelete
still failed 2 of 4 whole-assembly runs, identical signature and timings:

t+0.000   SubscribeRequest → ACME/CrudTest_… : HubDisposingException  (accepted, then threw)
t+5.000   RouteMessage: NotFound for ACME/CrudTest_…   ← authoritative, produced, discarded
t+10.000  FetchNode budget expires → "Unavailable, no verdict within 10s"

Same tombstone, same verdict. The contract sentence now lives in one place
(DeletedAddressMessage) so the two sites cannot drift — a drift here is silent, which is precisely
how this door stayed open.

Negative control, verified: DeletedAddressNackClassificationTest gains both halves, forcing the
door deterministically with a handler that throws the exception outright — no disposal race to lose.
Tombstoned ⇒ NotFound + "No node found" + never "shutting down"; not tombstoned ⇒
ShuttingDown, so the recycle path (#672) cannot be collapsed into it. Measured failing before,
passing after. Messaging.Hub.Test 169/169 green on the merged tree — including main's newly
landed DeliveryFailureClassificationWireTest.

The opt-in is backed out — AI.Test needs the machine

I did opt in, on five consecutive green local runs, and CI disproved it. Three failures on
shard 4, all concurrency-stress tests — tests that deliberately saturate the machine and whose
budgets assume they have it:

test failure
PatchWorkspaceAckTest.Patch_ConcurrentUpdates_NoDeadlock read reached no verdict within 10 s
CrossHubPatchAtomicityTest.ConcurrentCrossHubPatches_DoNotDropAQueuedMessage 137/288 not visible
AgentChatClientDeadlockTest.GetOrderedAgentsAsync_…_DoNotDeadlock TimeoutException

The middle one's own diagnostic settles it, and it is not a correctness failure:

WRITE ERRORS (0): []
OWNER-TRUTH probe: version=289 present=288 missing=[]
MIRROR SEQUENCE (192 emissions), REGRESSIONS (0): []; converged=NEVER
tail=[…190@v191(t36784ms)]

No write failed, the owner holds all 288, and the mirror moved monotonically forward with zero
regressions
— still climbing when the settle bound expired. Per the test's own printed guidance
that is "a slow box, not a lost write". Starved, not wrong.

Why no amount of local measurement could have caught this — and this PR said so before CI ran:
DOTNET_PROCESSOR_COUNT=4 sizes the thread pool and GC as if there were 4 cores but does not
remove the other 14
. A test that spawns its own concurrency therefore still got real parallelism
locally, across 14 whole-assembly runs and five consecutive green ones; on a true 4-vCPU runner four
such classes timeshare and blow their budgets. The stated caveat predicted the failure mode; CI
demonstrated it.

This is not #1040's cross-class shared state, and not a correctness defect — it is contention
between the runner's parallelism and tests that need the machine to themselves.

The way forward is to isolate the stress classes into their own serial collection and opt in the
remainder. Choosing that set off ONE CI run would be guessing, and the only box that can measure it
is the box that cannot reproduce the starvation — so it wants its own change. Emphatically not
the alternative of widening those budgets: they are deadlock detectors, and a deadlock detector with
a padded budget detects nothing.

What the opt-in was worth, for whoever picks it up

Real CI, like for like, same branch and shard split (AI.Test is split #1/2→shard 4, #2/2→shard 3):

AI.Test half serial parallel ×4 gain
540 tests (shard 3) 170.2s 113.0s 1.51×
599 tests (shard 4) 105.2s 99.0s 1.06×
combined 275.4s 212.0s 1.30×

~1.3×, not the 1.5–2.1× the 18-core box suggested — the same compression #999 measured. Modest and
lopsided, which is itself a hint that the 599-half is serialised by its own long tests.
shard-assign.sh weight left at 263 throughout.

The *_StaysLive_AndReEmitsWhen* family: ruled out, and now #1053

Neither #1040's premise nor #1038 explains it: the failure on main was under serial execution;
those three tests contain no deletes at all; the shape is a 30 s timeout on a live children
query that never re-emitted after a create that completed — a missed Added on the change-feed →
synced-query path. Filed as #1053 and fixed on main by #1060, which is merged into this branch.

What's New

Skipped. Defect 1 is test infrastructure. Defect 2 is user-visible — but it is the same statement
#1038 already shipped as 2026-08-09-deleted-node-reads-answer-not-found.md; this change is what
makes that entry true in the accepted-then-faulted case, and a second entry repeating it would be
noise.

🤖 Generated with Claude Code

Copilot AI left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Pull request overview

This PR updates ThreadTokenUsageTest to observe the token-usage satellite the same way the portal does (via a live children query), eliminating a parallel-only race where point-reading an absent usage node fails fast with an authoritative NotFound instead of waiting for creation.

Changes:

  • Added a new regression test that starts watching usage before any _Usage satellite exists, ensuring usage arrives once created.
  • Reworked WaitForUsage to use a live path:{thread}/_Usage scope:children query and select the model’s usage node from the result set (mirroring the portal binding path).
Suppressed comments (1)

test/MeshWeaver.AI.Test/ThreadTokenUsageTest.cs:397

  • This XML doc comment references TokenUsage.RecordUsage, but the implementation is TokenUsageNodeType.RecordUsage. Since TokenUsage.RecordUsage doesn't exist, the comment is misleading.
    /// <c>TokenUsage.RecordUsage</c>, which is subscribed as an INDEPENDENT side effect and

💡 Add a code-review agent skill or configure MCP servers for context-aware, tailored reviews. Learn more in the docs.

Comment thread test/MeshWeaver.AI.Test/ThreadTokenUsageTest.cs Outdated
@github-actions

github-actions Bot commented Aug 9, 2026 •

Copy link
Copy Markdown
Contributor

Test Results (shard 0)

701 tests  ±0   701 ✅ ±0   13m 18s ⏱️ -6s
 10 suites ±0     0 💤 ±0 
 10 files   ±0     0 ❌ ±0 

Results for commit 19d6268. ± Comparison against base commit 412fc5c.

♻️ This comment has been updated with latest results.

@github-actions

github-actions Bot commented Aug 9, 2026 •

Copy link
Copy Markdown
Contributor

Test Results (shard 4)

1 329 tests  ±0   1 324 ✅ ±0   9m 47s ⏱️ +20s
   11 suites ±0       5 💤 ±0 
   11 files   ±0       0 ❌ ±0 

Results for commit 19d6268. ± Comparison against base commit 412fc5c.

♻️ This comment has been updated with latest results.

@github-actions

github-actions Bot commented Aug 9, 2026 •

Copy link
Copy Markdown
Contributor

Test Results (shard 5)

1 769 tests   1 577 ✅  4m 49s ⏱️
   11 suites    192 💤
   11 files        0 ❌

Results for commit 19d6268.

♻️ This comment has been updated with latest results.

@github-actions

github-actions Bot commented Aug 9, 2026 •

Copy link
Copy Markdown
Contributor

Test Results (shard 2)

1 963 tests  ±0   1 961 ✅ ±0   6m 35s ⏱️ +4s
   11 suites ±0       2 💤 ±0 
   11 files   ±0       0 ❌ ±0 

Results for commit 19d6268. ± Comparison against base commit 412fc5c.

♻️ This comment has been updated with latest results.

@github-actions

github-actions Bot commented Aug 9, 2026 •

Copy link
Copy Markdown
Contributor

Test Results (shard 3)

   11 files  ±0     11 suites  ±0   9m 59s ⏱️ + 1m 6s
1 978 tests ±0  1 869 ✅  - 1  108 💤 ±0  1 ❌ +1 
2 147 runs  ±0  2 038 ✅  - 1  108 💤 ±0  1 ❌ +1 

For more details on these failures, see this check.

Results for commit 19d6268. ± Comparison against base commit 412fc5c.

♻️ This comment has been updated with latest results.

@github-actions

github-actions Bot commented Aug 9, 2026 •

Copy link
Copy Markdown
Contributor

Test Results (shard 1)

1 229 tests  ±0   1 229 ✅ ±0   6m 23s ⏱️ -12s
   11 suites ±0       0 💤 ±0 
   11 files   ±0       0 ❌ ±0 

Results for commit 19d6268. ± Comparison against base commit 412fc5c.

♻️ This comment has been updated with latest results.

@github-actions

github-actions Bot commented Aug 9, 2026 •

Copy link
Copy Markdown
Contributor

Test Results

   65 files  ±0     65 suites  ±0   50m 53s ⏱️ -17s
8 969 tests ±0  8 661 ✅  - 1  307 💤 ±0  1 ❌ +1 
9 138 runs  ±0  8 830 ✅  - 1  307 💤 ±0  1 ❌ +1 

For more details on these failures, see this check.

Results for commit 19d6268. ± Comparison against base commit 412fc5c.

♻️ This comment has been updated with latest results.

@rbuergi rbuergi changed the title Watch the token-usage satellite the way the portal does — AI.Test's biggest parallel blocker Make AI.Test parallel-safe: fix the usage-satellite read and close #1029's second door Aug 9, 2026
@rbuergi

rbuergi commented Aug 10, 2026

Copy link
Copy Markdown
Contributor Author

Deferred out of this PR: ToolTimeout reports its own timeout for a caller's cancellation

Recording this properly so the one-line fix is not lost. It is not in this PR — see "why not" at
the bottom.

The defect

src/MeshWeaver.AI/ChatClientAgentFactory.cs:952, in AccessContextAIFunction.InvokeCoreAsync:

using var cts = CancellationTokenSource.CreateLinkedTokenSource(cancellationToken);
var invocation = base.InvokeCoreAsync(arguments, cts.Token).AsTask();
try
{
    return await invocation.WaitAsync(_timeout.Value, cancellationToken);   // ← line 952
}
catch (TimeoutException)
{
    cts.Cancel();
    return $"Tool '{Name}' timed out after {_timeout.Value.TotalSeconds:F0}s. "
         + $"Add [ToolTimeout(N)] to allow longer.";
}

Task.WaitAsync(TimeSpan, CancellationToken) races our tool budget against the caller's
token
. When both become ready the BCL resolves the race internally and picks a winner we do not
control — and under a starved pool the caller's cancellation callback can be delayed past the
budget. The catch (TimeoutException) arm then fabricates "Tool 'X' timed out after 2s" for a call
the caller cancelled.

That contradicts the wrapper's own stated contract — the synthetic string is "reserved for its OWN
timer firing"
— and the test that pins it says so in its name:
ToolTimeoutAttributeTest.ExternalCancellation_PropagatesAsOperationCancelled_NotSyntheticTimeout,
which asserts an OperationCanceledException and instead saw no exception at all (the synthetic
string returned normally).

Why it matters outside the test

A user who cancels a round gets a bogus "tool timed out" injected into the conversation instead
of the round unwinding as cancelled — a fabricated failure attributed to a tool that did nothing
wrong, and one a model may well try to "work around" on the next turn.

The fix

Honour the caller's token before fabricating a timeout:

catch (TimeoutException)
{
    // The caller's cancel outranks our timer: WaitAsync races the two and the BCL picks a winner
    // we do not control, so a cancelled call can surface as OUR timeout. The synthetic string is
    // reserved for our own timer firing.
    cancellationToken.ThrowIfCancellationRequested();
    cts.Cancel();
    return $"Tool '{Name}' timed out after …";
}

Strictly narrowing: when the caller's token is not cancelled — the overwhelmingly common case —
behaviour is unchanged.

Observed rate

Once in ten whole-assembly parallel runs (run 4 of the measurement series in this PR, before
#1038 merged), at DOTNET_PROCESSOR_COUNT=4 -parallel collections. It did not recur in the nine
other runs. Note the local box understates it: DOTNET_PROCESSOR_COUNT sizes the thread pool as
if there were 4 cores but does not remove the other 14, so a real 4-vCPU runner starves harder and
is more likely to delay the cancellation callback past the budget. Pre-existing; parallelism raises
the rate rather than introducing it.

Why it is not fixed here

No test I can write today would fail first. The bug is reachable only through the BCL's own race
resolution inside WaitAsync — every deterministic construction I tried resolves the way the test
already expects:

  • external token cancelled before the call → WaitAsync throws OperationCanceledException
    immediately (passes today);
  • external cancel at 500 ms vs a 2 s budget, tool honouring the token → the tool unwinds with OCE
    (passes today);
  • external cancel after the budget → the timeout genuinely won, and the synthetic string is the
    correct answer.

Only genuine pool starvation flips it, which is not something a test may manufacture with a sleep or
a widened bound. Shipping the change unpinned would be guessing, so it wants its own PR with a
harness that injects the timeout decision rather than racing it — e.g. making the
timeout/cancellation arbitration an injectable seam so both orderings can be exercised directly.

Flagged here so that if this test ever reds AI.Test on CI, the cause is already written down.

@rbuergi rbuergi changed the title Make AI.Test parallel-safe: fix the usage-satellite read and close #1029's second door Fix the usage-satellite read and close #1029's second door (AI.Test parallel opt-in: measured no) Aug 10, 2026
@rbuergi

rbuergi commented Aug 10, 2026

Copy link
Copy Markdown
Contributor Author

Fixed in b2a439937 — both occurrences (lines 116 and 397).

Verified the claim before changing it rather than taking it on faith: in src/MeshWeaver.AI/TokenUsage.cs, RecordUsage is declared at line 138 inside public static class TokenUsageNodeType (line 77), while TokenUsage (line 26) is the separate record holding the per-(thread, model) counts. Two types in one file with near-identical names — an easy pair to conflate, and a dead end for anyone following the breadcrumb.

Worth fixing rather than deleting the reference: those comments explain why the satellite write is not ordered before the terminal status write, which is the reasoning this test exists to pin. A reader who cannot find the method loses the explanation, not just a name.

@rbuergi

rbuergi commented Aug 10, 2026

Copy link
Copy Markdown
Contributor Author

MonolithKernelTest.ThreeSubmissions_ShareState — not attributable to this PR, and this PR is now empty

Investigated rather than assumed, since this diff changes NACK classification and a kernel
submission can traverse that path. Two independent findings.

1. This PR no longer contains anything

git diff origin/main...origin/fix/1040-ai-test-parallel-safety --stat is empty. Both fixes
shipped in main via #1075 ("Isolate the five machine-hungry AI.Test classes, then let the rest
run in parallel"
), which carried the MessageService second-door fix, the ThreadTokenUsageTest
usage-satellite fix, the ConcurrencyStressCollection, and the opt-in. #1040 and #1029 are both
closed. So the failing run was effectively testing main, not this PR's contribution — and this
PR should be closed as superseded.

2. The change is provably inert on that test's path

The assertion is:

Expected "**Execution failed**:
(1,47): error CS0103: The name 'sharedValue' does not exist in the current context"
to contain "first: 100".

That is a successful execution returning a compile diagnostic — not a DeliveryFailure. The
only thing this diff can rewrite is a DeliveryFailure's ErrorType/Message, so it cannot
produce a CS0103.

And the branch cannot even be reached: it is gated on IsAddressDeleted(), which reads the delete
tombstone. RecentlyDeletedRegistry is written only by the delete handler, and
MonolithKernelTest contains no delete at all — every message it sends is a
SubmitCodeRequest. With no tombstone the else arm runs, byte-identical to pre-change code. No
HubDisposingException appears anywhere in the failing test's captured output either.

Locally, MonolithKernelTest is 8/8 green on the current merged tree.

3. A hypothesis I had, checked, and had to discard

7635713e5 — "Two updates for one page could swap places, and the loser was dropped forever" —
fixes exactly this reordering class: each delivery became its own SubscribeThroughPool leg, so two
messages to one destination could swap. That is a perfect fit for three back-to-back
SubmitCodeRequests arriving out of order.

It does not explain this failure, for two independent reasons:

  • It was already in the failing tree. compare/7635713e5...19d626812 → status=ahead, behind_by=0. (My first containment check was invalid — 19d626812 is not in the local object
    store, so git merge-base --is-ancestor errored and fell through to the wrong branch. The API
    comparison is the reliable one.)
  • It is Orleans-only. The fix lives in MeshWeaver.Hosting.Orleans/RoutingGrain.cs +
    OrderedRouteDispatcher. MonolithKernelTest runs on MonolithRoutingService, which has no
    SubscribeThroughPool / IoPool legs at all — so the pooled-leg reordering mechanism is not
    present on that path either way.

What is still open

The CS0103 itself. Both kernel tests post fire-and-forget submissions back-to-back and rely on
delivery order plus KernelExecutor's serial .Select(RunSubmission).Concat() pump; the two-post
sibling MultipleSubmissions_ShareKernelState passed in the same run, the three-post one failed.
ThreeSubmissions_ShareState's own docstring calls it "Minimal repro for the 'variables not
defined' bug"
— so a CS0103 here is precisely the symptom it was written to detect, and it is worth
treating as a live ordering defect on the monolith submission path rather than as noise. Not
something this (now empty) PR can carry.

@rbuergi

rbuergi commented Aug 10, 2026

Copy link
Copy Markdown
Contributor Author

Closing as superseded by #1075 — this branch is now empty.

git diff origin/main...origin/fix/1040-ai-test-parallel-safety returns nothing. Both fixes it carried shipped in main via #1075 ("Isolate the five machine-hungry AI.Test classes, then let the rest run in parallel"), which took the MessageService NACK-classification fix (#1029's second door), the ThreadTokenUsageTest usage-satellite fix, the ConcurrencyStressCollection, and the opt-in. #1040 and #1029 are both closed.

So the CI run that was red here was testing main, not this contribution.

On that red — it was not this diff, proven two ways

The assertion is error CS0103: The name 'sharedValue' does not exist — a successful execution returning a compile diagnostic, not a DeliveryFailure. This diff can only rewrite a DeliveryFailure's ErrorType/Message, so it cannot produce a CS0103.

Structurally the branch is also unreachable: it is gated on IsAddressDeleted(), RecentlyDeletedRegistry is written only by the delete handler, and MonolithKernelTest contains no delete at all — every message is a SubmitCodeRequest. With no tombstone the else arm runs, byte-identical to pre-change code. The class is 8/8 green locally on the merged tree.

The failure itself is real and now tracked separately

Filed as its own issue. Both kernel tests post fire-and-forget submissions back-to-back and depend on delivery order plus KernelExecutor's serial .Select(RunSubmission).Concat() pump; the two-post sibling MultipleSubmissions_ShareKernelState passed in the same run while the three-post one failed. The test's own docstring calls it "Minimal repro for the 'variables not defined' bug" — so this is exactly the symptom it exists to catch, not noise.

A hypothesis worth recording as discarded: 7635713e5 ("Two updates for one page could swap places, and the loser was dropped forever") looked like a perfect fit for out-of-order submissions, but it was already in the failing tree and it is Orleans-only (RoutingGrain/OrderedRouteDispatcher), while this test runs on MonolithRoutingService, which has no pooled route legs.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

AI.Test is not parallel-safe: cross-class shared state (repro in 100s via DOTNET_PROCESSOR_COUNT=4)

2 participants