Skip to content

Routing pool saturates under ThreadPool starvation — dispatch legs stall waiting for pool slots on portal pods #5249

Closed as not planned

Description

@systemorph-com

What is failing

The Orleans routing grain (MeshWeaver.Hosting.Orleans.RoutingGrain) repeatedly saturates its routing-dispatch pool: 64 legs in flight hit the reporting threshold on both portal pods, with tens of legs parked in waiting for a pool slot while routing pool subscribing reads 0.

Probable cause — medium confidence

Per the log site's own gauge semantics (subscribing=0 with a high pool-slot wait means legs are stuck before their subscribe prologue, i.e. waiting on a ThreadPool thread), this is ThreadPool starvation / a CPU-starved silo under burst load — the pool hands out slots but the leg cannot start. The evidence for load-not-leak is strong: every oldest-leg value is young (4 ms–2 s), the episode counter on activation 73be63b4 escalated #2→#3 (the earlier episode drained), and no channel shows deep head-of-line queuing (deepest queues 0–7 over 1–3 destinations). Cannot confirm from this incident alone whether the true fix is more silo CPU/threads or a larger/bounded pool — that needs a follow-up line (a clear or higher-episode stamp) and the pool's cap value, which the log does not print.

Impact

Five occurrences inside 21 seconds across both portal pods, part of a much larger recurring pattern: 50+ sibling back-pressure incidents from this same log site since 2026-09-21. Each episode in these samples appears self-draining (no evidence of a leaked slot), so the impact is episodic routing latency/queueing during load bursts rather than a hard outage — severity M. If any sibling episode shows an oldest leg of minutes, that one is a slot leak and should be re-ruled to blocking.

Where to look

