A late fold reads as no fold

Systemorph/MeshWeaver.Plugins#2152. For 5 h 47 min on 2026-09-19 — 07:28:51Z to 13:16:25Z — nothing was folded into a LogIncident on memex. Three portal rolls in that window produced zero folds where an earlier one had produced about twenty. The fleet was running without the thing that reports when it breaks, and the only symptom was an absence.

It was never dead. It was four hours behind. Measured on the control instance (the control instance), 2026-09-21:

Nothing was lost. Every red log in the hole was ticketed, hours after it fired.

f5b5cf382cffd6be is the one to read twice: it is on memex, the namespace the issue is about, and it proves the pipeline was capturing that namespace throughout the supposed blackout. Two siblings (978bf354d04f03b3, b0e9bc21fd5da4e3) were written in the same 11:42–11:43 burst, so the fold record actually resumes around 11:42:30Z — the 13:16:25Z figure is the createdDate of one node in the tail of the same backlog drain, which ran on to about 13:34Z.

The reading error, and it is not a detail

An incident node's createdDate and lastModified are DELIVERY times. Only firstSeen, lastSeen and the per-shape ledger say when the fault actually fired.

A listing gives you the delivery clock — sort:lastModified-desc is how anyone looks at this corpus — and off that clock a four-hour lag renders identically to a dead pipeline. #2152 was filed on that reading, and it was the right call to file it: the reading is indistinguishable from the real thing without opening the nodes.

The consequence reaches much further than one ticket. Every conclusion of the form "no recurrence since the roll, so this is fixed" is drawn off lastModified. Under lag that sentence is unsound in a way no amount of care about the roll time can fix, because the quiet is a property of the reporting and not of the fault. The discriminator is per node and it is cheap:

Read firstSeen / lastSeen / occurrences / shapes[].lastSeen. Never lastModified.

Why nothing said so

The watcher tickets itself about every blind spot it knows of. None of them could fire here:

Confirmed by absence, with a positive control so the absence means something: Admin/_LogIncident/log-pipeline-silent-window-memex and …/log-query-truncated-memex answer Not found, while …/log-burst-header-only-memex — same namespace, same credential — reads in full (v25, lastSeen 2026-09-19T05:31:46.901Z).

🚨 A long window that DID return lines was explicitly classified as fine, on the grounds that "a long window is exactly what catching up after downtime looks like, and one line is proof the stretch is readable". Both halves are true about the store and neither is true about the pipeline: a window an hour wide means nothing in that hour was read, grouped, queued or delivered while it was happening. A watcher hours behind therefore looked exactly like one in steady state — in the pod log and in the mesh alike.

The defect: the pass was all-or-nothing

LogWatchWorker.Tick was one chain:

Namespaces → Collect(ns) ──Concat──→ ToList → SelectMany(_ => Drain()) → Catch(log)

Concat propagates the first error. So a single namespace's failing Loki query aborted the whole pass, with two consequences:

1. Every later namespace's cursor froze too. Two namespaces are polled in one pass, so they stall together and recover together — which is why the 73-minute window landed on the second namespace while the issue was about the first.
2. Drain never ran. The drain reads the durable queue and needs nothing whatever from Loki. Reports that had been detected, fingerprinted and persisted to disk hours earlier simply sat there, delivering nothing, while the portal was perfectly healthy.

That second one inverts the queue's whole purpose. WatcherState persists the pending queue so that "a burst detected while the portal was wedged is delivered when it comes back, instead of being dropped" — detection and delivery are meant to be independent. Tick silently re-coupled them, and made delivery conditional on the one external system delivery does not touch.

The only trace either way was a LogError in the watcher's own pod, in namespace monitoring — which this watcher does not read, and which is the entire reason this subsystem exists.

The fix

Each Collect(ns) carries its own Catch, and Drain is reached whatever the collections did.

This is not swallow-and-continue: a failed collection was already fully handled by design — the cursor deliberately does not advance, so the next tick re-reads the same window — and it is logged at Error either way. What changed is the granularity at which the existing handling applies.

And the lag is now a finding of its own — LogPipelineGap.IsFallingBehind → log-pipeline-behind-{ns}, the exact complement of IsLostWindow on the line count:

Error, not Critical: this is deferral, not loss. The report names the lag, the undelivered backlog (which says whether the lag is collection or delivery), and — because that is what #2152 could not settle from the record — which clock a reader is looking at. It says out loud that a lag which keeps growing ends at the MaxCatchUp floor, where the window stops being late and becomes log-window-skipped-{ns}. The measured lag was 4 h against a 6 h floor.

