Skip to content

RoutingGrain back-pressure episodes on portal pod: dispatch pool saturated by ThreadPool wait during burst, threshold 64 crossed repeatedly #5416

Closed as not planned

Description

@systemorph-com

What is failing

The Orleans routing grain on the memex-cloud portal pod hit its route-dispatch back-pressure threshold (64 legs in flight), meaning stream routing was momentarily saturating its dispatch pool and new legs had to queue for pool slots.

Probable cause

Most likely transient load, not a defect — confidence moderate. The line's own gauges point that way: across all four samples the oldest leg in flight is 21–185 ms (all legs young — the load-vs-leak discriminator the log text names), ordered channel queues are 0 or draining (61 over 5 destinations then 0), and waiting for a pool slot is high (17–60) while routing pool subscribing is 0. Per the log's own diagnostics that combination reads as a ThreadPool/thread shortage on the silo absorbing a burst — legs waiting for a ThreadPool thread before their subscribe — with nothing stuck and no head-of-line blocking. No exception was logged, and there is no evidence a slot leaked (no minutes-old leg). It is worth noting that several dozen sibling back-pressure incidents of the same shape were opened on this log site within the surrounding hours, so the silo's thread pool appears repeatedly under pressure; whether that is a capacity/tuning question (pool cap vs. dispatch threshold) or an upstream burst pattern needs a human with the full log history.

Impact

Minimal as a single episode: 4 occurrences on one pod within ~29 seconds, all with young legs, and the episodes drained on their own. No user-visible failure is evidenced. If the sibling incidents continue to recur, elevated latency on stream-routed deliveries is the exposure.

Where to look

MeshWeaver.Hosting.Orleans.RoutingGrain — the route-dispatch pool sizing and the ThreadPool wait before a leg's subscribe prologue (the gauge split described in issues #5009 and #5018). No framework source for this grain was found in the mesh, so start from the repo's own Orleans hosting sources.

Note: this is one of many near-identical back-pressure incidents opened in this window (e.g. Admin/_LogIncident/1558f61997698782, Admin/_LogIncident/6f705fb904e816d6, and ~50 more); likely a duplicate family — a human may close this in favour of one systemic ticket.


Evidence

Fingerprint 032e11bf437f5f04
Category MeshWeaver.Hosting.Orleans.RoutingGrain
Severity Critical
Namespace memex-cloud
Pods memex-portal-deployment-857546649-vf2q6
Occurrences 4
First seen 2026-09-22 22:53:23Z
Last seen 2026-09-22 22:53:52Z
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:53:23Z memex-portal-deployment-857546649-vf2q6 crit: MeshWeaver.Hosting.Orleans.RoutingGrain[0]
      [ROUTE] Routing back-pressure [9bff309f#3 started 2026-09-22T22:53:23.6484815Z]: 64 route dispatches in flight (reporting threshold 64); ordered channels queued 61 over 5 stream destination(s), deepest per-channel queue 0, routing pool subscribing 0, waiting for a pool slot 17; oldest leg in flight 185 ms — stream-routed → cache/41czPxYhBke8Yz-MPeDDVQ (delivery FGBzGOvTrEuMfosfluAX6w). Latest dispatch target Admin/_PluginGrant/memex — 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 …[truncated]
2026-09-22 22:53:51Z memex-portal-deployment-857546649-vf2q6 crit: MeshWeaver.Hosting.Orleans.RoutingGrain[0]
      [ROUTE] Routing back-pressure [49e69485#1 started 2026-09-22T22:53:51.3441960Z]: 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 46 ms — dispatch → Manufacturing/WorkOrder/_Activity/compile-state (delivery yBHtHXBgrECgVryPR632UQ). Latest dispatch target Hosting/TriageStatus — 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, …[truncated]
2026-09-22 22:53:51Z memex-portal-deployment-857546649-vf2q6 crit: MeshWeaver.Hosting.Orleans.RoutingGrain[0]
      [ROUTE] Routing back-pressure [49e69485#2 started 2026-09-22T22:53:51.6661150Z]: 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 109 ms — dispatch → ReinsuranceDemo/Installer (delivery iC158yOvGU20qJHn4WOu4A). Latest dispatch target EventMonitoring/PerilEvent — 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-…[truncated]
2026-09-22 22:53:52Z memex-portal-deployment-857546649-vf2q6 crit: MeshWeaver.Hosting.Orleans.RoutingGrain[0]
      [ROUTE] Routing back-pressure [49e69485#3 started 2026-09-22T22:53:52.2124225Z]: 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 60; oldest leg in flight 21 ms — dispatch → Claims/Enquiry/_Activity/compile-state (delivery Ctiym1GC_EWpDVA9HQI6Xg). Latest dispatch target Ifrs17/RiskDriver — 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]

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/032e11bf437f5f04. 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-vf2q6. 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 22:53:23Z → 2026-09-22 22:53:52Z, 4 occurrence(s), fingerprint 032e11bf437f5f04.

    activation#episode started waiting subscribing deepest channels / dest oldest leg
    9bff309f#3 22:53:23Z 17 0 0 61 / 5 185 ms
    49e69485#1 22:53:51Z 58 0 0 0 / 0 46 ms
    49e69485#2 22:53:51Z 47 0 0 0 / 0 109 ms
    49e69485#3 22:53:52Z 60 0 0 0 / 0 21 ms

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