Repository navigation
RoutingGrain back-pressure recurs: 62-deep head-of-line pileup behind cache hub legs persists past issue #4903's window #4904
Description
What is failing
The Orleans RoutingGrain on the memex-cloud portal crossed its 64-dispatch in-flight threshold four times in ~1.3 seconds (16:39:58–16:39:59), on both portal pods, in the two shapes this log site distinguishes: head-of-line blocking on a cache/{meshId} destination (episodes 1c7f1383#2 and eb59bdbb#5: deepest per-destination queue 62 of 64 in flight, behind one leg to cache/YORFhwiyqEyTP9ESF-NUNg), and plain load (1c7f1383#3: deepest queue 0, nothing waiting). Routing pool idle (subscribing 0) in all samples.
Probable cause
Medium-high confidence: this is a continuation of the same slow/stalling cache/{meshId} hub legs already tracked in issue #4903, not a new defect. The evidence:
- Same grain activations (
eb59bdbb,1c7f1383), same log site, same destinationcache/YORFhwiyqEyTP9ESF-NUNg(pluscache/12xX8OXQIEmdwvf_ZZ8LjA) as the incident filed as RoutingGrain repeatedly hits back-pressure threshold: 62-deep dispatch pileup behind cache hub legs #4903, whose window closed at 16:32:47. This burst starts at 16:39:58 — the episodes drained and recurred again seven minutes later, same shape. - Episode stamps here are higher than in RoutingGrain repeatedly hits back-pressure threshold: 62-deep dispatch pileup behind cache hub legs #4903 (
eb59bdbbwent Test #2→Clarify license options with ag grid #4 there, now Get rid of project dependencies in NotebookEditorControl #5→moved canEdit and canRun permissions to props #6;1c7f1383Add entire company to Open SMC Teams #1 there, now Test #2→Determine back-end contributors #3), so the in-flight count keeps falling below half the threshold and climbing back: the legs terminate, but slowly — persistent intermittent slowness of the cache-hub legs, not a leaked dispatch slot and not a recycled grain. - The 62-deep samples are a real pileup, not the threshold artefact (the 🚨 caveat only explains depths of ~InFlight/N when the backlog is shared; 62 of 64 on one destination is head-of-line).
If #4903's investigation converges on the MeshNodeStreamCache hub, this ticket should be closed as its duplicate; the one thing this burst adds is evidence the stall outlived #4903's observation window and reappeared on the second pod simultaneously, i.e. fleet-side, not one sick grain.
Impact
Critical severity but small in volume: 4 occurrences in ~1.3 seconds on 2 pods, each episode self-recovering. Recurring pressure on the portal's routing tier across at least the last ~18 minutes (across both incidents); no outage, but the pattern is repeating, not decaying.
Where to look
MeshWeaver.Hosting.Orleans.RoutingGrain— dispatch-slot accounting and per-destination queueing behind this log site; see Doc/WhatsNew/2026-08-12-routing-alerts-name-what-they-actually-saw.MeshNodeStreamCacheand itscache/{meshId}hub (incl.sync/{streamId}sub-hubs) — whether legs tocache/YORFhwiyqEyTP9ESF-NUNg/cache/12xX8OXQIEmdwvf_ZZ8LjAwere stalling at 16:39–16:40 UTC.- Issue RoutingGrain repeatedly hits back-pressure threshold: 62-deep dispatch pileup behind cache hub legs #4903 and incident
Admin/_LogIncident/26dfad998e9f5893— the earlier window of this same pattern; start there.
Possible duplicates
Almost certainly the same underlying condition as #4903 (filed from Admin/_LogIncident/26dfad998e9f5893, seven minutes earlier, same activations and cache destination). This ticket extends the timeline; merge there if the investigation already covers it.
Evidence
| Fingerprint | c10a7bd229d71669 |
| Category | MeshWeaver.Hosting.Orleans.RoutingGrain |
| Severity | Critical |
| Namespace | memex-cloud |
| Pods | memex-portal-deployment-69956b6dbc-ndnxt, memex-portal-deployment-69956b6dbc-gx6z6 |
| Occurrences | 4 |
| First seen | 2026-09-19 16:39:58Z |
| Last seen | 2026-09-19 16:39:59Z |
Recent log lines
2026-09-19 16:39:58Z memex-portal-deployment-69956b6dbc-ndnxt crit: MeshWeaver.Hosting.Orleans.RoutingGrain[0]
[ROUTE] Routing back-pressure [1c7f1383#2 started 2026-09-19T16:39:58.6111031Z]: 64 route dispatches in flight (reporting threshold 64); stream destinations queued 1, deepest per-destination queue 62, routing pool subscribing 0. Latest dispatch target cache/YORFhwiyqEyTP9ESF-NUNg — the address that happened to cross the threshold, NOT a diagnosis. A slot is held from dispatch until the leg terminates, INCLUDING the unbounded wait for a ThreadPool thread before the leg's own timeouts start, so a CPU-starved silo raises this with nothing stuck. A deepest queue of 1 or more means legs are blocked behind a leg (head-of-line on one destination); 0 means nothing is waiting on anything, so read it as load. 🚨 Deepest is sampled AT THE CROSSING, so like the in-flight count it is partly an artefact of the threshold: with N destinations sharing the backlog it is ~InFlight/N whatever is wrong. READ THE EPISODE STAMP, not the depth: a later line with a HIGHER episode on this activation means this episode drained; a line with a DIFFERENT activation id means the grain was recycled; and if neither a clear nor a higher episode ever follows, the in-flight count never fell below half the threshold — which means a leg never terminated and its slot leaked, not that the silo was busy.
2026-09-19 16:39:58Z memex-portal-deployment-69956b6dbc-gx6z6 crit: MeshWeaver.Hosting.Orleans.RoutingGrain[0]
[ROUTE] Routing back-pressure [eb59bdbb#5 started 2026-09-19T16:39:58.7788229Z]: 64 route dispatches in flight (reporting threshold 64); stream destinations queued 1, deepest per-destination queue 62, routing pool subscribing 0. Latest dispatch target cache/YORFhwiyqEyTP9ESF-NUNg — the address that happened to cross the threshold, NOT a diagnosis. A slot is held from dispatch until the leg terminates, INCLUDING the unbounded wait for a ThreadPool thread before the leg's own timeouts start, so a CPU-starved silo raises this with nothing stuck. A deepest queue of 1 or more means legs are blocked behind a leg (head-of-line on one destination); 0 means nothing is waiting on anything, so read it as load. 🚨 Deepest is sampled AT THE CROSSING, so like the in-flight count it is partly an artefact of the threshold: with N destinations sharing the backlog it is ~InFlight/N whatever is wrong. READ THE EPISODE STAMP, not the depth: a later line with a HIGHER episode on this activation means this episode drained; a line with a DIFFERENT activation id means the grain was recycled; and if neither a clear nor a higher episode ever follows, the in-flight count never fell below half the threshold — which means a leg never terminated and its slot leaked, not that the silo was busy.
2026-09-19 16:39:59Z memex-portal-deployment-69956b6dbc-ndnxt crit: MeshWeaver.Hosting.Orleans.RoutingGrain[0]
[ROUTE] Routing back-pressure [1c7f1383#3 started 2026-09-19T16:39:59.8880937Z]: 64 route dispatches in flight (reporting threshold 64); stream destinations queued 0, deepest per-destination queue 0, routing pool subscribing 0. Latest dispatch target Reinsurance/AmountType — the address that happened to cross the threshold, NOT a diagnosis. A slot is held from dispatch until the leg terminates, INCLUDING the unbounded wait for a ThreadPool thread before the leg's own timeouts start, so a CPU-starved silo raises this with nothing stuck. A deepest queue of 1 or more means legs are blocked behind a leg (head-of-line on one destination); 0 means nothing is waiting on anything, so read it as load. 🚨 Deepest is sampled AT THE CROSSING, so like the in-flight count it is partly an artefact of the threshold: with N destinations sharing the backlog it is ~InFlight/N whatever is wrong. READ THE EPISODE STAMP, not the depth: a later line with a HIGHER episode on this activation means this episode drained; a line with a DIFFERENT activation id means the grain was recycled; and if neither a clear nor a higher episode ever follows, the in-flight count never fell below half the threshold — which means a leg never terminated and its slot leaked, not that the silo was busy.
2026-09-19 16:39:59Z memex-portal-deployment-69956b6dbc-gx6z6 crit: MeshWeaver.Hosting.Orleans.RoutingGrain[0]
[ROUTE] Routing back-pressure [eb59bdbb#6 started 2026-09-19T16:39:59.9023161Z]: 64 route dispatches in flight (reporting threshold 64); stream destinations queued 1, deepest per-destination queue 62, routing pool subscribing 0. Latest dispatch target cache/12xX8OXQIEmdwvf_ZZ8LjA — the address that happened to cross the threshold, NOT a diagnosis. A slot is held from dispatch until the leg terminates, INCLUDING the unbounded wait for a ThreadPool thread before the leg's own timeouts start, so a CPU-starved silo raises this with nothing stuck. A deepest queue of 1 or more means legs are blocked behind a leg (head-of-line on one destination); 0 means nothing is waiting on anything, so read it as load. 🚨 Deepest is sampled AT THE CROSSING, so like the in-flight count it is partly an artefact of the threshold: with N destinations sharing the backlog it is ~InFlight/N whatever is wrong. READ THE EPISODE STAMP, not the depth: a later line with a HIGHER episode on this activation means this episode drained; a line with a DIFFERENT activation id means the grain was recycled; and if neither a clear nor a higher episode ever follows, the in-flight count never fell below half the threshold — which means a leg never terminated and its slot leaked, not that the silo was busy.
Re-addressed by the current identity function: this incident inherited e4a97855ab595beb (Systemorph/MeshWeaver.Plugins#1796). Those nodes are superseded and will not fold, file or comment again.
Opened automatically from Admin/_LogIncident/c10a7bd229d71669. Recurrences are folded into this issue rather than opening new ones.
Activity
systemorph-com commentedon Sep 19, 2026
Still occurring: 6 more since the last update (10 total).
memex-portal-deployment-69956b6dbc-ndnxt,memex-portal-deployment-69956b6dbc-gx6z6,memex-portal-deployment-69956b6dbc-s246cRecent log lines
Re-addressed by the current identity function: this incident inherited
e4a97855ab595beb(Systemorph/MeshWeaver.Plugins#1796). Those nodes are superseded and will not fold, file or comment again.rbuergi commentedon Sep 19, 2026
Consolidation note — 4 duplicate tickets folded onto this one today
The
[ROUTE] Routing back-pressureline atMeshWeaver.Hosting.Orleans.RoutingGrainwas filed as11 separate open tickets in this repository. They are now consolidated onto two survivors,
split by the discriminator the log line states itself:
deepest per-destination queue 62, the head-of-line reading, every sample namingcache/YORFhwiyqEyTP9ESF-NUNg. Folded in: RoutingGrain repeatedly hits back-pressure threshold: 62-deep dispatch pileup behind cache hub legs #4902, RoutingGrain repeatedly hits back-pressure threshold: 62-deep dispatch pileup behind cache hub legs #4903, RoutingGrain dispatch budget saturates at cold-start, with head-of-line blocking on a cold cache address #4906, RoutingGrain back-pressure episodes on memex-portal pods — silo thread-pool saturation and a head-of-line block behind cache/* destinations #4913.deepest per-destination queue 0, which the line says to "read as load". Folded in:Route legs to cache pod hubs block behind slow deliveries, triggering back-pressure episodes on memex portal pods #4798, RoutingGrain dispatch pool saturates fleet-wide on bursts, with legs queuing behind unsubscribed cache stream destinations #4905, RoutingGrain back-pressure: whole dispatch budget head-of-line blocked on one mesh-node-cache destination #4907, RoutingGrain dispatch slots saturate again on portal pods — recurring head-of-line block behind cache/12xX8OXQIEmdwvf_ZZ8LjA and load episodes #4909, RoutingGrain back-pressure alert trips at 64 in flight with nothing blocked — verify episode drained or slots are leaking #4809.
Why there were so many. The message embeds the reporting activation's identity
(
[eb59bdbb#2 started …]), and the hex-masking rule on the image that filed them required 16+ hexcharacters, so an 8-character activation id survived normalization and each activation forked its own
fingerprint. The per-window site-fold floor could not bound it: the crossings are ~20 minutes apart,
so no single window exceeded the per-site budget.
Status of that cause. Fixed in code —
MixedHexIdinMeshWeaver.Plugins/src/MeshWeaver.Observability.Contract/LogLineParser.cs(Plugins#2164 / #2165) —and not live: all portal deploys are blocked by
Systemorph/Memex#437, so the production filer isstill the pre-fix one. Expect this line to keep forking new tickets until an image carrying the fix
rolls. Residual narrower masking gaps are tracked as Plugins#2166.
This ticket's own subject is untouched by any of that — the back-pressure condition it reports is
still open and still wants the fix it describes.
systemorph-com commentedon Sep 19, 2026
Still occurring: 7 more since the last update (17 total).
memex-portal-deployment-69956b6dbc-ndnxt,memex-portal-deployment-69956b6dbc-gx6z6,memex-portal-deployment-69956b6dbc-s246cRecent log lines
Re-addressed by the current identity function: this incident inherited
e4a97855ab595beb(Systemorph/MeshWeaver.Plugins#1796). Those nodes are superseded and will not fold, file or comment again.systemorph-com commentedon Sep 20, 2026
Still occurring: 28 more since the last update (33 total).
memex-portal-deployment-69956b6dbc-ndnxt,memex-portal-deployment-69956b6dbc-s246c,memex-portal-deployment-69956b6dbc-gx6z6Recent log lines
Re-addressed by the current identity function: this incident inherited
e4a97855ab595beb(Systemorph/MeshWeaver.Plugins#1796). Those nodes are superseded and will not fold, file or comment again.systemorph-com commentedon Sep 20, 2026
Still occurring: 2 more since the last update (6 total).
memex-portal-deployment-69956b6dbc-gx6z6,memex-portal-deployment-69956b6dbc-ndnxtRecent log lines
Re-addressed by the current identity function: this incident inherited
e4a97855ab595beb(Systemorph/MeshWeaver.Plugins#1796). Those nodes are superseded and will not fold, file or comment again.rbuergi commentedon Sep 20, 2026
The blocked destination is a POD HUB, which makes #2299 a candidate root for this issue
Every sample of this fingerprint names a
cache/…address as the destination the legs are queued behind —cache/ezttSXFWDEWtWNpLDcHDnw,cache/9Z2FQR1aPUm3BQnNOaNwVQ,cache/Shh_fzr3fESzr5O_xZt8QA. That is not an incidental detail.What a
cache/…address issrc/MeshWeaver.Connection.Orleans/IPodHubGrain.cs:7lists it among the pod-hub addresses by name:and
MeshWeaver.Hosting/MeshNodeStreamCache.cs:650mints it per process:So the destination the legs pile up behind is a per-pod infrastructure hub reached through
IPodHubGrain— which is precisely the subject of #2299, "RoutingGrain turns a stale pod-hub route into a sender-visible DeliveryFailure instead of re-resolving it".Why that would produce exactly this signature
#2299 records that the routing layer "has no step that invalidates a stale pod-hub route and re-resolves it", and — the part that matters here — that Orleans was not treating the condition as terminal:
Put that against this line's own accounting of a dispatch slot:
A leg aimed at a pod hub whose pod is gone is held for the whole re-resolve/retry window. Every subsequent message for that same address queues behind it. That is a 62-deep per-destination queue on one address while the other destinations sit at 0 — which is the shape reported here, and it is a different statement from the load-shaped crossings (deepest queue
0) that the same log line also produces.🚨 What this is and is not
Deliverforwarded to an activation already givenDeactivateOnIdle, re-forwarded untilForwardCounttrips) would show as a re-activation loop rather than a single stalled leg, and those are distinguishable.Why this issue stays open and the others did not
12 further reports of this line arrived overnight (#4936–#4947, roughly one an hour) and were closed onto this one — they are duplicates minted by an unnormalized activation id on the undeployed log-watcher (Systemorph/MeshWeaver.Plugins#2156), not 12 events. This issue is the one kept open deliberately, because a non-zero deepest queue is head-of-line blocking rather than load, and that is a real defect regardless of how many tickets the fingerprinting produces.
2026-09-20, Claude Opus 5 — read-only; source quoted from current
main.rbuergi commentedon Sep 21, 2026
Closes as duplicate of #5009 — Migrated: the recurrence seven minutes after #4903's window with higher episode stamps on the same activations (
eb59bdbb#2→#4 then #5→#6) — the proof that the block clears and re-forms rather than leaking. Now in §3 of the canonical.