Continuity is required for the same reason IsLostWindow requires it: a cold start synthesises a ColdStartLookback window already wider than the alarm, and a floored cursor reports itself. A fresh watcher files nothing here on its first tick.

"Long" now means long for this watcher's cadence

SilentWindowAlarm is independent of PollInterval, and that is a cry-wolf loop waiting to be configured: raise the poll to ten minutes, leave the alarm at five, and every ordinary poll clears the bare threshold. A current pipeline would file a lag once a poll — and a namespace scaled to zero would file a lost window once a poll, which was already shippable before this page existed.

So both judgements take max(alarm, 2 × pollInterval). Two polls is the smallest span that cannot be jitter: the steady-state window is exactly one PollInterval (the cursor is the previous window's end, so window == now − previousNow), which makes two polls' worth reachable only when a whole cycle went unread. Deriving the floor beats validating the option — there is no second value to set wrongly, and no startup refusal on a watcher whose job is to keep reporting. With the shipped defaults (poll 1 min, alarm 5 min) the alarm binds and nothing changes.

What this does NOT fix

One pass is still serial, so a long drain still freezes the cursor for its duration. Tick collects and then delivers; while N reports are POSTed one at a time, no window is read. That is a compounding shape — a drain lasting D freezes the cursor for D, so the next window is D wide and yields roughly D's worth of reports — and its terminal state is the MaxCatchUp floor, where the lag becomes loss.

Decoupling the two loops for real means two concurrent subscriptions over one WatcherState, and WatcherState computes each new queue under its lock but persists it outside it: two writers would lose each other's writes. Doing that properly needs the persistence serialized through one channel (a Subject + Concat, per Removing hand-woven gates), which is a larger change than this one. What is fixed here is the entry condition — a failure can no longer stop the drain, so the queue no longer builds for hours behind a Loki problem — and the lag is no longer invisible if the shape is ever entered again.

🚨 The 2026-09-22 reading: a lag can be CONSTANT, and that is a different defect

Measured read-only on the control instance, 2026-09-22 03:05–03:25Z, after this page's fix had been built but was not demonstrably running (which is not the same as "not deployed" — see the two branches at the end of this section). The pipeline was delivering again, and the lag was not the draining backlog this page describes. It was constant:

Both were chosen because they make the measurement unambiguous: version: 2 (created plus one update, so lastModified is not comment-retry churn) and a shape with occurrences: 1 and firstSeen == lastSeen — one occurrence, one delivery, nothing averaged. Six hours to within seven seconds, on two unrelated fingerprints three hours apart, and the next burst agreed (21:08 → 03:08, 21:17 → 03:17).

A backlog DRAIN gives varying lags that shrink. This does not vary — so the shape this page documents, a queue deepening behind a Loki failure and then clearing, is excluded.

🚨 But a constant lag does NOT establish a pinned boundary, and saying so was a diagnosis dressed as a measurement. A queue at equilibrium — arrivals and service at the same rate with six hours of work in flight — holds a stable lag that is indistinguishable from a window or cursor pinned at now − 6h. Two samples of the offset cannot separate them. Both remain live:

So the discriminator is cheap and nobody has taken it: does the lag survive a quiet period? An equilibrium queue drains when arrivals stop; a pinned boundary does not move. The direct reading is the queue depth in the watcher's own StateDirectory, which is also what tells a deep queue from an empty one. Either way the question is no longer "why did the pass fall behind", because the lag is not growing.

🚨 Two traps in reading it, both of which caught this measurement first.

1. Hour-bucket midpoints manufacture a trend. Bucketing detections by hour and comparing to delivery times read as 6h06 → 5h53 → 5h20 — a shrinking lag, i.e. a draining backlog, i.e. this page's defect. The two exact readings above show a flat line. A lag must be measured on ONE node's two clocks, never across buckets.
2. A constant offset IS the "it stopped" reading. With a fixed six-hour offset the newest delivered detection is always about six hours old, so any listing taken at any moment shows a six-hour hole at the head. The detection-hour census that morning read 20* → 2, 21* → 6, 22* → 0, 23* → 0, 2026-09-22* → 0, which looks exactly like a pipeline that died at 21:xx. It had not. A constant offset cannot be told from a stop that began one offset ago except by the single-node reading above.

And IsFallingBehind may be structurally blind to it

This page's own fix added log-pipeline-behind-{ns} as the complement of IsLostWindow on the line count. Under the six-hour offset no such finding existed: a complete enumeration (namespace:Admin scope:descendants nodeType:LogIncident name:*pipeline* → count: 10, truncated: false, with log-burst-header-only-memex readable as the positive control) contained no behind finding at all.

That has two readings and they want different actions:

• the 1.3.11 image carrying the fix is not running (MeshWeaver#4326 — nothing rolls memex-log-watcher, and there is no Deployments/* record for it), or
• the fix is running and cannot see this shape, because a constant offset delivers a FULL window every pass, on time, six hours late. A predicate asking "did this window return lines" is satisfied by a window that returned all of its lines from the wrong six hours.

The second is the one worth checking first, because it is a gap in the fix rather than in the deployment. The instrument this shape needs measures the offset itself, and it has to come from the WATCHER: the upper bound of the window its cursor has reached, compared against now.

🚨 Not now − max(lastSeen) over incident nodes, which is this page's own mistake one more time. lastSeen advances only when something ticketable fires, so a healthy but QUIET namespace drifts toward "infinitely behind" and trips the alarm on silence rather than on lag — an instrument that cannot tell "nothing happened" from "nothing was delivered", which is the whole subject of this page. The watermark is a fact about the watcher and must be published by it; it cannot be inferred from what the watcher happened to deliver.

🚨 Six hours is MaxCatchUp — the lag is the cursor floor, and the reading pace was the cause

Neither candidate above noticed the number itself: six hours is the default of LogWatcherOptions.MaxCatchUp, the age past which WatcherState.CursorFor drags a cursor forward to now − MaxCatchUp. A lag pinned at exactly that value, to within seconds, is a cursor sitting ON the floor.

How it gets there is a property of the code, not of the traffic. Until the fix below, a pass issued one query_range per namespace, capped at QueryLimit (5000) lines, and a truncated read resumed on the next poll. So the watcher's reading capacity was QueryLimit lines per PollInterval — 5000 lines a minute, about 83 a second, for an UNFILTERED query over every pod in the namespace. A namespace that talks faster falls behind by the difference on every poll; nothing later catches it up; the lag grows until the cursor is floored. From then on:

1. every pass starts at exactly now − 6 h and reads the first page of that window;
2. the cursor advances only as far as that page reached — seconds, under a flood;
3. a minute later that cursor is older than the floor again, so it is floored again.

Every incident is therefore delivered six hours after it fired, to within the few seconds one page spans — which is the measured 6 h 00 m 06.97 s / 5 h 59 m 59.93 s — and everything between two pages is skipped unread. It also settles the "structurally blind" branch above: a floored cursor is by definition not IsContinuousCursor, so IsFallingBehind cannot fire on it, whichever image is running. What a watcher carrying SkippedWindowReport and TruncatedReport files instead is log-window-skipped-{ns} and log-query-truncated-{ns} — both named in the table at the top of this page, and neither inside the name:*pipeline* enumeration that was taken.

The fix (Plugins#2152): a pass reads page by page until it reaches the window's end, within a budget of one PollInterval shared across the namespaces, so a whole pass still fits inside one poll and the drain still runs every tick. Each page is a complete collection — its own cursor write, queued reports and open-burst rewind — so a page boundary behaves exactly as a poll boundary always did, minus the minute's wait. A page continues only if it moved the cursor strictly forward (more than a page of lines on one timestamp cannot spin), and only the pass's FIRST page judges the window as a whole (lost, behind). log-query-truncated-{ns} now means what its text always claimed: a window left unread when the pass budget ran out, i.e. the namespace out-talks what the store can serve in one poll interval — no longer an accident of two unrelated settings. The page size is unchanged; what changed is that throughput is no longer tied to the poll cadence. Pinned by ADenseNamespaceIsReadWithinOnePassTest, whose two pins fail on the pre-fix pass.

🚨 What this does not establish. That the live namespace exceeds 5000 lines a minute is inferred from the offset equalling the floor; the line rate itself was not measured. The discriminator that would confirm it is on the control instance, readable: log-window-skipped-memex and log-query-truncated-memex with rising occurrences if the running image carries those findings, or neither if it predates them (Plugins#2156 measured the deployed watcher pre-2026-08-25). The fix ships in the mw-log-watcher image, not in this module, and nothing rolls that image (MeshWeaver#4326) — a merge changes nothing live until someone rolls it.

🚨 The 2026-09-24 stop was a real stop, and the watcher was not the cause: the INGEST could not run

From 2026-09-24T12:03:11Z no incident was folded on the control instance for more than 28 hours. This one was not a lag. Read on 2026-09-25 with a Logs InstanceAction over namespace memex (Ops/Actions/logs-memex-20260925-redlog-ingest-2152, then …-ingest-exception-2152):

• Red-log ingest failed for b85ee940c57e9a79 appears once a minute. The watcher was alive and POSTing. It was retrying the head of its durable queue, which is Drain's contract: it stops at the first retryable failure and tries again on the next tick.
• The exception under that line is System.MissingMethodException: Method not found: 'System.String MeshWeaver.Observability.LogIncidentIdentityResolution.SiteFold(MeshWeaver.Observability.LogIncidentReport)'.

MeshWeaver.Observability.Contract is platform-shipped: it is listed in src/platform-shipped.txt, so the portal IMAGE carries it and a module bundle does not. The Observability module is a bundle. It self-updates on its own cadence, and it was compiled against the Contract as it stood on main, which had SiteFold(LogIncidentReport) (and, from 2026-09-24, LogIncidentReport.Classification). The image did not have them. LogIncidentIngestService.Create and .Merge both reference SiteFold, so the JIT refuses them and EVERY report fails the same way: the endpoint answers 502, the watcher keeps the report queued, and nothing is written. No finding could fire, because every finding the pipeline raises about itself is written through the ingest that was failing. The one trace was a warn: line in the portal's own log.

The newest fold (67b2f953bf6d1799, 12:03:11Z) carries no siteFold. Merge heals an absent siteFold on every fold, so the module that wrote that fold still predated SiteFold. That points to the adoption of the newer module happening after 12:03Z. The exact adoption time was not measured.

What changed

• /health has a log_ingest check (Memex.Portal.Gui/Api/LogIngestLedger.cs). It is Degraded while every report since the last accepted one has failed, and it names the exception. The ledger lives in the image and the endpoint writes it, so it keeps working when the module cannot load. A Sample carries it onto Ops/Status/<id>. It is Degraded, never Unhealthy, like the other census checks: a ticketing outage must not become a serving outage.
• A binding fault is logged at Critical (MissingMemberException, TypeLoadException, FileLoadException, BadImageFormatException) and names the contract skew. It stays a 502, so the watcher keeps the reports and delivers them once the image or the module moves.
• A seam that throws synchronously is a 502, never a 400. Before this change, a throw from inside ILogIncidentIngest.Report escaped Handle into the body-binding Catch. BindingFailure then read the portal's own fault as an unreadable BODY and answered a PERMANENT 400, and a permanent answer makes the watcher destroy the report. On 2026-09-24 the JIT failure happened one call deeper, inside the observable, which is the only reason the reports were kept.

LogIngestFailureIsLoudTest pins all three against the real endpoint.

What this does NOT fix

• The skew itself. A module built against a newer platform-shipped Plugins assembly than the image carries still loads, and it fails when first called. ModulePlatformFloor measures the CORE platform version, and nothing measures the Plugins-owned assemblies in platform-shipped.txt. The fix for that class is a compatibility rule for those assemblies, for example a floor or a surface check. It is not a pin. It is not built yet; Plugins#2152 carries the measurement.
• A dead watcher. log_ingest answers "can this replica ingest". A process that received nothing reads Healthy and says so. Whether the watcher is running is a different question, and this check does not claim to answer it.
• Restoring the pipeline. That needs the control portal's image and its Observability module to agree again. It is a roll, not a merge.

A separate thing that is true and is not this

Admin/_LogIncident/e4a97855ab595beb — the node #2152 reads as churning while its lastSeen stays frozen at 05:43:46Z — is status: Superseded, and a8bd908a4fb78336 carries foldedFrom: ["e4a97855ab595beb"] with reporterFingerprint: e4a97855ab595beb. Folding genuinely moved off it, onto ids the portal computes: that is Incident identity working exactly as designed, not a stall. A frozen lastSeen on a Superseded node is expected; it is the successors going quiet that meant something, and they went quiet because of the lag above.

Related

• Incident identity — who computes it — why a reporter's fingerprint is re-addressed on ingest, and what foldedFrom means.
• When the ticketing pipeline tickets itself — the other direction: this pipeline reporting its own healthy retry as a production fault.
• Red-log watching and automatic ticketing — the pipeline end to end.