fix(#2882): the write registers its response callback BEFORE posting by rbuergi · Pull Request #2890 · Systemorph/MeshWeaver

rbuergi · 2026-08-31T07:23:45Z

Closes #2882.

MeshNodeStreamHandle.UpdateRemote posted the PatchDataRequest and only then registered the response subject (Post → arm late watch → Observe(delivery)). The hub drops a response whose requestId has no registered subject yet ("No subject found for response … treating as processed", HandleCallbacks) — and a warm owning per-node hub acks in sub-millisecond time. A thread-pool preemption between the two calls lost the verdict; the caller waited out the full 31 s WriteVerdictBound and failed OwnerUnreachable for a write that had applied. Reproduced 1-in-6 bulk runs of MeshWeaver.AI.Test; same signature as Plugins#1014 and the occurrence behind Plugins#971.

The read path had the identical defect and the identical fix — GetMeshNode's Issue(), pinned by GetMeshNode_WarmOwner_DropsResponse_WhenSubjectRegisteredAfterPost. The write couldn't take the same route because Observe(object, options) mints its own id after the caller's options run, and the write needs the id up front to arm LatePatchResponseRegistry before anything can answer.

The seam — exactly what the issue asked for

IObservable<IMessageDelivery>? Observe(object request, Func<PostOptions,PostOptions> options, string messageId)

Registers the subject under the supplied id, then posts with WithMessageId(id). Returns null when the post itself returned null (unresolvable address), removing the just-registered subject so nothing ripens into a leaked pending callback.

The write path, reordered

mint requestId → arm LatePatchResponseRegistry → Observe(request, options, requestId)
                                                  └ registers subject, THEN posts

Arming the late watch before the post also closes the sibling window where a DeliveryFailure could arrive before Register ran. The unresolvable-address branch keeps its immediate OwnerUnreachable error and now also disarms the watch it armed.

Side effect the issue led with: the write trail loses its permanent REGISTERED_AFTER_POST (earlier stages not recorded) marker — DescribeRequestFate can finally say where a write's delivery went.

The deterministic twin test

WriteVerdictRegisteredBeforePostTest mirrors the read path's pin, preemption made explicit in both directions:

post → 300 ms delay → observe: the warm ack is provably dropped — never emits (this arm is what fails if anyone reverts to post-then-observe);
the new seam under the same delay: the ack is buffered in the AsyncSubject and replayed — emits Success.

Verification

New twin test: deterministic pass.
Full write-path + cache suites (OwnerDisposalNack, LateNackReenqueue, WriteWaitsForCommitVerdict, QueuedWriteAdvancesOnHandoff, SupersededActivationPatchNack, NackReachesTheWaiterDuringTeardown, WorkspaceCacheEviction, the twin): 15/15.
Messaging.Hub / Mesh.Contract / Monolith.Test: -c Release -warnaserror, 0/0.

Why this matters beyond the one test

This is the strongest root-cause candidate yet for the ambient ADVANCE_WITHOUT_HANDOFF → 31 s family (#2865 / #2776): the update queue advances because the owner's ack was dropped, not because the owner never answered. If those flakes thin out after this lands, that family closes; if they don't, the now-unblinded write trail finally says where each delivery went.

One What's New entry (Category: Fix).

🤖 Generated with Claude Code

MeshNodeStreamHandle.UpdateRemote posted the PatchDataRequest and only then registered the response subject (Post -> arm late watch -> Observe(delivery)). The hub DROPS a response whose requestId has no registered subject yet ("No subject found for response ... treating as processed", HandleCallbacks), and a WARM owning per-node hub acks in sub-millisecond time — so a thread-pool preemption between Post and Observe lost the verdict, the caller waited out the full 31 s WriteVerdictBound, and failed OwnerUnreachable for a write that had APPLIED. Reproduced 1-in-6 bulk runs of MeshWeaver.AI.Test; same signature as Plugins#1014 and the recorded occurrence behind Plugins#971. The READ path had the identical defect and the identical fix (GetMeshNode's Issue(), pinned by GetMeshNode_WarmOwner_DropsResponse_WhenSubjectRegisteredAfterPost). The write could not take the same route because Observe(object, options) mints its own id AFTER the caller's options run, and the write needs the id UP FRONT to arm LatePatchResponseRegistry before anything can answer. ── the seam (#2882's ask, verbatim) ── Observe(object request, Func<PostOptions,PostOptions> options, string messageId) on IMessageHub + MessageHub + the public extension: registers the subject under the SUPPLIED id, then posts with WithMessageId(id). Returns null when Post returned null (unresolvable address), removing the just-registered subject so nothing ripens into a leaked pending callback. ── the write path, reordered ── mint requestId -> arm LatePatchResponseRegistry -> Observe(request, options, requestId) [registers subject, THEN posts] Arming the late watch before the post also closes the sibling window where a DeliveryFailure could arrive before Register ran. The unresolvable-address branch keeps its immediate OwnerUnreachable error and now also disarms the late watch it armed. As a side effect the write trail loses its permanent REGISTERED_AFTER_POST (earlier stages not recorded) marker — DescribeRequestFate can finally say where a write's delivery went, which is the diagnostic gap the issue led with. ── the deterministic twin test ── WriteVerdictRegisteredBeforePostTest mirrors the read path's regression pin, with the preemption made explicit in both directions: post-then-observe with a warm owner provably NEVER emits (the ack is dropped); the new seam under the same preemption provably emits the Success ack (the AsyncSubject buffers and replays it). Monolith.Test write-path + cache suites (OwnerDisposalNack, LateNackReenqueue, WriteWaitsForCommitVerdict, QueuedWriteAdvancesOnHandoff, SupersededActivationPatchNack, NackReachesTheWaiterDuringTeardown, WorkspaceCacheEviction, and the new twin): 15/15. Messaging.Hub / Mesh.Contract / Monolith.Test: -c Release -warnaserror, 0/0. This is the strongest root-cause candidate yet for the ambient ADVANCE_WITHOUT_HANDOFF -> 31 s family (#2865/#2776): the queue advances because the owner's ack was dropped, not because the owner never answered. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>

Copilot

Pull request overview

This PR fixes an intermittent cross-hub write timeout by ensuring the response callback is registered before the write request is posted, preventing fast owner acknowledgements from being dropped. It introduces a caller-supplied message-id observe seam in IMessageHub, rewires MeshNodeStreamHandle.UpdateRemote to use it, and adds a deterministic regression test plus a What’s New entry.

Changes:

Add a new Observe(request, options, messageId) seam that registers the response subject before posting under a caller-supplied id.
Reorder MeshNodeStreamHandle.UpdateRemote to mint the request id up front, arm late-watch state, then observe+post via the new seam.
Add WriteVerdictRegisteredBeforePostTest to deterministically pin the race and validate the fix; document the user-visible impact in What’s New.

Reviewed changes

Copilot reviewed 6 out of 6 changed files in this pull request and generated 1 comment.

Show a summary per file

File	Description
test/MeshWeaver.Hosting.Monolith.Test/WriteVerdictRegisteredBeforePostTest.cs	Adds a deterministic regression test for the post-then-observe vs observe-then-post ordering on warm owners.
src/MeshWeaver.Messaging.Hub/MessageHubExtensions.cs	Exposes a public extension method for caller-supplied-id observe to enable cross-assembly use.
src/MeshWeaver.Messaging.Hub/MessageHub.cs	Implements the new observe overload that registers the subject before posting with the provided message id.
src/MeshWeaver.Messaging.Hub/IMessageHub.cs	Adds the internal interface member for the caller-supplied-id observe seam.
src/MeshWeaver.Mesh.Contract/MeshNodeStreamExtensions.cs	Updates the remote write path to mint id first, arm the late registry, then observe+post in the correct order.
src/MeshWeaver.Documentation/Data/WhatsNew/2026-08-31-a-saved-answer-no-longer-goes-missing-on-a-fast-reply.md	Adds a user-facing What’s New entry describing the resolved “save times out despite fast confirmation” symptom.

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

+            lock (responseSubjects)
+            {
+                if (responseSubjects.TryGetValue(messageId, out var entry)
+                    && ReferenceEquals(entry.Subject, subject))
+                    responseSubjects.Remove(messageId);
+            }


github-actions · 2026-08-31T07:30:09Z

Test Results (shard 0)

792 tests 788 ✅ 4m 20s ⏱️
7 suites 4 💤
7 files 0 ❌

Results for commit 611e321.

github-actions · 2026-08-31T07:32:01Z

Test Results (shard 5)

8 files 8 suites 4m 10s ⏱️
1 490 tests 1 489 ✅ 1 💤 0 ❌
2 190 runs 2 189 ✅ 1 💤 0 ❌

Results for commit 611e321.

github-actions · 2026-08-31T07:32:15Z

Test Results (shard 1)

1 041 tests 1 041 ✅ 3m 21s ⏱️
7 suites 0 💤
7 files 0 ❌

Results for commit 611e321.

github-actions · 2026-08-31T07:32:23Z

Test Results (shard 4)

1 165 tests 1 165 ✅ 4m 20s ⏱️
7 suites 0 💤
7 files 0 ❌

Results for commit 611e321.

github-actions · 2026-08-31T07:34:24Z

Test Results (shard 2)

3 059 tests 2 867 ✅ 6m 9s ⏱️
8 suites 192 💤
8 files 0 ❌

Results for commit 611e321.

github-actions · 2026-08-31T07:34:54Z

Test Results (shard 3)

1 145 tests 1 145 ✅ 7m 41s ⏱️
7 suites 0 💤
7 files 0 ❌

Results for commit 611e321.

github-actions · 2026-08-31T07:35:28Z

Test Results

44 files 44 suites 30m 4s ⏱️
8 692 tests 8 495 ✅ 197 💤 0 ❌
9 392 runs 9 195 ✅ 197 💤 0 ❌

Results for commit 611e321.

…vious fix loses writes #2776 asked one question: what ended the activity node's two sync streams while the activity was still running. This answers it, records the measurement that shows the obvious cure is worse than the disease, and makes the diagnostic that caused the mis-triage state its own age. It changes NO behaviour. ── the answer ── Its own previous progress write did, at +0.12 s. IMeshChangeFeed is published after EVERY create/update/delete, and Workspace.EvictForPath drops every cached remote stream whose owner matches the changed path — including the mirror the writer itself is using. A write leases that mirror only for its Observable.Create subscription, so the lease is released moments after its own change event lands; the evicted stream then has no declared holder and ReclaimIfUnheld DISPOSES it — UnsubscribeRequest to the owner, both sync/{id} hubs gone — and the owner then announces StreamEndedEvent to a subscriber that no longer exists. Measured: six progress writes to one activity node with one live reader mint 7 client-side and 11 owner-side sync/ hubs, with 5 mirrors disposed mid-run. ── the two arithmetic traps that made it read as a hub teardown ── 1. The drop line is written FIVE SECONDS after the event it describes: RouteStreamMessage holds a StreamMessage whose sync/{id} hub is missing for SyncStreamOptions.SyncHubRegistrationGrace (5 s) and logs only on that Timeout. In #2776 the streams ended at +0.12 s — confirmed independently by the failure's own arithmetic (FAILED seq=3 elapsedMs=31015.7 at 13:28:58.952 ⇒ EnteredAt 13:28:27.936). The ADVANCE_WITHOUT_HANDOFF beside it is a DIFFERENT 5 s bound (QueueAdvanceBound) counting from the same instant. Two unrelated five-second bounds produced a coincidence that looked like the hosted-hub drain cap. 2. The SENDER rules out a recycle. The recycle announcement is posted by a carrier (a dying hub must never speak for itself); the healthy-owner announcement is posted by the owner and refuses to fire once RunLevel > Started. Both #2776 lines name the activity node — so the owner was Started and NOT disposing. #2763/#2582 are eliminated by the trace, not by argument. ── why the obvious fix is NOT taken ── Giving EvictForPath the liveness gate its two sibling listeners already have (MeshNodeStreamCache.ResetFailureState: "A healthy live entry is left untouched"; JsonSynchronizationStream's version-gated Resubscribe: "resubscribing on it is pure churn") was implemented and measured, and it LOSES WRITES. The eviction is incidentally what keeps a cross-hub writer's BASE current with respect to writes the OWNER makes for itself: _pendingSelfWrites carries only this cache's writes forward, while an owner-side write (an activity's messageCount, a sealed segment) reaches the mirror only through the async fan-out. Controlled, same box, DOTNET_PROCESSOR_COUNT=4, on StaticRepoImportActivityWriteCountTest.AppendCost_DoesNotGrowWithTheLengthOfTheActivity: gate ON FAILED — 2000 messages appended, 1975 recorded (a 25-message batch lost) gate OFF PASSED and on CI the gated build turned 80 append calls into 99 writes with 44 OWNER_NACK_REENQUEUE / "MergeGuard: refused stale/reordered cross-hub write to 'messageCount'". The O(1) append pin (6a48f9f, d1a239a) was right and is not touched. EvictForPath now carries a comment saying the unconditional eviction is deliberate, and why. ── what DOES change ── LogStreamMessageDrop states how long the message was HELD, so its timestamp can never again be read as the time the stream ended. That is the whole behavioural diff; the rest is a doc page and comments. ── the real fix, for whoever takes it ── Make the writer's base version-aware (MeshChangeEvent already carries Version) so a write waits for the mirror to reach the announced version instead of throwing the mirror away to force a fresh snapshot. That is a change to the write path, not to EvictForPath. ── not claimed ── #2776's visible failure was a write with no verdict at 31 s. That silence has a separate, already-fixed cause (#2882 / #2890, 4d23117 — the write registered its response subject after posting; the trail could only say REGISTERED_AFTER_POST, which is exactly what that trace says). Verified: Release -warnaserror 0/0 for Graph.Test and Documentation.Test (which transitively build MeshWeaver.Data, Hosting, Mesh.Contract, Graph, Layout, Messaging.Hub, Documentation). Graph.Test 1086/1086 and Documentation.Test 166/166 at DOTNET_PROCESSOR_COUNT=4; earlier full runs on this tree also had Data.Test 419/419 and Hosting.Test 274/274. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01SD7aiLSo59xng2TzU32xEa

Copilot AI lite review requested due to automatic review settings August 31, 2026 07:23

Copilot started reviewing on behalf of rbuergi August 31, 2026 07:24

View session

Copilot AI reviewed Aug 31, 2026

View reviewed changes

Comment thread src/MeshWeaver.Messaging.Hub/MessageHub.cs

Comment on lines +1054 to +1059

lock (responseSubjects)

{

if (responseSubjects.TryGetValue(messageId, out var entry)

&& ReferenceEquals(entry.Subject, subject))

responseSubjects.Remove(messageId);

}

rbuergi added this pull request to the merge queue Aug 31, 2026

Merged via the queue into main with commit 4d23117 Aug 31, 2026
26 checks passed

This was referenced Sep 5, 2026

QueuedWriteAdvancesOnHandoffTest: the successor's caller can miss its terminal when the first write's ack is late (1/330, Plugins shard 3) #3363

Closed

fix: the whisper container bakes its model — the release moved, the pin cannot follow (#3906) #3956

Merged

rbuergi deleted the fix/2882-register-before-post branch October 24, 2026 14:13

Navigation Menu

Repository navigation

fix(#2882): the write registers its response callback BEFORE posting - #2890

fix(#2882): the write registers its response callback BEFORE posting#2890
rbuergi merged 1 commit into
mainfrom
fix/2882-register-before-post

rbuergi commented Aug 31, 2026

Uh oh!

Copilot AI left a comment

Uh oh!

github-actions Bot commented Aug 31, 2026

Uh oh!

github-actions Bot commented Aug 31, 2026

Uh oh!

github-actions Bot commented Aug 31, 2026

Uh oh!

github-actions Bot commented Aug 31, 2026

Uh oh!

github-actions Bot commented Aug 31, 2026

Uh oh!

github-actions Bot commented Aug 31, 2026

Uh oh!

github-actions Bot commented Aug 31, 2026

Uh oh!

Uh oh!

Reviewers

Uh oh!

Assignees

Labels

Projects

Milestone

Development

Uh oh!

2 participants

Conversation

rbuergi commented Aug 31, 2026

The seam — exactly what the issue asked for

The write path, reordered

The deterministic twin test

Verification

Why this matters beyond the one test

Uh oh!

Copilot AI left a comment

Choose a reason for hiding this comment

Pull request overview

Reviewed changes

Uh oh!

github-actions Bot commented Aug 31, 2026

Test Results (shard 0)

Uh oh!

github-actions Bot commented Aug 31, 2026

Test Results (shard 5)

Uh oh!

github-actions Bot commented Aug 31, 2026

Test Results (shard 1)

Uh oh!

github-actions Bot commented Aug 31, 2026

Test Results (shard 4)

Uh oh!

github-actions Bot commented Aug 31, 2026

Test Results (shard 2)

Uh oh!

github-actions Bot commented Aug 31, 2026

Test Results (shard 3)

Uh oh!

github-actions Bot commented Aug 31, 2026

Test Results

Uh oh!

Uh oh!

Reviewers

Uh oh!

Assignees

Labels

Projects

Milestone

Development

Uh oh!

2 participants