Skip to content

RoutingGrain dispatch pool saturates on ThreadPool-thread wait under load (known back-pressure family, episode dd9fe751#2–5) #5406

Closed as not planned

Description

@systemorph-com

What is failing

The RoutingGrain dispatch pool on the memex-portal silo repeatedly saturates: all 64 route-dispatch slots are held while 55–63 legs sit in the pre-subscribe wait for a ThreadPool thread (routing pool subscribing 0, waiting for a pool slot high). No dispatch leg is actually stuck — the oldest leg in every sample is 2–24 ms old, no channels are queued, and the episode counter on activation dd9fe751 advanced from #2 to #5 over 11 minutes, meaning each back-pressure episode drained.

Probable cause (moderate confidence)

A transient ThreadPool/thread shortage on the silo: a routing pool slot is held from dispatch until the leg terminates, which includes the unbounded wait for a ThreadPool thread before the leg's own timeouts start (see the diagnostic text in the log line itself and core issue #5018). With subscribing 0 and waiting for a pool slot high, legs are queuing on thread acquisition, not on downstream I/O or a leaked slot. The evidence is consistent with load the silo absorbed; it does not support a slot leak (that would show minutes-old legs and an episode that never clears).

Impact

5 occurrences over ~11 minutes on 2 of 2 portal pods, all episodes self-resolved — route dispatch latency spikes under thread pressure, no delivery loss established. This log site is a known flood source: dozens of sibling Critical incidents with the same shape exist (see the grouping evidence on core issue #5018), so the per-incident numbers understate a recurring fleet-wide condition. This specific ticket is a strong candidate for consolidation into the known family rather than a new defect.

Where to look

Suggested disposition: consolidate with the #5009/#5018 family; the actionable residual defect is the normaliser masking gap already handed over, plus investigating the silo thread-pool starvation that keeps pushing legs past the 64-slot cap.


Evidence

Fingerprint 2efbcbf62a705539
Category MeshWeaver.Hosting.Orleans.RoutingGrain
Severity Critical
Namespace memex-cloud
Pods memex-portal-deployment-857546649-2c25b, memex-portal-deployment-857546649-rb7qd
Occurrences 5
First seen 2026-09-22 20:27:42Z
Last seen 2026-09-22 20:38: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 20:27:42Z memex-portal-deployment-857546649-2c25b crit: MeshWeaver.Hosting.Orleans.RoutingGrain[0]
      [ROUTE] Routing back-pressure [dd9fe751#2 started 2026-09-22T20:27:42.5647621Z]: 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 57; oldest leg in flight 24 ms — dispatch → LinkedIn/RecommendationGiven (delivery ItduqPn9CE-6ChcKgFTSyg). Latest dispatch target RolePlay/Story — 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 cou…[truncated]
2026-09-22 20:28:14Z memex-portal-deployment-857546649-2c25b crit: MeshWeaver.Hosting.Orleans.RoutingGrain[0]
      [ROUTE] Routing back-pressure [dd9fe751#3 started 2026-09-22T20:28:14.3886807Z]: 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 63; oldest leg in flight 2 ms — dispatch → Claims/Claim (delivery _QmF5lnATUmb_wTYC8T66A). Latest dispatch target EventMonitoring/ClimateState — 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 20:31:16Z memex-portal-deployment-857546649-rb7qd crit: MeshWeaver.Hosting.Orleans.RoutingGrain[0]
      [ROUTE] Routing back-pressure [cf58ba84#5 started 2026-09-22T20:31:16.6576646Z]: 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 61; oldest leg in flight 3 ms — dispatch → Analysis/_Activity/import-manifest (delivery JnXAMmIGl0qQPB74akpgfA). Latest dispatch target LearningRoadmap/_Activity/import-manifest — 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 20:31:42Z memex-portal-deployment-857546649-2c25b crit: MeshWeaver.Hosting.Orleans.RoutingGrain[0]
      [ROUTE] Routing back-pressure [dd9fe751#4 started 2026-09-22T20:31:42.5627919Z]: 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 55; oldest leg in flight 13 ms — dispatch → Collaboration/_Issue/2281 (delivery gKmOzFVfxkKd2R9ox4UmwQ). Latest dispatch target Chess/_Activity/import-a90e88f7852cdb09 — 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 …[truncated]
2026-09-22 20:38:42Z memex-portal-deployment-857546649-2c25b crit: MeshWeaver.Hosting.Orleans.RoutingGrain[0]
      [ROUTE] Routing back-pressure [dd9fe751#5 started 2026-09-22T20:38:42.5923594Z]: 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 58; oldest leg in flight 5 ms — dispatch → Marketing/EventHub (delivery S75Dd0p310m5TSa29zu5uA). Latest dispatch target ILS/Pipeline — 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 part…[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/2efbcbf62a705539. 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 23, 2026
  2. rbuergi commented on Sep 23, 2026

    @rbuergi
    Contributor

    Duplicate of #5118.

    Build: pod(s) memex-portal-deployment-857546649-2c25b, memex-portal-deployment-857546649-rb7qd. ReplicaSet 857546649 runs 3da3423c / 3.0.0-ci.9193, which does not contain the compile-off-ThreadPool fix (#5327/#5375) (read from Ops/Status/memex-cloud version 3130).

    Window 2026-09-22 20:27:42Z → 2026-09-22 20:38:42Z, 5 occurrence(s), fingerprint 2efbcbf62a705539.

    activation#episode started waiting subscribing deepest channels / dest oldest leg
    dd9fe751#2 20:27:42Z 57 0 0 0 / 0 24 ms
    dd9fe751#3 20:28:14Z 63 0 0 0 / 0 2 ms
    cf58ba84#5 20:31:16Z 61 0 0 0 / 0 3 ms
    dd9fe751#4 20:31:42Z 55 0 0 0 / 0 13 ms
    dd9fe751#5 20:38:42Z 58 0 0 0 / 0 5 ms

    This issue's own discriminator: thread shortage (T): waiting for a pool slot high while subscribing ≤ 1. The oldest leg is at most 24 ms, so no leg is minutes old and no slot leaked. Episodes keep advancing on the same activation (dd9fe751), 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.

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