Skip to content

Routing dispatch legs stall 10–14s in downstream delivery, saturating the RoutingGrain pool (64-slot cap) on the portal silo #5351

Closed as not planned

Description

@systemorph-com

What is failing

The RoutingGrain on the portal pod hit its route-dispatch back-pressure threshold (64 in flight) repeatedly over ~90 seconds, with 44–60 dispatch legs waiting for a routing-pool slot. Stream-routed message delivery on this silo was delayed by roughly 10–14 seconds per leg during the burst.

Probable cause (medium-high confidence)

This is a downstream I/O slowdown, not a slot leak and not a thread starvation. The log's own gauges distinguish the cases, and they agree here:

So the routing pool is draining, but each leg's downstream delivery (stream dispatch to destinations like Approvals/Desk, */_Activity/compile-state hubs) is taking seconds, enough to pile 60+ legs up against the pool's cap.

Impact

34 occurrences in one 90-second window on a single portal pod (memex-portal-deployment-5c444645f8-8pdzb), self-resolving — a burst of user-visible dispatch latency rather than an outage. However, this is one of dozens of near-identical RoutingGrain back-pressure incidents across 19–21 September on the same deployment, so whatever is slowing downstream delivery is recurring and worth correlating.

Where to look

Possibly a duplicate — many sibling RoutingGrain back-pressure incidents were opened 2026-09-19 → 2026-09-21 with the same gauge signature; if one of those was filed, this can be closed against it.


Evidence

Fingerprint 78f1b09427c7d92a
Category MeshWeaver.Hosting.Orleans.RoutingGrain
Severity Critical
Namespace memex-cloud
Pods memex-portal-deployment-5c444645f8-8pdzb
Occurrences 34
First seen 2026-09-22 14:50:08Z
Last seen 2026-09-22 14:51:39Z
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 14:50:53Z memex-portal-deployment-5c444645f8-8pdzb crit: MeshWeaver.Hosting.Orleans.RoutingGrain[0]
      [ROUTE] Routing back-pressure [f78403df#2 started 2026-09-22T14:50:53.1555507Z]: 64 route dispatches in flight (reporting threshold 64); ordered channels queued 1 over 1 stream destination(s), deepest per-channel queue 0, routing pool subscribing 1, waiting for a pool slot 60; oldest leg in flight 8313 ms — dispatch → Approvals/Desk (delivery 2OJIlTp7Ak6Sv0engcRhNA). Latest dispatch target mkleiner/_Install/ICloud — 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…[truncated]
2026-09-22 14:51:03Z memex-portal-deployment-5c444645f8-8pdzb crit: MeshWeaver.Hosting.Orleans.RoutingGrain[0]
      [ROUTE] Routing back-pressure [f78403df#3 started 2026-09-22T14:51:03.8201801Z]: 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 10669 ms — dispatch → AppleMaps/Maps/_Activity/compile-state (delivery Wt31Au2cRkKGsjE63NJ4YQ). Latest dispatch target AppleMusic/_Entitlements/robert.salzmann — 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 14:51:14Z memex-portal-deployment-5c444645f8-8pdzb crit: MeshWeaver.Hosting.Orleans.RoutingGrain[0]
      [ROUTE] Routing back-pressure [f78403df#4 started 2026-09-22T14:51:14.2084100Z]: 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 44; oldest leg in flight 13848 ms — dispatch → Chess/History/_Activity/compile-state (delivery ahKGYEzav0G7N77hh-7jzg). Latest dispatch target AgenticBusiness — 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 14:51:25Z memex-portal-deployment-5c444645f8-8pdzb crit: MeshWeaver.Hosting.Orleans.RoutingGrain[0]
      [ROUTE] Routing back-pressure [f78403df#5 started 2026-09-22T14:51:25.0647928Z]: 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 47; oldest leg in flight 10776 ms — dispatch → Edu/Lesson/_Activity/compile-state (delivery crB4jKFtpEuHhZuCsUE_Fg). Latest dispatch target AppleMaps/_Access/bing_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 CROSSING, s…[truncated]
2026-09-22 14:51:39Z memex-portal-deployment-5c444645f8-8pdzb crit: MeshWeaver.Hosting.Orleans.RoutingGrain[0]
      [ROUTE] Routing back-pressure [f78403df#6 started 2026-09-22T14:51:39.7940013Z]: 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 44; oldest leg in flight 14300 ms — dispatch → Governance/Activity/_Activity/compile-state (delivery RYWjtKMTHEGuEh9dcXyvpg). Latest dispatch target mkleiner/_Install/ICloud — 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 CROSSIN…[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/78f1b09427c7d92a. 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

    Duplicate of #5118, where the whole family is now consolidated with its cause, its two queued fixes and the verification that is still owed.

    Short version: the load was real and caused by NodeType compiles holding the silo's shared ThreadPool (#5327, queued); the reason each episode minted its own ticket is that every crossing logged at Critical (#5322, queued, levels it by shape) against a normaliser that leaves the per-episode activation id unmasked (#5270/#5271). Nothing is lost by closing this — the per-instance variation is that identity defect.

    Neither fix is deployed yet, so if crossings keep arriving at Critical with deepest = 0 after they roll, reopen against #5118 rather than filing fresh.

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