Repository navigation
fix(#1174): a base-state timeout says WHICH silence it waited on - #4342
Conversation
"Update aborted: no initial state arrived for '{path}' within 30s" lists four
suspects and cannot pick between them. There are really only two shapes, they
are opposite defects, and until now both raised the same bare
TimeoutException("The operation has timed out.") as the inner:
the mirror produced NO change item at all the owner never answered the
subscribe — activation/routing.
The node's content and its grants
are RULED OUT, not in: an absent
node and an unreadable one both
still produce a change item that
carries no node.
N change items, none carrying the node the owner IS answering and its
view of the path is EMPTY —
readability at the owner.
MEASURED, not guessed. Admin/_LogIncident/7473a637daf1e169 on memex-cloud,
read 2026-09-14 18:1xZ: 414 occurrences since 2026-08-10 across 57 pods,
lastSeen 2026-09-14T17:45:33Z. The 2026-08-10 verdict closed #1174 as a
duplicate of the roll-window route-starvation family because every occurrence
then known lay inside one join-to-Ready window; the retained samples now span
2026-09-02 -> 2026-09-14 on long-lived pods, so that no longer covers the
population. A Logs instance action on the control instance pinned the failing
write at the queue level — [UpdateQueue] ADVANCE_WITHOUT_HANDOFF seq=30538 at
17:45:08.832Z and [UpdateQueue] FAILED seq=30538 elapsedMs=30004 at
17:45:33.831Z, same seq — so the write was dispatched and never got a base; it
did not sit queued behind a predecessor. Which HALF of the fork the population
is in was not decidable from any line the portal emits. That is the gap.
BaseStateSource now counts what the mirror produced and raises a
BaseStateTimeoutException naming it; both wrapper sites append that sentence.
The counter sits UPSTREAM of the null-filter and the Timeout stays DOWNSTREAM
of it — #2543's order, which must not move: a census taken downstream reads
zero for EVERY timeout, i.e. reports case 1 for case 2. One interlocked
increment per emission, per subscription (Observable.Defer, because
RebaseSource/Take(1) may resubscribe). No bound changed, nothing retried,
nothing swallowed.
Nothing else is described: only the exception the base read itself raised
carries a census, so a foreign TimeoutException — an owner that missed the
REQUEST budget — keeps its message byte for byte. Describing one of those in
the language of the 30 s wait is #2387.
Three negative controls, each WATCHED red and then restored:
census moved downstream of the filter -> the chatty mirror reports "NO change
item at all" and the count assertion fails (case 1 reported for case 2);
the fork collapsed to one branch -> same failure;
BaseStateObservation describing every terminal -> the #2387 guard fails with
" The operation has timed out.".
Verified locally: Release -warnaserror 0 Error(s) 0 Warning(s) on
Mesh.Contract, Graph.Test and Documentation.Test. MeshWeaver.Graph.Test
1626/1626 in 3m33s. Documentation.Test 7/7 — AllInternalDocLinks_Resolve...,
EveryArchitecturePage_IsListedInTheTopicMap and the #1140 router ratchet.
Conserved as Doc/Architecture/BaseStateTimeoutCensus, which also records how to
read one off a running deployment and the trap that the Logs action's `query`
is filter text, not LogQL (a whole LogQL expression double-wraps and, being an
alternation, still returns some lines — so the mistake reads as a narrow answer
rather than an error).
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
There was a problem hiding this comment.
🟡 Changes recommended
Address the census correctness, race, regression-test, and documentation issues before approval.
Get a fresh assessment by requesting another Copilot review.
Pull request overview
Adds per-subscription emission census details to base-state timeout diagnostics, with tests and documentation.
Changes:
- Adds census-aware timeout exceptions and caller messages.
- Adds regression tests for timeout variants.
- Adds architecture and What's New documentation.
File summaries
| File | Review summary |
|---|---|
test/MeshWeaver.Graph.Test/BaseReadBoundIsReachableTest.cs |
The chatty control does not cover sibling-only patch emissions; add regression coverage for this shape. |
src/MeshWeaver.Mesh.Contract/MeshNodeStreamExtensions.cs |
Emission counts do not prove subscription acknowledgement or exclude initial-load failures. The count/version publication can also produce inconsistent diagnostics under a race. |
src/MeshWeaver.Documentation/Data/WhatsNew/2026-09-14-a-stalled-save-now-says-which-silence-it-waited-on.md |
Avoid presenting zero emissions as definitive proof that the owner never answered or readability was irrelevant. |
src/MeshWeaver.Documentation/Data/Architecture/BaseStateTimeoutCensus.md |
Document limitations involving acknowledgement timing, terminal failures, and sibling-only patch emissions; describe the result as no snapshot reaching the mirror. |
src/MeshWeaver.Documentation/Data/Architecture.md |
Adds the architecture topic-map entry. |
Review details
Suppressed comments (5)
src/MeshWeaver.Documentation/Data/Architecture/BaseStateTimeoutCensus.md:31
- The new fork overstates what the counter proves. The owner can acknowledge a fresh subscribe before its stream has produced a frame, and an owner-side access failure is a terminal rather than a node-less
ChangeItem; both can leave this mirror with zero change items. Thus zero emissions cannot rule out data-source/readability causes or establish that the owner never answered. Please describe this as “no snapshot reached the mirror” unless the census also tracks the subscribe/terminal outcome.
| **produced NO change item at all** | the owning per-node hub never answered the subscribe | its ACTIVATION and ROUTING — a saturated owner action block, a delivery that never arrived |
| **produced N change items, none carrying the node** | the owner IS answering; its view of this path is EMPTY | the node's readability FROM THE OWNER — the initial read's identity/RLS, or a `MeshDataSource` that did not load it |
src/MeshWeaver.Documentation/Data/Architecture/BaseStateTimeoutCensus.md:36
- This table is presented as an exhaustive fork, but the mirror can also emit null-valued items for sibling-only patches (
MeshDataSource.ReduceToMeshNodeemits that shape atsrc/MeshWeaver.Graph/MeshDataSource.cs:1884-1886). Those items make the second row's count nonzero even when the target is readable, so this guidance would send an investigation toward target RLS/MeshDataSourceincorrectly. Document that limitation or update the implementation to distinguish target-related changes before calling the view empty.
| **produced NO change item at all** | the owning per-node hub never answered the subscribe | its ACTIVATION and ROUTING — a saturated owner action block, a delivery that never arrived |
| **produced N change items, none carrying the node** | the owner IS answering; its view of this path is EMPTY | the node's readability FROM THE OWNER — the initial read's identity/RLS, or a `MeshDataSource` that did not load it |
🚨 **The first row rules the node's content and its grants OUT, not in.** An absent node, and one the
reader may not see, both still produce a change item that carries no node — that is what the
null-filter exists for. So "no emission at all" is never suspects (1)–(3); it is the owner not being
reachable, or not getting a turn.
src/MeshWeaver.Mesh.Contract/MeshNodeStreamExtensions.cs:288
- A positive count does not prove that the owner's view is empty.
MeshDataSource.ReduceToMeshNodedeliberately emits a null-valued item for sibling-only patches (MeshDataSource.cs:1851-1886), so these emissions can be unrelated churn while the target node exists and is readable. This message would send triage to RLS incorrectly; distinguish targeted/full absence from sibling-only updates, or avoid claimingEMPTY(and update the repeated documentation).
: $"The mirror produced {mirrorEmissions} change item(s) inside the bound (last "
+ $"Version={lastVersion}) and NONE of them carried the node: the owner IS "
+ "answering and its view of this path is EMPTY. Look at the node's readability "
+ "FROM THE OWNER — the initial read's identity/RLS, or a MeshDataSource that "
+ "did not load it — not at routing.";
src/MeshWeaver.Mesh.Contract/MeshNodeStreamExtensions.cs:239
- The emission count is published before
lastVersionis updated. If a mirror emission races the timeout callback between these two interlocked operations, the exception can report a positive count withLastVersion=-1(or the previous frame), making the diagnostic internally inconsistent. Update the version before publishing the count, or publish both fields as one atomic snapshot.
System.Threading.Interlocked.Increment(ref seen);
System.Threading.Interlocked.Exchange(ref lastVersion, change.Version);
test/MeshWeaver.Graph.Test/BaseReadBoundIsReachableTest.cs:160
- The new “chatty” control only emits
Empty()(a defaultChangeItem), so it does not exercise the real null-emission shape for sibling-onlyChangeType.Patchupdates produced byMeshDataSource.ReduceToMeshNode. The runtime census can therefore misclassify unrelated sibling churn while this fork test remains green; add a regression control with a readable target plus a sibling-only patch and assert that it is not reported as an empty target view.
var chatty = Run(
s => Observable.Interval(TimeSpan.FromSeconds(7), s).Select(_ => Empty()),
runFor: TimeSpan.FromSeconds(120));
- Files reviewed: 5/5 changed files
- Comments generated: 2
- Review effort level: Lite
💡 Add a code-review agent skill or configure MCP servers for context-aware, tailored reviews. Learn more in the docs.
| ? "The mirror produced NO change item at all inside the bound: the owning per-node " | ||
| + "hub never answered the subscribe. Look at its ACTIVATION and ROUTING (a " | ||
| + "saturated owner action block, a delivery that never arrived), not at the " | ||
| + "node's content or its grants — an absent node, and one the reader may not " | ||
| + "see, both still produce a change item that carries no node." |
There was a problem hiding this comment.
Accepted in full, and verified against the code you cite before changing anything. JsonSynchronizationStream says it in as many words:
🚨 A FRESH stream acks IMMEDIATELY, and the asymmetry with the re-assert path above is deliberate (#3058). This subscribe has no answer to overtake — the stream was just built and its first
Fullcomes out of the reduce's own hydration, which is IO-bound and unbounded (a cold data source, a per-node hub activating).
So seen == 0 means no snapshot ever hydrated, not "the owner never answered". An owner that acked and then produced no frame — cold data source, a per-node hub still activating, an initial read that yielded nothing — reads identically at this seam. The previous wording therefore ruled OUT exactly the causes a reader must still consider, which is worse than the four-suspect sentence it replaced: it would send someone away from a MeshDataSource / initial-load fault with confidence.
Fixed in 35b5243, in all four places the claim was made — the message, the XML doc on BaseStateSource, the doc page and the What's New entry. The zero branch now reads:
NO change item at all reached the mirror inside the bound — no snapshot ever hydrated. This does NOT establish that the owner never answered: a fresh subscribe is ACKNOWLEDGED BEFORE hydration, so an owner that acked and then produced no frame (a cold data source, a per-node hub still activating, an initial read that yielded nothing) reads identically here. Both the owner's activation/routing AND its initial read are still in scope.
Branch two is the one that excludes something — frames arriving is positive evidence that the subscription is established and producing — and the doc now says so explicitly rather than presenting the two as symmetric.
Pinned by a new assertion (does NOT establish) whose negative control I watched: restoring the overclaiming message turns ASilentMirrorAndAChattyOne_TimeOutWithDIFFERENTMessages red, quoting the overclaim back.
| - **The owner never said anything.** It was not reachable, or it never got a turn. The node's | ||
| content and who may read it are then irrelevant — a node that does not exist, and one the reader | ||
| is not allowed to see, both still produce an answer that carries nothing. |
There was a problem hiding this comment.
Agreed — same defect, and the user-facing copy was the worse place for it. Rewritten in 35b5243 to drop the owner-unreachable-versus-unreadable split entirely:
There are really only two shapes:
- Nothing came back at all. No snapshot of the node ever arrived.
- Answers came back, repeatedly, and none of them carried the node. The connection to the owner is working and producing — so the question is whether the owner could read that node at all.
The second shape is the one that narrows the search. The first deliberately says that it has not decided anything further — an owner that is unreachable and one that answered and then had nothing to send look the same from here, and a message that picked one would send the reader the wrong way.
…r answered
Copilot's finding, verified against the code and accepted in full. This seam
observes ChangeItem FRAMES, not the subscribe acknowledgement — and a FRESH
stream Ack()s IMMEDIATELY, deliberately, BEFORE its first Full comes out of the
reduce's own hydration. JsonSynchronizationStream says so in as many words:
A FRESH stream acks IMMEDIATELY, and the asymmetry with the re-assert path
above is deliberate (#3058). … its first Full comes out of the reduce's own
hydration, which is IO-bound and unbounded (a cold data source, a per-node
hub activating).
So seen == 0 means "no snapshot ever hydrated", NOT "the owner never answered".
An owner that acked and then produced no frame — a cold data source, a per-node
hub still activating, an initial read that yielded nothing — reads identically.
The previous text therefore ruled OUT exactly the causes a reader must still
consider, which is worse than the four-suspect sentence it replaced: it would
send someone away from a MeshDataSource/initial-load fault with confidence.
Corrected in all four places the claim was made — the message, the xml doc, the
doc page and the What's New entry. Branch TWO is the one that excludes
something: frames arriving is positive evidence that the subscription is
established and producing, which takes routing and activation off the table.
Branch ONE now says plainly that it has not decided, and names both directions.
The distinction the census buys is unchanged and is still what #1174 lacked:
"the mirror carried nothing at all" vs "the mirror carried frames, none of them
the node".
NEGATIVE CONTROL, watched: restoring the overclaiming zero-branch message turns
ASilentMirrorAndAChattyOne_TimeOutWithDIFFERENTMessages RED on the new
`does NOT establish` assertion, quoting the overclaim back. Restored, green.
Verified: Release -warnaserror 0 Error(s) 0 Warning(s) on Graph.Test,
Documentation.Test and the full solution (68 assemblies).
MeshWeaver.Documentation.Test 467/467. BaseReadBoundIsReachableTest 5/5.
Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
|
ℹ️ Merge-queue steward: no action — removed from the queue with reason |
The defect
Update aborted: no initial state arrived for '{path}' within 30slists four suspects and cannot pick between them. There are two shapes of silence, they need different fixes, and until now both raised the same bareTimeoutException("The operation has timed out.")as the inner:MeshDataSourcethat did not load it🚨 The zero branch does NOT mean "the owner never answered", and the message says so. This seam observes
ChangeItemframes, not the subscribe acknowledgement — and a FRESH streamAck()s immediately and deliberately, BEFORE its firstFullcomes out of the reduce's own hydration (JsonSynchronizationStream, #3058: "its first Full comes out of the reduce's own hydration, which is IO-bound and unbounded (a cold data source, a per-node hub activating)"). Branch two is the one that excludes something; branch one narrows nothing away and says as much. (Copilot caught an earlier draft claiming otherwise — see the review threads; corrected in35b5243.)Measured, not guessed — #1174
Admin/_LogIncident/7473a637daf1e169on the control instance, read 2026-09-14 18:1xZ: 414 occurrences since 2026-08-10 across 57 pods, lastSeen2026-09-14T17:45:33Z. Live, not historic.Logsinstance action on the control instance pinned the failing write at the queue level:[UpdateQueue] ADVANCE_WITHOUT_HANDOFF … seq=30538 bound=5000msat17:45:08.832Zand[UpdateQueue] FAILED … seq=30538 elapsedMs=30004at17:45:33.831Z— same seq. The write was dispatched and simply never got a base; it did not sit queued behind a predecessor.{user}/_UserActivity/{user}(one is at version 6498) or a page they revisit. Cold paths do not appear.Which of the two shapes that population is in was not decidable from any line the portal emits. That gap is what this PR closes. It does not by itself fix the underlying fault — #1174 stays open for it.
The change
BaseStateSourcecounts what the mirror produced and raises aBaseStateTimeoutExceptionnaming it; both wrapper sites append that sentence to the caller's message.🚨 The counter sits UPSTREAM of the null-filter and the
Timeoutstays DOWNSTREAM of it — #2543's order, and it must not move: a census taken downstream reads zero for every timeout, i.e. reports shape 1 for shape 2, which is the exact confusion it exists to end. One interlocked increment per emission, per subscription (Observable.Defer, becauseRebaseSource/Take(1)may resubscribe).No bound changed, nothing retried, nothing swallowed. And nothing else is described: only the exception the base read itself raised carries a census, so a foreign
TimeoutException— an owner that missed the REQUEST budget — keeps its message byte for byte. Describing one of those in the language of the 30 s wait is #2387.Negative controls — each WATCHED red, then restored
NO change item at all; the"4 change item(s)"assertion fails — shape 1 reported for shape 2BaseStateObservationdescribing EVERY terminal" The operation has timed out."does NOT establishassertion fails, quoting the overclaim backVerification
dotnet build -c Release -warnaserror, one project per invocation: 0 Error(s), 0 Warning(s) onMeshWeaver.Mesh.Contract,MeshWeaver.Graph.Test,MeshWeaver.Documentation.Test, and the full solution (68 assemblies).MeshWeaver.Graph.Test1626/1626 in 3 m 33 s (.trx, 2.9 MB).MeshWeaver.Documentation.Test467/467 — includingAllInternalDocLinks_ResolveToExistingNodes,EveryArchitecturePage_IsListedInTheTopicMap, and the Portal hubs send messages addressed from/to the mesh router hub instead of using their own hub identity #1140RouterAsNodeOperationOriginRatchetGuard.Conserved
Doc/Architecture/BaseStateTimeoutCensus— the two shapes, what the zero branch deliberately does NOT claim, how to read one off a running deployment, and the trap that theLogsaction'squeryis filter text, not LogQL (a whole LogQL expression double-wraps and, being an alternation, still returns some lines, so the mistake reads as a narrow answer rather than an error). Listed in the Architecture topic map; What's New entryCategory: Fix.Pairs-with: none — nothing public is removed; the diff adds an internal nested exception type and widens one private helper to internal for its guard test.
🤖 Generated with Claude Code