Two teardown/disposal races red one Build-and-Test run: a mesh shutting down mid-bake, and a faulted change-feed entry whose release does not claim it #3333

Activity

1. rbuergi commented on Sep 5, 2026

   

   rbuergi

   on Sep 5, 2026

   ContributorAuthor

   More actions

   Half 1 (ChangeFeedResetReleasesUpstreamTest) is root-caused and fixed — and half 2's stated cause is backwards

   The change-feed arm: the test measured its own assertion

   ReleaseIfUnwatched refuses an entry that still has a live subscriber (Entry.TryMarkIdleEvicted
   returns false while subscribers > 0). At line 178 the only subscriber left was the assertion on
   line 124 — the one that had just returned.

   ReactiveWait.First disposed its subscription as a continuation on the settled task, and a
   continuation structurally cannot get there first:

   • the task is created with RunContinuationsAsynchronously, so TrySetResult queues the awaiting
     test immediately;
   • every call site builds …Take(1).ToList().Timeout(…), and Take(1) disposes its upstream from
     inside ForwardOnCompleted — i.e. after it has pushed the value down into the handler.

   So the unsubscribe was always last, and the test resumed while still attached. On a quiet machine the
   producer's remaining few instructions win; under six concurrent shards they don't. That is the whole
   flake, and it was latent for every assertion in the fleet whose subject is "is anything still
   watching this?" — not just this test.

   Fix: ReactiveWait.First now disposes inside the handler, ahead of the settle, so "the wait
   settled" implies "the wait unsubscribed". A source that emits synchronously during Subscribe is
   covered by construction — the caller has no task to await until First returns, and
   SingleAssignmentDisposable disposes on assignment before that.

   Guarded by AssertionUnsubscribesBeforeItSettlesTest, which fails on the unpatched code
   (Expected value to be 0 … but found 1) and passes on the fix. It widens the window deliberately —
   the real one is a handful of instructions, so a guard written without that would have passed while
   the defect was present.

   Verified: MeshWeaver.Hosting.Test 350/350.

   The bake arm: the shutdown is a CONSEQUENCE, ~110 ms too late to be the cause

   The quote above (… mesh/O0ixdCgnbkawTtQz-bUBQw is shutting down (RunLevel=DisposeHostedHubs)) is the
   harness's own .Finally(harness.Dispose) firing because the run had already faulted. From the
   shard-3 job log:

   time	line
   01:51:46.593	ok Widget/Thing [compile:Passed render:Passed tests:Skipped]
   01:51:46.606	Actual: "InvalidOperationException: bake: 'Widget/Thing' cl"··· ← the test has already failed
   01:51:46.716	first … is shutting down (RunLevel=DisposeHostedHubs)
   01:51:48.719	[QUIESCE-TIMEOUT] Widget/Thing: 2 callback(s) still pending

   Teardown starts 110 ms after the assertion failed. So this is not #2543, and anyone starting
   from "a mesh shutting down mid-bake" will chase a symptom. Sorry — that was my reading, and the
   timestamps do not support it.

   What actually happened is a read-before-write, 13 ms wide:
   BakeOutput.CollectOne does workspace.GetMeshNodeStream(typePath).Where(n => n is not null).Take(1),
   reads LastCompiledVersion, then asks IAssemblyStore.TryGetAssemblyPath(path, version) and throws
   … claims a usable build at v{version} but the run's assembly store has NO bytes for it. The node
   advertised a version the store did not yet hold. The same log shows the post-compile chain still in
   flight at that instant — CREATE_CHAIN_SUBSCRIBED path=Widget/Thing/Release/20260905015146-qRmi8PqM
   was one of the two callbacks the quiesce timeout later named, and
   [ReleasePostCondition] Widget/Thing: … this compile succeeded, yet the node names NO release at all
   fired for the same node.

   Note the shape is the same family as the arm above: something read a state it had not observed
   settle. Take(1) on a live node stream takes whatever emission is in hand, which is not necessarily
   the one the compile just produced.

   Two things a fix has to decide, and I have not:

   1. whether LastCompiledVersion may become visible on the node before the store holds the bytes
      for it (an ordering defect in the compile chain), or
   2. whether CollectOne must wait for the version it was told to bake rather than Take(1)-ing the
      first non-null node (a read defect in the bake).

   FileSystemAssemblyStore.TryGetAssemblyPath also keys on v{version}-{FrameworkTag}-*.dll, so a
   third possibility is a tag mismatch — but both bakes in this run printed the same
   framework=gc4e2d62fdbadec41fd25bdacce82572243a2e911, so that one is ruled out for this failure.

   Leaving the bake half open with the corrected reading. The change-feed half is fixed.
