Repository navigation
RoutingGrain back-pressure episodes from pre-subscribe ThreadPool waits, not slot leaks or channel head-of-line blocking #5411
Description
What is failing
The Orleans RoutingGrain (MeshWeaver.Hosting.Orleans) hit its route-dispatch back-pressure threshold: 64 dispatches in flight on a reporting threshold of 64. All three sampled lines show zero ordered-channel queuing (0 channels, deepest queue 0) and routing pool subscribing 0 — this burst was neither a channel head-of-line block nor slow subscriptions. The distinguishing gauge is "waiting for a pool slot": 0 in the first line (22:09), then 31 and 42 in the later two lines (22:19–22:20). The oldest leg in flight was 14–42 ms — young.
Probable cause
The evidence (moderate-to-high confidence) says this is ThreadPool starvation / load the silo was absorbing, not a slot leak or a routing defect:
- Every leg is young (14–42 ms) — the log's own guidance is that "every leg young is load the silo is absorbing".
subscribing 0whilewaiting for a pool slotis 31–42 means the legs are stalled before their subscribe prologue — per issue RoutingGrain dispatch pool saturates repeatedly on portal silos; slots held through unbounded ThreadPool wait and episode-stamp splitting floods incidents #5018, that gauge is the one that sees the pre-subscribe wait. Legs past their subscribe would read as downstream I/O; these have not got there yet.- Zero channel queuing rules out head-of-line blocking within a stream (issue RoutingGrain dispatch slots saturate with legs head-of-line blocked behind one shared-cache destination while the second pod starves on load #5009's failure mode).
- The slot is held from dispatch until leg termination including the unbounded wait for a ThreadPool thread, so a CPU-starved silo raises exactly this line with nothing genuinely stuck. The rising wait-for-slot count (0 → 31 → 42) is consistent with the ThreadPool queuing up during a load burst.
I cannot fully rule out a slot leak from a single line — that needs a follow-up line showing neither a higher episode nor a drain on activation 19a9d1ee/eb5398a8 — but the young legs and non-zero wait gauge make "transient ThreadPool pressure under load" the far better supported reading. Note the "dispatch →" destinations are just the address that crossed the threshold, not a diagnosis.
Impact
Low, so far: 3 occurrences in an 11-minute window (2026-09-22 22:09–22:20 UTC) across 2 pods of memex-cloud, young legs throughout, no evidence of persistence beyond the window. No user-visible failure is evidenced. Worth watching for a repeat burst with a minutes-old oldest leg or a wait-for-slot count that never drains — that would indicate a real leak.
Where to look
MeshWeaver.Hosting.Orleans.RoutingGrain — start from the code path that acquires a routing-pool slot before the subscribe prologue and the ThreadPool wait preceding it. Correlate silo CPU/ThreadPool-queue metrics for the memex-portal pods around 22:09–22:20 UTC on 2026-09-22. Possible duplicate of #5145 (same log site, filed 2026-09-21, transient-load interpretation on the older per-destination message format) — this new message format with the wait-for-slot gauge gives stronger evidence for the thread-starvation reading; close as duplicate if the team prefers to track under #5145.
Evidence
| Fingerprint | 661754e45f4d52de |
| Category | MeshWeaver.Hosting.Orleans.RoutingGrain |
| Severity | Critical |
| Namespace | memex-cloud |
| Pods | memex-portal-deployment-857546649-2c25b, memex-portal-deployment-857546649-vf2q6 |
| Occurrences | 3 |
| First seen | 2026-09-22 22:09:11Z |
| Last seen | 2026-09-22 22:20:42Z |
| Routing | not determined — no configured route matches the category MeshWeaver.Hosting.Orleans.RoutingGrain. This repository is the configured fallback, not a finding about who owns the fault; the category names the LOGGER, which may not be the subject. |
Recent log lines
2026-09-22 22:09:11Z memex-portal-deployment-857546649-2c25b crit: MeshWeaver.Hosting.Orleans.RoutingGrain[0]
[ROUTE] Routing back-pressure [19a9d1ee#1 started 2026-09-22T22:09:11.4527498Z]: 64 route dispatches in flight (reporting threshold 64); ordered channels queued 0 over 0 stream destination(s), deepest per-channel queue 0, routing pool subscribing 0, waiting for a pool slot 0; oldest leg in flight 14 ms — dispatch → Hosting/Admin (delivery R0vpCzmRMkeVL7iWbokyvA). Latest dispatch target GoogleMaps/Gallery — 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 CHANNEL is (destination, stream), so a deepest queue of 1 or more means legs of the SAME stream are blocked behind one another (head-of-line within one channel); 0 means nothing is waiting on anything, so read it as load. Many channels over FEW destinations is a multiplexer hub draining in parallel, which is load too — before issue #5009 those legs shared one channel and read as head-of-line. 🚨 THE TWO POOL GAUGES ANSWER DIFFERENT QUESTIONS AND ONLY ONE SEES THE WAIT NAMED ABOVE — issue #5018. 'subscribing' counts legs inside their SUBSCRIBE PROLOGUE only, so a leg still waiting for a ThreadPool thread and a leg already past its subscribe BOTH read 0 there; 'waiting for a pool slot' is the gauge that sees the pre-subscribe wait. High while subscribing is below the pool's cap is a THREAD shortage; both near zero means the legs are past their subscribe and the wait is downstream I/O. 🚨 READ THE OLDEST LEG FIRST: it is the only load-vs-leak discriminator available from a SINGLE line — every leg young is load the silo is absorbing, one leg minutes old is a slot that never came back and the label names it — whereas the episode stamp below needs a SECOND line to say anything. 🚨 Deepest is sampled AT THE CROSSING, so like the in-flight count it is par…[truncated]
2026-09-22 22:19:40Z memex-portal-deployment-857546649-vf2q6 crit: MeshWeaver.Hosting.Orleans.RoutingGrain[0]
[ROUTE] Routing back-pressure [eb5398a8#13 started 2026-09-22T22:19:40.1062569Z]: 64 route dispatches in flight (reporting threshold 64); ordered channels queued 0 over 0 stream destination(s), deepest per-channel queue 0, routing pool subscribing 0, waiting for a pool slot 31; oldest leg in flight 42 ms — dispatch → Reinsurance/ModelledReinsuranceSection (delivery GtzDxrGkyEesIr3g6NMtMA). Latest dispatch target Feedback/Feedback — 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 CHANNEL is (destination, stream), so a deepest queue of 1 or more means legs of the SAME stream are blocked behind one another (head-of-line within one channel); 0 means nothing is waiting on anything, so read it as load. Many channels over FEW destinations is a multiplexer hub draining in parallel, which is load too — before issue #5009 those legs shared one channel and read as head-of-line. 🚨 THE TWO POOL GAUGES ANSWER DIFFERENT QUESTIONS AND ONLY ONE SEES THE WAIT NAMED ABOVE — issue #5018. 'subscribing' counts legs inside their SUBSCRIBE PROLOGUE only, so a leg still waiting for a ThreadPool thread and a leg already past its subscribe BOTH read 0 there; 'waiting for a pool slot' is the gauge that sees the pre-subscribe wait. High while subscribing is below the pool's cap is a THREAD shortage; both near zero means the legs are past their subscribe and the wait is downstream I/O. 🚨 READ THE OLDEST LEG FIRST: it is the only load-vs-leak discriminator available from a SINGLE line — every leg young is load the silo is absorbing, one leg minutes old is a slot that never came back and the label names it — whereas the episode stamp below needs a SECOND line to say anything. 🚨 Deepest is sampled AT THE CROSSING, so like the…[truncated]
2026-09-22 22:20:42Z memex-portal-deployment-857546649-2c25b crit: MeshWeaver.Hosting.Orleans.RoutingGrain[0]
[ROUTE] Routing back-pressure [19a9d1ee#2 started 2026-09-22T22:20:42.5815464Z]: 64 route dispatches in flight (reporting threshold 64); ordered channels queued 0 over 0 stream destination(s), deepest per-channel queue 0, routing pool subscribing 0, waiting for a pool slot 42; oldest leg in flight 33 ms — dispatch → YouTube/Dashboard (delivery 2Xts0pZL8EClT9Ymf7Bg5g). Latest dispatch target AppleMaps/Maps — 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 CHANNEL is (destination, stream), so a deepest queue of 1 or more means legs of the SAME stream are blocked behind one another (head-of-line within one channel); 0 means nothing is waiting on anything, so read it as load. Many channels over FEW destinations is a multiplexer hub draining in parallel, which is load too — before issue #5009 those legs shared one channel and read as head-of-line. 🚨 THE TWO POOL GAUGES ANSWER DIFFERENT QUESTIONS AND ONLY ONE SEES THE WAIT NAMED ABOVE — issue #5018. 'subscribing' counts legs inside their SUBSCRIBE PROLOGUE only, so a leg still waiting for a ThreadPool thread and a leg already past its subscribe BOTH read 0 there; 'waiting for a pool slot' is the gauge that sees the pre-subscribe wait. High while subscribing is below the pool's cap is a THREAD shortage; both near zero means the legs are past their subscribe and the wait is downstream I/O. 🚨 READ THE OLDEST LEG FIRST: it is the only load-vs-leak discriminator available from a SINGLE line — every leg young is load the silo is absorbing, one leg minutes old is a slot that never came back and the label names it — whereas the episode stamp below needs a SECOND line to say anything. 🚨 Deepest is sampled AT THE CROSSING, so like the in-flight count it is pa…[truncated]
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/661754e45f4d52de. Recurrences are folded into this issue rather than opening new ones.
Activity
rbuergi commentedon Sep 23, 2026
Duplicate of #5118.
Build: pod(s)
memex-portal-deployment-857546649-2c25b,memex-portal-deployment-857546649-vf2q6. ReplicaSet857546649runs3da3423c/3.0.0-ci.9193, which does not contain the compile-off-ThreadPool fix (#5327/#5375) (read fromOps/Status/memex-cloudversion 3130).Window 2026-09-22 22:09:11Z → 2026-09-22 22:20:42Z, 3 occurrence(s), fingerprint
661754e45f4d52de.19a9d1ee#1eb5398a8#1319a9d1ee#2This issue's own discriminator: thread-shortage (T) and past-subscribe (L) samples interleaved on the same pods. The oldest leg is at most 42 ms, so no leg is minutes old and no slot leaked. Episodes keep advancing on the same activation (
19a9d1ee), so each episode drained. It is the same log site and the same reading, sampled on the build without the fix. The cause, the fix, and the verification after memex rolls are recorded on #5118.