Skip to content

Route dispatch head-of-line blocked on a slow cache pod hub, throttling routing across the silo #4994

Closed as duplicate

Description

@systemorph-com

What is failing

The Orleans RoutingGrain (route dispatch) on the memex-portal pods repeatedly crossed its 64-dispatch in-flight threshold for ~2.5 minutes. On activation 458dc6c9 (pod …s246c) the crossing lines consistently report a deepest per-destination queue of 62 behind a single destination, cache/12xX8OXQIEmdwvf_ZZ8LjA — i.e. legs were queued behind one leg to that cache hub (real head-of-line blocking), while the same activation's other episodes and the second pod's activation (211c55d4, deepest queue 0) show plain load.

Probable cause

Medium confidence: deliveries to the cache pod hub cache/12xX8OXQIEmdwvf_ZZ8LjA were completing slowly or not at all, so nearly the entire in-flight budget (62 of 64 slots) piled up in that one destination's queue, throttling all route dispatch on the silo. The pattern is consistent with a slow or stuck consumer on that cache hub (cf. the known Ops/Logs pattern of directed delivery to cache hubs being refused on 2026-09-14). It is not a leaked slot: episode stamps advanced on the same activation (#2→#4 with the backlog, then #5 with deepest queue 0), meaning earlier episodes drained and the episode eventually cleared — but no cleared line was captured in the samples window, so a slow-draining or partially leaked episode cannot be fully ruled out.

Impact