2. rbuergi commented on Sep 5, 2026

   

   rbuergi

   on Sep 5, 2026

   ContributorAuthor

   More actions

   Bake arm — two more hypotheses ruled OUT, and the one that survives

   Recording the negative results so nobody re-walks them.

   ❌ Cross-test eviction through the shared pid-scoped store. This looked compelling: the default
   IAssemblyStore (PersistenceExtensions.RegisterDefaultAssemblyStore) roots at
   {temp}/MeshWeaver-AssemblyStore-pid{ProcessId} — per process, not per mesh — and shard 3 runs
   five tests that each compile a node called Widget/Thing in the same host
   (BakeAgainstPlatformHostTest, BakeOutputTest, two BakeGateSplitTest methods,
   BakeEquivalenceTest), all landing in the same Widget/Thing directory with low, colliding version
   numbers. FileSystemAssemblyStore.EvictSupersededVersions keeps only the top 3 versions per
   (type, framework tag) and protects only the file the current Put just published — so one test's
   Put deleting another's still-referenced bytes is exactly the right shape.

   It is not what happened: PluginGateRunner replaces that store per run —

   // Per-run isolated assembly store + compilation cache (AddInMemoryPersistence
   // TryAdds a process-pid-scoped store — REPLACE it, mirroring the test base).
   s.RemoveAll<IAssemblyStore>();
   return s.AddFileSystemAssemblyStore(Path.Combine(runRoot, "assembly-store"));

   so each gate run has its own root and cannot see another test's versions.

   ❌ Framework-tag mismatch. TryGetAssemblyPath matches v{version}-{FrameworkTag}-*.dll, so a
   tag change between Put and Get would miss with bytes present — but both bakes in this run printed
   the same framework=gc4e2d62fdbadec41fd25bdacce82572243a2e911.

   ✅ What survives: a stale node read meeting the store's own retention, both inside one run.

   1. BakeOutput.CollectOne reads workspace.GetMeshNodeStream(typePath).Where(n => n is not null).Take(1).
      .Take(1) takes whatever the cache's Replay(1) has in hand, which is not necessarily the
      revision the compile that just finished produced.
   2. Every write to the node bumps its version, and ApplyCompileSuccess stamps
      LastCompiledVersion = result.Version ?? currentNodeVersion — its own comment warns that a
      mismatch here "would point activation at a store key that has no bytes".
   3. Within one run the retention is still live: keep 3 versions, and only the file the current
      Put published is protected. A type that gets four or more Puts in a run loses its earliest.

   A stale revision naming an evicted version produces exactly claims a usable build at v{version} but the run's assembly store has NO bytes for it, and needs enough compiles of one type in one run to
   bite — which fits how rarely it does.

   That points the fix at (1) rather than at teardown: CollectOne should wait for the node revision
   whose compile it is baking, not Take(1) the first non-null one. Same family as the arm fixed in
   #3336 — something read a state it had not observed settle — but a separate defect in separate code,
   and I have not proved step 3 fires here (it needs a Put count per run, which I have not measured).
   Not claiming it as root-caused.
