StreamResyncGivesUpTest: a faulted stream reads USABLE for the whole of its own terminal delivery, so the cache hands the corpse to the consumer it just told — #4151's store-before-flag window (consolidates #4244; 6 occurrences) #4180

Activity

1. rbuergi commented on Sep 13, 2026

   

   rbuergi

   on Sep 13, 2026

   ContributorAuthor

   More actions

   2026-09-13 — reproduced locally, then a NULL result with the instrument. No hypothesis settled; correcting my own rate estimate.

   1. It reproduces off CI, on pristine main

   Detached worktree at origin/main 5bf8bbadf, macOS, Release:

   profile	runs	AResyncThatNeverConverges failures
   solo — -method "*StreamResyncGivesUp*"	60	0
   whole MeshWeaver.Data.Test (512 tests), one loop alone on the machine	6	1

   So it is reproducible without CI and without any PR's diff, which also settles an attribution question: MeshWeaver#4191's red on this test was this defect, not its own change (#4191 touches MessageService teardown classification and its docs — nothing near the stream cache). That tree did not contain #4191.

   2. The instrument, built to #4180's own specification

   Rather than reading IsUsable from the test — which sits inside the window it is measuring — the reading was moved to where the events happen:

   • inside FaultStore: three monotonic stamps — entering, Store.OnError returned, and the finally writing faulted;
   • inside StreamLiveness.IsUsable: every consult recorded on the stream (count, first/last timestamp, first/last result), so it covers all four Workspace consult sites and can also report "the cache never consulted at all", which would move the trail.

   Four readings were spelled out in advance so the first reproduction would settle it rather than start an argument: a consult stamped between onErrorReturned and flagWritten returning usable=true is (a) at FaultStore's window; usable=false with the same instance still handed back is (a) at the eviction seam; consults only ever after flagWritten returning true means the flag is not what decided it (IsUsable walks the reduce chain, so an ancestor could); no consult at all means the cache path does not go through this predicate.

   3. The null, with both denominators

   Instrumented tree and an uninstrumented control built from the identical commit 5bf8bbadf, run concurrently so the comparison is same-machine, same-minute:

   tree	runs	failures
   instrumented (FaultStore + IsUsable stamps)	40	0
   control (same commit, no instrument)	40	0

   🚨 The control did not reproduce either. That is the finding. It exonerates the instrument — the earlier worry that a probe might close the window it measures is not supported, because the tree without the probe behaved identically — but it means no reading was obtained and none of the four cases is settled.

   4. What changed between the profile that reproduces and the one that does not

   The only profile that has ever reproduced here is one full-project loop alone on the machine. The null came from two full-project loops running concurrently. Those are different load profiles, and load is the variable this race is known to turn on — so the concurrent pair, chosen to make the control fair, plausibly changed the very condition that drives it. I am flagging that as a hypothesis, not a conclusion: I did not re-test the single-loop profile with the instrument, because one implementation and one loop was the agreed budget and a third loop would be fishing.

   5. 🚨 Correcting a number I published earlier

   I described this as "~17%" off the 1-in-6 reading and reasoned from it that a merge-queue build clears it most of the time. 1 of 6 was too small a sample to carry that number. Pooling every uninstrumented full-project run today gives 1 failure in 46 (6 + 40) ≈ 2%, with a wide interval. The qualitative conclusion survives and in fact strengthens — at 2% a queue build almost always clears it, so being red on this defect does not reliably hold a PR (MeshWeaver#4191 merged on a queue build that passed) — but the figure I gave was wrong and anything reasoned from "17%" should be re-derived.

   What the next person should do

   The instrument is the right one and is cheap to rebuild from the description above (three field writes in FaultStore, one recording call in IsUsable, a temporary IDbg4180 interface on SynchronizationStream<TStream>). Run it under the profile that actually reproduces — a single full-project loop, alone on the machine — rather than against a concurrent control. One reproduction gives the four-way reading and settles (a) versus (b) outright.

   The test is unchanged; I did not adapt it to pass, and I did not pick a hypothesis from silence.
2. rbuergi commented on Sep 14, 2026

   

   rbuergi

   on Sep 14, 2026

   ContributorAuthor

   More actions

   Settled: outcome 1 — FaultStore's store-before-flag window. Reproduced deterministically, not sampled.

   #4244 is this issue and is closed into it; every occurrence either issue knows about is tabulated below.

   The reading

   The four outcomes were named in advance. It is the first: a consult inside the delivery, before the flag is written, returning usable=true. It did not need a lucky loop — the same defect is reachable at 100% through the other production shape, a consumer whose OnError arm runs on the delivering thread:

   MeshWeaver.Data.Test.FaultedStreamEvictionOrderingTest
       .AConsumerReactingToTheFault_IsHandedAFreshStream_NotTheCorpse   [FAIL]  (200 ms, on pristine main)
   
   Expected value to be false because a faulted mirror must be evicted from the stream cache,
   not replayed to the next caller, but found True.
   

   That is StreamResyncGivesUpTest's assertion, verbatim, off a test whose only act is: subscribe, and in the OnError arm ask the workspace for the stream again — the documented recovery path (#2387, "the next natural caller opens a fresh one"). It gets back the instance it was just told had died.

   Why the 2% version is provably the same defect

   ReferenceEquals(recovered, clientStream) can only be TRUE by Workspace.GetExternalClientSynchronizationStream finding StreamLiveness.IsUsable(stream) TRUE at its consult — every other route through that method mints a new instance (a false verdict evicts and loops; a freshly-built dead stream is a different object). And once the terminal has been delivered — which the test awaited — the only state in which the flag still reads live is the window between Store.OnError and the finally that writes it. So the failure message is the reading.

   StreamResyncGivesUpTest lands in that window because ReactiveWait.First settles its TaskCompletionSource with RunContinuationsAsynchronously from inside the delivery: the awaiting test thread is queued right there, and then races the producer's remaining few microseconds of unwinding to the finally. The producer usually wins. Hence ~1 in 46, and hence it reading as a flake — it is not one, and hypothesis (b) ("the test reads at an instant the contract never promised") is refuted: the contract is what was wrong.

   Why it is not "swap the order back"

   Two facts must hold at the same instant, and a bool beside the store can only hold one — each order is the other's window:

   order	bought	broke
   flag first (before #4151)	a reader that has SEEN the terminal finds the stream refused	a reader arriving between the two found a refused stream with an open store, answered completed, and the fault reached nobody — Plugins#1715
   store first (#4151, 72c2ee2a56)	the probe above became exact	the flag trailed the whole synchronous delivery — so every consumer reacting to the fault got the corpse. This issue.

   The second is the larger window by construction: it is not an interleaving, it is the delivery itself, which is exactly when consumers act.

   The fix publishes the terminal instead of a bit. FaultStore records the exception (Interlocked.CompareExchange, so the record names the same FIRST error the ReplaySubject keeps) and only then errors the store; IsFaulted is "that record is not null". One write, no ordering. A reader refused by IsUsable reads stream.TerminalFault() and forwards that exact instance instead of probing a store that may not have terminated yet — LayoutExtensions.GetStream<T> now does, which closes Plugins#1715 without depending on an ordering at all.

   Every occurrence (this issue + #4244)

   #	run	how it showed	that PR's whole diff
   #4162	34750776579	merge-queue solo build, shard 1	activation-retirement fix — touches neither streams nor the workspace cache
   #4215	—	dequeued from the merge queue	CI: one-build-per-assembly-name
   #4227	—	dequeued from the merge queue	token validation issued off the router
   #4239	34782436418	shard 1, ~21:05Z	Plugin.Build/*, Plugin.Packaging/*, two Graph tests, one doc
   #4241	34783283849	shard 1, 21:15Z	two localization JSON files
   #4191	—	reddened	teardown log-level fix

   A six-line localization diff cannot change whether a resync converges, which is what removed "the PR perturbed it" as a reading.

   One correction to this issue's own framing

   #4151 … may have traded one window for the other

   It did, and the resolution is neither order. Note also that #4151's pin AFaultingStream_PublishesItsTerminal_BeforeItReadsAsDead asserted IsUsable() == true during the delivery — i.e. the failing assertion here and that green pin were direct contradictions of each other, in the same tree. It is replaced by AFaultingStream_ReadsAsDead_AndNamesItsTerminal_FromTheFirstDelivery, which asserts both halves at that one instant.

   Fix: #4255. No known-flakes.json entry — a race is a defect.
3. rbuergi

   changed the title [-]StreamResyncGivesUpTest: a faulted mirror was handed back by the stream cache — #4151's store-before-flag ordering opens a window where a faulted stream still reads USABLE (1 observation, load-dependent)[/-] [+]StreamResyncGivesUpTest: a faulted stream reads USABLE for the whole of its own terminal delivery, so the cache hands the corpse to the consumer it just told — #4151's store-before-flag window (consolidates #4244; 6 occurrences)[/+] on Sep 14, 2026
4. meshweaver-cloud

   closed this as completedin #4255on Sep 14, 2026