Repository navigation
fix(#1198): an unattributed delete timeout reports what it actually removed - #5170
Conversation
…emoved Both halves this issue's title names have already landed: the budget ladder is DERIVED through a strictly-contracting `Nest` (30/25/20/15 s), and the pre-flight fan-out carries a per-leg bound. What is left is the arm the reported occurrence actually came through. `partial-deleted=` was read off `ex.Data[DeletedPathsDataKey]` alone. That key is stamped by exactly two sites — the commit stage's own `TimeoutAtStage` arm and the drain-pass fold — and both read `SnapshotProgress()` to do it, so `ex.Data` can never hold a path this closure's accumulator lacks: every removal goes through `RecordDeleted`. What `ex.Data` CAN be is absent. A terminal raised by a plain `.Timeout(...)` that is not one of the six stages — the absence probe, a leaf's re-entrant `NestedTimeout` surfacing through this handler, i.e. the `stage=unattributed` case — carries no `Data` at all, so the line printed `partial-deleted=0` while the accumulator in scope knew the real number. That zero is NOT a measurement. It is "not measured" wearing the same rendering as "none" — the defect class the `unanswered=` comment three lines below already spells out for its own field — and #1198's ORIGINAL occurrence is an instance of it: a bare `System.TimeoutException: The operation has timed out.` over a subtree whose progress was in scope and unread. Reading the accumulator closes it for EVERY terminal rather than the two that remembered to stamp, so a torn subtree is reported as torn whatever raised the fault. The union cannot under-report either side and no bound is touched. Second half: the ladder's invariant was stated in `MeshOperationOptions`'s own summary and only ONE pair of it was pinned by a test (the innermost two, in QueryFanInStallIsTerminalTest). A test naming one member of an ordered set cannot see a regression in the others — a change making `NestedTimeout` equal `Timeout`, the exact 30 = 30 shape this issue was, passes it and reproduces the defect on the two rungs that produced the production occurrences. `TheBudgetLadderContractsAtEveryRungTest` asserts all four rungs, `Nest`'s contraction iterated twelve levels deep, and the sub-millisecond refusal — parameterised over both regimes, because which term of `Nest` governs depends on the enclosing value and a test fixture configures the SMALL one. Also conserves the grouping work product: `OneLogSiteManyTerminals` — why an incident fingerprint both splits one log site across tickets and folds unrelated roots into one, how to group on the innermost terminal, and the three reasons a frozen `lastSeen` is not the fix working. Measured: ladder suite 13/13; every delete test in MeshWeaver.Graph.Test 27/27 (the regression control — the stage-tagged readings must not move); `DocumentationLinkIntegrityTest` 1/1. `MeshWeaver.Mesh.Contract`, `MeshWeaver.Hosting.Test`, `MeshWeaver.Graph.Test` and `MeshWeaver.Documentation.Test` each build `-c Release -warnaserror` with 0 Error(s), 0 Warning(s). NOT established: there is no deterministic repro of the unattributed arm itself — injecting a bare `.Timeout` deeper in `HandleDeleteNodeRequest` has no seam short of restructuring the pipeline. The change rests on the two-site argument above and on the union being incapable of reporting less than before. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
There was a problem hiding this comment.
Copilot review overview
🟡 Changes recommended
Address the reported moderate findings before approval.
Get a fresh assessment by requesting another Copilot review.
Review effort: Lite
Findings: 1
Open (2)
What changed in this PR
Improves recursive-delete timeout diagnostics, adds budget-ladder contract coverage, and documents timeout incident grouping.
Changes:
- Reports accumulated deletion progress for unattributed failures.
- Adds budget-ladder contract tests.
- Adds and indexes timeout-triage documentation.
| File | Summary |
|---|---|
test/MeshWeaver.Hosting.Test/TheBudgetLadderContractsAtEveryRungTest.cs |
Adds ladder tests; moderate findings concern configuration coverage, while nits concern regime wording and mutable collections. |
src/MeshWeaver.Mesh.Contract/MeshExtensions.cs |
Updates deletion-progress reporting; moderate finding notes an incomplete description of DeletedPaths writers. |
src/MeshWeaver.Documentation/Data/Architecture/OneLogSiteManyTerminals.md |
Adds timeout incident-triage guidance. |
src/MeshWeaver.Documentation/Data/Architecture.md |
Indexes the new architecture documentation. |
💡 Configure MCP servers for context-aware, tailored reviews. Learn more in the docs.
| // `ex.Data[DeletedPathsDataKey]` is stamped by exactly two sites — the commit | ||
| // stage's own TimeoutAtStage arm and the drain-pass fold — and BOTH read | ||
| // `SnapshotProgress()` to do it. So `ex.Data` can never hold a path this closure's | ||
| // `deletedProgress` does not: every removal goes through `RecordDeleted`. |
There was a problem hiding this comment.
Correct, and the way I got it wrong matters more than the count: I grepped DeletedPathsDataKey, the constant — and two of the four writers spell the key as the bare literal "DeletedPaths", so they were invisible to the instrument I used to write the sentence. Verified now:
| site | value written | spelling |
|---|---|---|
MeshExtensions.cs:3813 (commit-stage TimeoutAtStage) |
SnapshotProgress() |
constant |
MeshExtensions.cs:4288 (drain-pass fold) |
deletedSoFar.AddRange(passDeleted) |
constant |
MeshExtensions.cs:4340 (max-pass branch) |
acc |
literal |
HierarchicalPathDeletion.cs:83 |
deleted.ToImmutable() |
literal |
So "exactly two sites" is wrong and the comment is being rewritten to describe the writers without claiming a count, at all three locations you name (3936, 3952, 3960).
The argument the change rests on survives, and your finding actually makes the chosen shape the right one rather than a belt-and-braces one. Every writer above is fed by the same set of real removals: :3813 and :4288 read the accumulator directly, :4340's acc is the drain fold over FanOutDeleteSubtree's emissions, and HierarchicalPathDeletion's deleted is appended in a .Do(...) on the same deleteOne emission that RecordDeleted appends from. What I cannot claim — and had implicitly claimed with the two-site inventory — is that the accumulator is a strict superset: HierarchicalPathDeletion appends to its own builder and RecordDeleted to deletedProgress off one emission with no ordering between them, so an in-flight removal can be in either builder and not yet the other.
That is precisely why the code takes the union rather than preferring the accumulator, and the corrected comment will say that instead of asserting a superset it cannot prove.
Separately worth noting, though out of scope here: a private const string DeletedPathsDataKey = "DeletedPaths" with two call sites bypassing it is the thing that hid this. Renaming the constant today would leave the two literals silently writing to the old key. I am not folding that into this PR, but it is what made the inaccuracy possible.
| var seen = new List<TimeSpan> { enclosing }; | ||
| for (var level = 0; level < 12; level++) | ||
| { | ||
| var nested = options.Nest(enclosing); | ||
| nested.Should().BeLessThan(enclosing, | ||
| $"Nest must contract at level {level + 1} — the ladder's whole guarantee is that a " | ||
| + "bound nested inside another is strictly quicker to give up"); | ||
| nested.Should().BePositive( | ||
| $"level {level + 1} collapsed to zero or below; the contraction must stay inside " | ||
| + "the positive domain or a nested bound becomes an instant refusal"); | ||
| seen.Add(nested); | ||
| enclosing = nested; | ||
| } |
There was a problem hiding this comment.
Correct — the collections policy is src/ and test/, with no carve-out for a method-local accumulator, and a mutable List<T> in a new test file is exactly the kind of instance that makes the rule read as optional. Fixing it to ImmutableList<TimeSpan> with the result of Add assigned back, so the uniqueness assertion still sees every rung including the seed.
Two notes on what the fix must not lose, since the collection is load-bearing here rather than incidental:
- The seed (
Timeoutitself) has to stay in the set. The uniqueness assertion is what catches a collapse between rung 1 and rung 2 — the exact 30 = 30 shape A recursive delete's commit stage can stall for its whole budget — pre-flight fan-out and budget nesting are fixed and deployed; the commit stall is unmeasured on memex-cloud #1198 was — so dropping the seed while switching container type would quietly remove the pair the test exists for. - The per-iteration
BeLessThan/BePositiveassertions are the ones that name which level failed; the uniqueness assertion over the whole set is the one that catches a non-adjacent collision. Both are kept.
Re-running the suite after the change rather than assuming the container swap is behaviour-neutral.
…the ladder test Two Copilot findings, both right. 1) The comment claimed `ex.Data["DeletedPaths"]` is stamped by "exactly two sites". It is four, and the reason I got it wrong is the interesting half: I grepped `DeletedPathsDataKey`, the constant — and the max-pass branch (MeshExtensions.cs:4340) and `HierarchicalPathDeletion` (:83) spell the key as a bare literal, so they were invisible to the instrument that wrote the sentence. The change's argument survives, and the finding makes the chosen shape the right one rather than belt-and-braces: every writer is fed by the same set of real removals, but `HierarchicalPathDeletion` appends to its own builder off the same `deleteOne` emission `RecordDeleted` appends from, with no ordering between them — so neither side is provably a SUPERSET and an in-flight removal can be in either and not yet the other. That is exactly why the code takes the UNION. The comment now says that instead of asserting a superset it cannot prove, and describes the writers without claiming a count. 2) The ladder test's accumulator was a mutable `List<TimeSpan>`. The collections policy covers `test/` with no carve-out for a method-local, and a new test file is where that reads as optional. Now an `ImmutableList<TimeSpan>` with the result of `Add` assigned back — and the seed stays in the set, with a comment saying why: the uniqueness assertion is what catches a rung-1/rung-2 collapse, the exact 30 = 30 shape #1198 was, so dropping `Timeout` itself would remove the pair the test exists for. Re-measured rather than assumed neutral: `MeshWeaver.Mesh.Contract` and `MeshWeaver.Hosting.Test` each build `-c Release -warnaserror` with 0 Error(s), 0 Warning(s); the ladder suite is 13/13 after the container swap. Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
…-timeout-partial-count # Conflicts: # src/MeshWeaver.Documentation/Data/Architecture.md
…ishes neither breakage nor a fix Raised by a session working area:ai on `[ThreadExec]`, and it applies to the incident-hub pair (#4962 / #5087) squarely: those lines are written at the refusal and say so in the same sentence — "it still carries its request and is picked up again on the next change to the incident collection" — so the outcome is decided by a LATER branch. #4962's own Impact section records the retry landing ~90 seconds later. So the counter measures the log statement's position in the code, not the defect, and it is unsound in BOTH directions: a fixed root keeps it climbing for ever, so a recurrence check reading it can never let the issue stay closed; and a high count does not establish a live root either, because the attempts may all have been repaired by the branch that runs after the line. OneLogSiteManyTerminals said only that a count cannot verify a FIX. It now says the stronger thing, names the tell (a message that names its own recovery), and points at the reading that IS sound — the retained samples' inner exceptions, which are produced at the point they name. Links AFaultDoesNotStateTheVerdict, which landed on main in the same window and documents the general shape. Doc guards on the merged tree: DocumentationLinkIntegrityTest, ArchitectureTopicMapTest and DocumentationFrontMatterGuard 7/7; MeshWeaver.Documentation.Test builds -c Release -warnaserror with 0 Error(s). Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Both halves of #1198's title have already landed — this closes the arm its own occurrence came through
Measured on
mainbefore changing anything: the budget ladder is DERIVED through a strictly-contractingNest(30/25/20/15 s at the production default), andPreValidateDescendantsObscarries a per-leg bound with the stage bound demoted to a backstop. So the two things the title names are fixed. What remains is narrower and more interesting.partial-deleted=0was still "not measured" wearing the rendering of "none"ex.Data[DeletedPathsDataKey]is stamped by exactly two sites — the commit stage'sTimeoutAtStagearm and the drain-pass fold — and both readSnapshotProgress()to do it. Soex.Datacan never hold a path this closure'sdeletedProgresslacks: every removal goes throughRecordDeleted. Whatex.Datacan be is absent — a terminal raised by a plain.Timeout(...)that is not one of the six stages (the absence probe, a leaf's re-entrantNestedTimeoutsurfacing through this handler) carries noDataat all, i.e.stage=unattributed.And #1198's original occurrence is exactly that case:
[DeleteNode] timeout path=KmuBasics/Buchungsjournal partial-deleted=0with a bareSystem.TimeoutException: The operation has timed out.— the only producer of that bare message is Rx's own.Timeout, neverTimeoutAtStage, which tags every one of its own. So the zero that sent this ticket's triage exclusively to the pre-commit stages was never a reading.The arm now reads the accumulator, union'd with anything
ex.Datacarries. That closes it for every terminal rather than the two that remembered to stamp — a torn subtree is reported as torn whatever raised the fault. It is the same defect theunanswered=comment three lines below already spells out for its own field.No bound touched, no retry, no catch removed. The union cannot report less than before.
The ladder invariant was stated and only one pair of it was pinned
MeshOperationOptions's own summary statesQueryInitialBudget < PermissionEstablishmentBudget < NestedTimeout < Timeoutfor every configuration. Exactly one pair was covered by a test (QueryFanInStallIsTerminalTest.TheFanInsRung_IsStrictlyInsideTheFoldsBudget— the innermost two).A test naming ONE member of an ordered set cannot see a rule that CHOOSES among them: a change making
NestedTimeoutequalTimeout— the exact 30 = 30 shape this issue was — passes it, and reproduces the defect on the two rungs that produced the production occurrences.TheBudgetLadderContractsAtEveryRungTestpins all four rungs as adjacent pairs (so a failure names the pair that collapsed),Nest's contraction iterated twelve levels deep with a uniqueness assertion, and the sub-millisecond refusal. Parameterised over both regimes —Nesttakes the larger of an absolute reserve and a fraction, so which term governs depends on the enclosing value, and a contraction proved only where the reserve governs says nothing about the small budgets a test fixture actually configures.Work product conserved
Doc/Architecture/OneLogSiteManyTerminals— why an incident fingerprint both splits one log site across tickets and folds unrelated roots into one, how to group a cluster of timeout tickets on the innermost terminal rather than the logger category, the four terminals the mesh's write-wait produces (one of which is not a mesh defect at all), and the three reasons a frozenlastSeenis not the fix working. Written while grouping thearea:meshtimeout cluster; it is what made that grouping repeatable.Verification
dotnet build -c Release -warnaserror, one project per invocation:MeshWeaver.Mesh.Contract0 Error(s) 0 Warning(s);MeshWeaver.Hosting.Test0 Error(s) 0 Warning(s);MeshWeaver.Graph.Test0 Error(s) 0 Warning(s);MeshWeaver.Documentation.Test0 Error(s).TheBudgetLadderContractsAtEveryRungTest: 13 total / 13 succeeded / 0 failed (963 ms).MeshWeaver.Graph.Test(--filter FullyQualifiedName~Delete): 27 total / 27 succeeded / 0 failed (29 s). These are the tests that pin the stage-taggedpartial-deleted=readings; the union must not move them, and it does not.DocumentationLinkIntegrityTest: 1 / 1 passed.What this does NOT establish
.Timeoutdeeper insideHandleDeleteNodeRequesthas no seam short of restructuring the pipeline, so the change rests on the two-site argument above (both stampers read the same accumulator, so it is a superset) and on the union being incapable of reporting less than before. The 27 passing delete tests are a regression control, not a positive one for this arm.IoPoolRegistrysample on the portal the occurrences come from. That is operational and unchanged by this PR.Pairs-with: none— no public type or member is removed; one private local and one test file are added.Implementers: none— no member added to a public interface or abstract class.Mirror-sync: none— nostrings.{en,de}.jsonkey added, removed or re-worded. The changed text is a log line, English by house rule.Refs #1198
🤖 Generated with Claude Code