3. rbuergi commented on Sep 5, 2026

   

   rbuergi

   on Sep 5, 2026

   ContributorAuthor

   More actions

   Bake arm — eviction is out too. Measured, not reasoned.

   Ran BakeEquivalenceTest locally (green) and looked at what the gate's own per-run store actually
   contains afterwards:

   $TMPDIR/mw-plugin-test-40321-<guid>/assembly-store/
     Widget_Thing/v3-58f3adaa-1d396291f01d.dll
     Lib_Shared/v3-58f3adaa-8b9390b942a8.dll
   

   Exactly one version per type. EvictSupersededVersions keeps 3, so with a single Put per type
   per run it never fires — the retention hypothesis from my previous comment is ruled out, in-run as
   well as cross-test.

   That is actually the useful result, because it removes the last way "bytes existed but were not
   found" could be true. In the failing run the store held one version for Widget/Thing, and the
   node named a different one. So:

   NodeTypeDefinition.LastCompiledVersion did not match the version IAssemblyStore.Put used.

   which is the exact hazard ApplyCompileSuccess documents against itself:

   // Stamp LastCompiledVersion to MATCH the version the IAssemblyStore upload used
   // (set by UploadToStoreIfNeeded — the captured node Version at compile kickoff).
   // A different version here would point activation at a store key that has no
   // bytes — TryGetAssemblyPath miss, activation falls back to the default config.
   LastCompiledVersion = result.Version ?? currentNodeVersion,

   The ?? is the whole exposure. When result.Version is present it is the kickoff version and matches
   the Put. When it is null, the stamp falls back to currentNodeVersion — the node's version at
   stamp time — and the node has been written since (the failing run shows Widget: installed (9 written…) plus a CreateOrUpdateNodeRequest from CompileStateMirror and a CreateNodeRequest for
   the Release node, both still pending at teardown). A node that has moved on produces a stamp naming a
   key the store never held.

   So the question for whoever picks this up is narrow: under what conditions does
   UploadToStoreIfNeeded return a result with no Version, and is falling back to currentNodeVersion
   ever correct? Given the comment's own reasoning — the fallback is only right if the node has not
   been written since kickoff, which nothing enforces — a stamp with no store version looks like it
   should be a failure to stamp Ok, not a guess.

   Note the bake's postcondition is behaving correctly throughout: it refuses to write a bundle that
   ships less than the gate verdict claims. It is reporting a real inconsistency, not inventing one, and
   the same inconsistency would send a portal's activation to a store key with no bytes.

   Summary of what is now excluded, with evidence:

   hypothesis	verdict
   mesh tearing down mid-bake (#2543)	❌ shutdown logs land 110 ms after the failure
   cross-test eviction via the pid-scoped default store	❌ the gate RemoveAll<IAssemblyStore>() and roots per run
   in-run eviction (keep-3 retention)	❌ measured: one version per type per run
   framework-tag mismatch in the store key	❌ both bakes printed the same framework=g c4e2d62…
   LastCompiledVersion ≠ the version Put used	✅ the only shape left standing
4. rbuergi commented on Sep 5, 2026

   

   rbuergi

   on Sep 5, 2026

   ContributorAuthor

   More actions

   Both halves are owned, fixed and guarded on main

   This issue asked for "an owner rather than a re-run" for two teardown/disposal races. Both have
   one now, each with a root cause, a merged fix and a guard that fails without it.

   1. ChangeFeedResetReleasesUpstreamTest — the test measured its own assertion. ReactiveWait.First
   disposed its subscription as a continuation on the settled task, so the unsubscribe was structurally
   always last and the test resumed while still attached. It now disposes inside the handler, ahead
   of the settle, so "the wait settled" implies "the wait unsubscribed". Guarded by
   AssertionUnsubscribesBeforeItSettlesTest (present on main), which widens the window deliberately
   — the real one is a handful of instructions, and a guard written without that would pass while the
   defect was present. This was latent for every assertion in the fleet whose subject is "is
   anything still watching this?", not just this test.

   2. BakeEquivalenceTest — the store address was not moving as one. #3341, merged. The three
   fields that address one blob each fall back to the definition's previous value — except
   LastCompiledVersion, which fell back to the node's version at stamp time:

   LatestAssemblyCollection = result.Collection  ?? def.LatestAssemblyCollection,
   LatestAssemblyPath       = result.ContentPath ?? def.LatestAssemblyPath,
   LastCompiledVersion      = result.Version     ?? currentNodeVersion,   // ← now def.LastCompiledVersion

   result.Version is set in exactly one place — the projection over a successful PutWithLocation —
   so a null means nothing was stored, and the old fallback produced old collection + old path +
   new version: a key the store never held. NodeTypeBatchBake states the invariant it broke in as
   many words ("LastCompiledVersion always names a store key that has bytes"). Because the stamp
   reads from the same projection that performs the Put, this was the only way the recorded
   version could disagree with the stored one — the single row this issue's elimination table left
   standing after teardown, cross-test eviction, in-run retention and framework-tag mismatch were each
   excluded by measurement.

   The existing test had pinned the defect: named …AndFallsBackToTheNodeVersion, asserting the
   version jumps while asserting two lines below that the collection and path do not. Rewritten, plus a
   case for "nothing ever uploaded" staying null. Mutation-proved. Committed to
   Doc/Architecture/NodeTypeCompilation as "The store address is a TRIPLE, and it moves together or
   not at all".

   What is NOT proven, stated plainly

   That the store-address fix is what made that particular run fail. The failing run's store is
   gone, so whether it took the no-upload path cannot be established post-hoc. What is established is
   that the shape existed, that it was the only remaining mechanism for the mismatch this issue
   narrowed to, and that it is now closed and guarded.

   Closing on the issue's own terms — both races have owners and merged fixes — rather than on a clean
   run, which at this base rate would prove nothing either way. Reopen if BakeEquivalenceTest fails
   again with a bake: '<Type>' cl… refusal: that would mean a second mechanism exists, and the
   elimination table above is the right place for whoever picks it up to start.
5. rbuergi

   closed this as completedon Sep 5, 2026
6. rbuergi commented on Sep 5, 2026

   

   rbuergi

   on Sep 5, 2026

   ContributorAuthor

   More actions

   Recurrence — second instance, and this one is blocking a release PR

   BakeEquivalenceTest.MeshDrivenAndCompilerDrivenBakes_ProduceTheSameArtifacts failed again on
   #3366 ("release: 3.0.0 is cut first, then the line moves to 3.1.0"), shard 3, with the
   identical signature:

   Assert.Null() Failure: Value is not null
   Actual:   "InvalidOperationException: bake: 'Widget/Thing' cl"···
   

   first seen	#3332, run 33937167117, 2026-09-05 ~01:52Z
   now	#3366, shard 3, 2026-09-05 ~21:26Z
   both	Widget/Thing, same truncated message, same assertion

   Two instances ~20 h apart on unrelated PRs (a probe-endpoint change and a release cut) means this is
   a standing flake in MeshWeaver.PluginTester.Test, not something either diff reached. It is now on
   the critical path: a release PR cannot merge through it.

   Where the diagnosis already stands

   From the earlier comments on this issue, four hypotheses are eliminated by measurement, not
   argument:

   hypothesis	verdict
   mesh tearing down mid-bake (#2543)	❌ shutdown logs land 110 ms after the assertion failed
   cross-test eviction via the pid-scoped default store	❌ the gate does RemoveAll<IAssemblyStore>() and roots per run
   in-run eviction (keep-3 retention)	❌ measured: exactly one version per type per run
   framework-tag mismatch in the store key	❌ both bakes printed the same framework=gc4e2d62…

   What survives: NodeTypeDefinition.LastCompiledVersion names a version the assembly store never
   held. The exposure is one line in ApplyCompileSuccess:

   LastCompiledVersion = result.Version ?? currentNodeVersion,

   Its own comment says the stamp must MATCH the version UploadToStoreIfNeeded used. When
   result.Version is present it does. When it is null, the fallback takes the node's version at
   stamp time — and the node has been written since (the failing run shows
   Widget: installed (9 written…) plus a CompileStateMirror CreateOrUpdateNodeRequest and the
   Release-node CreateNodeRequest still pending at teardown). A node that has moved on yields a stamp
   naming a store key that was never written.

   The question to answer first: under what conditions does UploadToStoreIfNeeded return a result
   with no Version? If the answer is "when the upload did not happen", then falling back to
   currentNodeVersion is stamping success onto bytes that do not exist, and the correct behaviour is
   to fail the compile rather than guess a version — the bake's postcondition is right to refuse it.

   I have not proved that last step, which is why this is still open rather than fixed.
7. rbuergi commented on Sep 5, 2026

   

   rbuergi

   on Sep 5, 2026

   ContributorAuthor

   More actions

   The bake arm is fixed on main — 8614af280, "The store address moves together: stamp the version
   the upload used, or keep the previous one (#3333)". Recording it here so nobody re-derives it from
   my earlier comments, which stopped one step short.

   LastCompiledVersion = result.Version ?? def.LastCompiledVersion,   // was: ?? currentNodeVersion

   My narrowing was right about where — result.Version is set in exactly one place, the projection
   over a successful PutWithLocation, so a null means nothing was stored rather than "we forgot
   the version". But I framed the damage as "the version names a key with no bytes." The commit's
   reasoning is sharper:

   That splits the triple that addresses one blob: old collection, old path, new version — a key the
   store never held.

   The three fields that address a blob (LatestAssemblyCollection, LatestAssemblyPath,
   LastCompiledVersion) all fall back to their previous value except the version, which fell back to
   the node's version at stamp time. So two thirds of the address stayed put while the third moved.
   Keeping the previous value keeps the triple coherent, and a null stays honest because every reader
   already applies its own ?? node.Version — the guess lives at the read, where it is a heuristic,
   instead of frozen into the node as a claim.

   Timeline consistent with the sightings: the two failures (#3332 ~01:52Z, #3366 ~21:26Z) both ran
   against trees predating this, and #3366's re-run went green afterwards.

   Worth keeping from the investigation, since the eliminations cost real measurement:

   hypothesis	verdict
   mesh tearing down mid-bake (#2543)	❌ shutdown logs land 110 ms after the assertion failed
   cross-test eviction via the pid-scoped store	❌ the gate RemoveAll<IAssemblyStore>() and roots per run
   in-run eviction (keep-3 retention)	❌ measured: one version per type per run
   framework-tag mismatch in the store key	❌ both bakes printed the same framework identity
   LastCompiledVersion naming a key never written	✅ — fixed in 8614af280

   Suggest closing this arm. BakeEquivalenceTest should now be watched only for a third sighting on
   a tree that contains the fix; that would mean a different cause.
8. rbuergi commented on Sep 5, 2026

   

   rbuergi

   on Sep 5, 2026

   ContributorAuthor

   More actions

   ⚠️ Retracting the previous comment — do NOT close this arm

   I said the bake arm was fixed by 8614af280 and suggested closing. A third sighting says otherwise,
   and it is the exact case I named as the discriminator.

   #3369 (a one-file docs PR — docs: a head-truncated view of ordered output is biased) failed
   BakeEquivalenceTest.MeshDrivenAndCompilerDrivenBakes_ProduceTheSameArtifacts on shard 3 at
   22:31:55Z with the identical message:

   Assert.Null() Failure: Value is not null
   Actual:   "InvalidOperationException: bake: 'Widget/Thing' cl"···
   

   And its tree contains the fix:

   $ git merge-base --is-ancestor 8614af280 <#3369 head>   → YES
   

   So LastCompiledVersion = result.Version ?? def.LastCompiledVersion did not resolve it. Either the
   incoherent-triple defect was real but not the only cause, or it was never the cause of this test's
   failure at all.

   What I got wrong. I inferred the fix worked from #3366's green re-run. That was a single passing
   run of an intermittent test — the same "a flake's passing re-run proves nothing on its own" trap I
   have been careful about all night, and I walked into it because the fix's reasoning was persuasive
   and matched my own narrowing. A passing run of a flaky test is not evidence a fix landed; only a
   failing run on a fixed tree is decisive, and that is what #3369 now provides.

   Corrected state — three sightings:

   PR	when	tree has 8614af280?	result
   #3332	09-05 01:52Z	no	FAIL
   #3366	09-05 21:26Z	no	FAIL
   #3369	09-05 22:31Z	yes	FAIL

   Unrelated diffs each time (probe endpoints, a release cut, a docs page), so nothing about those PRs
   reaches it. It is a standing flake in MeshWeaver.PluginTester.Test, still open, and it has now
   touched a release PR once.

   The four eliminations in my earlier comments still hold and are still worth not re-deriving. What is
   no longer eliminated is the store-key question: the fix addressed one way for the triple to go
   incoherent, and the test says there is another. The next decisive step is the one I never took —
   capture the full exception text (xUnit truncates at 'Widget/Thing' cl), which names the version
   it claims and lets that be compared against what the run's store actually holds. The message exists
   in the run's own log; it just needs reading rather than inferring from the assertion summary.