The dispatch/leg lifecycle in MeshWeaver.Hosting.Orleans.RoutingGrain — specifically the pool-slot acquisition path before the subscribe prologue, and the unbounded pre-subscribe ThreadPool wait the log documents (compare issues #5009 and #5018 referenced in the message). Grep category MeshWeaver.Hosting.Orleans.RoutingGrain[0], message [ROUTE] Routing back-pressure. No RoutingGrain source was reachable in the mesh to link directly.

Note for the filer: many near-duplicate incidents exist for this log site; a human may want to consolidate them under one ticket.


Evidence

Fingerprint 47a839579445b639
Category MeshWeaver.Hosting.Orleans.RoutingGrain
Severity Critical
Namespace memex
Pods memex-portal-deployment-7f4f9b7689-d67t5, memex-portal-deployment-5c99d79997-xs87x
Occurrences 5
First seen 2026-09-22 17:35:10Z
Last seen 2026-09-22 17:35:31Z
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 17:35:10Z memex-portal-deployment-7f4f9b7689-d67t5 crit: MeshWeaver.Hosting.Orleans.RoutingGrain[0]
      [ROUTE] Routing back-pressure [3ea815dc#1 started 2026-09-22T17:35:10.6225591Z]: 64 route dispatches in flight (reporting threshold 64); ordered channels queued 48 over 3 stream destination(s), deepest per-channel queue 7, routing pool subscribing 0, waiting for a pool slot 1; oldest leg in flight 398 ms — dispatch → UWDeepfield/CatastropheModel/_Activity/compile-state (delivery rvh1wvAizE-kyxvp6PVQSg). Latest dispatch target cache/1QAwYRsEEECyTahoEnMnPg — 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 …[truncated]
2026-09-22 17:35:29Z memex-portal-deployment-5c99d79997-xs87x crit: MeshWeaver.Hosting.Orleans.RoutingGrain[0]
      [ROUTE] Routing back-pressure [73be63b4#2 started 2026-09-22T17:35:29.2208141Z]: 64 route dispatches in flight (reporting threshold 64); ordered channels queued 2 over 1 stream destination(s), deepest per-channel queue 0, routing pool subscribing 0, waiting for a pool slot 39; oldest leg in flight 141 ms — dispatch → LinkedIn/Learning (delivery HcIq7PjNLUC8yUJmZRWtVg). Latest dispatch target Hosting/MissingFeatureDiagnosis/_Access/Anonymous_Access — 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 CRO…[truncated]
2026-09-22 17:35:29Z memex-portal-deployment-7f4f9b7689-d67t5 crit: MeshWeaver.Hosting.Orleans.RoutingGrain[0]
      [ROUTE] Routing back-pressure [d2faf60c#1 started 2026-09-22T17:35:29.2697521Z]: 64 route dispatches in flight (reporting threshold 64); ordered channels queued 51 over 2 stream destination(s), deepest per-channel queue 0, routing pool subscribing 0, waiting for a pool slot 46; oldest leg in flight 4 ms — stream-routed → cache/8vueoRAunUm0rJkh9e1u0g (delivery FkTXM30gTUi7yVrCaQId0g). Latest dispatch target cache/8vueoRAunUm0rJkh9e1u0g — 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 lik…[truncated]
2026-09-22 17:35:30Z memex-portal-deployment-5c99d79997-xs87x crit: MeshWeaver.Hosting.Orleans.RoutingGrain[0]
      [ROUTE] Routing back-pressure [73be63b4#3 started 2026-09-22T17:35:30.0473607Z]: 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 45; oldest leg in flight 832 ms — dispatch → Providers (delivery a6Hip-_G80-ut9f4paAwdw). Latest dispatch target Admin/Build/DefaultViews — 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…[truncated]
2026-09-22 17:35:31Z memex-portal-deployment-7f4f9b7689-d67t5 crit: MeshWeaver.Hosting.Orleans.RoutingGrain[0]
      [ROUTE] Routing back-pressure [d2faf60c#2 started 2026-09-22T17:35:31.3160362Z]: 64 route dispatches in flight (reporting threshold 64); ordered channels queued 33 over 1 stream destination(s), deepest per-channel queue 1, routing pool subscribing 0, waiting for a pool slot 10; oldest leg in flight 2049 ms — dispatch → Hosting/FleetWatch (delivery iJENzYuqMka2tTfqw9zfxw). Latest dispatch target cache/1QAwYRsEEECyTahoEnMnPg — 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-fli…[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/47a839579445b639. Recurrences are folded into this issue rather than opening new ones.

Activity

  1. added
    bugSomething isn't working
    sev:MMedium - secondary path broken, or easy workaround
    on Sep 22, 2026
  2. rbuergi commented on Sep 22, 2026

    @rbuergi
    Contributor

    Closing as a duplicate of #5118 — the fingerprint-split flood.

    Why this is a duplicate. Every one of these comes from the same log site — [ROUTE] Routing back-pressure, category MeshWeaver.Hosting.Orleans.RoutingGrain — split into one issue per grain activation. The 8-hex activation id survived normalization (a0e2984b → a0e2{n}b): HexBlob required 16+ chars, and Number() then masked only the digit-run preceded by a digit, leaving a per-activation residue in the hash.

    Measured over 101 verbatim bursts drawn from 29 issues, covering 42 activation ids: the old parser yields 41 distinct fingerprints, the current parser yields 1.

    The fix is already merged in MeshWeaver.Plugins — #2165 (MixedHexId), #2167, #2168 (positional episode/target masking) and #2218 (the portal re-parses raw samples, instead of hashing text a stale watcher already masked).

    It is not live yet. The control instance is sealed on an older set because the Plugins Portal image rebuild workflow fails at its GitHub App token step — actions: write is not granted to the installation — so core's rebuild is never dispatched. Until that is granted, new split issues will keep arriving, and an issue whose activation is still alive may reopen here.

    Not closed by this. The underlying routing condition — cache-destination head-of-line blocking versus ThreadPool starvation — is a real defect and stays open in #5118. The normaliser itself is tracked in #5270 and #5271.

  3. rbuergi commented on Sep 22, 2026

    @rbuergi
    Contributor

    Why this is its own issue, and what stops the next one — posted on each RoutingGrain back-pressure incident issue filed 2026-09-22; not a disposition of this one.

    This incident's fingerprint was split from its siblings by two values the incident normaliser did not mask — the delivery id and a single-segment destination in the line's oldest leg in flight … — dispatch → <address> (delivery <id>) field — not by the episode stamp, which was already masked. Fixed in Systemorph/MeshWeaver.Plugins#2286 (merged 2026-09-22T21:46Z as b922f070fc): over the 146 back-pressure samples quoted in the open core issues (43 filed fingerprints), the identity now yields 3 (one per leg kind, plus the pre-#5151 wording). It reaches production with the portal roll; existing incidents re-address onto their successors through LogIncidentCorpusMigration.

    What the crossing itself means is a separate question and is not answered by the fix above. A line reading high waiting for a pool slot with routing pool subscribing 0 is legs the ThreadPool had not yet run (the pool's cap is 256 and no permit is held — see #5261 (comment)); that starvation root is being investigated separately (family: #5018, #4886). A line with a non-zero deepest per-channel queue on a cache/… destination and an old oldest leg is #5009's falsifier and should be raised there.

    Disposition stays with triage: a symptom gauge can invert the causal arrow, so this issue's own sample may carry evidence its siblings do not.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    bugSomething isn't workingsev:MMedium - secondary path broken, or easy workaround

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions