You signed in with another tab or window. Reload to refresh your session.You signed out in another tab or window. Reload to refresh your session.You switched accounts on another tab or window. Reload to refresh your session.Dismiss alert
{{ message }}
Repository navigation
CrossProcessChangeFeedTest intermittently reproduces the PRE-FIX signature it was written to detect #2008
CrossProcessChangeFeedTest.AWriteInOneProcess_ReachesTheOtherProcessesLiveMirror_WithoutARecycle failed on #1988's shard 1 with the pre-fix signature from #1929 — the failure that fix exists to eliminate:
Expected value to be 2 because the mirror ADOPTS the durable version verbatim.
Against `main` this is where the test fails: the mirror ends at durable+1 — a revision
the store never held (#1432) — because the notification was dropped and the content only
arrived later, through a read-seeded mint. … but found 3.
It passed on re-run, and the six shards are now green.
Why this is not "just a flake"
The assertion is not a timing bound — it is a value comparison, and the value it found (durable+1 = 3) is specifically the shape #1432 describes: converging on content by accident, at a version that exists nowhere, because the notification was dropped and the content arrived later through a read-seeded mint.
So the observed behaviour is the notification losing a race with the read-seeded mint. #1929 closed that path in the steady case; intermittently it still loses. A green re-run tells you the race is not deterministic. It does not tell you it is gone.
What was ruled out
#1988 is not the cause. Its entire diff is one file — memex/Memex.Portal.Shared/MemexConfiguration.cs — adding a response-header middleware (app.Use → OnStarting → set headers) to the HTTP request pipeline. CrossProcessChangeFeedTest builds hubs against a shared store and runs no HTTP pipeline at all. It is rebuilt by the change (MeshWeaver.Hosting.Monolith.Test references Memex.Portal.Shared), so it is not out of reach by dependency — only by behaviour. The re-run passing is consistent with that.
What is NOT evidence, and should not be cited as such
The test passes locally on main — in 2 s for 3 tests, against bounds of [Fact(Timeout = 90_000)] and TestHardDeadline = 120 s. That is far too fast to have exercised the Postgres notify path CI uses, so the local run clears nothing. Anyone reproducing this needs to confirm which path they are actually on before drawing a conclusion.
Suggested next step
Establish the race rather than re-running until green: instrument the ordering between the delivered notification and the read-seeded mint, and assert the notification wins — or make the mint unable to advance the version when a notification for that revision is in flight. The current assertion is correct and should not be relaxed; it caught this.
Reported by me because the fix in #1929 is mine, so this is my debt rather than #1988's.
Local attribution on the same tree: 10/10 sequential passes (--filter FullyQualifiedName~CrossProcessChangeFeedTest.AWriteInOneProcess, Release). Matches the issue title: the CI environment intermittently re-samples the dropped-notification → read-seeded-mint path that #1929 closed. Per the repo's race-repro note, DOTNET_PROCESSOR_COUNT=4 locally is the known way to approximate CI scheduling for this family.
(Reporting to keep the record in one place — both PR runs were re-run rather than "fixed", since the diffs are unrelated.)
Another occurrence: PR #2184, run 32781941594, shard 1 (2026-08-24 22:15 UTC) — AWriteInOneProcess_ReachesTheOtherProcessesLiveMirror_WithoutARecycle, sole failing test. The branch's diff (Blazor component moves + module publish lanes) has no cross-process change-feed surface, and the same suite ran 757/757 locally on the branch. Rerunning per the standing flake protocol.
Still live, and the two CI traces are byte-identical — so this is a second deterministic path, not jitter
Swept the last 300MeshWeaver Build and Test runs (2026-08-23 → 2026-08-25), reading the [FAIL] lines out of every attempt, not just runs whose final conclusion was failure (a
re-run-to-green hides the attempt that failed). This test is the third most frequent failure in
that window:
Occurrences: 32722799059/1, 32728115289/1, 32781941594/1, 32891723627/1 — all shard 1.
(Its Postgres sibling CrossProcessNotifyPgTests.AWriteByAnotherProcess_ArrivesOnThisProcessesPartitionFeed
also failed once in the window — worth keeping in view, same family.)
The traces are identical to the character across two independent runs a day apart:
against the healthy shape, which is equally invariant (31/31 local runs):
[B emit] name=written-in-A v=2 writesB=0 readsB=7
So the failing run does exactly two extra reads and exactly one extra mint. That reproducibility
is the most useful thing in the issue: this is a second, deterministic path being taken, not a
timing smear.
What is now ruled out
NOT the "subscribed after the event" class (the defect PR Arm the observer BEFORE the trigger — a hot emission missed has no second chance #2259 established). The trace
subscription is armed before the write, the mirror is Replay(1).RefCount() with a keepAlive,
and every emission is printed. There is no emission at v2 that the assertion could have missed —
the mirror genuinely never held v2.
NOT a stale durable capture in the test.WaitDurable returns the first store snapshot
matching the name, so "the store moved on afterwards" was the obvious test-side explanation. The [store] v=2 line printed immediately before the assertion refutes it: the store held 2 at
assert time, and the mirror held 3. The assertion is correct and must not be relaxed.
NOT reproducible locally: 30/30 sequential green with DOTNET_PROCESSOR_COUNT=4, Release,
isolated — every run the healthy readsB 4→7 / v=2 shape. Matches the earlier 10/10 comment.
The mechanism this points at — a hypothesis with a code path, not a guess
AdoptPersisted is careful not to mint (UpdateOwn(..., adoptPersisted: true) skips NextVersion and records the durable version in PostCommitFlushRegistry). But the value it
commits still passes through the data source, and MeshNodeTypeSource.UpdateImpl re-stamps it:
PreviousVersion comes from _lastSaved, and _lastSaved is written from two places that are
not ordered against the workspace's own store:
BuildInstanceCollection sets it eagerly, when the collection is BUILT — before the workspace
has applied it;
UpdateImpl sets it at the end of a commit.
The entity-less notification wakes two consumers in process B that both re-read the same durable
row — the per-node hub's coalesced re-read (SubscribeToOwnDeletion's reReadTrigger) and the
routing/catalog leg feeding _ownNodeStream. Those two reads are, I believe, the +2 that separate
the failing trace from the healthy one. If the routing leg wins and builds a collection at durable
v2 — setting _lastSaved = {v2} while the workspace store is still at v1 — then:
the re-read's AdoptPersisted(v2) sees current.Version == 1, so the forward-only guard lets it
through and it commits;
UpdateImpl diffs the incoming v2 against _lastSavedalready at v2. It still counts as an
update, because the version-ignoring comparison is record Equals, which is reference-based on Content — two deserializations of the same row are not equal;
That produces precisely what the trace shows: one emission, at durable+1, carrying the durable
content, with nothing written to the store — "converging on content by accident, at a version that
exists nowhere", which is the #1432 wording this test was given.
This is a hypothesis. It explains every observable (the exact +2 reads, the single v3 emission, writesB=0, the store at 2) and it names a real window in the code, but it has not been reproduced.
I am deliberately not shipping a speculative change to the own-node versioning core on that basis: MeshNodeTypeSource's stamping logic already carries the scars of #325, #590, #1432 and the
2026-07-30 refusals, and a wrong move there is write loss rather than a flaky test.
What would settle it in one CI run
Both lines needed already exist at LogDebug and cost nothing to turn on for this assembly:
A failing run that shows a second own-node collection build at version 2 before the adoption's UpdateImpl confirms the hypothesis; one that does not, kills it. Note the test's ILogger output
goes to XUnitFileOutputHelper's file rather than to xUnit's console output, which is why none of
it appears in the CI logs today — that alone is worth fixing before the next attempt at this issue.
If it is confirmed, the fix is not a wider bound but a rule with a name: an own-node update whose
version is already recorded DURABLE (PostCommitFlushRegistry) is an observation, not an unminted
edit — never re-stamp it. That is exactly the discrimination AdoptPersisted already makes one
layer up; the layer underneath does not make it.
Follow-up on the sibling named above: the Postgres one turned out to be a different defect, so it now has its own issue — #2281, fixed in #2286. Its failure is a 30 s TimeoutException (no notification at all), not a wrong version, and the cause is that CrossProcessNotifyPgTests gated on pg_stat_activity — which reports the CONNECTION, while LISTEN mesh_node_changes runs one statement later. The gate went green inside the window it existed to close, and Postgres never replays a NOTIFY.
Recording it here only so nobody folds the two together while working this one: #2008 is not that. Its notification demonstrably arrives (the mirror converges on the right content); what is wrong is the version it converges at.
Local reproduction attempts, for the record (all -c Release, DOTNET_PROCESSOR_COUNT=4, on ed4588222):
30/30 sequential, isolated filter — every run the healthy readsB 4→7 / v=2 shape.
1 co-tenant run (every class in the assembly whose name starts with C, so the test runs alongside neighbours rather than alone) — also healthy, same shape.
The full-assembly control could not be completed locally: the test host crashes part-way through MeshWeaver.Hosting.Monolith.Test (The active test run was aborted. Reason: Test host process crashed), twice, ~35 tests in and unrelated to this test. CI splits the assembly across two parts and does not hit it. That is a separate local-only obstacle, but it is worth knowing that "I ran the full assembly locally" is not currently an available control for anything in this assembly — which matters because an isolated run discriminates nothing for a full-suite-only failure.
So: not reproduced. The analysis in the previous comment rests on the two CI traces being byte-identical (readsB 4→9, one emission at v=3, store at v=2, writesB=0) and on the code path, not on a local red.
On the suggestion that this and the PostgreSQL cross-process test are one mechanism: they are not, and the discriminator is in the two failures' own text.
"The announcement was delivered and then mis-applied" and "the announcement was never delivered" cannot be the same defect, and #2281 is now closed by a deterministic red/green (#2286) that leaves this one untouched. Same area, same night, two mechanisms.
Recording it because the pairing is a natural thing to assume, and assuming it here would send the next investigator looking at the wire — which is the half that works.
A correction to the hypothesis's mechanism (not the fix), plus a diagnostics-visibility PR
Read through the mechanism the last comment's hypothesis rests on — a second own-node reconcile
path (the ROUTING leg's _ownNodeStream re-resolving on notification, invalidated by PathResolutionService) that re-emits into MeshNodeTypeSource.BuildInstanceCollection,
bypassing UpdateImpl's diff/version-stamping, racing SubscribeToOwnDeletion's reReadTrigger → AdoptDurable → AdoptPersisted path.
That specific mechanism does not apply to this test as stated.MonolithRoutingService.CreateHub
supplies the routing leg's _ownNodeStream as a one-shotObservable.Return(enriched):
// src/MeshWeaver.Hosting.Monolith/MonolithRoutingService.csvarownStream=Observable.Return(enriched);varcreatedHub=Mesh.GetHostedHub(address, c =>enriched.HubConfiguration!(c.WithOwnNodeStream(ownStream)));
with the comment: "One-shot is fine on Monolith — cross-hub MeshNode updates flow through
IDataChangeNotifier / IMeshChangeFeed already." That stream emits once, at hub activation, and
completes — well before the write this test exercises happens (process B's mirror is already
seeded and live by the time A writes). So for the event this test asserts on, Initialize()'s .Concat(_ownNodeStream...) leg contributes nothing further, and BuildInstanceCollection is not
re-entered on this path after activation. The only live reconcile at that point is SubscribeToOwnDeletion's single reReadTrigger → AdoptDurable → AdoptPersisted → UpdateOwn(adoptPersisted: true) chain, which — walking UpdateImpl's diff — looks correctly
guarded (alreadyAdvanced holds because the adopted version is strictly above PreviousVersion).
I believe the "two independent re-read consumers" shape in the hypothesis describes Orleans' PathResolutionService-memoized AddressResolution, invalidated by "the per-silo change feed"
(silo terminology, and MessageHubGrain.cs also touches WithOwnNodeStream) — not Monolith, which
is what CrossProcessChangeFeedTest actually runs. Recording this so the next investigator doesn't
re-derive it, and doesn't waste time confirming/refuting a mechanism that can't fire here.
I have not identified the actual mechanism. readsB going 4→9 instead of the healthy 4→7 (two
extra reads) still needs an explanation, and I don't have one that survives the one-shot-ownStream
correction above.
What I did ship: #2348 — process B's diagnostics now reach captured output
Confirmed empirically that process B (BuildSecondProcess) had zero logging providers — services.AddLogging(l => l.ClearProviders()) with nothing added back — so every ILogger call in
process B, including the two MeshNodeTypeSource.LogDebug lines this issue's earlier comment named
as "cost nothing to turn on," went nowhere: not xUnit output, not the file, regardless of level.
That's a stronger defect than "goes to the file instead of the console" — it's "goes nowhere at
all" — and it means every occurrence to date, including the ones analyzed above, ran with zero
visibility into process B's own-node reconcile.
#2348 wires process B's logging the same way process A's already is (TestBase's XUnitFileLoggerProvider, pointed at the shared FileOutput) and grants MeshWeaver.Graph.MeshNodeTypeSource a Debug override for both processes (appsettings.json for
A, an in-memory IConfiguration for B, since B never loads the JSON file). Verified locally that
process B's diagnostics now reach the captured test output where they were previously completely
absent.
Not a fix — no production code changed. This issue stays open until a CI occurrence with the new
diagnostics on lands and the actual mechanism can be read off it.
First reproduction WITH process B's diagnostics — #2348 worked
This issue asked for exactly one thing to settle it: "the two LogDebug lines already in MeshNodeTypeSource, which today never reach any CI artifact for process B."#2348 (merged 5b1901fb6) restored process B's logging providers — it had services.AddLogging(l => l.ClearProviders()) with nothing added back, so every ILogger call in that process went nowhere, including on every failing run.
The flake has now recurred on a run that carries the fix — PR #2352, shard 2, run 32964944158, 2026-08-26 ~11:53Z. (#2352's diff is deploy/helm YAML only and cannot reach this assembly; it is an unrelated carrier.)
The assertion
MeshWeaver.Reactive.Assertions.AssertionException :
Expected value to be 2 because the mirror ADOPTS the durable version verbatim.
Against `main` this is where the test fails: the mirror ends at durable+1 — a revision the
store never held (#1432) — because the notification was dropped and the content only arrived
later, through a read-seeded mint. Converging on content by accident, at a version that exists
nowhere, is not a mirror learning of a write, but found 3.
Expected 2, found 3 — durable+1, precisely the shape this issue describes.
What process B actually did (previously invisible)
[11:53:04.432] MeshNodeTypeSource: Created for hubPath=TestData/cross-proc-34b038d7…
(routingSuppliedStream=True)
[11:53:04.436] MeshNodeTypeSource[…]: durable activation seed read (version=1)
[11:53:04.519] MeshNodeTypeSource: Opening gate for … — node Active via update
[11:53:04.519] MeshNodeTypeSource.UpdateImpl: adds=0, updates=1, deletes=0
Three things worth reading off that, which were unavailable before:
routingSuppliedStream=True — process B's MeshNodeTypeSource was constructed with the routing-supplied _ownNodeStream. test: make process B's own-node diagnostics reach CI output (#2008) #2348's investigation established that on Monolith this is a one-shotObservable.Return(enriched) that completes at activation, so it cannot be the source of a later re-emission.
durable activation seed read (version=1) — B seeded from durable at v1, i.e. before the write under test.
UpdateImpl: adds=0, updates=1, deletes=0 — B classified the arriving change as an update, not an add, and the gate opened "node Active via update". So the path that ran is the update branch, and the mirror still landed on 3 rather than adopting durable's 2.
That narrows it: the mirror did not miss the event entirely — it processed an update — but ended a revision above durable, which is the "content arrived through a read-seeded mint rather than the notification" reading this issue proposed.
Caveats, stated rather than glossed
This is one occurrence. The issue measures ~1.3% (4/300), so a single trace can mislead; treat the above as the first data point of a set, not a proof.
I have not re-derived the timing of the writer side against B's clock here — the log excerpt above is B's own sequence.
The run's logs will age out with GitHub's retention, so anyone picking this up should pull the full shard-2 log now rather than later.
#2008 stays open.#2348 was observability only and said so; this comment is the payoff, not a fix.
Root-caused, deterministic red/green, fix in #2392 — plus a correction to the last comment
First the correction, because it points the next reader the wrong way
The MeshNodeTypeSource Debug lines quoted in the #2348 payoff comment as "what process B actually did" are process A's.
#2348 gave process B a logger provider, but not AddConfiguration — and the level that decides whether a record is emitted at all lives in LoggerFilterOptions, which ILoggerFactory consults before any provider and which defaults to Information. So B's Warning/Error records did start arriving (a real improvement on "no providers at all", so the change was not wasted), while every LogDebug the same change added — including the two own-node reconcile lines the exercise was for — was still dropped by the factory.
Measured rather than argued: resolving ILogger<MeshNodeTypeSource> in both processes and reading IsEnabled(Debug) gives A: true, B: false. That also explains why the trace read as uninformative — routingSuppliedStream=True, seed read (version=1), UpdateImpl: adds=0, updates=1 are exactly what a healthy local run prints, because they describe A's per-node hub activating to serve the write. #2392 adds l.AddConfiguration(...); with it you get two Created / durable activation seed read pairs per run instead of one.
The mechanism
A per-node hub writes its own activation seed back to storage — the durable row it just read.
MeshNodeTypeSource.Initialize builds two instance collections back to back (the durable seed, then the routing-supplied leg) and each stamps OwnNodeCache.PersistedSnapshot. That stamp is one slot, and the persistence sampler's initial-load echo suppression is a reference comparison against it. So by the time the workspace delivers the seed emission to the sampler, the slot already holds the routing instance: the seed fails the reference test and is dispatched as a SaveMeshNodeRequest as if it were a local edit.
Instrumented directly (raw file probe, both processes tagged, so it depends on none of the logging above):
BIC hub=TestData/x v=1 hash=44597241 <- emission #1, the durable seed
BIC hub=TestData/x v=1 hash=60718826 <- emission #2, the routing leg — overwrites the stamp
SAMPLER-IN proc=B v=1 refEq=False hash=44597241 persistedHash=60718826
SAMPLER-POST proc=B v=1
HANDLE-HW proc=B v=1 hw=0
WRITE proc=B v=1 <- the mirror writes back the row it just READ
On a quiet node that is an equal-version rewrite and invisible. When A's real write lands first it is a strict version regression → MonotonicWriteGuard refuses it → AdoptDurableTruth (correctly, for a hub that has something of its own to save) rebases the refusing owner at durable + 1 → the mirror holds a revision the store never held. Whether the echo or the real write got there first is the coin flip that made this read as a ~1.3% flake.
It also accounts for the two observables this issue singled out as its best clues, neither of which had an explanation before:
readsB 4→9 instead of 4→7 — the two extra reads are the guard's verification read plus the rebase's read. Not a second reconcile consumer.
writesB=0 while the guard still fired — MonotonicWriteGuard.ResolveConflict returns early on IsLatestUnchanged without calling the inner adapter, which is also precisely what merged=(none); latest-wins (stale values DROPPED)=Name in the CI log reported.
So the earlier hypothesis was pointing at the right file and the wrong mechanism: there is no second own-node reconcile consumer, and UpdateImpl never re-stamps the adoption. The two builds are both inside Initialize, and what they corrupt is the echo-suppression stamp, not the version.
The fix
DurableSeed records the version it read on PostCommitFlushRegistry, so HandleSaveMeshNodeand the dispose-time FlushPendingOwnSave drop the echo — the suppression MeshNodeStreamHandle.AdoptPersisted already applies to the other durable-observation path (a storage change notification). The activation seed was the one durable read that did not.
Through a new RecordObservedDurable, notRecord: Record is the flush's completion signal and resolves any unresolved Claim with "persisted: true". A read is not a completed write, and resolving someone's in-flight claim would tell a deferred SaveMeshNodeRequest to drop itself for a write that may still fail — trading a duplicate-write bug for a lost-write one. A real edit is unaffected: UpdateImpl mints it strictly above the seed.
Both directions, measured
New test CrossProcessChangeFeedTest.AMirroringProcess_NeverWritesTheNode_NotEvenItsActivationSeed. It uses two nodes deliberately: the mirrored node under test is never written by anyone, so nothing can rescue B's echo — asserting on a path A also writes lets B's own AdoptPersisted raise the high-water first and turns the red back into the same coin flip this issue is (verified: that shape passed on unfixed code). A sibling node A does write supplies the wait.
check
result
new test, framework fix reverted
10/10 RED ([B writes] seed=1 clock=0)
new test + the 3 existing ones, fix applied
10/10 GREEN
full MeshWeaver.Hosting.Monolith.Test, fix reverted
773 passed, the only failure is the new test
full MeshWeaver.Hosting.Monolith.Test, fix applied
new test green
MeshWeaver.Graph.Test
1607/1607
Environment: macOS, DOTNET_PROCESSOR_COUNT=4.
This is a production defect, not a test artefact: every per-node hub activation re-persisted its own row, and at two replicas that echo is a live lost-update hazard on any node the other replica is writing — the same shape as the rival-mirror case this test class was written for.
Activity
rbuergi commentedon Aug 24, 2026
Two more CI hits today, both on unrelated RN/JS-client branches (diffs that cannot reach the feed), both shard 1:
AWriteInOneProcess_ReachesTheOtherProcessesLiveMirror_WithoutARecycle, mirror ended at 3 vs durable 2 (the pre-fix Adopting an already-durable external write MINTS a phantom revision and persists it (deterministic; root cause under #1384) #1432 signature:[B emit] name=written-in-A v=3after[A durable] version=2).Local attribution on the same tree: 10/10 sequential passes (
--filter FullyQualifiedName~CrossProcessChangeFeedTest.AWriteInOneProcess, Release). Matches the issue title: the CI environment intermittently re-samples the dropped-notification → read-seeded-mint path that #1929 closed. Per the repo's race-repro note,DOTNET_PROCESSOR_COUNT=4locally is the known way to approximate CI scheduling for this family.(Reporting to keep the record in one place — both PR runs were re-run rather than "fixed", since the diffs are unrelated.)
rbuergi commentedon Aug 24, 2026
Another occurrence: PR #2184, run 32781941594, shard 1 (2026-08-24 22:15 UTC) —
AWriteInOneProcess_ReachesTheOtherProcessesLiveMirror_WithoutARecycle, sole failing test. The branch's diff (Blazor component moves + module publish lanes) has no cross-process change-feed surface, and the same suite ran 757/757 locally on the branch. Rerunning per the standing flake protocol.rbuergi commentedon Aug 25, 2026
Still live, and the two CI traces are byte-identical — so this is a second deterministic path, not jitter
Swept the last 300
MeshWeaver Build and Testruns (2026-08-23 → 2026-08-25), reading the[FAIL]lines out of every attempt, not just runs whose final conclusion wasfailure(are-run-to-green hides the attempt that failed). This test is the third most frequent failure in
that window:
UserDirectoryCompletenessTests.AUserOutsideTheMostRecentlyModifiedPage_…PartitionRootActivationTest.BarePartitionPath_NoMeshNode_RespondsToPingCrossProcessChangeFeedTest.AWriteInOneProcess_…Occurrences:
32722799059/1,32728115289/1,32781941594/1,32891723627/1— all shard 1.(Its Postgres sibling
CrossProcessNotifyPgTests.AWriteByAnotherProcess_ArrivesOnThisProcessesPartitionFeedalso failed once in the window — worth keeping in view, same family.)
The traces are identical to the character across two independent runs a day apart:
against the healthy shape, which is equally invariant (31/31 local runs):
So the failing run does exactly two extra reads and exactly one extra mint. That reproducibility
is the most useful thing in the issue: this is a second, deterministic path being taken, not a
timing smear.
What is now ruled out
tracesubscription is armed before the write, the mirror is
Replay(1).RefCount()with akeepAlive,and every emission is printed. There is no emission at v2 that the assertion could have missed —
the mirror genuinely never held v2.
durablecapture in the test.WaitDurablereturns the first store snapshotmatching the name, so "the store moved on afterwards" was the obvious test-side explanation. The
[store] v=2line printed immediately before the assertion refutes it: the store held 2 atassert time, and the mirror held 3. The assertion is correct and must not be relaxed.
writesB=0is counted insideCrossProcessFeedAdapter.Write,i.e. below every guard, so the v3 was minted in RAM and never persisted — the 200 ms
persistence sampler had not fired when the test ended. (Had it fired, the store would have gone to
3 and the Adopting an already-durable external write MINTS a phantom revision and persists it (deterministic; root cause under #1384) #1432 phantom would have become durable. The test ends before that only by luck.)
DOTNET_PROCESSOR_COUNT=4, Release,isolated — every run the healthy
readsB 4→7 / v=2shape. Matches the earlier 10/10 comment.The mechanism this points at — a hypothesis with a code path, not a guess
AdoptPersistedis careful not to mint (UpdateOwn(..., adoptPersisted: true)skipsNextVersionand records the durable version inPostCommitFlushRegistry). But the value itcommits still passes through the data source, and
MeshNodeTypeSource.UpdateImplre-stamps it:PreviousVersioncomes from_lastSaved, and_lastSavedis written from two places that arenot ordered against the workspace's own store:
BuildInstanceCollectionsets it eagerly, when the collection is BUILT — before the workspacehas applied it;
UpdateImplsets it at the end of a commit.The entity-less notification wakes two consumers in process B that both re-read the same durable
row — the per-node hub's coalesced re-read (
SubscribeToOwnDeletion'sreReadTrigger) and therouting/catalog leg feeding
_ownNodeStream. Those two reads are, I believe, the +2 that separatethe failing trace from the healthy one. If the routing leg wins and builds a collection at durable
v2 — setting
_lastSaved = {v2}while the workspace store is still at v1 — then:AdoptPersisted(v2)seescurrent.Version == 1, so the forward-only guard lets itthrough and it commits;
UpdateImpldiffs the incoming v2 against_lastSavedalready at v2. It still counts as anupdate, because the version-ignoring comparison is
record Equals, which is reference-based onContent— two deserializations of the same row are not equal;PreviousVersion == Node.Version == 2⇒alreadyAdvanced == false⇒Version = NextVersion(2) = 3.That produces precisely what the trace shows: one emission, at durable+1, carrying the durable
content, with nothing written to the store — "converging on content by accident, at a version that
exists nowhere", which is the #1432 wording this test was given.
This is a hypothesis. It explains every observable (the exact +2 reads, the single v3 emission,
writesB=0, the store at 2) and it names a real window in the code, but it has not been reproduced.I am deliberately not shipping a speculative change to the own-node versioning core on that basis:
MeshNodeTypeSource's stamping logic already carries the scars of #325, #590, #1432 and the2026-07-30 refusals, and a wrong move there is write loss rather than a flaky test.
What would settle it in one CI run
Both lines needed already exist at
LogDebugand cost nothing to turn on for this assembly:MeshNodeTypeSource.UpdateImpl: adds={Adds}, updates={Updates}, deletes={Deletes}MeshNodeTypeSource[{HubPath}]: durable activation seed {Outcome} (version={Version})A failing run that shows a second own-node collection build at version 2 before the adoption's
UpdateImplconfirms the hypothesis; one that does not, kills it. Note the test's ILogger outputgoes to
XUnitFileOutputHelper's file rather than to xUnit's console output, which is why none ofit appears in the CI logs today — that alone is worth fixing before the next attempt at this issue.
If it is confirmed, the fix is not a wider bound but a rule with a name: an own-node update whose
version is already recorded DURABLE (
PostCommitFlushRegistry) is an observation, not an unmintededit — never re-stamp it. That is exactly the discrimination
AdoptPersistedalready makes onelayer up; the layer underneath does not make it.
rbuergi commentedon Aug 25, 2026
Follow-up on the sibling named above: the Postgres one turned out to be a different defect, so it now has its own issue — #2281, fixed in #2286. Its failure is a 30 s
TimeoutException(no notification at all), not a wrong version, and the cause is thatCrossProcessNotifyPgTestsgated onpg_stat_activity— which reports the CONNECTION, whileLISTEN mesh_node_changesruns one statement later. The gate went green inside the window it existed to close, and Postgres never replays aNOTIFY.Recording it here only so nobody folds the two together while working this one: #2008 is not that. Its notification demonstrably arrives (the mirror converges on the right content); what is wrong is the version it converges at.
rbuergi commentedon Aug 25, 2026
Local reproduction attempts, for the record (all
-c Release,DOTNET_PROCESSOR_COUNT=4, oned4588222):readsB 4→7 / v=2shape.C, so the test runs alongside neighbours rather than alone) — also healthy, same shape.MeshWeaver.Hosting.Monolith.Test(The active test run was aborted. Reason: Test host process crashed), twice, ~35 tests in and unrelated to this test. CI splits the assembly across two parts and does not hit it. That is a separate local-only obstacle, but it is worth knowing that "I ran the full assembly locally" is not currently an available control for anything in this assembly — which matters because an isolated run discriminates nothing for a full-suite-only failure.So: not reproduced. The analysis in the previous comment rests on the two CI traces being byte-identical (
readsB 4→9, one emission at v=3, store at v=2,writesB=0) and on the code path, not on a local red.rbuergi commentedon Aug 25, 2026
On the suggestion that this and the PostgreSQL cross-process test are one mechanism: they are not, and the discriminator is in the two failures' own text.
[B emit] name=written-in-A) — the cross-process wire worked. What is wrong is the VERSION it converges at (durable+1, a revision the store never held). Failure mode: a value assertion.CrossProcessNotifyPgTests): nothing arrives at all —System.TimeoutExceptionat 30 s, with theLISTENregistration racing the write. Failure mode: a timeout."The announcement was delivered and then mis-applied" and "the announcement was never delivered" cannot be the same defect, and #2281 is now closed by a deterministic red/green (#2286) that leaves this one untouched. Same area, same night, two mechanisms.
Recording it because the pairing is a natural thing to assume, and assuming it here would send the next investigator looking at the wire — which is the half that works.
rbuergi commentedon Aug 26, 2026
A correction to the hypothesis's mechanism (not the fix), plus a diagnostics-visibility PR
Read through the mechanism the last comment's hypothesis rests on — a second own-node reconcile
path (the ROUTING leg's
_ownNodeStreamre-resolving on notification, invalidated byPathResolutionService) that re-emits intoMeshNodeTypeSource.BuildInstanceCollection,bypassing
UpdateImpl's diff/version-stamping, racingSubscribeToOwnDeletion'sreReadTrigger → AdoptDurable → AdoptPersistedpath.That specific mechanism does not apply to this test as stated.
MonolithRoutingService.CreateHubsupplies the routing leg's
_ownNodeStreamas a one-shotObservable.Return(enriched):with the comment: "One-shot is fine on Monolith — cross-hub MeshNode updates flow through
IDataChangeNotifier / IMeshChangeFeed already." That stream emits once, at hub activation, and
completes — well before the write this test exercises happens (process B's mirror is already
seeded and live by the time A writes). So for the event this test asserts on,
Initialize()'s.Concat(_ownNodeStream...)leg contributes nothing further, andBuildInstanceCollectionis notre-entered on this path after activation. The only live reconcile at that point is
SubscribeToOwnDeletion's singlereReadTrigger → AdoptDurable → AdoptPersisted → UpdateOwn(adoptPersisted: true)chain, which — walkingUpdateImpl's diff — looks correctlyguarded (
alreadyAdvancedholds because the adopted version is strictly abovePreviousVersion).I believe the "two independent re-read consumers" shape in the hypothesis describes Orleans'
PathResolutionService-memoizedAddressResolution, invalidated by "the per-silo change feed"(silo terminology, and
MessageHubGrain.csalso touchesWithOwnNodeStream) — not Monolith, whichis what
CrossProcessChangeFeedTestactually runs. Recording this so the next investigator doesn'tre-derive it, and doesn't waste time confirming/refuting a mechanism that can't fire here.
I have not identified the actual mechanism.
readsBgoing 4→9 instead of the healthy 4→7 (twoextra reads) still needs an explanation, and I don't have one that survives the one-shot-ownStream
correction above.
What I did ship: #2348 — process B's diagnostics now reach captured output
Confirmed empirically that process B (
BuildSecondProcess) had zero logging providers —services.AddLogging(l => l.ClearProviders())with nothing added back — so everyILoggercall inprocess B, including the two
MeshNodeTypeSource.LogDebuglines this issue's earlier comment namedas "cost nothing to turn on," went nowhere: not xUnit output, not the file, regardless of level.
That's a stronger defect than "goes to the file instead of the console" — it's "goes nowhere at
all" — and it means every occurrence to date, including the ones analyzed above, ran with zero
visibility into process B's own-node reconcile.
#2348 wires process B's logging the same way process A's already is (
TestBase'sXUnitFileLoggerProvider, pointed at the sharedFileOutput) and grantsMeshWeaver.Graph.MeshNodeTypeSourceaDebugoverride for both processes (appsettings.jsonforA, an in-memory
IConfigurationfor B, since B never loads the JSON file). Verified locally thatprocess B's diagnostics now reach the captured test output where they were previously completely
absent.
Not a fix — no production code changed. This issue stays open until a CI occurrence with the new
diagnostics on lands and the actual mechanism can be read off it.
Merge pull request #2348 from Systemorph/fix/2008-cross-process-mirro…
rbuergi commentedon Aug 26, 2026
First reproduction WITH process B's diagnostics — #2348 worked
This issue asked for exactly one thing to settle it: "the two
LogDebuglines already inMeshNodeTypeSource, which today never reach any CI artifact for process B." #2348 (merged5b1901fb6) restored process B's logging providers — it hadservices.AddLogging(l => l.ClearProviders())with nothing added back, so everyILoggercall in that process went nowhere, including on every failing run.The flake has now recurred on a run that carries the fix — PR #2352, shard 2, run 32964944158, 2026-08-26 ~11:53Z. (#2352's diff is
deploy/helmYAML only and cannot reach this assembly; it is an unrelated carrier.)The assertion
Expected 2, found 3 — durable+1, precisely the shape this issue describes.
What process B actually did (previously invisible)
Three things worth reading off that, which were unavailable before:
routingSuppliedStream=True— process B'sMeshNodeTypeSourcewas constructed with the routing-supplied_ownNodeStream. test: make process B's own-node diagnostics reach CI output (#2008) #2348's investigation established that on Monolith this is a one-shotObservable.Return(enriched)that completes at activation, so it cannot be the source of a later re-emission.durable activation seed read (version=1)— B seeded from durable at v1, i.e. before the write under test.UpdateImpl: adds=0, updates=1, deletes=0— B classified the arriving change as an update, not an add, and the gate opened "node Active via update". So the path that ran is the update branch, and the mirror still landed on 3 rather than adopting durable's 2.That narrows it: the mirror did not miss the event entirely — it processed an update — but ended a revision above durable, which is the "content arrived through a read-seeded mint rather than the notification" reading this issue proposed.
Caveats, stated rather than glossed
#2008 stays open. #2348 was observability only and said so; this comment is the payoff, not a fix.
rbuergi commentedon Aug 26, 2026
Root-caused, deterministic red/green, fix in #2392 — plus a correction to the last comment
First the correction, because it points the next reader the wrong way
The
MeshNodeTypeSourceDebug lines quoted in the #2348 payoff comment as "what process B actually did" are process A's.#2348 gave process B a logger provider, but not
AddConfiguration— and the level that decides whether a record is emitted at all lives inLoggerFilterOptions, whichILoggerFactoryconsults before any provider and which defaults toInformation. So B'sWarning/Errorrecords did start arriving (a real improvement on "no providers at all", so the change was not wasted), while everyLogDebugthe same change added — including the two own-node reconcile lines the exercise was for — was still dropped by the factory.Measured rather than argued: resolving
ILogger<MeshNodeTypeSource>in both processes and readingIsEnabled(Debug)gives A: true, B: false. That also explains why the trace read as uninformative —routingSuppliedStream=True,seed read (version=1),UpdateImpl: adds=0, updates=1are exactly what a healthy local run prints, because they describe A's per-node hub activating to serve the write. #2392 addsl.AddConfiguration(...); with it you get twoCreated/durable activation seed readpairs per run instead of one.The mechanism
A per-node hub writes its own activation seed back to storage — the durable row it just read.
MeshNodeTypeSource.Initializebuilds two instance collections back to back (the durable seed, then the routing-supplied leg) and each stampsOwnNodeCache.PersistedSnapshot. That stamp is one slot, and the persistence sampler's initial-load echo suppression is a reference comparison against it. So by the time the workspace delivers the seed emission to the sampler, the slot already holds the routing instance: the seed fails the reference test and is dispatched as aSaveMeshNodeRequestas if it were a local edit.Instrumented directly (raw file probe, both processes tagged, so it depends on none of the logging above):
On a quiet node that is an equal-version rewrite and invisible. When A's real write lands first it is a strict version regression →
MonotonicWriteGuardrefuses it →AdoptDurableTruth(correctly, for a hub that has something of its own to save) rebases the refusing owner atdurable + 1→ the mirror holds a revision the store never held. Whether the echo or the real write got there first is the coin flip that made this read as a ~1.3% flake.It also accounts for the two observables this issue singled out as its best clues, neither of which had an explanation before:
readsB4→9 instead of 4→7 — the two extra reads are the guard's verification read plus the rebase's read. Not a second reconcile consumer.writesB=0while the guard still fired —MonotonicWriteGuard.ResolveConflictreturns early onIsLatestUnchangedwithout calling the inner adapter, which is also precisely whatmerged=(none); latest-wins (stale values DROPPED)=Namein the CI log reported.So the earlier hypothesis was pointing at the right file and the wrong mechanism: there is no second own-node reconcile consumer, and
UpdateImplnever re-stamps the adoption. The two builds are both insideInitialize, and what they corrupt is the echo-suppression stamp, not the version.The fix
DurableSeedrecords the version it read onPostCommitFlushRegistry, soHandleSaveMeshNodeand the dispose-timeFlushPendingOwnSavedrop the echo — the suppressionMeshNodeStreamHandle.AdoptPersistedalready applies to the other durable-observation path (a storage change notification). The activation seed was the one durable read that did not.Through a new
RecordObservedDurable, notRecord:Recordis the flush's completion signal and resolves any unresolvedClaimwith "persisted: true". A read is not a completed write, and resolving someone's in-flight claim would tell a deferredSaveMeshNodeRequestto drop itself for a write that may still fail — trading a duplicate-write bug for a lost-write one. A real edit is unaffected:UpdateImplmints it strictly above the seed.Both directions, measured
New test
CrossProcessChangeFeedTest.AMirroringProcess_NeverWritesTheNode_NotEvenItsActivationSeed. It uses two nodes deliberately: the mirrored node under test is never written by anyone, so nothing can rescue B's echo — asserting on a path A also writes lets B's ownAdoptPersistedraise the high-water first and turns the red back into the same coin flip this issue is (verified: that shape passed on unfixed code). A sibling node A does write supplies the wait.[B writes] seed=1 clock=0)MeshWeaver.Hosting.Monolith.Test, fix revertedMeshWeaver.Hosting.Monolith.Test, fix appliedMeshWeaver.Graph.TestEnvironment: macOS,
DOTNET_PROCESSOR_COUNT=4.This is a production defect, not a test artefact: every per-node hub activation re-persisted its own row, and at two replicas that echo is a live lost-update hazard on any node the other replica is writing — the same shape as the rival-mirror case this test class was written for.
Merge pull request #2392 from Systemorph/fix/2008-cross-process-mirro…