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 (memex.systemorph.com), 2026-09-21:
| node | createdDate |
firstSeen |
reading |
|---|---|---|---|
Admin/_LogIncident/ab4f533a0d848402 |
2026-09-19T13:16:25.586Z | 2026-09-19T09:09:36.941Z | the burst the "recovery" moment is made of was detected 4 h 07 min earlier |
Admin/_LogIncident/a8bd908a4fb78336 |
2026-09-19T13:30:24Z | 11:34:19.709Z (lastSeen 12:47:45.787Z, 14 occurrences) |
fourteen occurrences in ONE report, and a report spans ONE window — so that window was 73 minutes wide |
Admin/_LogIncident/f5b5cf382cffd6be — namespace memex |
2026-09-19T11:42:30.806Z | 2026-09-19T09:55:27.249Z | a crit: line the portal emitted inside the window that "produced zero folds" — ticketed 1 h 47 min later |
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. NeverlastModified.
Why nothing said so
The watcher tickets itself about every blind spot it knows of. None of them could fire here:
| finding | requires | that window |
|---|---|---|
IsLostWindow → log-pipeline-silent-window-{ns} |
zero lines back | lines came back |
IsTruncated → log-query-truncated-{ns} |
the result AT QueryLimit |
under it |
SkippedWindowReport → log-window-skipped-{ns} |
a cursor floored by MaxCatchUp (6 h) |
4 h — inside the floor |
RejectedReport → log-report-rejected-{ns} |
a permanent refusal | nothing was refused |
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:
- Every later namespace's cursor froze too.
memexandmemex-cloudare polled in one pass, so they stall together and recover together — which is why the 73-minute window landed onmemex-cloudwhile the issue was aboutmemex. Drainnever 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:
| lines back | long window, cursor continuous | verdict |
|---|---|---|
| zero | yes | the store lost the stretch → log-pipeline-silent-window-{ns}, Critical |
| some | yes | we were not reading it → log-pipeline-behind-{ns}, Error |
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.
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
foldedFrommeans. - 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.