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
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
The MeshNode.DeleteNode operation in MeshWeaver.Mesh.MeshNode timed out when deleting KmuBasics/Buchungsjournal. The partial-deleted=0 flag indicates no child nodes were successfully deleted before the timeout — the operation made zero progress.
Probable cause
A System.TimeoutException with partial-deleted=0 suggests the delete operation never got past its initial setup. The two most likely explanations:
Lock contention (moderate confidence): Another grain operation held the lock on this mesh node, and the delete's acquire-wait exceeded the configured timeout.
Infrastructure stall (equally likely): A transient database or storage latency spike on this single pod caused the operation to exceed its timeout.
Without a deeper stack trace or a repeat occurrence, the root cause cannot be narrowed further.
Impact
Extremely low. A single occurrence on a single pod, affecting one path (KmuBasics/Buchungsjournal). The user likely received a 500 or hung response for that one delete request. No broader outage.
Where to look
The MeshNode class in the MeshWeaver.Mesh namespace — specifically the DeleteNode method or the corresponding message/command handler. Investigate:
The timeout duration configured for delete operations.
Whether CancellationToken from the caller is properly plumbed through.
Whether the grain lock is being held too long by concurrent operations on the same node path.
Whether the persistence layer (database/grain storage) can stall under load for this specific node shape.
Evidence
Fingerprint
bf8199089cb3236b
Category
MeshWeaver.Mesh.MeshNode
Severity
Error
Exception
System.TimeoutException
Namespace
memex-cloud
Pods
memex-portal-deployment-59479dc7d9-kmwvr
Occurrences
1
First seen
2026-08-11 05:46:41Z
Last seen
2026-08-11 05:46:41Z
Recent log lines
2026-08-11 05:46:41Z memex-portal-deployment-59479dc7d9-kmwvr fail: MeshWeaver.Mesh.MeshNode[0]
[DeleteNode] timeout path=KmuBasics/Buchungsjournal partial-deleted=0
System.TimeoutException: The operation has timed out.
Opened automatically from Admin/_LogIncident/bf8199089cb3236b. Recurrences are folded into this issue rather than opening new ones.
Diagnostics shipped in #1294 — the root cause is NOT fixed, and this issue's key evidence was misleading.
partial-deleted=0 never meant "zero progress"
The commit phase is wrapped in .Timeout(opts.Timeout). A timeout unsubscribes, and the
deleted-path list is attached only to the exception HierarchicalPathDeletion raises itself —
the freshly-constructed TimeoutException carries no Data. So partial-deleted printed 0 for every timeout, however much of the subtree had already been removed. The reading that narrowed
this to the pre-commit stages does not hold; the commit stage was never excluded.
What the one log line could not distinguish
HandleDeleteNodeRequest bounds six stages with the same MeshOperationOptions.Timeout, and
three of them (root read, permission fold, root validators) had no bound at all — a wedge there
produced no [DeleteNode] line whatsoever. Every bounded one threw a bare TimeoutException.
Stage names: read-root, check-permission, validate-root, collect-paths, pre-validate-descendants, commit. The fan-out stage additionally names the descendants that
never answered ValidateDeleteRequest — that stage posts at every descendant and waits for all of them under one budget, so a single unresponsive per-node hub refuses the whole delete. partial-deleted and the response's AffectedPaths are now truthful. The stage + detail also ride
on the response the caller sees, not only the log. No budget was raised and the descendant
validation was not made optional.
Why this stays open
Three stages now fit the original occurrence equally well, and the plausible fixes differ in kind
(a per-leaf report for an unresponsive descendant; a stalled storage enumeration; a leaf hub wedged
mid-commit). Attributing it from one line would be a guess. The next occurrence names the stage
and the silent hub — please re-post the new log line here and the fix becomes decidable.
Two defects root-caused today each produce exactly this signature — a timeout with partial-deleted=0, i.e. an operation that made zero progress. Both were found while investigating unrelated symptoms, and neither existed as a hypothesis when this issue was written. Worth re-checking against them before spending any more effort on lock contention or infrastructure latency, which were the two guesses recorded above.
Candidate 1 — a request that is handled and never answered (#1362, PR #1364)
HandleGetDataRequest subscribes a live workspace stream and posts each emission, but .Subscribe(onNext) has no completion arm. SynchronizationStream.Dispose() deliberately completes its store without publishing a value (the #1170/#1171 recognised-shutdown outcome), and a reduced stream over an already-disposed parent completes on first subscribe. The terminal signal is discarded: the delivery reads Processed, the subscription dies with the hub, and the caller's callback sits registered until its wall-clock bound.
Why it fits here: the observed shape in #1362 was HANDLER_ENTER → HANDLER_EXIT state=Processed → [SYNC_STREAM] … stream is disposed ~30 ms later → silence to the bound. The error message then names the state at t+timeout rather than what happened at t+0 — which is why it reads as "never started" when the handler in fact ran. A delete that must first read the node would report precisely partial-deleted=0.
Any recycle in that window produces it — idle deactivation, delete, republish, or overlay self-heal — so it needs no unusual conditions, just unlucky timing.
MeshNodeStreamCache._queries cached each synced query as Replay(1).AutoConnect(1) with no eviction. A ReplaySubject latches a terminal and replays it to every later subscriber; AutoConnect(1) never reconnects. So one transient Postgres handshake failure made a query id permanently unreadable for the life of the process — every later attempt re-subscribed to an instantly-replayed error.
Why it fits here: a delete that cannot read what it must delete makes zero progress and then times out, indefinitely and only on the affected pod. That matches "a transient database latency spike on this single pod" as observed, while explaining why it did not clear on its own.
This is now the fourth instance of that class this week; a related un-evicted promise-cache (PostgreSqlPartitionStorageProvider._provisioned) can permanently block partition provisioning after one transient DDL failure, surfacing forever as 42P01.
Suggested disposition
Leave open until #1364 and #1367 have merged, then treat a recurrence as new information rather than a repeat. If it does not recur after both land, close it as fixed-by-those rather than as unreproducible — the two are very different records for whoever meets this next.
Not worth an independent investigation before then: the impact is genuinely low, and both candidates are already being fixed for their own reasons.
Both candidates re-checked against the code — neither is reachable, and the premise they shared was false
#1364 and #1367 have both merged (in main at 86aab11), so the previous comment's "re-check then
decide" is now due. I traced both against the delete path at that commit. The answer is not the one
that comment expected, and the more important finding is underneath it.
The premise — "zero progress" — was never established
Both candidates were selected because they explain an operation that made no progress. That
criterion has no discriminating power here.
The incident is 2026-08-11 05:46:41Z. #1294 — which introduced the stage names and the
progress sink that makes the counter truthful — merged 2026-08-12 13:07:28Z (de494c25f). The
log line therefore came from pre-#1294 code, where partial was read solely from ex.Data["DeletedPaths"], a key set only by HierarchicalPathDeletion's own .Catch. A .Timeout unsubscribes and throws a freshTimeoutException whose Data is empty, so partial-deleted=0 was printed for every timeout regardless of how much of the subtree had
already gone. That is what the previous comment said about #1294's own reading; it applies with
equal force to the two candidates chosen after it.
HandleGetDataRequest runs only in answer to a posted GetDataRequest. No stage of the delete
posts one. Concretely, at 86aab11:
read-root reads through persistence.Read(path, …) — a direct IStorageAdapter call, and
deliberately so: the comment at MeshExtensions.cs:2218 says it avoids activating the per-node
hub that GetMeshNodeStream would trigger.
collect-paths uses storage.ListDescendantPaths — direct storage again.
pre-validate-descendants posts ValidateDeleteRequest; the answering handler
(HandleValidateDeleteRequest, :3132) reads via persistence.Read and runs validators.
the per-path stream cache hydrates over SubscribeRequest, not GetDataRequest — a
different handler with a different defect surface.
Enumerating every new GetDataRequest(...) in src/ puts all of them (GetMeshNode, layout
areas, export, indexing, HubStreamProviderFactory, …) off the delete's reactive chain. #1364 is
a real fix for a real bug; it cannot produce a [DeleteNode] timeout line at all.
The delete does reach MeshNodeStreamCache._queries, via PermissionEvaluator
($security-access:{scope} at PermissionEvaluator.cs:713, plus policy/roles/memberships) — hit
at check-permission, at validate-root through RlsNodeValidator, and at every leaf's [RequiresPermission(Delete)] gate. So reachability is genuine and I expected this one to land.
It does not, because a poisoned _queries entry replays a latched OnError, instantly —
never silence — and Observable.Timeout fires on silence, not on error. Downstream that error is answered: AccessControlPipeline folds it to Undetermined → DeliveryFailure(Unavailable),
and PreValidateDescendantsObs' per-leaf .Catch logs [DeleteNode] pre-validation failed at
Warning. On the unbounded stages it surfaces as [DeleteNode] unexpected. Neither is the line we
got.
The exception text corroborates it. grep -rn "new TimeoutException()" src/ returns nothing, and
the hub's own RequestTimeout throws a named one ("No response received in hub …"). The only
producer of the default message System.TimeoutException: The operation has timed out. is Rx's .Timeout(TimeSpan) — i.e. a stage that went silent, which is precisely what a replayed
cache error is not.
What the one line does still tell us
Pre-#1294 only three stages carried a bound (collect-paths, pre-validate-descendants, commit); the other three were unbounded and a wedge in them would have logged nothing at all. So
the bare-.Timeout fingerprint narrows the 2026-08-11 occurrence to one of those three, and no
further from that line.
The two mechanisms that actually fit, and are unfixed
Both scale with subtree size, which is also the cheapest way to discriminate them — how many
descendants did KmuBasics/Buchungsjournal have?
pre-validate-descendants pays a per-descendant permission-query cold start under ONE
budget.GetEffectivePermissions keys its cached synced query on the node path itself, plus
the recursive ancestor chain and a parallel $security-policy:{path}. For a non-static-role
caller the static seed is empty, so a recursive delete opens up to one brand-new SyncedQueryMeshNodesper descendant, simultaneously — each a cross-hub SubscribeRequest
plus a Postgres round-trip — inside a single 30 s window. The commit stage does not pay this
(System short-circuits), which is exactly why the pre-flight is the expensive half.
commit fans N leaf deletes over a cap-1 Postgres write pool.pg:{adapter} is capped at
1, so Observable.Merge parallelism collapses to one serialised connection, again under one
30 s budget. This is the mechanical form of the original triage's "database latency spike"
guess.
EvictFaultedQuery fires only from the OnError arm, and Replay(1).AutoConnect(1) never
reconnects — so a hung (as opposed to faulted) _queries entry is still shared, silently, for
the process lifetime. That variant does produce silence, so unlike the faulted one it is
shape-compatible with this incident. I could neither confirm nor refute that it occurred.
Disposition — stays open
Explicitly not closed as fixed-by-#1364/#1367: that would record a false cause, and the two
fixes are unrelated to this path. Also not closed as unreproducible — #1294 already made the
next occurrence decidable, and post-fix silence carries no signal either way (the pre-fix window,
2026-08-11 → 08-13, also recorded zero recurrences, and the portals self-update on a 6 h poll so
memex-cloud may not even be running the fixes yet).
Post-#1294 the message is [DeleteNode:{stage}] … and names the silent hub, so a recurrence
self-identifies and one line resolves this.
Not established: which stage the 2026-08-11 timeout came from (irreducible from a pre-#1294
line — that is the thing #1294 fixed); the exact image memex-cloud was running at 05:46Z, beyond
the fact that it could not have contained #1294; and the subtree size of KmuBasics/Buchungsjournal, which is the single strongest discriminator between the two
mechanisms above and is one query away on the live portal.
A third candidate — #1446/#1454 — and it is the first REACHABLE one. It still does not close this, and I can now show why with line numbers.
Retitled. The 2026-08-11 occurrence is not attributable and never will be (pre-#1294 line ⇒ stage irreducible; that is exactly what #1294 fixed). What is attributable is the structure that produces the signature, which is live, source-documented, and now has a second, sharper defect in it. The title names that instead of the stale report.
Where the previous two candidates stand
Unchanged from my comment above: #1364 is not reachable on the delete path (no stage posts a GetDataRequest; read-root and collect-paths go direct to storage, pre-validate-descendants posts ValidateDeleteRequest, and the per-path cache hydrates over SubscribeRequest). #1367 is reachable but the wrong shape (a poisoned _queries entry replays a latched OnErrorinstantly; Observable.Timeout fires on silence, not on error, and the only producer of the bare message System.TimeoutException: The operation has timed out. is Rx's .Timeout). Closing this as fixed-by-those would record a false cause.
Candidate 3 — #1446 / PR #1454 — reachable, right shape, and it did not exist when this was filed
This one lands where the other two did not:
Reachable.RlsNodeValidator.SupportedOperations includes NodeOperation.Delete (src/MeshWeaver.Graph/Security/RlsNodeValidator.cs:55), and fix: a permission check that could not be ESTABLISHED answers so, instead of blocking the create #1454 explicitly carries the new outcome through to NodeDeletionRejectionReason.Unavailable. The delete hits it at validate-root and again at every descendant, since HandleValidateDeleteRequest runs the same validators.
So the mechanism I named as unfixed #1 above — "pre-validate-descendants pays a per-descendant permission-query cold start under ONE budget" — now has a real, merged fix for its starved variant.
🚨 But the ordering #1454 depends on does not hold on the delete path
Default 30 s: comfortably above any healthy cold fold, and strictly below the 60 s hub RequestTimeout — which is the point, since a request killed by its caller reports the wrong thing.
That is true for CreateNodeRequest, whose enclosing bound is the hub's 60 s RequestTimeout. On the delete path the enclosing bound is not 60 s. It is MeshOperationOptions.Timeout, default 30 s (src/MeshWeaver.Mesh.Contract/Services/MeshOperationOptions.cs:14) — and it appears at three nested levels at the same value:
30 = 30 = 30. The outer bound fires at or before the inner one, so a starved permission read during a recursive delete still surfaces as the anonymous TimeoutException this issue is named after, never as the Unavailable#1454 introduced. The fix is correct and lands for creates; on deletes its answer can never win the race.
To be explicit, since this repo's rule on the point is absolute: the fix is not "raise the outer bound." That would be pure headroom. The defect is that three independent budgets are set to one number with no ordering between them, so the innermost — the only one that knows what starved — is the one that cannot report. Whatever shape the fix takes, it has to make the specific answer beat the generic one.
The other mechanism is still live, and the source says so
MeshExtensions.cs:3049-3053, citing this issue by number:
🚨 Who has NOT answered yet. This fan-out waits for EVERY descendant under ONE timeout, so a single unresponsive per-node hub times out the whole delete with the subtree untouched — and the operator's only evidence used to be an anonymous "[DeleteNode] timeout … partial-deleted=0" (issue #1198).
And unfixed mechanism #2 from my previous comment is untouched: commit fans N leaf deletes over a pg:{adapter} pool capped at 1, so Observable.Merge's parallelism collapses to one serialised connection, again under a single 30 s budget. That is the mechanical form of the original triage's "database latency spike" guess.
Disposition
Stays open, retitled to the residual. Explicitly not closed as fixed-by-#1364/#1367 (false cause), not closed as fixed-by-#1454 (reachable and right-shaped, but demonstrably cannot change the reported outcome here), and not closed as unreproducible (post-fix silence carries no signal — the pre-fix window recorded zero recurrences too, and the portals self-update on a 6 h poll).
What the issue is now a spec for, in the order I would take them:
Give the three nested budgets an ordering so the innermost, most specific answer (Unavailable, naming the starved read) reaches the caller instead of the outermost generic timeout.
The commit stage's N-deletes-over-a-cap-1-pool shape.
Still not established, and one query away on a live portal: the subtree size of KmuBasics/Buchungsjournal, which is the strongest discriminator between (2) and (3).
changed the title [-]DeleteNode times out on mesh node with zero partial progress[/-][+]A recursive delete waits for every descendant under ONE budget, and the nested permission budget equals rather than nests inside it[/+]on Aug 13, 2026
2026-09-06 11:40:47Z memex-portal-deployment-5b9cbf46dd-n67tt fail: MeshWeaver.Mesh.MeshNode[0]
[DeleteNode] timeout path=OpenStreetMap/Gallery/_Access/Public_Access stage=commit partial-deleted=0 unanswered=-
System.TimeoutException: [DeleteNode:commit] the bottom-up delete of 'OpenStreetMap/Gallery/_Access/Public_Access' did not drain within 30s — 0 of 1 planned path(s) were already removed from storage
2026-09-10 13:39:00Z memex-portal-deployment-7456f8f447-ctqhw fail: MeshWeaver.Mesh.MeshNode[0]
[DeleteNode] timeout path=sglauser/AgenticBusiness stage=pre-validate-descendants partial-deleted=0 unanswered=sglauser/AgenticBusiness/01-MeetYourCoworker/AskAdvisor, sglauser/AgenticBusiness/01-MeetYourCoworker/Exercise/FirstBriefChat, sglauser/AgenticBusiness/02-WishForATool/Exercise/DesignASkillChat, sglauser/AgenticBusiness/02-WishForATool/Exercise/ToolWishChat, sglauser/AgenticBusiness/02-WishForATool/Exercise/WishAgainChat, sglauser/AgenticBusiness/03-DataAndTheHandbook/Exercise/BuildYourAppChat, sglauser/AgenticBusiness/03-DataAndTheHandbook/Exercise/FeedTheHandbookChat
System.TimeoutException: [DeleteNode:pre-validate-descendants] 7 of 83 descendant(s) of 'sglauser/AgenticBusiness' did not answer ValidateDeleteRequest within 30s, so the delete was refused with the subtree untouched: sglauser/AgenticBusiness/01-MeetYourCoworker/AskAdvisor, sglauser/AgenticBusiness/01-MeetYourCoworker/Exercise/FirstBriefChat, sglauser/AgenticBusiness/02-WishForATool/Exercise/DesignASkillChat, sglauser/AgenticBusiness/02-WishForATool/Exercise/ToolWishChat, sglauser/AgenticBusiness/02-WishForATool/Exercise/WishAgainChat, sglauser/AgenticBusiness/03-DataAndTheHandbook/Exercise/BuildYourAppChat, sglauser/AgenticBusiness/03-DataAndTheHandbook/Exercise/FeedTheHandbookChat
2026-09-14 08:45:38Z memex-portal-deployment-7fd9668b69-4qtkx fail: MeshWeaver.Mesh.MeshNode[0]
[DeleteNode] timeout path=Hosting/TriageStatus stage=commit partial-deleted=3 unanswered=-
System.TimeoutException: [DeleteNode:commit] the bottom-up delete of 'Hosting/TriageStatus' made no progress for 30s — 3 path(s) removed from storage so far
2026-09-14 — re-measured against today's occurrence. Two of the three spec items have landed; a FOURTH one, not in the spec, was the thing actually firing today — and it is now fixed (#4316).
The 09-14 reopen carries the newest occurrence, and it is the one worth reading:
2026-09-14 08:45:38Z [DeleteNode] timeout path=Hosting/TriageStatus stage=commit
partial-deleted=3 unanswered=-
System.TimeoutException: [DeleteNode:commit] the bottom-up delete of 'Hosting/TriageStatus'
made no progress for 30s — 3 path(s) removed from storage so far
Where the three-item spec actually stands
#
spec item
state on today's main
1
"Give the three nested budgets an ordering so the innermost, most specific answer reaches the caller"
LANDED — 05c51adb19 / PR #1457, "the innermost delete bound can now actually fire". RowLevelSecurityOptions was deleted; MeshOperationOptions now has ONE configured value and derives every rung by Nest: Timeout 30 s → NestedTimeout 25 s (:107) → PermissionEstablishmentBudget 20 s (:130). The 30 = 30 = 30 coincidence this thread measured is gone.
2
"Per-leaf reporting for the fan-out" — diagnostic half
LANDED (#1294) and verified in production: the 2026-09-10 occurrence reads stage=pre-validate-descendants … unanswered=sglauser/AgenticBusiness/01-MeetYourCoworker/AskAdvisor, … — 7 of 83 named.
2
behavioural half — one unresponsive descendant should not consume the whole subtree's budget
still unbuilt. PreValidateDescendantsObs is Observable.Merge(perPath) … .TimeoutAtStage(timeout, …): one bound over the whole fan-out.
3
the commit stage's N-deletes-over-a-cap-1 pg:{adapter} pool
untouched.
The thing that was actually firing is a fourth item the spec never named
unanswered= exists on the shared line so an operator learns WHICH node stopped the operation. Only the pre-flight stage ever filled it. So a stage=commit timeout rendered unanswered=- — and - is the same rendering the line uses for "there is nothing outstanding".
That is worse than an absent field. It did not abstain; it asserted the opposite of the truth: three paths were removed, the drain was stuck on the rest of the subtree, and the report said it owed nothing. Beside it, a count — which identifies what SUCCEEDED and therefore identifies nothing about the failure. An operator reading that line has no path to go and look at.
Both halves of the answer were already live in that closure: the plan (collected.ToDelete) and the progress (SnapshotProgress()). The difference is the answer, and it costs one set operation on a path that has already failed. #4316 makes the commit stage report:
[DeleteNode:commit] the bottom-up delete of 'Hosting/TriageStatus' made no progress for 30s —
3 of 9 planned path(s) removed from storage so far; still owed by the plan:
Hosting/TriageStatus, …
and fill DeleteUnansweredDataKey, so the shared [DeleteNode] timeout line prints those paths instead of -.
Two deliberate details: it says "still owed by the plan", never "remaining" — a drain can remove MORE than it planned (#3392), so the set is what the plan still owes and is never a claim about what else storage holds; and the progress COUNT stays, because reporting real progress rather than 0 is the half of this issue that landed earlier and names are ADDED, not traded.
Repro, both directions
DeleteCommitTimeoutNamesWhatIsStuckTest (MeshWeaver.Graph.Test): a real IStorageAdapter over a real InMemoryStorageAdapter that serves two deletes under the root and then never answers — the store took the call and went silent, which is the state the no-progress watchdog exists for. Nothing is widened or raced; the watchdog's own budget ends the wait and the assertion is about what it SAYS.
With the production edit reverted and the test project rebuilt, the message is the production shape verbatim: made no progress for 3s — 0 path(s) removed from storage so far, with no names. The test also carries a negative control — the two paths the store DID remove must not appear in the owed set, so "the plan echoed back under a new label" fails.
Disposition — stays OPEN, narrowed to two items
Not closed: spec items 2 (behavioural half) and 3 are untouched, and both are real. What is closed is the part that made today's occurrence unreadable.
Read-only for the measurements; git log -S / grep on origin/main in a worktree; the suite run locally on a -c Release -warnaserror build (MeshWeaver.Graph.Test 1610/1610).
2026-09-15 — item 2's behavioural half is built (#4363). Item 3 is MEASURED, the hypothesis as written is FALSIFIED, and what is left is a different mechanism. Stays open.
Item 2, behavioural half — built
PreValidateDescendantsObs bounded the whole Observable.Merge with ONE timeout and capped nothing. Each leg now carries its own bound, derived with MeshOperationOptions.Nest at the call site — never a second configured constant, because equal budgets are not an ordering and that is what this issue is named after. A leg that lapses reports itself, by name, as Unavailable: a hub that never spoke decided nothing, and IMeshService.DeleteNode maps Unavailable and ValidationFailed to different exception types, so the distinction reaches the caller rather than sending a correctly-entitled user to ask for permissions they already hold (#1446).
Two consequences that had to be handled rather than papered over:
HandleValidateDeleteRequest moved one rung deeper (Nest(NestedTimeout)). At the leg's own value its clock starts one post, one route and one activation later, so it could never fire first — the caller's new per-leg bound would have preempted the leaf's specific answer every time. That is item 1's defect recreated one level out. It now shares a rung with the permission fold, which is correct: the read completes before the validator chain starts, so they are SIBLINGS, not nested. No configured value changed; the production rungs are still 30 / 25 / 20.
The fan-out is capped. A bare Merge subscribes every leg at once and each post can ACTIVATE a per-node hub — an unbounded activation burst on a subtree of any size. It cannot strand the fan-out (every leg terminates on its own budget), but it does make outstanding, posted and planned three different numbers, so the stage backstop reports all three and unanswered is filled on post, not seeded from the plan. Claiming a leaf "did not answer" a request that was never sent is the same class of untruth as the unanswered=- fixed in fix: a teardown report and a stalled delete name what they tell you to find (#3712, #1198) #4316.
Regression: DeletePreflightNamesTheSilentDescendantTest — a real Monolith mesh whose middle descendant carries a deletion validator that never emits (the hub took the request and went silent, which is the shape a starved read produces and the only one Observable.Timeout reports). Reverted against mainwith the test project rebuilt, it fails exactly as production did: the stage backstop, at the full budget, 1 of 3 descendant(s) … did not answer ValidateDeleteRequest within 10s, [DeleteNode] timeout … stage=pre-validate-descendants partial-deleted=0. With the fix it passes in one leg budget, naming the one silent path.
Item 3 — the hypothesis as written is FALSIFIED
"the commit stage's N-deletes-over-a-cap-1 pg:{adapter} pool"
Since #3392 the commit bound is an inter-emission no-progress watchdog, not a duration cap: the fan-out publishes a tick per removed path and every tick resets the clock. Serializing the drain's own N writes therefore cannot time it out. The 2026-08-13 comment's mechanism #2 — "Observable.Merge parallelism collapses to one serialised connection, again under one 30 s budget" — depends on a total-duration cap that no longer exists. The measurement comes back negative.
What IS measurable, and is a different mechanism
Measured 2026-09-15 against MeshWeaver.Plugins (read-only; grep over src/):
PostgreSqlPartitionStorageProvider resolves one write pool and one read pool, both named from the PROVIDER — _ioPool = registry.Get($"{PostgresAdapterPrefix}{Name}"), _readPool = registry.Get($"{PostgresReadAdapterPrefix}{Name}"), with Name => "Postgres".
PostgreSqlPathRoutingAdapter.GetOrCreateAdapter hands every per-schema adapter that same WritePool, that same ReadPool and the same BaseDataSource.
So the cap-1 gate is one process-wide write serializer, not one per partition. A delete's next leaf removal therefore queues behind unrelated writes from every other partition — and those do not tick this delete's progress. A portal under sustained write load can starve one drain for a whole budget with zero removals, which is the made no progress for 30s shape logged on 2026-09-14 for Hosting/TriageStatus. Whether that is what happened is not decidable from the line, and I am not going to attribute it from one occurrence — that is the mistake this thread already made twice.
Why it is not fixed here
Raising the cap is the band-aid this repo forbids. Doc/Architecture/ControlledIoPooling states the real rationale and it is not "the gate is the connection": the caps are a connection budget — 16 reads + 1 write, aggregate, under the shared NpgsqlDataSource's MaxPoolSize=50. There is headroom, but no measurement that says what to spend it on. The instrument that would decide it — the queue-wait distribution on pg:Postgres under portal load — is not built, and the code is in MeshWeaver.Plugins, not core.
🚨 Why this item sat unmeasured for a month
IoPoolNames.PostgresAdapterPrefix and the AsynchronousCalls table row asserted "the gate IS the connection… the single Npgsql connection that adapter holds (MaxPoolSize=1)". That design was deliberately removed — CreateAdapterForTable's own comment says minting a data source per (schema, table) leaked a pool per hub and exhausted the server, "One shared pool per silo instead." Two core docs contradicted a third, and the one a reader lands on made a live question look settled. #4363 corrects both, in four places, so the next reader sees an open question with its denominator rather than a closed one.
Doc/Architecture/PartitionStorageHubs carries the same removed premise in three more places. I have not verified that layer and did not edit it on a guess — noting it here so it is not lost.
Disposition
Stays open, narrowed to one item: the commit stage's writes serialize process-wide, and the number 1 has no measurement behind it. Item 2 closes with #4363. The next occurrence of stage=commit … made no progress is still the decidable evidence — and now, so is anything that measures the pg:Postgres queue.
Read-only for the Plugins measurements (grep on a local checkout). The core change is built and tested locally on a -c Release -warnaserror build: MeshWeaver.Graph.Test 1632/1632, MeshWeaver.Documentation.Test 469/469.
The instrument this issue's last comment said was missing is now built: #4460.
"the commit stage's writes serialize process-wide, and the number 1 has no measurement behind it … The instrument that would decide it — the queue-wait distribution on pg:Postgres under portal load — is not built."
IIoPool.QueueWait now reports how long granted work WAITED for a slot: total, max, and six buckets (<1 ms, <10 ms, <100 ms, <1 s, <10 s, >=10 s). A distribution rather than a mean, for the reason this issue is named after — a pool whose mean wait is a millisecond can still be starving one caller for a whole budget, and the mean is the statistic that hides it.
It is complete across admission paths by construction: the three async-gate sites and the blocking path, which never touches _gate and is therefore timed at the limited-concurrency scheduler's own grant point. A cancelled wait records nothing — it never became an admission, and folding it in would blend "how long work waited to run" with "how long a teardown took to unwind". And it costs no allocation per admission: the first shape wrapped the gate wait in an async helper, which allocates a Task on the busiest path in the system, so it is inlined instead.
What this does and does not settle. It does not decide the cap — that still needs a reading taken on a portal under real write load, which is where pg:Postgres actually queues. It removes the reason the item sat unmeasured: the number can now be looked at rather than argued about, and a decision to spend the headroom (16 reads + 1 write against MaxPoolSize=50) has something to point at.
Item 2 remains closed on #4363. This issue stays open on the same one item until a reading exists.
Folded in — a DIFFERENT fingerprint from the same log site.
This issue tracks the log site a8d7b0457bb403c8 (MeshWeaver.Mesh.MeshNode), and these occurrences belong to it. They carry their own fingerprint — the masking split one site across several — so before this they would have opened a SEPARATE ticket. One log site fanned out into 46 of those, which is why they fold here instead. Nothing is discarded: the distinguishing evidence is below, and splitting this back out is a person's call.
Folded fingerprint
f3d0300939687f61
Log site
a8d7b0457bb403c8
Category
MeshWeaver.Mesh.MeshNode
Severity
Error
Exception
System.TimeoutException
Detail
[DeleteNode:commit] the bottom-up delete of '{value}' made no progress for {n}s — {n} of {n} planned path(s) removed from storage so far; still owed by the plan: {path} At the timeout: {path} pools with work queued at that moment: pg:Postgres(cap {n}) {n} waiting, {n} in flight ({n} async at {n} free permit(s): {n} behind the exhausted cap), {n} admission(s) waited >= {n} s during this stage, longest wait on this pool ever {n} ms; FileSystem(cap {n}) {n} waiting, {n} in flight ({n} async at {n} free permit(s): {n} waiting for a THREAD, not for this cap [{n} before the gate, {n} granted and not yet resumed]), {n} admission(s) waited >= {n} s during this stage, longest wait on this pool ever {n} ms. ThreadPool at that moment: {n} thread(s), {n} work item(s) queued
Namespace
memex
Pods
memex-portal-deployment-cfb58787b-b6klj
Occurrences
1
First seen
2026-10-09 13:38:58Z
Last seen
2026-10-09 13:38:58Z
Already folded here
8 fingerprint(s)
Incident
Admin/_LogIncident/f3d0300939687f61
What triage wrote about this fingerprint
What is failing
Node deletes in the mesh never reach storage: the [DeleteNode:commit] stage for Marketing/EventHub/_Activity/compile-20260917170729615… removed 0 of 1 planned paths in 25s and timed out. In the same instant on the same pod, a burst of ~200 sibling delete timeouts of the same shape occurred (see below), so an entire bulk-delete pass of stale compile-* activity nodes failed wholesale.
Probable cause
High confidence the commit stage is starved behind the pg:Postgres I/O pool, not blocked by the delete itself. The diagnostic snapshot embedded in the exception is explicit: pg:Postgres(cap 1) 211 waiting, 1 in flight, 211 behind the exhausted cap, 1326 admission(s) waited >= 1 s during this stage, longest wait ever 24690 ms. The pool's admission capacity is 1, yet hundreds of concurrent deletes queue against it; each delete's first storage write can sit behind the whole queue and exceed the 25s no-progress timeout. The plan itself is trivial (1 path, a leaf compile-activity node), ruling out a pathological subtree. The ThreadPool (18 threads, 17 queued) and the FileSystem pool are not the constraint here; the cap-1 Postgres semaphore is. What launched ~200 concurrent deletes at once (likely an automated cleanup of stale compile-* activity nodes in the Marketing space) is the trigger; the cap-1 pool is the defect.
Impact
One pod (memex-portal-deployment-cfb58787b-b6klj), one burst at 2026-10-09T13:38:58Z. This fingerprint counts 1 occurrence, but sibling incidents from the same second (below) show ~197 deletes failing together, plus 1 delete of the Marketing root aborted with partial-deleted=1383 — meaning the bulk operation was interrupted mid-flight and up to ~1,400 nodes may be in an indeterminate partial-delete state. Deletes are retryable, but the transient exhaustion of a shared cap-1 Postgres pool slows every concurrent tenant on the pod whenever it recurs (longest-ever wait ≈ 24.7s matches this stage).
Where to look
Log category MeshWeaver.Mesh.MeshNode, the [DeleteNode]/[DeleteNode:commit] timeout and no-progress path — the code that builds the diagnostic snapshot naming the pools (pg:Postgres, pg-read:Postgres, FileSystem) is the admission/throttling layer for storage writes.
The pg:Postgres I/O pool configuration: why its admission cap is 1 and whether the delete path bypasses or shares the same gate as all other Postgres work.
The caller that enqueues bulk deletes of stale compile-* nodes (samples live under Marketing/*/_Activity/compile-*) — it should pace its deletes or use a batch delete that holds the permit once.
Related incidents (same second, same pod, same evidence)
Admin/_LogIncident/afc2a08c4f9ce905 — 195 occurrences of the same [DeleteNode:commit] timeout (bulk Marketing/Campaign/_Activity/compile-* deletes)
Admin/_LogIncident/8178a08b09190bba — same timeout, Marketing/_Activity/0490f133, shows pg-read:Postgres also waiting on a thread
Admin/_LogIncident/3250ed6f31f0eff1 — the resulting Delete failed for 'Marketing/_Activity/dacd7d46' with partial-deleted=1383
These are almost certainly one underlying defect (cap-1 Postgres pool + un-paced bulk delete); if the platform files them separately they can be consolidated into one issue.
Reopened — this fault is happening again.
Still occurring: 1 more since the last update (1 total).
Last seen: 2026-10-09 13:38:58Z
Pods: memex-portal-deployment-cfb58787b-b6klj
Recent log lines
2026-10-09 13:38:58Z memex-portal-deployment-cfb58787b-b6klj fail: MeshWeaver.Mesh.MeshNode[0]
[DeleteNode] timeout path=Marketing/EventHub/_Activity/compile-202609171707296151a21d651b5384b538dd922bd411401c2 stage=commit partial-deleted=0 unanswered=Marketing/EventHub/_Activity/compile-202609171707296151a21d651b5384b538dd922bd411401c2
System.TimeoutException: [DeleteNode:commit] the bottom-up delete of 'Marketing/EventHub/_Activity/compile-202609171707296151a21d651b5384b538dd922bd411401c2' made no progress for 25s — 0 of 1 planned path(s) removed from storage so far; still owed by the plan: Marketing/EventHub/_Activity/compile-202609171707296151a21d651b5384b538dd922bd411401c2. At the timeout: I/O pools with work queued at that moment: pg:Postgres(cap 1) 211 waiting, 1 in flight (211 async at 0 free permit(s): 211 behind the exhausted cap), 1326 admission(s) waited >= 1 s during this stage, longest wait on this pool ever 24690.56 ms; FileSystem(cap 256) 1 waiting, 0 in flight (1 async at 255 free permit(s): 1 waiting for a THREAD, not for this cap [0 before the gate, 1 granted and not yet resumed]), 0 admission(s) waited >= 1 s during this stage, longest wait on this pool ever 1280.278 ms. ThreadPool at that moment: 18 thread(s), 17 work item(s) queued
Folded in — a DIFFERENT fingerprint from the same log site.
This issue tracks the log site a8d7b0457bb403c8 (MeshWeaver.Mesh.MeshNode), and these occurrences belong to it. They carry their own fingerprint — the masking split one site across several — so before this they would have opened a SEPARATE ticket. One log site fanned out into 46 of those, which is why they fold here instead. Nothing is discarded: the distinguishing evidence is below, and splitting this back out is a person's call.
Folded fingerprint
afc2a08c4f9ce905
Log site
a8d7b0457bb403c8
Category
MeshWeaver.Mesh.MeshNode
Severity
Error
Exception
System.TimeoutException
Detail
[DeleteNode:commit] the bottom-up delete of '{value}' made no progress for {n}s — {n} of {n} planned path(s) removed from storage so far; still owed by the plan: {path} At the timeout: {path} pools with work queued at that moment: pg:Postgres(cap {n}) {n} waiting, {n} in flight ({n} async at {n} free permit(s): {n} behind the exhausted cap), {n} admission(s) waited >= {n} s during this stage, longest wait on this pool ever {n} ms. ThreadPool at that moment: {n} thread(s), {n} work item(s) queued
Namespace
memex
Pods
memex-portal-deployment-cfb58787b-b6klj
Occurrences
195
First seen
2026-10-09 13:38:58Z
Last seen
2026-10-09 13:38:58Z
Already folded here
9 fingerprint(s)
Incident
Admin/_LogIncident/afc2a08c4f9ce905
Triage called it
Bulk single-node deletes starve on the cap-1 Postgres write pool and trip the 25s no-progress watchdog together
What triage wrote about this fingerprint
What is failing
DeleteNode's commit stage fails wholesale when many single-node deletes are issued at once. A cleanup sweep of stale compile-* activity-bookkeeping nodes under Marketing/Campaign/_Activity ran as a concurrent fan-out, and every delete's storage write sat queued on the process-wide cap-1 pg:Postgres write pool until its 25-second no-progress watchdog fired — 0 of 1 planned path(s) removed, nothing partially deleted. This is not a storage fault: the delete's own diagnostic names the queue (pg:Postgres at cap 1 with a deep waiting queue, zero free permits, over a thousand admissions waiting ≥1s during the stage), and the ThreadPool is healthy. It is precisely the "waiting in line" congestion shape the 2026-09-16 stall diagnostic (Doc/WhatsNew/2026-09-16-a-delete-that-stalls-now-says-whether-it-was-stuck-or-just-waiting-in-line) was built to distinguish from a stuck storage call.
Probable cause
High confidence. Per Doc/Architecture/ControlledIoPooling, every Postgres write is one leaf on the shared pg:{provider} pool, capped at 1 process-wide. A bulk sweep of ~200 single-node deletes issues ~200 simultaneous claimants of that one permit. Each delete's watchdog measures its own progress — 0 of 1 planned paths removed — not the pool's, so the whole batch times out together while the queue is merely draining serially. Two contributing defects:
The bulk delete path has no admission control against the cap-1 shared write gate — it fans out concurrently instead of bounding its outstanding writes.
The commit-stage watchdog treats "queued behind sibling deletes" as "no progress", so a healthy serial drain reads as a stall in every delete at once.
Impact
One namespace, one pod, one burst. A bulk cleanup operation fails outright (deletes reported as failed, the stale nodes remain), user-visible to whoever issued it. Normal single deletes are unaffected — the measured write-pool queue-wait is single-digit milliseconds under normal load. No data loss: nothing was partially removed.
Where to look
MeshWeaver.Mesh.MeshNode — the DeleteNode commit-stage watchdog ("made no progress for 25s") and how bulk deletes are admitted.
The cap-1 write gate and its queue ledger: IoPoolOptions.MaxConcurrencyFor / IoPoolNames.PostgresAdapterPrefix in Controlled I/O Pooling — that page also carries the queue-wait baseline showing the write pool normally never queues, which is what makes this burst anomalous.
The bulk delete caller sweeping _Activity/compile-* nodes — it should bound its concurrent outstanding deletes against the shared write pool, or drain them serially as the recursive-delete drain does.
Related same-site incident (older, different namespace and much smaller, not a duplicate): Admin/_LogIncident/54544acf7013f034.
Still occurring: 195 more since the last update (195 total).
Last seen: 2026-10-09 13:38:58Z
Pods: memex-portal-deployment-cfb58787b-b6klj
Recent log lines
2026-10-09 13:38:58Z memex-portal-deployment-cfb58787b-b6klj fail: MeshWeaver.Mesh.MeshNode[0]
[DeleteNode] timeout path=Marketing/Campaign/_Activity/compile-20260924100722512ba65bd9793a24328b444d37de13ccf93 stage=commit partial-deleted=0 unanswered=Marketing/Campaign/_Activity/compile-20260924100722512ba65bd9793a24328b444d37de13ccf93
System.TimeoutException: [DeleteNode:commit] the bottom-up delete of 'Marketing/Campaign/_Activity/compile-20260924100722512ba65bd9793a24328b444d37de13ccf93' made no progress for 25s — 0 of 1 planned path(s) removed from storage so far; still owed by the plan: Marketing/Campaign/_Activity/compile-20260924100722512ba65bd9793a24328b444d37de13ccf93. At the timeout: I/O pools with work queued at that moment: pg:Postgres(cap 1) 30 waiting, 1 in flight (30 async at 0 free permit(s): 30 behind the exhausted cap), 1326 admission(s) waited >= 1 s during this stage, longest wait on this pool ever 24690.56 ms. ThreadPool at that moment: 18 thread(s), 3 work item(s) queued
2026-10-09 13:38:58Z memex-portal-deployment-cfb58787b-b6klj fail: MeshWeaver.Mesh.MeshNode[0]
[DeleteNode] timeout path=Marketing/Campaign/_Activity/compile-20260908202858813745ff128b5824dd4834ac7af371c2ac9 stage=commit partial-deleted=0 unanswered=Marketing/Campaign/_Activity/compile-20260908202858813745ff128b5824dd4834ac7af371c2ac9
System.TimeoutException: [DeleteNode:commit] the bottom-up delete of 'Marketing/Campaign/_Activity/compile-20260908202858813745ff128b5824dd4834ac7af371c2ac9' made no progress for 25s — 0 of 1 planned path(s) removed from storage so far; still owed by the plan: Marketing/Campaign/_Activity/compile-20260908202858813745ff128b5824dd4834ac7af371c2ac9. At the timeout: I/O pools with work queued at that moment: pg:Postgres(cap 1) 30 waiting, 1 in flight (30 async at 0 free permit(s): 30 behind the exhausted cap), 1326 admission(s) waited >= 1 s during this stage, longest wait on this pool ever 24690.56 ms. ThreadPool at that moment: 18 thread(s), 3 work item(s) queued
2026-10-09 13:38:58Z memex-portal-deployment-cfb58787b-b6klj fail: MeshWeaver.Mesh.MeshNode[0]
[DeleteNode] timeout path=Marketing/Campaign/_Activity/compile-202609170739501376e90cbdeaec644e59d6c205b474d2c4a stage=commit partial-deleted=0 unanswered=Marketing/Campaign/_Activity/compile-202609170739501376e90cbdeaec644e59d6c205b474d2c4a
System.TimeoutException: [DeleteNode:commit] the bottom-up delete of 'Marketing/Campaign/_Activity/compile-202609170739501376e90cbdeaec644e59d6c205b474d2c4a' made no progress for 25s — 0 of 1 planned path(s) removed from storage so far; still owed by the plan: Marketing/Campaign/_Activity/compile-202609170739501376e90cbdeaec644e59d6c205b474d2c4a. At the timeout: I/O pools with work queued at that moment: pg:Postgres(cap 1) 30 waiting, 1 in flight (30 async at 0 free permit(s): 30 behind the exhausted cap), 1326 admission(s) waited >= 1 s during this stage, longest wait on this pool ever 24690.56 ms. ThreadPool at that moment: 18 thread(s), 2 work item(s) queued
Folded in — a DIFFERENT fingerprint from the same log site.
This issue tracks the log site a8d7b0457bb403c8 (MeshWeaver.Mesh.MeshNode), and these occurrences belong to it. They carry their own fingerprint — the masking split one site across several — so before this they would have opened a SEPARATE ticket. One log site fanned out into 46 of those, which is why they fold here instead. Nothing is discarded: the distinguishing evidence is below, and splitting this back out is a person's call.
Folded fingerprint
8178a08b09190bba
Log site
a8d7b0457bb403c8
Category
MeshWeaver.Mesh.MeshNode
Severity
Error
Exception
System.TimeoutException
Detail
[DeleteNode:commit] the bottom-up delete of '{value}' made no progress for {n}s — {n} of {n} planned path(s) removed from storage so far; still owed by the plan: {path} At the timeout: {path} pools with work queued at that moment: pg:Postgres(cap {n}) {n} waiting, {n} in flight ({n} async at {n} free permit(s): {n} behind the exhausted cap), {n} admission(s) waited >= {n} s during this stage, longest wait on this pool ever {n} ms; pg-read:Postgres(cap {n}) {n} waiting, {n} in flight ({n} async at {n} free permit(s): {n} waiting for a THREAD, not for this cap [{n} before the gate, {n} granted and not yet resumed]), {n} admission(s) waited >= {n} s during this stage, longest wait on this pool ever {n} ms. ThreadPool at that moment: {n} thread(s), {n} work item(s) queued
Namespace
memex
Pods
memex-portal-deployment-cfb58787b-b6klj
Occurrences
1
First seen
2026-10-09 13:38:58Z
Last seen
2026-10-09 13:38:58Z
Already folded here
10 fingerprint(s)
Incident
Admin/_LogIncident/8178a08b09190bba
Triage called it
Postgres write pool capped at 1 permit starves DeleteNode commit — a single write can't get a slot within its 25s budget
What triage wrote about this fingerprint
What is failing
A single-node delete (of Marketing/_Activity/0490f133 in memex) reached its commit stage, made no progress for its full 25s no-progress budget, and removed 0 of 1 planned paths — the target node is still in storage and the delete failed user-visibly. The delete logic itself is not the problem: its one write never got a turn on the Postgres write pool.
Probable cause — high confidence in the mechanism, unclear why it is happening now
The write pool pg:Postgres is configured with capacity 1. At the moment of the timeout 211 callers were queued behind the single in-flight operation (0 free permits), 1326 admissions had waited ≥1s during that stage alone, and the pool's longest-ever wait is ~24.7s. A cap-1 pool has zero parallelism, so any burst of write work queues hundreds deep and a single write — this delete's commit — cannot land within its budget.
What is not clear is why this pool queues at all now: the 14-hour live-portal measurement behind A delete that stalls now says whether it was stuck or just waiting in line concluded the write pool never made anything wait more than ~0.2s, and no tuning was done on the strength of it. Either the write workload changed (a burst writer — e.g. an import) or a post-2026-09-16 regression increased write volume or hold time. Reconciling that measurement with this sample is the first investigation step.
Secondary signal, plausibly downstream: at the same moment the pod's ThreadPool had 18 threads with 16 work items queued, and the one read-pool (pg-read, cap 16) waiter was waiting for a thread, not a pool permit — mild thread-pool starvation consistent with the write backlog.
Impact
One occurrence on one pod so far — judged from the numbers this is not an outage. The failed delete removed nothing, so it is safe to retry (the partial-delete accounting from A delete that times out now says what it was waiting for makes "removed nothing" trustworthy). The wider exposure is pool-level: while the write pool was backed up, every write on that pod queued behind it, so other operations in the same window were degraded even where they didn't hit their own timeouts. If the backlog proves persistent rather than a one-off burst, the impact moves from "a delete fails occasionally" to "all writes on the pod crawl" — worth a human re-rule then.
Where to look
The DeleteNode commit stage in the MeshWeaver.Mesh.MeshNode handler (the failing log category) — confirm the commit takes a single write-pool admission and has no reserved slot that would let small deletes jump a burst queue.
The Postgres I/O pool configuration where pg:Postgres gets capacity 1 while pg-read:Postgres gets 16 — the cap and its admission/wait counters are the central question; the 2026-09-16 doc's decision not to tune this number is the premise this incident now challenges.
The queue-watch instrumentation added 2026-09-16 is what makes this diagnosable — pull its per-pool counters for this window and compare against that doc's baseline to identify what changed.
Still occurring: 1 more since the last update (1 total).
Last seen: 2026-10-09 13:38:58Z
Pods: memex-portal-deployment-cfb58787b-b6klj
Recent log lines
2026-10-09 13:38:58Z memex-portal-deployment-cfb58787b-b6klj fail: MeshWeaver.Mesh.MeshNode[0]
[DeleteNode] timeout path=Marketing/_Activity/0490f133 stage=commit partial-deleted=0 unanswered=Marketing/_Activity/0490f133
System.TimeoutException: [DeleteNode:commit] the bottom-up delete of 'Marketing/_Activity/0490f133' made no progress for 25s — 0 of 1 planned path(s) removed from storage so far; still owed by the plan: Marketing/_Activity/0490f133. At the timeout: I/O pools with work queued at that moment: pg:Postgres(cap 1) 211 waiting, 1 in flight (211 async at 0 free permit(s): 211 behind the exhausted cap), 1326 admission(s) waited >= 1 s during this stage, longest wait on this pool ever 24690.56 ms; pg-read:Postgres(cap 16) 1 waiting, 0 in flight (1 async at 16 free permit(s): 1 waiting for a THREAD, not for this cap [1 before the gate, 0 granted and not yet resumed]), 0 admission(s) waited >= 1 s during this stage, longest wait on this pool ever 6228.772 ms. ThreadPool at that moment: 18 thread(s), 16 work item(s) queued
Folded in — a DIFFERENT fingerprint from the same log site.
This issue tracks the log site a8d7b0457bb403c8 (MeshWeaver.Mesh.MeshNode), and these occurrences belong to it. They carry their own fingerprint — the masking split one site across several — so before this they would have opened a SEPARATE ticket. One log site fanned out into 46 of those, which is why they fold here instead. Nothing is discarded: the distinguishing evidence is below, and splitting this back out is a person's call.
Folded fingerprint
d1833dd0f0d9fb2c
Log site
a8d7b0457bb403c8
Category
MeshWeaver.Mesh.MeshNode
Severity
Error
Exception
System.TimeoutException
Detail
[DeleteNode:commit] the bottom-up delete of '{value}' made no progress for {n}s — {n} of {n} planned path(s) removed from storage so far; still owed by the plan: {path} At the timeout: {path} pools with work queued at that moment: pg:Postgres(cap {n}) {n} waiting, {n} in flight ({n} async at {n} free permit(s): {n} waiting for a THREAD, not for this cap [{n} before the gate, {n} granted and not yet resumed]; {n} behind the exhausted cap), {n} admission(s) waited >= {n} s during this stage, longest wait on this pool ever {n} ms. ThreadPool at that moment: {n} thread(s), {n} work item(s) queued
Namespace
memex
Pods
memex-portal-deployment-cfb58787b-b6klj
Occurrences
1
First seen
2026-10-09 14:24:07Z
Last seen
2026-10-09 14:24:07Z
Already folded here
11 fingerprint(s)
Incident
Admin/_LogIncident/d1833dd0f0d9fb2c
Triage called it
DeleteNode commit stage times out with zero progress: Postgres I/O pool admits one operation at a time and starves the delete
What triage wrote about this fingerprint
What is failing
DeleteNode for a single mesh node never reaches storage at its commit stage: the bottom-up delete times out after 25s with 0 of 1 planned paths removed, because the Postgres I/O pool (pg:Postgres) admits only one operation at a time and the delete's storage work never gets a turn. The node is left un-deleted (partial-deleted=0), so the caller's delete simply fails.
Probable cause (medium-high confidence on the mechanism, lower on why the cap is 1)
The pool snapshot inside the timeout message is explicit: at the moment of the timeout the pool ran at cap 1 with 633 waiting, 1 in flight — 632 of those behind the exhausted cap, only 1 waiting on a thread — and 1033 admissions waited ≥ 1s during this single stage, with the pool's longest-ever wait at 24,690 ms, i.e. the pool already sits at the timeout budget under load. ThreadPool pressure was mild (18 threads, 26 queued), which rules out thread starvation: the bottleneck is the per-pool admission cap of 1. Any bulk or background I/O traffic sharing that pool head-of-line-blocks a delete commit indefinitely. What needs deciding is whether cap 1 is a misconfiguration of the Postgres pool for this deployment or a by-design serial pool that the delete path should not be routed through.
Impact
One occurrence on one portal pod, on a delete of a test-activity node — the operation failed for one caller and is retriable. But the same cap starves everything else sharing the pool: 1033 admissions waited over a second during this one stage and the pool's record wait is ~25s, so any user-visible write under concurrent load is exposed to the same starvation. No duplicate incident found for this shape; the numerous existing TimeoutException incidents (Memory queue adapters, MessageHubGrain, thread exec) have different fingerprints and do not cover it.
Where to look
The MeshWeaver.Mesh.MeshNode delete path — specifically the commit stage that emits the [DeleteNode:commit] no-progress timeout — and the Postgres storage adapter's admission/permit logic (the pool reporting as pg:Postgres(cap 1) with the waiting/behind-cap/waiting-for-thread breakdown). The framework source is not indexed in the mesh, so no file links; the log site names to grep for are DeleteNode:commit and the pool admission dump (behind the exhausted cap, admission(s) waited).
Still occurring: 1 more since the last update (1 total).
Last seen: 2026-10-09 14:24:07Z
Pods: memex-portal-deployment-cfb58787b-b6klj
Recent log lines
2026-10-09 14:24:07Z memex-portal-deployment-cfb58787b-b6klj fail: MeshWeaver.Mesh.MeshNode[0]
[DeleteNode] timeout path=SocialMedia/SocialTests/_Activity/compile-202610031508055428a9fb3ebc4aa4519a9a8e19ea1e3f711 stage=commit partial-deleted=0 unanswered=SocialMedia/SocialTests/_Activity/compile-202610031508055428a9fb3ebc4aa4519a9a8e19ea1e3f711
System.TimeoutException: [DeleteNode:commit] the bottom-up delete of 'SocialMedia/SocialTests/_Activity/compile-202610031508055428a9fb3ebc4aa4519a9a8e19ea1e3f711' made no progress for 25s — 0 of 1 planned path(s) removed from storage so far; still owed by the plan: SocialMedia/SocialTests/_Activity/compile-202610031508055428a9fb3ebc4aa4519a9a8e19ea1e3f711. At the timeout: I/O pools with work queued at that moment: pg:Postgres(cap 1) 633 waiting, 1 in flight (633 async at 0 free permit(s): 1 waiting for a THREAD, not for this cap [1 before the gate, 0 granted and not yet resumed]; 632 behind the exhausted cap), 1033 admission(s) waited >= 1 s during this stage, longest wait on this pool ever 24690.56 ms. ThreadPool at that moment: 18 thread(s), 26 work item(s) queued
The 2026-10-09 reopen is the commit-stage stall, and this time its cause is measured. The fix is in #6357. Same burst as #6351, which carries the outer-wrapper log site.
On the control instance (…-cfb58787b-b6klj, ci.10310), the Marketing delete (13:38:58Z) and the SocialMedia delete (14:24:07Z) each failed on a leaf commit 0 of 1 planned. In the SocialMedia burst, 194 of those leaf timeouts landed within one second, all under SocialMedia/. The governed read is Ops/Actions/logs-sevM-a4315-20261009-q1.
So the 2026-09-16 exoneration of the write pool was right for that portal, but its "unrelated writes from other partitions" mechanism is not what happened here either. The commit posted every leaf at once through HierarchicalPathDeletion's unbounded nested Merge. Every leaf's write queued on the one cap-1 pg pool. Each leaf's own no-progress watchdog then counted its wait behind its siblings as a stall.
#6357 gives the commit one bounded admission lane for the whole tree (MeshOperationOptions.CascadeFanOutConcurrency, 64). It also stops a leaf's Unavailable from being reported as ValidationFailed / UnauthorizedAccessException. Doc/Architecture/RecursiveDeleteDrain carries the reading.
Stays open until an image carrying #6357 runs on memex and a bulk delete of that size completes with no [DeleteNode:commit] burst.
#6357 is merged as 78a670acfb (2026-10-09 17:47Z). The Plugins dependent-suite verdict was green on the third candidate: the first two lost their build runner mid-step.
This stays open until memex.systemorph.com runs an image carrying 78a670acfb and a bulk recursive delete of more than 1,000 paths completes with no [DeleteNode:commit] … 0 of 1 planned burst. memex currently runs 8b791643f1. This is host code, so no recycle is needed.
Still occurring: 6 more since the last update (7 total).
Last seen: 2026-10-09 14:24:07Z
Pods: memex-portal-deployment-cfb58787b-b6klj
Recent log lines
2026-10-09 14:24:07Z memex-portal-deployment-cfb58787b-b6klj fail: MeshWeaver.Mesh.MeshNode[0]
[DeleteNode] timeout path=SocialMedia/SocialTests/_Activity/compile-20261006203059966e7ea82da08ce41d09494f40db82ff0cc stage=commit partial-deleted=0 unanswered=SocialMedia/SocialTests/_Activity/compile-20261006203059966e7ea82da08ce41d09494f40db82ff0cc
System.TimeoutException: [DeleteNode:commit] the bottom-up delete of 'SocialMedia/SocialTests/_Activity/compile-20261006203059966e7ea82da08ce41d09494f40db82ff0cc' made no progress for 25s — 0 of 1 planned path(s) removed from storage so far; still owed by the plan: SocialMedia/SocialTests/_Activity/compile-20261006203059966e7ea82da08ce41d09494f40db82ff0cc. At the timeout: I/O pools with work queued at that moment: pg:Postgres(cap 1) 307 waiting, 1 in flight (307 async at 0 free permit(s): 307 behind the exhausted cap), 1036 admission(s) waited >= 1 s during this stage, longest wait on this pool ever 24690.56 ms; FileSystem(cap 256) 1 waiting, 1 in flight (1 async at 256 free permit(s): 1 waiting for a THREAD, not for this cap [1 before the gate, 0 granted and not yet resumed]), 0 admission(s) waited >= 1 s during this stage, longest wait on this pool ever 1327.606 ms. ThreadPool at that moment: 18 thread(s), 16 work item(s) queued
2026-10-09 14:24:07Z memex-portal-deployment-cfb58787b-b6klj fail: MeshWeaver.Mesh.MeshNode[0]
[DeleteNode] timeout path=SocialMedia/Post/_Activity/compile-state stage=commit partial-deleted=0 unanswered=SocialMedia/Post/_Activity/compile-state
System.TimeoutException: [DeleteNode:commit] the bottom-up delete of 'SocialMedia/Post/_Activity/compile-state' made no progress for 25s — 0 of 1 planned path(s) removed from storage so far; still owed by the plan: SocialMedia/Post/_Activity/compile-state. At the timeout: I/O pools with work queued at that moment: pg:Postgres(cap 1) 308 waiting, 1 in flight (308 async at 0 free permit(s): 308 behind the exhausted cap), 1036 admission(s) waited >= 1 s during this stage, longest wait on this pool ever 24690.56 ms; FileSystem(cap 256) 1 waiting, 1 in flight (1 async at 256 free permit(s): 1 waiting for a THREAD, not for this cap [1 before the gate, 0 granted and not yet resumed]), 0 admission(s) waited >= 1 s during this stage, longest wait on this pool ever 1327.606 ms. ThreadPool at that moment: 18 thread(s), 16 work item(s) queued
2026-10-09 14:24:07Z memex-portal-deployment-cfb58787b-b6klj fail: MeshWeaver.Mesh.MeshNode[0]
[DeleteNode] timeout path=SocialMedia/Post/_Activity/compile-20260909212118491a25cc20c59994bf088685097bb9709f0 stage=commit partial-deleted=0 unanswered=SocialMedia/Post/_Activity/compile-20260909212118491a25cc20c59994bf088685097bb9709f0
System.TimeoutException: [DeleteNode:commit] the bottom-up delete of 'SocialMedia/Post/_Activity/compile-20260909212118491a25cc20c59994bf088685097bb9709f0' made no progress for 25s — 0 of 1 planned path(s) removed from storage so far; still owed by the plan: SocialMedia/Post/_Activity/compile-20260909212118491a25cc20c59994bf088685097bb9709f0. At the timeout: I/O pools with work queued at that moment: pg:Postgres(cap 1) 306 waiting, 1 in flight (306 async at 0 free permit(s): 306 behind the exhausted cap), 1036 admission(s) waited >= 1 s during this stage, longest wait on this pool ever 24690.56 ms; FileSystem(cap 256) 1 waiting, 1 in flight (1 async at 256 free permit(s): 1 waiting for a THREAD, not for this cap [1 before the gate, 0 granted and not yet resumed]), 0 admission(s) waited >= 1 s during this stage, longest wait on this pool ever 1327.606 ms. ThreadPool at that moment: 18 thread(s), 8 work item(s) queued
Still occurring: 719 more since the last update (914 total).
Last seen: 2026-10-09 14:24:07Z
Pods: memex-portal-deployment-cfb58787b-b6klj
Recent log lines
2026-10-09 14:24:07Z memex-portal-deployment-cfb58787b-b6klj fail: MeshWeaver.Mesh.MeshNode[0]
[DeleteNode] timeout path=SocialMedia/PostTarget/_Activity/compile-20260907224233580c4f14d5c7dc5498fa729859d9321322b stage=commit partial-deleted=0 unanswered=SocialMedia/PostTarget/_Activity/compile-20260907224233580c4f14d5c7dc5498fa729859d9321322b
System.TimeoutException: [DeleteNode:commit] the bottom-up delete of 'SocialMedia/PostTarget/_Activity/compile-20260907224233580c4f14d5c7dc5498fa729859d9321322b' made no progress for 25s — 0 of 1 planned path(s) removed from storage so far; still owed by the plan: SocialMedia/PostTarget/_Activity/compile-20260907224233580c4f14d5c7dc5498fa729859d9321322b. At the timeout: I/O pools with work queued at that moment: pg:Postgres(cap 1) 41 waiting, 1 in flight (41 async at 0 free permit(s): 41 behind the exhausted cap), 1042 admission(s) waited >= 1 s during this stage, longest wait on this pool ever 24690.56 ms. ThreadPool at that moment: 18 thread(s), 21 work item(s) queued
2026-10-09 14:24:07Z memex-portal-deployment-cfb58787b-b6klj fail: MeshWeaver.Mesh.MeshNode[0]
[DeleteNode] timeout path=SocialMedia/PostTarget/_Activity/compile-state stage=commit partial-deleted=0 unanswered=SocialMedia/PostTarget/_Activity/compile-state
System.TimeoutException: [DeleteNode:commit] the bottom-up delete of 'SocialMedia/PostTarget/_Activity/compile-state' made no progress for 25s — 0 of 1 planned path(s) removed from storage so far; still owed by the plan: SocialMedia/PostTarget/_Activity/compile-state. At the timeout: I/O pools with work queued at that moment: pg:Postgres(cap 1) 41 waiting, 1 in flight (41 async at 0 free permit(s): 41 behind the exhausted cap), 1042 admission(s) waited >= 1 s during this stage, longest wait on this pool ever 24690.56 ms. ThreadPool at that moment: 18 thread(s), 21 work item(s) queued
2026-10-09 14:24:07Z memex-portal-deployment-cfb58787b-b6klj fail: MeshWeaver.Mesh.MeshNode[0]
[DeleteNode] timeout path=SocialMedia/PostTarget/_Activity/compile-2026090921524469345e843f1745c4e9ba4abbde612035cee stage=commit partial-deleted=0 unanswered=SocialMedia/PostTarget/_Activity/compile-2026090921524469345e843f1745c4e9ba4abbde612035cee
System.TimeoutException: [DeleteNode:commit] the bottom-up delete of 'SocialMedia/PostTarget/_Activity/compile-2026090921524469345e843f1745c4e9ba4abbde612035cee' made no progress for 25s — 0 of 1 planned path(s) removed from storage so far; still owed by the plan: SocialMedia/PostTarget/_Activity/compile-2026090921524469345e843f1745c4e9ba4abbde612035cee. At the timeout: I/O pools with work queued at that moment: pg:Postgres(cap 1) 41 waiting, 1 in flight (41 async at 0 free permit(s): 41 behind the exhausted cap), 1042 admission(s) waited >= 1 s during this stage, longest wait on this pool ever 24690.56 ms. ThreadPool at that moment: 18 thread(s), 20 work item(s) queued
Reading.Ops/Actions/verify-w13-1198-memex-delete-commit-26h, {namespace="memex"} |~ "(?i)\[DeleteNode", 2026-10-09 18:45Z → 2026-10-10 20:45Z: 2 lines, not cut. Both are [DeleteNode] permission-denied path=rbuergi/ApiToken/…. There is no[DeleteNode:commit] line. The filter is a superset of the burst's text and returned lines, so the instrument reads this site.
Not established: that any recursive delete of more than 1,000 paths ran in that window. A clean delete logs nothing at this level, so the zero is "no failure", not "a bulk delete passed".
Close condition, unchanged: a bulk recursive delete of more than 1,000 paths completes on memex with no [DeleteNode:commit] … 0 of 1 planned burst. It needs someone to run one (the 10-09 ones were the Marketing and SocialMedia partition deletes).
verify sweep w13, Claude Opus 5.5 (agent session).
A queue the delete does not own:Credit the commit watchdog while a delete leaf is queued behind a moving write lane #6403 (2de67a326e, merged 2026-10-10 06:59Z). The commit watchdog is credited while its leaf waits behind a write lane that is still granting slots, capped at 4 stage budgets; a leaf that is granted and then hangs still fails at one budget. DeleteCommitQueuedBehindAMovingLaneTest fails on the parent commit with 0 of 1 planned and passes with the change. The earlier comments here do not mention this one.
Live: memex.systemorph.com and memex.meshweaver.cloud both report e438ab89e7 (/api/version); both commits are ancestors.
Quiet: on memex.systemorph.com the newest [DeleteNode:commit] incident (afc2a08c4f9ce905, f3d0300939687f61) was last written 2026-10-09 19:39Z, before either fix rolled. The incident watcher is live (other incidents folded on 2026-10-10 and 10-11).
Not exercised, as far as can be read: nothing shows a bulk delete on memex since the roll. A clean delete logs nothing, so the silence is "no failure", not "a bulk delete passed". I did not create and delete a thousand nodes on the control instance to produce the event.
#6351 is the outer-wrapper log site of the same 2026-10-09 bursts, with the same fixes and the same closing condition, so it is closed as a duplicate of this issue.
Owner act: the next recursive delete of more than 1,000 paths on memex.systemorph.com (a space deletion) completes with no [DeleteNode:commit] … made no progress line. Then close this. A recurrence reopens it through the incident fold, and the line says whether the leaf was queued or stuck.
Activity
rbuergi commentedon Aug 12, 2026
Diagnostics shipped in #1294 — the root cause is NOT fixed, and this issue's key evidence was misleading.
partial-deleted=0never meant "zero progress"The commit phase is wrapped in
.Timeout(opts.Timeout). A timeout unsubscribes, and thedeleted-path list is attached only to the exception
HierarchicalPathDeletionraises itself —the freshly-constructed
TimeoutExceptioncarries noData. Sopartial-deletedprinted0forevery timeout, however much of the subtree had already been removed. The reading that narrowed
this to the pre-commit stages does not hold; the commit stage was never excluded.
What the one log line could not distinguish
HandleDeleteNodeRequestbounds six stages with the sameMeshOperationOptions.Timeout, andthree of them (root read, permission fold, root validators) had no bound at all — a wedge there
produced no
[DeleteNode]line whatsoever. Every bounded one threw a bareTimeoutException.After #1294
Stage names:
read-root,check-permission,validate-root,collect-paths,pre-validate-descendants,commit. The fan-out stage additionally names the descendants thatnever answered
ValidateDeleteRequest— that stage posts at every descendant and waits forall of them under one budget, so a single unresponsive per-node hub refuses the whole delete.
partial-deletedand the response'sAffectedPathsare now truthful. The stage + detail also rideon the response the caller sees, not only the log. No budget was raised and the descendant
validation was not made optional.
Why this stays open
Three stages now fit the original occurrence equally well, and the plausible fixes differ in kind
(a per-leaf report for an unresponsive descendant; a stalled storage enumeration; a leaf hub wedged
mid-commit). Attributing it from one line would be a guess. The next occurrence names the stage
and the silent hub — please re-post the new log line here and the fix becomes decidable.
rbuergi commentedon Aug 13, 2026
Two defects root-caused today each produce exactly this signature — a timeout with
partial-deleted=0, i.e. an operation that made zero progress. Both were found while investigating unrelated symptoms, and neither existed as a hypothesis when this issue was written. Worth re-checking against them before spending any more effort on lock contention or infrastructure latency, which were the two guesses recorded above.Candidate 1 — a request that is handled and never answered (#1362, PR #1364)
HandleGetDataRequestsubscribes a live workspace stream and posts each emission, but.Subscribe(onNext)has no completion arm.SynchronizationStream.Dispose()deliberately completes its store without publishing a value (the #1170/#1171 recognised-shutdown outcome), and a reduced stream over an already-disposed parent completes on first subscribe. The terminal signal is discarded: the delivery readsProcessed, the subscription dies with the hub, and the caller's callback sits registered until its wall-clock bound.Why it fits here: the observed shape in #1362 was
HANDLER_ENTER→HANDLER_EXIT state=Processed→[SYNC_STREAM] … stream is disposed~30 ms later → silence to the bound. The error message then names the state at t+timeout rather than what happened at t+0 — which is why it reads as "never started" when the handler in fact ran. A delete that must first read the node would report preciselypartial-deleted=0.Any recycle in that window produces it — idle deactivation, delete, republish, or overlay self-heal — so it needs no unusual conditions, just unlucky timing.
Candidate 2 — a permanently poisoned cache entry (#1316, PR #1367)
MeshNodeStreamCache._queriescached each synced query asReplay(1).AutoConnect(1)with no eviction. AReplaySubjectlatches a terminal and replays it to every later subscriber;AutoConnect(1)never reconnects. So one transient Postgres handshake failure made a query id permanently unreadable for the life of the process — every later attempt re-subscribed to an instantly-replayed error.Why it fits here: a delete that cannot read what it must delete makes zero progress and then times out, indefinitely and only on the affected pod. That matches "a transient database latency spike on this single pod" as observed, while explaining why it did not clear on its own.
This is now the fourth instance of that class this week; a related un-evicted promise-cache (
PostgreSqlPartitionStorageProvider._provisioned) can permanently block partition provisioning after one transient DDL failure, surfacing forever as42P01.Suggested disposition
Leave open until #1364 and #1367 have merged, then treat a recurrence as new information rather than a repeat. If it does not recur after both land, close it as fixed-by-those rather than as unreproducible — the two are very different records for whoever meets this next.
Not worth an independent investigation before then: the impact is genuinely low, and both candidates are already being fixed for their own reasons.
rbuergi commentedon Aug 13, 2026
Both candidates re-checked against the code — neither is reachable, and the premise they shared was false
#1364 and #1367 have both merged (in
mainat86aab11), so the previous comment's "re-check thendecide" is now due. I traced both against the delete path at that commit. The answer is not the one
that comment expected, and the more important finding is underneath it.
The premise — "zero progress" — was never established
Both candidates were selected because they explain an operation that made no progress. That
criterion has no discriminating power here.
The incident is 2026-08-11 05:46:41Z. #1294 — which introduced the stage names and the
progress sink that makes the counter truthful — merged 2026-08-12 13:07:28Z (
de494c25f). Thelog line therefore came from pre-#1294 code, where
partialwas read solely fromex.Data["DeletedPaths"], a key set only byHierarchicalPathDeletion's own.Catch. A.Timeoutunsubscribes and throws a freshTimeoutExceptionwhoseDatais empty, sopartial-deleted=0was printed for every timeout regardless of how much of the subtree hadalready gone. That is what the previous comment said about #1294's own reading; it applies with
equal force to the two candidates chosen after it.
Candidate 1 — #1362 / PR #1364 — NOT REACHABLE
HandleGetDataRequestruns only in answer to a postedGetDataRequest. No stage of the deleteposts one. Concretely, at
86aab11:read-rootreads throughpersistence.Read(path, …)— a directIStorageAdaptercall, anddeliberately so: the comment at
MeshExtensions.cs:2218says it avoids activating the per-nodehub that
GetMeshNodeStreamwould trigger.collect-pathsusesstorage.ListDescendantPaths— direct storage again.pre-validate-descendantspostsValidateDeleteRequest; the answering handler(
HandleValidateDeleteRequest,:3132) reads viapersistence.Readand runs validators.SubscribeRequest, notGetDataRequest— adifferent handler with a different defect surface.
Enumerating every
new GetDataRequest(...)insrc/puts all of them (GetMeshNode, layoutareas, export, indexing,
HubStreamProviderFactory, …) off the delete's reactive chain. #1364 isa real fix for a real bug; it cannot produce a
[DeleteNode] timeoutline at all.Candidate 2 — #1316 / PR #1367 — cache reachable, failure shape wrong
The delete does reach
MeshNodeStreamCache._queries, viaPermissionEvaluator(
$security-access:{scope}atPermissionEvaluator.cs:713, plus policy/roles/memberships) — hitat
check-permission, atvalidate-rootthroughRlsNodeValidator, and at every leaf's[RequiresPermission(Delete)]gate. So reachability is genuine and I expected this one to land.It does not, because a poisoned
_queriesentry replays a latchedOnError, instantly —never silence — and
Observable.Timeoutfires on silence, not on error. Downstream that error isanswered:
AccessControlPipelinefolds it toUndetermined→DeliveryFailure(Unavailable),and
PreValidateDescendantsObs' per-leaf.Catchlogs[DeleteNode] pre-validation failedatWarning. On the unbounded stages it surfaces as
[DeleteNode] unexpected. Neither is the line wegot.
The exception text corroborates it.
grep -rn "new TimeoutException()" src/returns nothing, andthe hub's own
RequestTimeoutthrows a named one ("No response received in hub …"). The onlyproducer of the default message
System.TimeoutException: The operation has timed out.is Rx's.Timeout(TimeSpan)— i.e. a stage that went silent, which is precisely what a replayedcache error is not.
What the one line does still tell us
Pre-#1294 only three stages carried a bound (
collect-paths,pre-validate-descendants,commit); the other three were unbounded and a wedge in them would have logged nothing at all. Sothe bare-
.Timeoutfingerprint narrows the 2026-08-11 occurrence to one of those three, and nofurther from that line.
The two mechanisms that actually fit, and are unfixed
Both scale with subtree size, which is also the cheapest way to discriminate them — how many
descendants did
KmuBasics/Buchungsjournalhave?pre-validate-descendantspays a per-descendant permission-query cold start under ONEbudget.
GetEffectivePermissionskeys its cached synced query on the node path itself, plusthe recursive ancestor chain and a parallel
$security-policy:{path}. For a non-static-rolecaller the static seed is empty, so a recursive delete opens up to one brand-new
SyncedQueryMeshNodesper descendant, simultaneously — each a cross-hubSubscribeRequestplus a Postgres round-trip — inside a single 30 s window. The commit stage does not pay this
(System short-circuits), which is exactly why the pre-flight is the expensive half.
commitfans N leaf deletes over a cap-1 Postgres write pool.pg:{adapter}is capped at1, so
Observable.Mergeparallelism collapses to one serialised connection, again under one30 s budget. This is the mechanical form of the original triage's "database latency spike"
guess.
A genuine gap left by #1367, worth its own issue
EvictFaultedQueryfires only from theOnErrorarm, andReplay(1).AutoConnect(1)neverreconnects — so a hung (as opposed to faulted)
_queriesentry is still shared, silently, forthe process lifetime. That variant does produce silence, so unlike the faulted one it is
shape-compatible with this incident. I could neither confirm nor refute that it occurred.
Disposition — stays open
Explicitly not closed as fixed-by-#1364/#1367: that would record a false cause, and the two
fixes are unrelated to this path. Also not closed as unreproducible — #1294 already made the
next occurrence decidable, and post-fix silence carries no signal either way (the pre-fix window,
2026-08-11 → 08-13, also recorded zero recurrences, and the portals self-update on a 6 h poll so
memex-cloud may not even be running the fixes yet).
Post-#1294 the message is
[DeleteNode:{stage}] …and names the silent hub, so a recurrenceself-identifies and one line resolves this.
Not established: which stage the 2026-08-11 timeout came from (irreducible from a pre-#1294
line — that is the thing #1294 fixed); the exact image memex-cloud was running at 05:46Z, beyond
the fact that it could not have contained #1294; and the subtree size of
KmuBasics/Buchungsjournal, which is the single strongest discriminator between the twomechanisms above and is one query away on the live portal.
rbuergi commentedon Aug 13, 2026
A third candidate — #1446/#1454 — and it is the first REACHABLE one. It still does not close this, and I can now show why with line numbers.
Retitled. The 2026-08-11 occurrence is not attributable and never will be (pre-#1294 line ⇒ stage irreducible; that is exactly what #1294 fixed). What is attributable is the structure that produces the signature, which is live, source-documented, and now has a second, sharper defect in it. The title names that instead of the stale report.
Where the previous two candidates stand
Unchanged from my comment above: #1364 is not reachable on the delete path (no stage posts a
GetDataRequest;read-rootandcollect-pathsgo direct to storage,pre-validate-descendantspostsValidateDeleteRequest, and the per-path cache hydrates overSubscribeRequest). #1367 is reachable but the wrong shape (a poisoned_queriesentry replays a latchedOnErrorinstantly;Observable.Timeoutfires on silence, not on error, and the only producer of the bare messageSystem.TimeoutException: The operation has timed out.is Rx's.Timeout). Closing this as fixed-by-those would record a false cause.Candidate 3 — #1446 / PR #1454 — reachable, right shape, and it did not exist when this was filed
This one lands where the other two did not:
RlsNodeValidator.SupportedOperationsincludesNodeOperation.Delete(src/MeshWeaver.Graph/Security/RlsNodeValidator.cs:55), and fix: a permission check that could not be ESTABLISHED answers so, instead of blocking the create #1454 explicitly carries the new outcome through toNodeDeletionRejectionReason.Unavailable. The delete hits it atvalidate-rootand again at every descendant, sinceHandleValidateDeleteRequestruns the same validators.CombineLatestover a leg that starves never emits, never completes, never errors, becauseSyncedQueryMeshNodesgates onSeenInitialover a merge containing aSubjectthat is never completed. Silence is precisely what a bare.Timeoutreports, and precisely what fix: a faulted synced query is evicted, not replayed forever (#1316) #1367 could not produce.So the mechanism I named as unfixed #1 above — "
pre-validate-descendantspays a per-descendant permission-query cold start under ONE budget" — now has a real, merged fix for its starved variant.🚨 But the ordering #1454 depends on does not hold on the delete path
#1454 states its own design rule:
That is true for
CreateNodeRequest, whose enclosing bound is the hub's 60 sRequestTimeout. On the delete path the enclosing bound is not 60 s. It isMeshOperationOptions.Timeout, default 30 s (src/MeshWeaver.Mesh.Contract/Services/MeshOperationOptions.cs:14) — and it appears at three nested levels at the same value:MeshExtensions.cs:2385(pre-validate-descendants),:2290/:2311(validate-root)opts.Timeout= 30 sMeshExtensions.cs:3195—HandleValidateDeleteRequest….Timeout(opts.Timeout)RlsNodeValidator.cs:42←RowLevelSecurityOptions.cs:29PermissionEstablishmentBudget30 = 30 = 30. The outer bound fires at or before the inner one, so a starved permission read during a recursive delete still surfaces as the anonymous
TimeoutExceptionthis issue is named after, never as theUnavailable#1454 introduced. The fix is correct and lands for creates; on deletes its answer can never win the race.To be explicit, since this repo's rule on the point is absolute: the fix is not "raise the outer bound." That would be pure headroom. The defect is that three independent budgets are set to one number with no ordering between them, so the innermost — the only one that knows what starved — is the one that cannot report. Whatever shape the fix takes, it has to make the specific answer beat the generic one.
The other mechanism is still live, and the source says so
MeshExtensions.cs:3049-3053, citing this issue by number:And unfixed mechanism #2 from my previous comment is untouched:
commitfans N leaf deletes over apg:{adapter}pool capped at 1, soObservable.Merge's parallelism collapses to one serialised connection, again under a single 30 s budget. That is the mechanical form of the original triage's "database latency spike" guess.Disposition
Stays open, retitled to the residual. Explicitly not closed as fixed-by-#1364/#1367 (false cause), not closed as fixed-by-#1454 (reachable and right-shaped, but demonstrably cannot change the reported outcome here), and not closed as unreproducible (post-fix silence carries no signal — the pre-fix window recorded zero recurrences too, and the portals self-update on a 6 h poll).
What the issue is now a spec for, in the order I would take them:
Unavailable, naming the starved read) reaches the caller instead of the outermost generic timeout.unanswered=list is the diagnostic half of this; the behavioural half is unbuilt.commitstage's N-deletes-over-a-cap-1-pool shape.Still not established, and one query away on a live portal: the subtree size of
KmuBasics/Buchungsjournal, which is the strongest discriminator between (2) and (3).[-]DeleteNode times out on mesh node with zero partial progress[/-][+]A recursive delete waits for every descendant under ONE budget, and the nested permission budget equals rather than nests inside it[/+]Merge pull request #1457 from Systemorph/fix/1198-nested-timeout-ladder
systemorph-com commentedon Sep 14, 2026
Reopened — this fault is happening again.
Still occurring: 833 more since the last update (834 total).
memex-portal-deployment-59479dc7d9-kmwvr,memex-portal-deployment-7d4b5684bb-9lrxl,memex-portal-deployment-6c54db76fc-s4j9h,memex-portal-deployment-6c54db76fc-zb69f,memex-portal-deployment-567b7b8cbb-lj8jv,memex-portal-deployment-59ccff47c5-xw4zx,memex-portal-deployment-78788d4b4b-6nhv4,memex-portal-deployment-75d6b58db5-5b57k,memex-portal-deployment-d7dd9796b-66g44,memex-portal-deployment-d7dd9796b-rc4bh,memex-portal-deployment-55f6c4c4c5-wcccn,memex-portal-deployment-55f6c4c4c5-j8r9m,memex-portal-deployment-688b496b7-brp4j,memex-portal-deployment-688b496b7-2sdt8,memex-portal-deployment-df7ddfdf4-dtp44,memex-portal-deployment-57b689f955-wrstj,memex-portal-deployment-57b689f955-h6d47,memex-portal-deployment-569544576b-fphfv,memex-portal-deployment-569544576b-9h52b,memex-portal-deployment-569544576b-q6nvd,memex-portal-deployment-569544576b-89r5k,memex-portal-deployment-867dc45877-wtcks,memex-portal-deployment-867dc45877-lgskl,memex-portal-deployment-867dc45877-xqs4p,memex-portal-deployment-867dc45877-hz7wt,memex-portal-deployment-867dc45877-h8tjc,memex-portal-deployment-5b6c4f89f8-hpcbf,memex-portal-deployment-5b6c4f89f8-6tzrt,memex-portal-deployment-5b6c4f89f8-rpfmq,memex-portal-deployment-5b6c4f89f8-rhmkw,memex-portal-deployment-58c7bb4b9d-97pjf,memex-portal-deployment-58c7bb4b9d-z2xcv,memex-portal-deployment-6f64bf4b56-djkrh,memex-portal-deployment-6f64bf4b56-vvtv6,memex-portal-deployment-6f64bf4b56-gxmrr,memex-portal-deployment-6f64bf4b56-2mzrf,memex-portal-deployment-6f64bf4b56-zd594,memex-portal-deployment-7b67cb5577-rctvc,memex-portal-deployment-7b67cb5577-cqzp2,memex-portal-deployment-6dc5679f77-vf2qx,memex-portal-deployment-6dc5679f77-nd67w,memex-portal-deployment-6fd666bc95-f7brs,memex-portal-deployment-6fd666bc95-s79r4,memex-portal-deployment-7b5f547cb7-cp2wv,memex-portal-deployment-7b5f547cb7-ps2nz,memex-portal-deployment-6c7b9889c7-rkr8g,memex-portal-deployment-6c7b9889c7-knbcm,memex-portal-deployment-6c7b9889c7-72fmv,memex-portal-deployment-c4d47bf4c-kmcls,memex-portal-deployment-c4d47bf4c-n9k84,memex-portal-deployment-595d8b9995-9tcnj,memex-portal-deployment-5d4bfc98b7-vb64z,memex-portal-deployment-5f9479f848-57t9h,memex-portal-deployment-5f9479f848-fsvjr,memex-portal-deployment-9bf79b774-jwrng,memex-portal-deployment-67dbc7bc9c-lswwx,memex-portal-deployment-85859db964-7sqbk,memex-portal-deployment-85859db964-q5zcm,memex-portal-deployment-55547495d7-c8z9r,memex-portal-deployment-85859db964-mgxj7,memex-portal-deployment-85859db964-bldn9,memex-portal-deployment-85859db964-xk5gw,memex-portal-deployment-85859db964-d52m6,memex-portal-deployment-77cfc55bfc-txpk7,memex-portal-deployment-77cfc55bfc-tgtr4,memex-portal-deployment-77cfc55bfc-767mq,memex-portal-deployment-5b9cbf46dd-q8v6s,memex-portal-deployment-77898c4947-bfnft,memex-portal-deployment-5b9cbf46dd-n67tt,memex-portal-deployment-7456f8f447-ctqhw,memex-portal-deployment-7fd9668b69-4qtkxRecent log lines
rbuergi commentedon Sep 14, 2026
2026-09-14 — re-measured against today's occurrence. Two of the three spec items have landed; a FOURTH one, not in the spec, was the thing actually firing today — and it is now fixed (#4316).
The 09-14 reopen carries the newest occurrence, and it is the one worth reading:
Where the three-item spec actually stands
main05c51adb19/ PR #1457, "the innermost delete bound can now actually fire".RowLevelSecurityOptionswas deleted;MeshOperationOptionsnow has ONE configured value and derives every rung byNest:Timeout30 s →NestedTimeout25 s (:107) →PermissionEstablishmentBudget20 s (:130). The 30 = 30 = 30 coincidence this thread measured is gone.stage=pre-validate-descendants … unanswered=sglauser/AgenticBusiness/01-MeetYourCoworker/AskAdvisor, …— 7 of 83 named.PreValidateDescendantsObsisObservable.Merge(perPath) … .TimeoutAtStage(timeout, …): one bound over the whole fan-out.commitstage's N-deletes-over-a-cap-1pg:{adapter}poolThe thing that was actually firing is a fourth item the spec never named
unanswered=exists on the shared line so an operator learns WHICH node stopped the operation. Only the pre-flight stage ever filled it. So astage=committimeout renderedunanswered=-— and-is the same rendering the line uses for "there is nothing outstanding".That is worse than an absent field. It did not abstain; it asserted the opposite of the truth: three paths were removed, the drain was stuck on the rest of the subtree, and the report said it owed nothing. Beside it, a count — which identifies what SUCCEEDED and therefore identifies nothing about the failure. An operator reading that line has no path to go and look at.
Both halves of the answer were already live in that closure: the plan (
collected.ToDelete) and the progress (SnapshotProgress()). The difference is the answer, and it costs one set operation on a path that has already failed. #4316 makes the commit stage report:and fill
DeleteUnansweredDataKey, so the shared[DeleteNode] timeoutline prints those paths instead of-.Two deliberate details: it says "still owed by the plan", never "remaining" — a drain can remove MORE than it planned (#3392), so the set is what the plan still owes and is never a claim about what else storage holds; and the progress COUNT stays, because reporting real progress rather than
0is the half of this issue that landed earlier and names are ADDED, not traded.Repro, both directions
DeleteCommitTimeoutNamesWhatIsStuckTest(MeshWeaver.Graph.Test): a realIStorageAdapterover a realInMemoryStorageAdapterthat serves two deletes under the root and then never answers — the store took the call and went silent, which is the state the no-progress watchdog exists for. Nothing is widened or raced; the watchdog's own budget ends the wait and the assertion is about what it SAYS.With the production edit reverted and the test project rebuilt, the message is the production shape verbatim:
made no progress for 3s — 0 path(s) removed from storage so far, with no names. The test also carries a negative control — the two paths the store DID remove must not appear in the owed set, so "the plan echoed back under a new label" fails.Disposition — stays OPEN, narrowed to two items
Not closed: spec items 2 (behavioural half) and 3 are untouched, and both are real. What is closed is the part that made today's occurrence unreadable.
Read-only for the measurements;
git log -S/greponorigin/mainin a worktree; the suite run locally on a-c Release -warnaserrorbuild (MeshWeaver.Graph.Test1610/1610).🤖 Generated with Claude Code
test(#1198): check the stalled-delete report against the STORE, not o…
review(#1198): count the post before it is outstanding, and stop two …
rbuergi commentedon Sep 15, 2026
2026-09-15 — item 2's behavioural half is built (#4363). Item 3 is MEASURED, the hypothesis as written is FALSIFIED, and what is left is a different mechanism. Stays open.
Item 2, behavioural half — built
PreValidateDescendantsObsbounded the wholeObservable.Mergewith ONE timeout and capped nothing. Each leg now carries its own bound, derived withMeshOperationOptions.Nestat the call site — never a second configured constant, because equal budgets are not an ordering and that is what this issue is named after. A leg that lapses reports itself, by name, asUnavailable: a hub that never spoke decided nothing, andIMeshService.DeleteNodemapsUnavailableandValidationFailedto different exception types, so the distinction reaches the caller rather than sending a correctly-entitled user to ask for permissions they already hold (#1446).Two consequences that had to be handled rather than papered over:
HandleValidateDeleteRequestmoved one rung deeper (Nest(NestedTimeout)). At the leg's own value its clock starts one post, one route and one activation later, so it could never fire first — the caller's new per-leg bound would have preempted the leaf's specific answer every time. That is item 1's defect recreated one level out. It now shares a rung with the permission fold, which is correct: the read completes before the validator chain starts, so they are SIBLINGS, not nested. No configured value changed; the production rungs are still 30 / 25 / 20.Mergesubscribes every leg at once and each post can ACTIVATE a per-node hub — an unbounded activation burst on a subtree of any size. It cannot strand the fan-out (every leg terminates on its own budget), but it does make outstanding, posted and planned three different numbers, so the stage backstop reports all three andunansweredis filled on post, not seeded from the plan. Claiming a leaf "did not answer" a request that was never sent is the same class of untruth as theunanswered=-fixed in fix: a teardown report and a stalled delete name what they tell you to find (#3712, #1198) #4316.Regression:
DeletePreflightNamesTheSilentDescendantTest— a real Monolith mesh whose middle descendant carries a deletion validator that never emits (the hub took the request and went silent, which is the shape a starved read produces and the only oneObservable.Timeoutreports). Reverted againstmainwith the test project rebuilt, it fails exactly as production did: the stage backstop, at the full budget,1 of 3 descendant(s) … did not answer ValidateDeleteRequest within 10s,[DeleteNode] timeout … stage=pre-validate-descendants partial-deleted=0. With the fix it passes in one leg budget, naming the one silent path.Item 3 — the hypothesis as written is FALSIFIED
Since #3392 the commit bound is an inter-emission no-progress watchdog, not a duration cap: the fan-out publishes a tick per removed path and every tick resets the clock. Serializing the drain's own N writes therefore cannot time it out. The 2026-08-13 comment's mechanism #2 — "
Observable.Mergeparallelism collapses to one serialised connection, again under one 30 s budget" — depends on a total-duration cap that no longer exists. The measurement comes back negative.What IS measurable, and is a different mechanism
Measured 2026-09-15 against
MeshWeaver.Plugins(read-only;grepoversrc/):PostgreSqlPartitionStorageProviderresolves one write pool and one read pool, both named from the PROVIDER —_ioPool = registry.Get($"{PostgresAdapterPrefix}{Name}"),_readPool = registry.Get($"{PostgresReadAdapterPrefix}{Name}"), withName => "Postgres".PostgreSqlPathRoutingAdapter.GetOrCreateAdapterhands every per-schema adapter that sameWritePool, that sameReadPooland the sameBaseDataSource.So the cap-1 gate is one process-wide write serializer, not one per partition. A delete's next leaf removal therefore queues behind unrelated writes from every other partition — and those do not tick this delete's progress. A portal under sustained write load can starve one drain for a whole budget with zero removals, which is the
made no progress for 30sshape logged on 2026-09-14 forHosting/TriageStatus. Whether that is what happened is not decidable from the line, and I am not going to attribute it from one occurrence — that is the mistake this thread already made twice.Why it is not fixed here
Raising the cap is the band-aid this repo forbids.
Doc/Architecture/ControlledIoPoolingstates the real rationale and it is not "the gate is the connection": the caps are a connection budget — 16 reads + 1 write, aggregate, under the sharedNpgsqlDataSource'sMaxPoolSize=50. There is headroom, but no measurement that says what to spend it on. The instrument that would decide it — the queue-wait distribution onpg:Postgresunder portal load — is not built, and the code is in MeshWeaver.Plugins, not core.🚨 Why this item sat unmeasured for a month
IoPoolNames.PostgresAdapterPrefixand theAsynchronousCallstable row asserted "the gate IS the connection… the single Npgsql connection that adapter holds (MaxPoolSize=1)". That design was deliberately removed —CreateAdapterForTable's own comment says minting a data source per(schema, table)leaked a pool per hub and exhausted the server, "One shared pool per silo instead." Two core docs contradicted a third, and the one a reader lands on made a live question look settled. #4363 corrects both, in four places, so the next reader sees an open question with its denominator rather than a closed one.Doc/Architecture/PartitionStorageHubscarries the same removed premise in three more places. I have not verified that layer and did not edit it on a guess — noting it here so it is not lost.Disposition
Stays open, narrowed to one item: the commit stage's writes serialize process-wide, and the number 1 has no measurement behind it. Item 2 closes with #4363. The next occurrence of
stage=commit … made no progressis still the decidable evidence — and now, so is anything that measures thepg:Postgresqueue.Read-only for the Plugins measurements (
grepon a local checkout). The core change is built and tested locally on a-c Release -warnaserrorbuild:MeshWeaver.Graph.Test1632/1632,MeshWeaver.Documentation.Test469/469.🤖 Generated with Claude Code
rbuergi commentedon Sep 15, 2026
The instrument this issue's last comment said was missing is now built: #4460.
IIoPool.QueueWaitnow reports how long granted work WAITED for a slot: total, max, and six buckets (<1 ms,<10 ms,<100 ms,<1 s,<10 s,>=10 s). A distribution rather than a mean, for the reason this issue is named after — a pool whose mean wait is a millisecond can still be starving one caller for a whole budget, and the mean is the statistic that hides it.It is complete across admission paths by construction: the three async-gate sites and the blocking path, which never touches
_gateand is therefore timed at the limited-concurrency scheduler's own grant point. A cancelled wait records nothing — it never became an admission, and folding it in would blend "how long work waited to run" with "how long a teardown took to unwind". And it costs no allocation per admission: the first shape wrapped the gate wait in anasynchelper, which allocates a Task on the busiest path in the system, so it is inlined instead.What this does and does not settle. It does not decide the cap — that still needs a reading taken on a portal under real write load, which is where
pg:Postgresactually queues. It removes the reason the item sat unmeasured: the number can now be looked at rather than argued about, and a decision to spend the headroom (16 reads + 1 write againstMaxPoolSize=50) has something to point at.Item 2 remains closed on #4363. This issue stays open on the same one item until a reading exists.
Measured 2026-09-15 by Claude Opus 5.
fix(review): cover every admission path, and synchronise on arrival i…
32 remaining items
systemorph-com commentedon Oct 9, 2026
Folded in — a DIFFERENT fingerprint from the same log site.
This issue tracks the log site
a8d7b0457bb403c8(MeshWeaver.Mesh.MeshNode), and these occurrences belong to it. They carry their own fingerprint — the masking split one site across several — so before this they would have opened a SEPARATE ticket. One log site fanned out into 46 of those, which is why they fold here instead. Nothing is discarded: the distinguishing evidence is below, and splitting this back out is a person's call.f3d0300939687f61a8d7b0457bb403c8MeshWeaver.Mesh.MeshNodeSystem.TimeoutException[DeleteNode:commit] the bottom-up delete of '{value}' made no progress for {n}s — {n} of {n} planned path(s) removed from storage so far; still owed by the plan: {path} At the timeout: {path} pools with work queued at that moment: pg:Postgres(cap {n}) {n} waiting, {n} in flight ({n} async at {n} free permit(s): {n} behind the exhausted cap), {n} admission(s) waited >= {n} s during this stage, longest wait on this pool ever {n} ms; FileSystem(cap {n}) {n} waiting, {n} in flight ({n} async at {n} free permit(s): {n} waiting for a THREAD, not for this cap [{n} before the gate, {n} granted and not yet resumed]), {n} admission(s) waited >= {n} s during this stage, longest wait on this pool ever {n} ms. ThreadPool at that moment: {n} thread(s), {n} work item(s) queuedmemexmemex-portal-deployment-cfb58787b-b6kljAdmin/_LogIncident/f3d0300939687f61What triage wrote about this fingerprint
What is failing
Node deletes in the mesh never reach storage: the
[DeleteNode:commit]stage forMarketing/EventHub/_Activity/compile-20260917170729615…removed 0 of 1 planned paths in 25s and timed out. In the same instant on the same pod, a burst of ~200 sibling delete timeouts of the same shape occurred (see below), so an entire bulk-delete pass of stalecompile-*activity nodes failed wholesale.Probable cause
High confidence the commit stage is starved behind the
pg:PostgresI/O pool, not blocked by the delete itself. The diagnostic snapshot embedded in the exception is explicit:pg:Postgres(cap 1) 211 waiting, 1 in flight, 211 behind the exhausted cap, 1326 admission(s) waited >= 1 s during this stage, longest wait ever 24690 ms. The pool's admission capacity is 1, yet hundreds of concurrent deletes queue against it; each delete's first storage write can sit behind the whole queue and exceed the 25s no-progress timeout. The plan itself is trivial (1 path, a leaf compile-activity node), ruling out a pathological subtree. The ThreadPool (18 threads, 17 queued) and the FileSystem pool are not the constraint here; the cap-1 Postgres semaphore is. What launched ~200 concurrent deletes at once (likely an automated cleanup of stalecompile-*activity nodes in the Marketing space) is the trigger; the cap-1 pool is the defect.Impact
One pod (
memex-portal-deployment-cfb58787b-b6klj), one burst at 2026-10-09T13:38:58Z. This fingerprint counts 1 occurrence, but sibling incidents from the same second (below) show ~197 deletes failing together, plus 1 delete of theMarketingroot aborted withpartial-deleted=1383— meaning the bulk operation was interrupted mid-flight and up to ~1,400 nodes may be in an indeterminate partial-delete state. Deletes are retryable, but the transient exhaustion of a shared cap-1 Postgres pool slows every concurrent tenant on the pod whenever it recurs (longest-ever wait ≈ 24.7s matches this stage).Where to look
MeshWeaver.Mesh.MeshNode, the[DeleteNode]/[DeleteNode:commit]timeout and no-progress path — the code that builds the diagnostic snapshot naming the pools (pg:Postgres,pg-read:Postgres,FileSystem) is the admission/throttling layer for storage writes.pg:PostgresI/O pool configuration: why its admission cap is 1 and whether the delete path bypasses or shares the same gate as all other Postgres work.compile-*nodes (samples live underMarketing/*/_Activity/compile-*) — it should pace its deletes or use a batch delete that holds the permit once.Related incidents (same second, same pod, same evidence)
Admin/_LogIncident/afc2a08c4f9ce905— 195 occurrences of the same[DeleteNode:commit]timeout (bulkMarketing/Campaign/_Activity/compile-*deletes)Admin/_LogIncident/8178a08b09190bba— same timeout,Marketing/_Activity/0490f133, showspg-read:Postgresalso waiting on a threadAdmin/_LogIncident/3250ed6f31f0eff1— the resultingDelete failed for 'Marketing/_Activity/dacd7d46'withpartial-deleted=1383These are almost certainly one underlying defect (cap-1 Postgres pool + un-paced bulk delete); if the platform files them separately they can be consolidated into one issue.
Reopened — this fault is happening again.
Still occurring: 1 more since the last update (1 total).
memex-portal-deployment-cfb58787b-b6kljRecent log lines
systemorph-com commentedon Oct 9, 2026
Folded in — a DIFFERENT fingerprint from the same log site.
This issue tracks the log site
a8d7b0457bb403c8(MeshWeaver.Mesh.MeshNode), and these occurrences belong to it. They carry their own fingerprint — the masking split one site across several — so before this they would have opened a SEPARATE ticket. One log site fanned out into 46 of those, which is why they fold here instead. Nothing is discarded: the distinguishing evidence is below, and splitting this back out is a person's call.afc2a08c4f9ce905a8d7b0457bb403c8MeshWeaver.Mesh.MeshNodeSystem.TimeoutException[DeleteNode:commit] the bottom-up delete of '{value}' made no progress for {n}s — {n} of {n} planned path(s) removed from storage so far; still owed by the plan: {path} At the timeout: {path} pools with work queued at that moment: pg:Postgres(cap {n}) {n} waiting, {n} in flight ({n} async at {n} free permit(s): {n} behind the exhausted cap), {n} admission(s) waited >= {n} s during this stage, longest wait on this pool ever {n} ms. ThreadPool at that moment: {n} thread(s), {n} work item(s) queuedmemexmemex-portal-deployment-cfb58787b-b6kljAdmin/_LogIncident/afc2a08c4f9ce905What triage wrote about this fingerprint
What is failing
DeleteNode's commit stage fails wholesale when many single-node deletes are issued at once. A cleanup sweep of stalecompile-*activity-bookkeeping nodes underMarketing/Campaign/_Activityran as a concurrent fan-out, and every delete's storage write sat queued on the process-wide cap-1pg:Postgreswrite pool until its 25-second no-progress watchdog fired —0 of 1 planned path(s) removed, nothing partially deleted. This is not a storage fault: the delete's own diagnostic names the queue (pg:Postgresat cap 1 with a deep waiting queue, zero free permits, over a thousand admissions waiting ≥1s during the stage), and the ThreadPool is healthy. It is precisely the "waiting in line" congestion shape the 2026-09-16 stall diagnostic (Doc/WhatsNew/2026-09-16-a-delete-that-stalls-now-says-whether-it-was-stuck-or-just-waiting-in-line) was built to distinguish from a stuck storage call.Probable cause
High confidence. Per
Doc/Architecture/ControlledIoPooling, every Postgres write is one leaf on the sharedpg:{provider}pool, capped at 1 process-wide. A bulk sweep of ~200 single-node deletes issues ~200 simultaneous claimants of that one permit. Each delete's watchdog measures its own progress —0 of 1 planned paths removed— not the pool's, so the whole batch times out together while the queue is merely draining serially. Two contributing defects:Impact
One namespace, one pod, one burst. A bulk cleanup operation fails outright (deletes reported as failed, the stale nodes remain), user-visible to whoever issued it. Normal single deletes are unaffected — the measured write-pool queue-wait is single-digit milliseconds under normal load. No data loss: nothing was partially removed.
Where to look
MeshWeaver.Mesh.MeshNode— theDeleteNodecommit-stage watchdog ("made no progress for 25s") and how bulk deletes are admitted.IoPoolOptions.MaxConcurrencyFor/IoPoolNames.PostgresAdapterPrefixin Controlled I/O Pooling — that page also carries the queue-wait baseline showing the write pool normally never queues, which is what makes this burst anomalous._Activity/compile-*nodes — it should bound its concurrent outstanding deletes against the shared write pool, or drain them serially as the recursive-delete drain does.Admin/_LogIncident/54544acf7013f034.Still occurring: 195 more since the last update (195 total).
memex-portal-deployment-cfb58787b-b6kljRecent log lines
systemorph-com commentedon Oct 9, 2026
Folded in — a DIFFERENT fingerprint from the same log site.
This issue tracks the log site
a8d7b0457bb403c8(MeshWeaver.Mesh.MeshNode), and these occurrences belong to it. They carry their own fingerprint — the masking split one site across several — so before this they would have opened a SEPARATE ticket. One log site fanned out into 46 of those, which is why they fold here instead. Nothing is discarded: the distinguishing evidence is below, and splitting this back out is a person's call.8178a08b09190bbaa8d7b0457bb403c8MeshWeaver.Mesh.MeshNodeSystem.TimeoutException[DeleteNode:commit] the bottom-up delete of '{value}' made no progress for {n}s — {n} of {n} planned path(s) removed from storage so far; still owed by the plan: {path} At the timeout: {path} pools with work queued at that moment: pg:Postgres(cap {n}) {n} waiting, {n} in flight ({n} async at {n} free permit(s): {n} behind the exhausted cap), {n} admission(s) waited >= {n} s during this stage, longest wait on this pool ever {n} ms; pg-read:Postgres(cap {n}) {n} waiting, {n} in flight ({n} async at {n} free permit(s): {n} waiting for a THREAD, not for this cap [{n} before the gate, {n} granted and not yet resumed]), {n} admission(s) waited >= {n} s during this stage, longest wait on this pool ever {n} ms. ThreadPool at that moment: {n} thread(s), {n} work item(s) queuedmemexmemex-portal-deployment-cfb58787b-b6kljAdmin/_LogIncident/8178a08b09190bbaWhat triage wrote about this fingerprint
What is failing
A single-node delete (of
Marketing/_Activity/0490f133in memex) reached its commit stage, made no progress for its full 25s no-progress budget, and removed 0 of 1 planned paths — the target node is still in storage and the delete failed user-visibly. The delete logic itself is not the problem: its one write never got a turn on the Postgres write pool.Probable cause — high confidence in the mechanism, unclear why it is happening now
The write pool
pg:Postgresis configured with capacity 1. At the moment of the timeout 211 callers were queued behind the single in-flight operation (0 free permits), 1326 admissions had waited ≥1s during that stage alone, and the pool's longest-ever wait is ~24.7s. A cap-1 pool has zero parallelism, so any burst of write work queues hundreds deep and a single write — this delete's commit — cannot land within its budget.What is not clear is why this pool queues at all now: the 14-hour live-portal measurement behind A delete that stalls now says whether it was stuck or just waiting in line concluded the write pool never made anything wait more than ~0.2s, and no tuning was done on the strength of it. Either the write workload changed (a burst writer — e.g. an import) or a post-2026-09-16 regression increased write volume or hold time. Reconciling that measurement with this sample is the first investigation step.
Secondary signal, plausibly downstream: at the same moment the pod's ThreadPool had 18 threads with 16 work items queued, and the one read-pool (
pg-read, cap 16) waiter was waiting for a thread, not a pool permit — mild thread-pool starvation consistent with the write backlog.Impact
One occurrence on one pod so far — judged from the numbers this is not an outage. The failed delete removed nothing, so it is safe to retry (the partial-delete accounting from A delete that times out now says what it was waiting for makes "removed nothing" trustworthy). The wider exposure is pool-level: while the write pool was backed up, every write on that pod queued behind it, so other operations in the same window were degraded even where they didn't hit their own timeouts. If the backlog proves persistent rather than a one-off burst, the impact moves from "a delete fails occasionally" to "all writes on the pod crawl" — worth a human re-rule then.
Where to look
MeshWeaver.Mesh.MeshNodehandler (the failing log category) — confirm the commit takes a single write-pool admission and has no reserved slot that would let small deletes jump a burst queue.pg:Postgresgets capacity 1 whilepg-read:Postgresgets 16 — the cap and its admission/wait counters are the central question; the 2026-09-16 doc's decision not to tune this number is the premise this incident now challenges.Still occurring: 1 more since the last update (1 total).
memex-portal-deployment-cfb58787b-b6kljRecent log lines
systemorph-com commentedon Oct 9, 2026
Folded in — a DIFFERENT fingerprint from the same log site.
This issue tracks the log site
a8d7b0457bb403c8(MeshWeaver.Mesh.MeshNode), and these occurrences belong to it. They carry their own fingerprint — the masking split one site across several — so before this they would have opened a SEPARATE ticket. One log site fanned out into 46 of those, which is why they fold here instead. Nothing is discarded: the distinguishing evidence is below, and splitting this back out is a person's call.d1833dd0f0d9fb2ca8d7b0457bb403c8MeshWeaver.Mesh.MeshNodeSystem.TimeoutException[DeleteNode:commit] the bottom-up delete of '{value}' made no progress for {n}s — {n} of {n} planned path(s) removed from storage so far; still owed by the plan: {path} At the timeout: {path} pools with work queued at that moment: pg:Postgres(cap {n}) {n} waiting, {n} in flight ({n} async at {n} free permit(s): {n} waiting for a THREAD, not for this cap [{n} before the gate, {n} granted and not yet resumed]; {n} behind the exhausted cap), {n} admission(s) waited >= {n} s during this stage, longest wait on this pool ever {n} ms. ThreadPool at that moment: {n} thread(s), {n} work item(s) queuedmemexmemex-portal-deployment-cfb58787b-b6kljAdmin/_LogIncident/d1833dd0f0d9fb2cWhat triage wrote about this fingerprint
What is failing
DeleteNodefor a single mesh node never reaches storage at its commit stage: the bottom-up delete times out after 25s with 0 of 1 planned paths removed, because the Postgres I/O pool (pg:Postgres) admits only one operation at a time and the delete's storage work never gets a turn. The node is left un-deleted (partial-deleted=0), so the caller's delete simply fails.Probable cause (medium-high confidence on the mechanism, lower on why the cap is 1)
The pool snapshot inside the timeout message is explicit: at the moment of the timeout the pool ran at
cap 1with 633 waiting, 1 in flight — 632 of those behind the exhausted cap, only 1 waiting on a thread — and 1033 admissions waited ≥ 1s during this single stage, with the pool's longest-ever wait at 24,690 ms, i.e. the pool already sits at the timeout budget under load. ThreadPool pressure was mild (18 threads, 26 queued), which rules out thread starvation: the bottleneck is the per-pool admission cap of 1. Any bulk or background I/O traffic sharing that pool head-of-line-blocks a delete commit indefinitely. What needs deciding is whethercap 1is a misconfiguration of the Postgres pool for this deployment or a by-design serial pool that the delete path should not be routed through.Impact
One occurrence on one portal pod, on a delete of a test-activity node — the operation failed for one caller and is retriable. But the same cap starves everything else sharing the pool: 1033 admissions waited over a second during this one stage and the pool's record wait is ~25s, so any user-visible write under concurrent load is exposed to the same starvation. No duplicate incident found for this shape; the numerous existing TimeoutException incidents (Memory queue adapters, MessageHubGrain, thread exec) have different fingerprints and do not cover it.
Where to look
The
MeshWeaver.Mesh.MeshNodedelete path — specifically the commit stage that emits the[DeleteNode:commit]no-progress timeout — and the Postgres storage adapter's admission/permit logic (the pool reporting aspg:Postgres(cap 1)with the waiting/behind-cap/waiting-for-thread breakdown). The framework source is not indexed in the mesh, so no file links; the log site names to grep for areDeleteNode:commitand the pool admission dump (behind the exhausted cap,admission(s) waited).Still occurring: 1 more since the last update (1 total).
memex-portal-deployment-cfb58787b-b6kljRecent log lines
rbuergi commentedon Oct 9, 2026
The 2026-10-09 reopen is the commit-stage stall, and this time its cause is measured. The fix is in #6357. Same burst as #6351, which carries the outer-wrapper log site.
On the control instance (
…-cfb58787b-b6klj, ci.10310), theMarketingdelete (13:38:58Z) and theSocialMediadelete (14:24:07Z) each failed on a leaf commit0 of 1 planned. In theSocialMediaburst, 194 of those leaf timeouts landed within one second, all underSocialMedia/. The governed read isOps/Actions/logs-sevM-a4315-20261009-q1.So the 2026-09-16 exoneration of the write pool was right for that portal, but its "unrelated writes from other partitions" mechanism is not what happened here either. The commit posted every leaf at once through
HierarchicalPathDeletion's unbounded nestedMerge. Every leaf's write queued on the one cap-1pgpool. Each leaf's own no-progress watchdog then counted its wait behind its siblings as a stall.#6357 gives the commit one bounded admission lane for the whole tree (
MeshOperationOptions.CascadeFanOutConcurrency, 64). It also stops a leaf'sUnavailablefrom being reported asValidationFailed/UnauthorizedAccessException.Doc/Architecture/RecursiveDeleteDraincarries the reading.Stays open until an image carrying #6357 runs on memex and a bulk delete of that size completes with no
[DeleteNode:commit]burst.rbuergi commentedon Oct 9, 2026
#6357 is merged as
78a670acfb(2026-10-09 17:47Z). The Plugins dependent-suite verdict was green on the third candidate: the first two lost their build runner mid-step.This stays open until memex.systemorph.com runs an image carrying
78a670acfband a bulk recursive delete of more than 1,000 paths completes with no[DeleteNode:commit] … 0 of 1 plannedburst. memex currently runs8b791643f1. This is host code, so no recycle is needed.systemorph-com commentedon Oct 9, 2026
Still occurring: 6 more since the last update (7 total).
memex-portal-deployment-cfb58787b-b6kljRecent log lines
systemorph-com commentedon Oct 9, 2026
Still occurring: 719 more since the last update (914 total).
memex-portal-deployment-cfb58787b-b6kljRecent log lines
Credit a commit-stage delete watchdog while its leaf is queued behind…
Tie the #1198 queue credit to this delete: refuse it while any busy w…
rbuergi commentedon Oct 10, 2026
Re-read 2026-10-10 ~20:45Z: #6357 is live on memex, and no bulk delete has exercised it yet.
a263a27b3f, which contains fix(#6351): a recursive delete's commit fans out through one bounded lane; a leaf's refusal keeps its reason #6357 (78a670acfb); memex-cloud (d2f068a1fb) and control (108ad866c0) contain it too.Ops/Actions/verify-w13-1198-memex-delete-commit-26h,{namespace="memex"} |~ "(?i)\[DeleteNode", 2026-10-09 18:45Z → 2026-10-10 20:45Z: 2 lines, not cut. Both are[DeleteNode] permission-denied path=rbuergi/ApiToken/…. There is no[DeleteNode:commit]line. The filter is a superset of the burst's text and returned lines, so the instrument reads this site.Close condition, unchanged: a bulk recursive delete of more than 1,000 paths completes on memex with no
[DeleteNode:commit] … 0 of 1 plannedburst. It needs someone to run one (the 10-09 ones were theMarketingandSocialMediapartition deletes).verify sweep w13, Claude Opus 5.5 (agent session).
test(delete): pin the queue ahead of the leaf instead of hoping repla…
docs(delete): the #1198 queue test's summary states what it guarantees
Merge pull request #6458 from Systemorph/fix/1198-queue-credit-under-…
rbuergi commentedon Oct 11, 2026
Reading 2026-10-11: both commit-stall mechanisms are fixed and live. One act remains.
78a670acfb), one admission lane for every leaf of a recursive delete.2de67a326e, merged 2026-10-10 06:59Z). The commit watchdog is credited while its leaf waits behind a write lane that is still granting slots, capped at 4 stage budgets; a leaf that is granted and then hangs still fails at one budget.DeleteCommitQueuedBehindAMovingLaneTestfails on the parent commit with0 of 1 plannedand passes with the change. The earlier comments here do not mention this one.e438ab89e7(/api/version); both commits are ancestors.[DeleteNode:commit]incident (afc2a08c4f9ce905,f3d0300939687f61) was last written 2026-10-09 19:39Z, before either fix rolled. The incident watcher is live (other incidents folded on 2026-10-10 and 10-11).#6351 is the outer-wrapper log site of the same 2026-10-09 bursts, with the same fixes and the same closing condition, so it is closed as a duplicate of this issue.
Owner act: the next recursive delete of more than 1,000 paths on memex.systemorph.com (a space deletion) completes with no
[DeleteNode:commit] … made no progressline. Then close this. A recurrence reopens it through the incident fold, and the line says whether the leaf was queued or stuck.