7 occurrences over 2m19s on 2 of the memex-portal pods (both replicas of the same deployment), rated Critical by the logger. Route dispatch was throttled cluster-wide for a burst around 10:41–10:44 UTC on 2026-09-20; the backlog did drain (episode #5 reports no queuing), so this was a transient stall rather than a sustained outage. Worth confirming what the cache/12xX8OXQIEmdwvf_ZZ8LjA hub was doing at 10:41–10:44 UTC.

Where to look

  • MeshWeaver.Hosting.Orleans.RoutingGrain — the dispatch-slot accounting and per-destination queues.
  • The pod hub behind cache/12xX8OXQIEmdwvf_ZZ8LjA — what its leg was waiting on during the window (ThreadPool starvation vs. a genuinely slow consumer).
  • Context on the alert semantics and the previously fixed shutdown-slot leak: Doc/WhatsNew/2026-08-12-routing-alerts-name-what-they-actually-saw.
  • Earlier cache-hub delivery refusals for comparison: Ops/Logs/memex-1789415827319451765-6b6b44-klrt7 and neighbours (different fingerprint, 2026-09-14).

Evidence

Fingerprint fcead6ae8d579a75
Category MeshWeaver.Hosting.Orleans.RoutingGrain
Severity Critical
Namespace memex-cloud
Pods memex-portal-deployment-69956b6dbc-s246c, memex-portal-deployment-69956b6dbc-ndnxt
Occurrences 7
First seen 2026-09-20 10:41:47Z
Last seen 2026-09-20 10:44:06Z
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-20 10:41:47Z memex-portal-deployment-69956b6dbc-s246c crit: MeshWeaver.Hosting.Orleans.RoutingGrain[0]
      [ROUTE] Routing back-pressure [458dc6c9#1 started 2026-09-20T10:41:47.4720034Z]: 64 route dispatches in flight (reporting threshold 64); stream destinations queued 0, deepest per-destination queue 0, routing pool subscribing 0. Latest dispatch target LinkedIn/Message — 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 deepest queue of 1 or more means legs are blocked behind a leg (head-of-line on one destination); 0 means nothing is waiting on anything, so read it as load. 🚨 Deepest is sampled AT THE CROSSING, so like the in-flight count it is partly an artefact of the threshold: with N destinations sharing the backlog it is ~InFlight/N whatever is wrong. READ THE EPISODE STAMP, not the depth: a later line with a HIGHER episode on this activation means this episode drained; a line with a DIFFERENT activation id means the grain was recycled; and if neither a clear nor a higher episode ever follows, the in-flight count never fell below half the threshold — which means a leg never terminated and its slot leaked, not that the silo was busy.
2026-09-20 10:41:47Z memex-portal-deployment-69956b6dbc-ndnxt crit: MeshWeaver.Hosting.Orleans.RoutingGrain[0]
      [ROUTE] Routing back-pressure [211c55d4#1 started 2026-09-20T10:41:47.7958652Z]: 64 route dispatches in flight (reporting threshold 64); stream destinations queued 0, deepest per-destination queue 0, routing pool subscribing 1. Latest dispatch target Edu/Quiz — 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 deepest queue of 1 or more means legs are blocked behind a leg (head-of-line on one destination); 0 means nothing is waiting on anything, so read it as load. 🚨 Deepest is sampled AT THE CROSSING, so like the in-flight count it is partly an artefact of the threshold: with N destinations sharing the backlog it is ~InFlight/N whatever is wrong. READ THE EPISODE STAMP, not the depth: a later line with a HIGHER episode on this activation means this episode drained; a line with a DIFFERENT activation id means the grain was recycled; and if neither a clear nor a higher episode ever follows, the in-flight count never fell below half the threshold — which means a leg never terminated and its slot leaked, not that the silo was busy.
2026-09-20 10:41:47Z memex-portal-deployment-69956b6dbc-s246c crit: MeshWeaver.Hosting.Orleans.RoutingGrain[0]
      [ROUTE] Routing back-pressure [458dc6c9#2 started 2026-09-20T10:41:47.8347649Z]: 64 route dispatches in flight (reporting threshold 64); stream destinations queued 1, deepest per-destination queue 62, routing pool subscribing 0. Latest dispatch target cache/12xX8OXQIEmdwvf_ZZ8LjA — 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 deepest queue of 1 or more means legs are blocked behind a leg (head-of-line on one destination); 0 means nothing is waiting on anything, so read it as load. 🚨 Deepest is sampled AT THE CROSSING, so like the in-flight count it is partly an artefact of the threshold: with N destinations sharing the backlog it is ~InFlight/N whatever is wrong. READ THE EPISODE STAMP, not the depth: a later line with a HIGHER episode on this activation means this episode drained; a line with a DIFFERENT activation id means the grain was recycled; and if neither a clear nor a higher episode ever follows, the in-flight count never fell below half the threshold — which means a leg never terminated and its slot leaked, not that the silo was busy.
2026-09-20 10:44:05Z memex-portal-deployment-69956b6dbc-s246c crit: MeshWeaver.Hosting.Orleans.RoutingGrain[0]
      [ROUTE] Routing back-pressure [458dc6c9#3 started 2026-09-20T10:44:05.1039250Z]: 64 route dispatches in flight (reporting threshold 64); stream destinations queued 1, deepest per-destination queue 62, routing pool subscribing 0. Latest dispatch target cache/12xX8OXQIEmdwvf_ZZ8LjA — 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 deepest queue of 1 or more means legs are blocked behind a leg (head-of-line on one destination); 0 means nothing is waiting on anything, so read it as load. 🚨 Deepest is sampled AT THE CROSSING, so like the in-flight count it is partly an artefact of the threshold: with N destinations sharing the backlog it is ~InFlight/N whatever is wrong. READ THE EPISODE STAMP, not the depth: a later line with a HIGHER episode on this activation means this episode drained; a line with a DIFFERENT activation id means the grain was recycled; and if neither a clear nor a higher episode ever follows, the in-flight count never fell below half the threshold — which means a leg never terminated and its slot leaked, not that the silo was busy.
2026-09-20 10:44:05Z memex-portal-deployment-69956b6dbc-ndnxt crit: MeshWeaver.Hosting.Orleans.RoutingGrain[0]
      [ROUTE] Routing back-pressure [211c55d4#2 started 2026-09-20T10:44:05.3205847Z]: 64 route dispatches in flight (reporting threshold 64); stream destinations queued 0, deepest per-destination queue 0, routing pool subscribing 1. Latest dispatch target Reinsurance/Currency — 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 deepest queue of 1 or more means legs are blocked behind a leg (head-of-line on one destination); 0 means nothing is waiting on anything, so read it as load. 🚨 Deepest is sampled AT THE CROSSING, so like the in-flight count it is partly an artefact of the threshold: with N destinations sharing the backlog it is ~InFlight/N whatever is wrong. READ THE EPISODE STAMP, not the depth: a later line with a HIGHER episode on this activation means this episode drained; a line with a DIFFERENT activation id means the grain was recycled; and if neither a clear nor a higher episode ever follows, the in-flight count never fell below half the threshold — which means a leg never terminated and its slot leaked, not that the silo was busy.
2026-09-20 10:44:05Z memex-portal-deployment-69956b6dbc-s246c crit: MeshWeaver.Hosting.Orleans.RoutingGrain[0]
      [ROUTE] Routing back-pressure [458dc6c9#4 started 2026-09-20T10:44:05.3318325Z]: 64 route dispatches in flight (reporting threshold 64); stream destinations queued 1, deepest per-destination queue 62, routing pool subscribing 0. Latest dispatch target cache/12xX8OXQIEmdwvf_ZZ8LjA — 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 deepest queue of 1 or more means legs are blocked behind a leg (head-of-line on one destination); 0 means nothing is waiting on anything, so read it as load. 🚨 Deepest is sampled AT THE CROSSING, so like the in-flight count it is partly an artefact of the threshold: with N destinations sharing the backlog it is ~InFlight/N whatever is wrong. READ THE EPISODE STAMP, not the depth: a later line with a HIGHER episode on this activation means this episode drained; a line with a DIFFERENT activation id means the grain was recycled; and if neither a clear nor a higher episode ever follows, the in-flight count never fell below half the threshold — which means a leg never terminated and its slot leaked, not that the silo was busy.
2026-09-20 10:44:06Z memex-portal-deployment-69956b6dbc-s246c crit: MeshWeaver.Hosting.Orleans.RoutingGrain[0]
      [ROUTE] Routing back-pressure [458dc6c9#5 started 2026-09-20T10:44:06.4240567Z]: 64 route dispatches in flight (reporting threshold 64); stream destinations queued 0, deepest per-destination queue 0, routing pool subscribing 0. Latest dispatch target Ifrs17/ExchangeRate — 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 deepest queue of 1 or more means legs are blocked behind a leg (head-of-line on one destination); 0 means nothing is waiting on anything, so read it as load. 🚨 Deepest is sampled AT THE CROSSING, so like the in-flight count it is partly an artefact of the threshold: with N destinations sharing the backlog it is ~InFlight/N whatever is wrong. READ THE EPISODE STAMP, not the depth: a later line with a HIGHER episode on this activation means this episode drained; a line with a DIFFERENT activation id means the grain was recycled; and if neither a clear nor a higher episode ever follows, the in-flight count never fell below half the threshold — which means a leg never terminated and its slot leaked, not that the silo was busy.

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/fcead6ae8d579a75. Recurrences are folded into this issue rather than opening new ones.

Activity

  1. rbuergi commented on Sep 21, 2026

    @rbuergi
    Contributor

    Closes as duplicate of #5009 — Migrated: the 2.5-minute burst on cache/12xX8OXQIEmdwvf_ZZ8LjA across both pods with 458dc6c9 #2→#5, and its honest caveat that no cleared line was captured in the window. Destination in §1, caveat covered by §3.

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 working

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions