Repository navigation
Incident-filer normaliser leaves hex letters of the RoutingGrain episode stamp unmasked, splitting one back-pressure condition into dozens of Critical incidents #5421
Description
What is failing
The log-watch incident filer's message normaliser does not mask the per-episode identity inside the MeshWeaver.Hosting.Orleans.RoutingGrain back-pressure message, so ONE recurring condition mints a distinct Critical incident per activation/episode crossing. This incident is one fragment of an active flood: ~50 sibling RoutingGrain back-pressure incidents were created under Admin/_LogIncident within the ~40 minutes preceding this triage, each a distinct fingerprint of the same log site on the same pod. The underlying routing condition itself looks like benign transient load (2 occurrences in 1.2 s; subscribing 0; deepest queue 1–2; oldest leg 90 ms→1200 ms; consecutive episode numbers on one activation) — the defect being ticketed is the alerting split, not the routing.
Probable cause — high confidence
The normaliser has a partial mask for this shape, and the residue is what splits the fingerprint. The bracketed episode stamp [activation#episode started timestamp] is masked digit-wise ({n}) and the timestamp as {time}, but the activation id is hex, so its letters survive: the sibling incident names retain letter runs like f2, e6, bff3, dd9fe7, eb5…a8 after masking. Since the fingerprint hashes the normalised message, each activation's letter residue keeps it distinct from every other, and recurrences never fold. This confirms the mechanism hypothesised in the 2026-09-21 feedback node (rbuergi/Feedback/route-backpressure-fingerprint-splits-20260921-2236), which measured ~87 bot-filed tickets from this one log site over 2026-09-19→21 and was uncertain whether the normaliser had a pattern at all — it does, it is just digit-only. The delivery id (Fut1XwvQ9…yRL1aWHAFESA) is likewise unmasked, though the bracketed stamp alone is sufficient to split.
Impact
Judged from the numbers: no user-facing failure, no data loss — this episode drained. The cost is alerting integrity: dozens of Critical incidents per hour bury any genuine slot-leak signal (core issue 5118's own stated worry), and each requires hand-folding (48 tickets were folded by hand into core 5009, 24 into 5018, per that feedback). Ops-only, easy manual workaround, hence sev:M.
Where to look
- The masking rules of the log-watch incident filer's message normaliser — per the feedback node, the filer lives in
MeshWeaver.Plugins. The fix is a pattern masking the bracketed[activation#episode started timestamp]group (and the delivery id) for this log category, so recurrences fold onto one incident and its occurrence count becomes the signal. Do NOT strip the values from the log line itself — they are deliberate and load-bearing for load-vs-leak diagnosis. - The emitting call site (attributed, not read in this triage):
src/MeshWeaver.Hosting.Orleans/RoutingGrain.cs, methodReportSaturation— composes the activation id, episode number and start timestamp into the message. - Related core issues: RoutingGrain back-pressure, thread-shortage shape (waiting-for-slot high, subscribing ≤1): compile-off-ThreadPool fix #5327/#5375 live on memex-cloud, pending on memex; post-fix residual under verification #5118 (flood severity — this is its remaining half), RoutingGrain dispatch pool saturates repeatedly on portal silos; slots held through unbounded ThreadPool wait and episode-stamp splitting floods incidents #5018 (load verdict + seven-issues-one-fingerprint measurement in its consolidation comments), RoutingGrain dispatch slots saturate with legs head-of-line blocked behind one shared-cache destination while the second pod starves on load #5009 (head-of-line verdict, fixed in PR 5151).
Duplicates — many sibling Admin/_LogIncident nodes for the same log site exist and may be triaged into near-identical tickets; a human can consolidate them against this one and the feedback node above.
Evidence
| Fingerprint | ce1cb539f6dacb6e |
| Category | MeshWeaver.Hosting.Orleans.RoutingGrain |
| Severity | Critical |
| Namespace | memex-cloud |
| Pods | memex-portal-deployment-857546649-vf2q6 |
| Occurrences | 2 |
| First seen | 2026-09-22 22:59:20Z |
| Last seen | 2026-09-22 22:59:22Z |
| 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:59:20Z memex-portal-deployment-857546649-vf2q6 crit: MeshWeaver.Hosting.Orleans.RoutingGrain[0]
[ROUTE] Routing back-pressure [6f268927#1 started 2026-09-22T22:59:20.9471251Z]: 64 route dispatches in flight (reporting threshold 64); ordered channels queued 44 over 6 stream destination(s), deepest per-channel queue 1, routing pool subscribing 0, waiting for a pool slot 5; oldest leg in flight 90 ms — stream-routed → cache/41czPxYhBke8Yz-MPeDDVQ (delivery Fut1XwvQ90yRL1aWHAFESA). Latest dispatch target cache/zIA-4kPmiEePY3qfW1foNA — 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 lik…[truncated]
2026-09-22 22:59:22Z memex-portal-deployment-857546649-vf2q6 crit: MeshWeaver.Hosting.Orleans.RoutingGrain[0]
[ROUTE] Routing back-pressure [6f268927#2 started 2026-09-22T22:59:22.1454019Z]: 64 route dispatches in flight (reporting threshold 64); ordered channels queued 37 over 7 stream destination(s), deepest per-channel queue 2, routing pool subscribing 0, waiting for a pool slot 14; oldest leg in flight 1200 ms — stream-routed → cache/41czPxYhBke8Yz-MPeDDVQ (delivery j0uYOM7CRU6BvTlrW2VTSQ). Latest dispatch target cache/2v3dSLXHq0ekZ_MHIaE63g — 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]
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/ce1cb539f6dacb6e. Recurrences are folded into this issue rather than opening new ones.
Activity
rbuergi commentedon Sep 23, 2026
Duplicate of #5271. Same code site: the filer normaliser
LogLineParser.Normalize(Plugins). Same discriminator: a back-pressure crossing mints a new fingerprint instead of folding.This issue's specific claim was checked and does not hold on Plugins
main. The claim: the hex letters of the episode stamp survive masking. I compiledLogLineParser.Normalizefrom Pluginsorigin/mainand ran it over all 159 back-pressure lines quoted in the flood issues, including this issue's own stamps. Every stamp, letters included, normalises to[{hex}#{n} started {time}], and the whole set folds to 3 texts: one per leg kind, plus the older wording. What actually split the fingerprints was the delivery id and the single-segment destination, which Plugins#2286 (b922f070) masks. The flood continued because the filer's host (the control instance, Plugins seal954e7795) does not containb922f070yet. Details and the corrected close condition are on #5271.The routing half of this issue (memex-cloud
857546649=3da3423c, before the fix; waiting 5–14, deepest 1–2, legs ≤ 1.2 s) is the thread-shortage family tracked on #5118.