Skip to content

Routing saturation crossings on memex-cloud are a ThreadPool thread shortage (legs young, pool-wait high); the unmasked episode stamp splits this log site into one incident per grain activation #5410

Closed as not planned

Description

@systemorph-com

What is failing

Nothing in routing is stuck. The RoutingGrain saturation gauge (a log call gated at 64 in-flight dispatches, nothing more — see Reading a Routing Saturation Report) crossed the threshold repeatedly in one short window on the memex-cloud portal, across all its pods. Read per the report's own reading order, every retained sample is the load verdict: deepest per-channel queue 0 with ordered channels queued 0 over 0 destinations (no head-of-line anywhere), oldest leg in flight milliseconds only (no leaked slot — every leg young), and rising episode stamps on the same activation proving each episode drained.

Probable cause

The two pool gauges name it directly: waiting for a pool slot read 40–61 while routing pool subscribing sat at 0–2 — far below the routing pool's cap. Per the report (and IIoPool.CurrentlyWaiting's own XML doc), waiting-high-while-subscribing-low means legs parked before their subscribe prologue waiting for a ThreadPool thread — a thread/CPU starvation episode on the silo, not a routing defect and not a slot shortage. Confidence: high on the thread-shortage reading (the gauge pair is the designed discriminator); unknown on what starved the process — that is not determinable from these lines. Before treating this as anything routing-internal, rule the process out per the doc: an OutOfMemoryException, a LocalSiloHealthMonitor "Thread Pool execution stalled", or an Orleans placement timeout on the same pods in the same window is upstream of this line.

Secondary defect worth fixing: the episode stamp is not masked

The fingerprint's masked template retains a literal fragment of the grain activation hex (the fb7-style token inside [<activation>#<episode> started …]), so every new grain activation mints a new fingerprint from the one log site — this incident is one of dozens of sibling back-pressure incidents in Admin/_LogIncident, and the site's already-consolidated ticket history (~87 filings folded onto 3) is the same pattern. The masking rule (LogLineParser.Normalize) needs a case for the activation#episode stamp, so one fault at this site stops opening one ticket per activation.

Impact

Transient: every episode drained, no leg held a slot, no delivery loss is evidenced. The gauge was the instrument that noticed the process being starved, not the cause. Judged from the numbers this is an operational signal (thread starvation on one portal fleet-wide for a few minutes), not an outage; severity reflects that no primary path is broken.

This is a member of the long-known, already-consolidated routing back-pressure family — a human can likely close it as such in seconds — but it also carries the new thread-shortage signature that the pre-fix lines in the surviving tickets could not show.

Where to look

  • MeshWeaver.Hosting.Orleans.RoutingGrain — the saturation report and RoutingGrain.SaturationThreshold (gates a log call only; do not raise it to the pool cap — different populations, see the doc's category-error section).
  • Reading a Routing Saturation Report — the reading order used above; Controlled I/O Pooling for the two pool gauges.
  • Masking: LogLineParser.Normalize / StructuralLogIncidentIdentity.Compute — the unmasked activation-hex fragment.
  • Downstream: memex-cloud pod logs for the same window (OOM / health-monitor stall / placement timeout) to find what starved the threads.

Evidence

Fingerprint 3851cef51e8b9fa0
Category MeshWeaver.Hosting.Orleans.RoutingGrain
Severity Critical
Namespace memex-cloud
Pods memex-portal-deployment-857546649-xx9j4, memex-portal-deployment-857546649-vf2q6, memex-portal-deployment-857546649-2c25b
Occurrences 13
First seen 2026-09-22 19:12:00Z
Last seen 2026-09-22 19:18: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 19:12:41Z memex-portal-deployment-857546649-vf2q6 crit: MeshWeaver.Hosting.Orleans.RoutingGrain[0]
      [ROUTE] Routing back-pressure [1c963883#2 started 2026-09-22T19:12:41.2868681Z]: 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 93 ms — dispatch → AppleMusic/_Entitlements/markus.staeger (delivery 6L-SNxn8d0SvbqaUimz92w). Latest dispatch target rhodmorris/_Install/Northwind — 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 19:13:00Z memex-portal-deployment-857546649-xx9j4 crit: MeshWeaver.Hosting.Orleans.RoutingGrain[0]
      [ROUTE] Routing back-pressure [68500fb7#5 started 2026-09-22T19:13:00.4042700Z]: 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 11 ms — dispatch → TaskManagement/_Entitlements/_Policy (delivery x5Jx0Eqj40OMQ1gcUb_p3A). Latest dispatch target Underwriting/AppetiteMetric/_Activity/compile-state — 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 sampl…[truncated]
2026-09-22 19:15:40Z memex-portal-deployment-857546649-vf2q6 crit: MeshWeaver.Hosting.Orleans.RoutingGrain[0]
      [ROUTE] Routing back-pressure [1c963883#3 started 2026-09-22T19:15:40.0424531Z]: 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 1, waiting for a pool slot 61; oldest leg in flight 4 ms — dispatch → Publish/_Entitlements/_Policy (delivery uo2Y53m8y06zP8eTc0NscA). Latest dispatch target OpenStreetMap/_Policy — 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]
2026-09-22 19:18:42Z memex-portal-deployment-857546649-2c25b crit: MeshWeaver.Hosting.Orleans.RoutingGrain[0]
      [ROUTE] Routing back-pressure [33ed7faf#1 started 2026-09-22T19:18:42.5721693Z]: 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 1, waiting for a pool slot 40; oldest leg in flight 25 ms — dispatch → MeshWeaver/samples/Graph/Data/FutuRe/LineOfBusiness/Source/LineOfBusiness (delivery mxy9hJhLwkKilTPKYKYnfw). Latest dispatch target Systemorph/Event/Venue/_Activity/compile-state — 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 s…[truncated]
2026-09-22 19:18:42Z memex-portal-deployment-857546649-2c25b crit: MeshWeaver.Hosting.Orleans.RoutingGrain[0]
      [ROUTE] Routing back-pressure [33ed7faf#2 started 2026-09-22T19:18:42.5949044Z]: 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 2, waiting for a pool slot 56; oldest leg in flight 5 ms — dispatch → Systemorph/Underwriting/Layer (delivery nWZwyqVsNkGC2ySFoldgeA). Latest dispatch target MeshWeaver/samples/Graph/Data/PensionFund/Position/_Activity/compile-state — 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. 🚨 D…[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/3851cef51e8b9fa0. 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-xx9j4, memex-portal-deployment-857546649-vf2q6, memex-portal-deployment-857546649-2c25b. 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 19:12:00Z → 2026-09-22 19:18:42Z, 13 occurrence(s), fingerprint 3851cef51e8b9fa0.

    activation#episode started waiting subscribing deepest channels / dest oldest leg
    1c963883#2 19:12:41Z 61 0 0 0 / 0 93 ms
    68500fb7#5 19:13:00Z 61 0 0 0 / 0 11 ms
    1c963883#3 19:15:40Z 61 1 0 0 / 0 4 ms
    33ed7faf#1 19:18:42Z 40 1 0 0 / 0 25 ms
    33ed7faf#2 19:18:42Z 56 2 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 93 ms, so no leg is minutes old and no slot leaked. Episodes keep advancing on the same activation (1c963883, 33ed7faf), 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