fix(#2776): a write no longer ends its own streams — the change feed leaves a LIVE mirror alone by rbuergi · Pull Request #3013 · Systemorph/MeshWeaver

rbuergi · 2026-09-01T19:56:48Z

What ended the activity node's streams

Its own previous progress write did — at +0.12 s, not +5 s, and with no recycle and no teardown anywhere in it.

IMeshChangeFeed is published by the persistence layer after every create/update/delete. Workspace.EvictForPath listened to it and dropped every cached remote stream whose owner matched the changed path — including the mirror the writer itself was using, on the writer's own write. A cross-hub write leases that mirror only for the duration of its Observable.Create subscription, so:

write N leases the mirror for P, posts its patch, the owner commits, persistence publishes Updated for P;
EvictForPath("P") removes that very mirror from _remoteStreamCache;
write N settles and releases its lease;
the evicted stream now has no declared holder → ReclaimIfUnheld disposes it → UnsubscribeRequest to the owner → the client sync/{id} hub and its owner-side twin both die;
the owner announces StreamEndedEvent to a subscriber whose sync hub step 4 just destroyed → held 5 s → dropped with the diagnostic Flake: ActivityLiveProgressTest.EveryProgressLine_LandsWhileTheCommandIsStillRunning — the activity node's owner ends its streams ~5 s in, the next progress write gets no verdict (OwnerUnreachable after 31 s) #2776 is titled after.

One full subscribe / initial-state / unsubscribe round trip per write, for as long as anything is watching the node.

The two arithmetic traps that made this read as a mid-run hub teardown

1. The drop line is written five seconds after the event it describes. RouteStreamMessage does not drop a StreamMessage whose sync/{id} sub-hub is missing — it holds it for SyncStreamOptions.SyncHubRegistrationGrace (5 s, present at the failing commit 2abb6a60) and logs only when that Timeout fires. Re-reading the #2776 trace with that in hand puts everything in one 10 ms window at +0.12 s:

log line	logged at	actual event
`Dropping StreamEndedEvent … uZzjE4MWi0KBrSXTSLNN9g`	13:28:32.936	arrived 13:28:27.936 (+121 ms)
`ADVANCE_WITHOUT_HANDOFF seq=3 bound=5000ms`	13:28:32.940	write started 13:28:27.940 (+125 ms)
`Dropping StreamEndedEvent … dPb18nIfvUCsJEhA8RgoLQ`	13:28:32.946	arrived 13:28:27.946 (+131 ms)

Confirmed independently by the failure's own arithmetic: FAILED … seq=3 elapsedMs=31015.7 at 13:28:58.952 ⇒ EnteredAt = 13:28:27.936. Two unrelated five-second bounds (SyncHubRegistrationGrace, QueueAdvanceBound) counting from one instant produced a coincidence that looked like a mechanism — "+5 s is the hosted-hub drain cap". The second witness (InstanceSyncRemoteDeletionTest, +5.1/+5.2 s) is the same artifact, not a corroboration.

2. The sender rules out a recycle. The recycle announcement (AnnounceRecycleToClientSubscriptions) is deliberately posted by a carrier — a dying hub must never speak for itself. The healthy-owner announcement (JsonSynchronizationStream's disposal registration) is posted by the owner and refuses to fire once RunLevel > Started or IsDisposing. Both #2776 lines name the activity node itself, so at that instant the owner was Started and not disposing. #2763 / #2582 and the drain cap are eliminated by the trace, not by argument.

The fix

EvictForPath now probes StreamLiveness.IsUsable — the one shared liveness predicate — and leaves a live mirror where it is. A dead one (disposed hub, terminally faulted store) is evicted and reclaimed exactly as before. The probe runs before the removal and reads Lazy.Value only when already materialised, so the handler can never open the SubscribeRequest it is meant to police.

This is the rule the other two listeners on the same broadcast already state:

MeshNodeStreamCache.ResetFailureState — "A healthy live entry is left untouched: the owner's sync stream already delivers routine updates, and tearing the shared handle down on every post-commit broadcast would sever live GUI subscribers."
JsonSynchronizationStream's coalesced, version-gated change-feed Resubscribe, throttled after exactly this defect one layer over (ChangeFeedResubscribeCoalesceTest) — "a HEALTHY subscriber receives that same write through its own subscription, so resubscribing on it is pure churn — at scale it is the storm that starved prod's hubs."

EvictForPath was the third and the only one still acting unconditionally.

Nothing is lost. The guarantee the eviction claimed — "the next GetRemoteStream caller spins up a fresh stream" — was never the eviction's to give: GetExternalClientSynchronizationStream re-checks StreamLiveness.IsUsable on every cache hit and rebuilds on a false verdict. Recycled-owner recovery belongs to the stream's own change-feed Resubscribe ("the sole recycled-grain detector"), the recycle re-arm, and the heartbeat — never to this eviction. And a recycle publishes its Updated event before the owner is disposed, so the eager eviction never had a timing advantage either.

Diagnosability, so the next occurrence cannot be misdated

LogStreamMessageDrop now states how long the message was held, so its timestamp can never again be read as the time the stream ended.

(The other diagnosability item #2776 asks for — switching the write off the Observe(delivery) overload so the trail is not REGISTERED_AFTER_POST — already landed on 2026-08-31 in 4d231170a / #2890.)

Measured

🚨 Counts, not timings. This host was at load average 100–220 on 18 cores throughout, and both bounds in the original trace (QueueAdvanceBound 5 s, WriteVerdictBound 31 s) are ones a starved machine trips on its own. Counting hub creations is load-independent: a slow box mints the same number of hubs, just later.

Monolith harness (test/MeshWeaver.Graph.Test), one activity node, one live reader, six progress writes:

	before	after
client-side `sync/` hubs minted	7	2
owner-side `sync/` hubs minted	11	6
change-feed mirror evictions	7	0
mirrors disposed mid-run (⇒ `UnsubscribeRequest` + `StreamEndedEvent`)	5	0
reader emissions (versions 1…7)	7	7

Regression guard — MirrorSurvivesItsOwnWriteTest counts the sync/ hubs the owner mints while the writes run, for two write counts, and requires them equal:

RED without the fix: 2 writes → 4, 8 writes → 16 (exactly two per write).
GREEN with it: 2 writes → 2, 8 writes → 2.

What this does not claim

#2776's visible failure was a write that reached no verdict in 31 s. That silence has its own, already-fixed cause — #2882 / #2890: the write registered its response subject after posting, so a warm owner's sub-millisecond ack could land before anything was listening, and the trail could only ever say REGISTERED_AFTER_POST — which is exactly what that trace says. This PR fixes the stream-ending the issue is titled after. Removing the churn also removes a per-write subscribe/unsubscribe race from the write path; that is a consequence, not a claim that it caused that particular timeout.

Work products conserved

Doc/Architecture/LiveMirrorsAndTheChangeFeed — the full RCA, linked from the Architecture index.
What's New (Category: Fix): A live view is no longer resubscribed every time its page is written.

Verification

dotnet build -c Release -warnaserror, one project per invocation: test/MeshWeaver.Graph.Test, test/MeshWeaver.Data.Test, test/MeshWeaver.Documentation.Test, test/MeshWeaver.Hosting.Test — 0 Warning(s), 0 Error(s) each (these transitively build MeshWeaver.Data, MeshWeaver.Hosting, MeshWeaver.Mesh.Contract, MeshWeaver.Graph, MeshWeaver.Layout, MeshWeaver.Messaging.Hub, MeshWeaver.Documentation).
DocumentationLinkIntegrityTest — passed.
Full local suites: see the comment below. CI is the authority here — the local box was 12× oversubscribed.

🤖 Generated with Claude Code

https://claude.ai/code/session_01SD7aiLSo59xng2TzU32xEa

Copilot

🟡 Changes recommended

The new test awaits IObservable directly instead of using ObservableAwait.Await()/.Await(), which violates the repo’s sanctioned observable→Task bridge rule and can resume inline on the signalling thread.

Once you've addressed the issues Copilot identified, you can request another Copilot review.

Pull request overview

This PR addresses #2776 by preventing the workspace’s change-feed eviction (Workspace.EvictForPath) from tearing down live remote synchronization streams (“mirrors”) on the writer’s own writes, and improves diagnosability of stream-message drops.

Changes:

Update Workspace.EvictForPath to evict only unusable cached remote streams by gating on StreamLiveness.IsUsable.
Enhance DataExtensions stream-drop logging to include how long a stream message was held before being dropped.
Add an integration/regression test plus documentation/What’s New entries capturing the RCA and user-visible impact.

File summaries

File	Description
test/MeshWeaver.Graph.Test/MirrorSurvivesItsOwnWriteTest.cs	New regression test counting `sync/` hub churn during repeated writes.
src/MeshWeaver.Data/Workspace.cs	Change-feed eviction now preserves live mirrors and only removes unusable ones.
src/MeshWeaver.Data/DataExtensions.cs	Stream-drop diagnostics now report hold time (“age”) to avoid misreading timestamps.
src/MeshWeaver.Documentation/Data/Architecture/LiveMirrorsAndTheChangeFeed.md	New architecture/RCA page documenting the defect, traps, and the fix.
src/MeshWeaver.Documentation/Data/WhatsNew/2026-09-02-a-live-view-is-no-longer-resubscribed-every-time-its-page-is-written.md	New What’s New entry describing the observable user impact.
src/MeshWeaver.Documentation/Data/Architecture.md	Adds the new architecture page to the “Reading & writing nodes” section.

Review details

Suppressed comments (3)

test/MeshWeaver.Graph.Test/MirrorSurvivesItsOwnWriteTest.cs:116

This awaits an IObservable directly (via Rx’s awaiter), which is equivalent to a ToTask-style bridge and can resume continuations inline on the signalling thread. Use the repo’s sanctioned bridge ObservableAwait.Await() instead (via the .Await() extension) to ensure continuations run asynchronously.

            .FirstAsync().Timeout(TestTimeouts.Convergence);

test/MeshWeaver.Graph.Test/MirrorSurvivesItsOwnWriteTest.cs:139

This awaits an IObservable directly (via Rx’s awaiter), which is equivalent to a ToTask-style bridge and can resume continuations inline on the signalling thread. Use the repo’s sanctioned bridge ObservableAwait.Await() instead (via the .Await() extension) to ensure continuations run asynchronously.

                .FirstAsync().Timeout(TestTimeouts.Convergence);

test/MeshWeaver.Graph.Test/MirrorSurvivesItsOwnWriteTest.cs:145

This awaits an IObservable directly (via Rx’s awaiter), which is equivalent to a ToTask-style bridge and can resume continuations inline on the signalling thread. Use the repo’s sanctioned bridge ObservableAwait.Await() instead (via the .Await() extension) to ensure continuations run asynchronously.

                .FirstAsync().Timeout(TestTimeouts.Convergence);

Files reviewed: 6/6 changed files
Comments generated: 1
Review effort level: Lite

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

github-actions · 2026-09-01T20:06:05Z