Skip to content

port(upstream#1885): retained MQTT status is not observer liveness - #26

Merged
dborup merged 4 commits into
masterfrom
codex/port-upstream-1885-retained-status-liveness
Sep 22, 2026
Merged

dborup merged 4 commits into
masterfrom
codex/port-upstream-1885-retained-status-liveness

Conversation

@adminopenclaw8-sketch

@adminopenclaw8-sketch adminopenclaw8-sketch commented Sep 13, 2026 •

Copy link
Copy Markdown
Collaborator

Split out of #25 (commit c28a20b9 there). This branch holds exactly one upstream change so it can be reviewed, tested and reverted on its own.

Upstream

Problem

The MQTT broker replays every retained status message on (re)subscribe, and the status path stamps observers.last_seen with ingest time and clears inactive. Every ingestor restart therefore marks long-dead observers as alive, so RemoveStaleObservers can never age them out. A replay that arrives through a bridging broker loses the RETAIN flag, so the flag alone cannot catch it.

Change

handleMessage treats a status message as a replay when m.Retained() is set or the new statusIsLiveness rejects the payload: a status other than online, or a payload timestamp older than 24 h (payloads with no or unparseable timestamp keep the old behaviour). Replays go through the new Store.UpsertObserverRetained, which only refreshes metadata columns on an existing row. It does not advance last_seen, clear inactive, bump packet_count or insert new rows. The column flattening shared by both upserts moved into observerMetaColumns.

Adaptation to this fork

None. The cherry-pick applied without conflicts and the changed lines are identical to upstream.

Notes for review

Behaviour change operators may notice: observers whose only traffic is a replayed status snapshot no longer reappear as active after a restart.

Dependencies and merge order

Verification

Local run of the same commands as CI's “Go Build & Test” job (server tests with -race), on this branch and on master fda24ca5 under the same conditions (same machine, run one after another):

Check master fda24ca5 this branch verdict
go-ingestor-build-vet PASS PASS
go-ingestor-test FAIL FAIL TestBackfillTxLastSeen_ResolvesFromMaxObservationTimestamp, TestPruneOldNeighborMetrics baseline failure, unchanged
channel-lib-test PASS PASS
decrypt-cli-build-test PASS PASS
dockerfile-copy-invariants FAIL FAIL not runnable locally: script needs bash ≥4 (declare -A), macOS has 3.2; identical on master
staging-disk-monitor PASS PASS
css-vars-lint PASS PASS

Baseline failures (fail identically on master; not introduced or changed here): see rows marked baseline failure, unchanged.

Browser validation (local, fixture DB, no staging/production): Not applicable (no frontend change).

Not run:

  • Playwright E2E suites (no local Playwright install); CI's E2E job will also be skipped, see below.
  • eslint (not installed locally; CI installs it on the fly).
  • Frontend JS suites (no frontend change).
  • Browser tests against staging/production (deliberately none).

Expected GitHub CI: “Go Build & Test” is expected to fail on TestPruneOldNeighborMetrics, which already fails on master (see #25's run). Downstream jobs (Playwright, image build) are therefore skipped. “Deploy Staging” and all GHCR publish steps only run on push to master and cannot run for this PR.
Two further ingestor tests have failed intermittently in this split's CI on branches whose cmd/ingestor tree is byte-identical to master (#27, #28), so they can also appear here without being caused by this change:

GitHub CI result: run 34749188316 on 40f804d8. Go Build & Test: failure; all downstream jobs incl. Deploy Staging skipped. Failed tests:

  • TestPruneOldNeighborMetrics: fails on master, documented baseline

🤖 Generated with Claude Code

efiten and others added 4 commits September 13, 2026 10:42
…a-clawbot#1885)

## Problem

The broker replays every retained `status` message on subscribe, so each
ingestor restart pushes all of them through the status path in
`handleMessage`. That path stamps `last_seen` with `time.Now()`
(deliberately, per Kpa-clawbot#1465).

Observed on a live deployment on 2026-08-11: **23 observers all carried
`last_seen = 2026-08-06T08:20:09Z`** — 15 seconds after container start
— and 18 of them had sent no actual packet in over a month. Their
retained publish dates lined up almost 1:1 with `last_packet_at`, i.e.
the replay was their only sign of "life":

| observer | last real packet | retained status published |
|---|---|---|
| ON8AR - Observer | never | 2026-03-20 |
| BE-BGS-RRY120-RES | never | 2026-04-02 |
| A3BEF374 | 2026-04-30 | 2026-04-30 |
| BE-BGS-RRY120-RUDY | 2026-05-18 | 2026-05-18 |
| BE-JBE-ETG-O1 | 2026-06-10 | 2026-06-10 |

That makes dead observers immortal, three ways per restart:

1. `last_seen` jumps forward, so `RemoveStaleObservers` can never age
them out as long as a restart happens inside `observerDays`.
2. The unconditional `inactive = 0` reactivation at the end of
`UpsertObserverAt` undoes any soft-delete that did land.
3. A metrics sample is filed at ingest time, dating a months-old reading
as a present-tense measurement.

`UpsertObserverAt`'s docstring already claimed retained replays were a
no-op for `last_seen` thanks to the `MAX` guard. That held only while
the caller passed the envelope timestamp; Kpa-clawbot#1465 switched it to ingest
time, which defeats the guard.

## Fix

The retained path now updates metadata only, via a new
`UpsertObserverRetained`:

- no `last_seen` advance
- no `inactive = 0` reactivation
- no `packet_count` bump
- no metrics sample
- **no INSERT** — a retained-only observer the analyzer has never heard
from live describes a past that may be months old and does not belong in
the list. A live message from the same observer creates the row through
the normal path moments later.

Live status handling is unchanged.

## Tests

Seven tests in `cmd/ingestor/retained_status_test.go`, written before
the fix:

- 4 that failed on the bug: `last_seen` advance, reactivation of a
soft-deleted row, creation of a never-seen observer, metrics-sample
insert
- 2 regression guards pinning live (non-retained) behaviour: `last_seen`
still advances, unknown observer still created
- 1 asserting retained metadata is still applied — the snapshot is the
observer's last known state, only the liveness signal is suppressed

`mockMessage` gained a `retained` field so `Retained()` is controllable.

Meta flattening is extracted to `observerMetaColumns` so both write
paths bind identical args.

Full `cmd/ingestor` suite passes.

🤖 Generated with [Claude Code](https://claude.com/claude-code)

---------

Co-authored-by: Claude Opus 5 (1M context) <noreply@anthropic.com>
(cherry picked from commit 9bd5f5a)
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
An independent mutation run against the port's original seven tests left
nine mutants alive. Six of them sit on behaviour the change is actually
responsible for; these tests kill all six, each verified by re-applying the
mutation and watching the named test fail on a real assertion (not a
compile error).

  packet_count bump re-added to UpsertObserverRetained  -> killed
  can_relay_seen regressed 1 -> 0 on the retained path  -> killed
  strings.EqualFold replaced by a case-sensitive ==     -> killed
  the `s != ""` guard dropped                           -> killed
  !t.Before(cutoff) flipped to t.After(cutoff)          -> killed
  IATA TrimSpace/ToUpper dropped on the retained path   -> killed

Two of these matter more than their size suggests. Losing the
case-insensitive comparison would silently suppress liveness for any
firmware publishing "ONLINE" — the observer would age out while alive,
which is worse than the bug this port fixes. And can_relay_seen is the
tristate's "we have actually observed this" bit (Kpa-clawbot#1290); a replay carrying
no `repeat` field must not erase an answer the live path recorded.

The three remaining survivors are left deliberately and are noted in the
file: two concern statusLivenessMaxAge's exact value, which is documented
as a generous margin rather than a threshold, and one concerns
Stats.ObserverUpserts, a counter with no behavioural consequence.

No production code and no existing assertion was changed.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
@dborup

dborup commented Sep 20, 2026

Copy link
Copy Markdown
Owner

Uafhængig review + målt verifikation — ingen blockers

Gennemgået af en reviewer, der ikke skrev ændringen, med krav om at eksekvere frem for at ræsonnere. Branchen er synkroniseret med master 96319acc (almindelig merge-commit 4bfc7ee9, ingen rebase/squash/force-push), og testhullerne er lukket i ca9d98cb.

Kerneregressionen er rettet — begge halvdele verificeret

Samme payload (status:"online", friskt tidsstempel, fuld metadata) mod en soft-deleted observer sået 60 dage gammel med packet_count = 7:

retained live
last_seen frosset 2026-07-22T21:55:45Z → 2026-09-20T21:55:45Z
inactive bliver 1 → 0
packet_count 7 → 7 7 → 8
observer_metrics 0 rækker 1 række
firmware opdateret til v9.9.9 opdateret til v9.9.9

Ukendt observer: retained indsætter intet (WriteErrors = 0 — en 0-rækkes UPDATE er korrekt ikke en fejl), live opretter rækken. Og formålet holder ende-til-ende: efter et replay markerer RemoveStaleObservers(30) observeren inaktiv (1 række, både med retain-flag og med forældet payload); efter en live-status markerer den 0.

Begge halvdele var påkrævet. En rettelse, der også knækkede levende observers, ville være værre end fejlen.

Grænseadfærd (46 tilfælde, alle som dokumenteret)

parseEnvelopeTime accepterer kun RFC3339 (Z eller ±HH:MM), 2006-01-02T15:04:05.999999 og 2006-01-02T15:04:05. Den afviser mellemrumssepareret, kun-dato, epoch-sekunder, RFC1123 og +0200 uden kolon. Grænsen er eksakt: now-24h → live, +1s → live, -1s → ikke live. Tidszone-påstanden i docstringen er verificeret for hver offset fra UTC-12 til UTC+14 (27 subtests, alle rykkede last_seen).

Dokumenteret begrænsning: fail-open

12 af 14 payload-former genopliver stadig en soft-deleted observer fuldstændigt, når RETAIN er ryddet — herunder alle de former, repoets egne eksisterende tests bruger ({"origin":"MyObserver"}, {"type":"status"}, {"model":"L1"}), "online" med et tidsstempel i et af de afviste formater, og "timestamp" som JSON-tal (msg["timestamp"].(string) fejler → fail-open).

Ærligt forbehold fra revieweren: de fixtures er syntetiske minimalpayloads, ikke opsamlet produktionstrafik, og det kunne ikke afgøres fra repoet, hvad rigtige payloads indeholder. Nettopositionen: rettelsen er strengt bedre end master overalt og aldrig værre, retain-flag-halvdelen fanger 100 % af replays på egen subscribe, og den konkrete hændelse PR'en citerer (payload der siger "offline") bliver fanget. Derfor en dokumenteret begrænsning, ikke en blocker. Bemærk at TestStatusWithoutTimestampStillCountsAsLiveness test-låser adfærden, så en senere stramning kræver at den test ændres.

Testhuller lukket (ca9d98cb)

Mutationskørslen efterlod 9 mutanter i live. Seks af dem sidder på adfærd, ændringen faktisk er ansvarlig for; de er nu dræbt, hver enkelt verificeret ved at genindsætte mutationen og se den navngivne test fejle på en rigtig assertion — ikke en compilefejl:

mutation resultat
packet_count + 1 genindsat i UpsertObserverRetained dræbt
can_relay_seen regresserer 1 → 0 dræbt
strings.EqualFold → case-sensitiv == dræbt
s != ""-garden fjernet dræbt
!t.Before(cutoff) → t.After(cutoff) dræbt
IATA-normalisering fjernet på retained-stien dræbt

Den tredje fortjener en note: mistes case-ufølsomheden, ville enhver firmware, der publicerer "ONLINE", få sin liveness stille undertrykt — observeren ville ælde ud, mens den er i live. Det er værre end den fejl, porten retter, og det var helt utestet.

De tre resterende overlevende er bevidst efterladt og noteret i filen: to angår statusLivenessMaxAge's eksakte værdi, som er dokumenteret som en generøs margin og ikke en tærskel, og én angår Stats.ObserverUpserts, en tæller uden adfærdsmæssig konsekvens.

Revieweren rapporterede desuden en fejl i sit eget harness: første mutationsdriver pipede go test | tail og returnerede dermed tails exitkode, så alt så ud til at overleve. Den blev fanget, da en umulig mutant "overlevede", rettet med pipefail og alt blev kørt om. De tal, der står her, er fra den rettede driver.

Kontrolleret og fundet i orden

  • COALESCE med tom streng er pre-eksisterende, ikke ny. A/B på store-niveau med identiske argumenter: UpsertObserverRetained("ab1","","",nil) og UpsertObserverAt("ab2","","",nil,"") efterlader begge name="", iata="" — identisk. Verificeret igen mod master-baseline 16ffe105. Den udtrukne observerMetaColumns er tekstuelt adfærdsbevarende mod masters inline-blok.
  • Ingen ny låserisiko. SetMaxOpenConns(1) + busy_timeout=5000 serialiserer i puljen, før SQLite ser kontention. 1200 samtidige operationer over fire goroutiner (retained upserts, live UpsertObserverAt, InsertTransmission med writerMu, og en WriterExec-kalder): 0 fejl, 0 WriteErrors, ingen race. Den live-sti, den erstatter, omgår også writerMu, så lådisciplinen er uændret. Bonus: retained-stien er 5× billigere (16,4 µs/op mod 80,5 µs/op).
  • can_relay_seen har eksakt paritet med live-stien: 18 kombinationer (3 førtilstande × 6 payloads), identiske i hver celle, og flaget regresserer aldrig 1 → 0.
  • go test -race ./... på den synkroniserede branch: grøn, 315 s, 0 races, 0 fejl. Revieweren så her en race, men den var pre-eksisterende — den lækkede StartStatsFileWriter-goroutine — og den blev rettet på master af test(ingestor): stop background work from outliving the test that started it #71 (96319acc), som nu er med i denne branchs merge-base. Det er en direkte bekræftelse af, at test(ingestor): stop background work from outliving the test that started it #71 var værd at lave.

SHOULD-FIX, som jeg bevidst ikke retter her

De ville ændre porten væk fra upstream #1885 og koste paritet for fremtidige ports. Dokumenteret i stedet:

  1. status er en whitelist med præcis én værdi. Målt: "connected", "up", "ok" giver alle false. Firmware med andet ordforråd ville få liveness permanent slået fra.
  2. Ingen TrimSpace på status — målt: " online" og "online " giver begge ikke-live, mens TrimSpace anvendes på repeat (main.go:1232) og iata (db.go:1448). Inkonsistent.
  3. Fremtidige tidsstempler er ubegrænsede — målt: now+10 år → live. resolveRxTime (main.go:1307) afviser hårdt >14t fremtid af netop denne grund. Asymmetrien ser utilsigtet ud.
  4. Scope-hul: garden sidder kun i /status-grenen. Målt: en retained pakke genopliver stadig (last_seen rykkede, inactive 1→0, packet_count 7→8) via den ugarderede main.go:887. En retained /neighbors-rapport gør korrekt ikke (målt).
  5. Identisk loglinje for undertrykt og live status (main.go:648 og :674). En operatør kan ikke se på loggen, at liveness blev undertrykt — uheldigt for en rettelse, hvis pointe er at diagnosticere en replay-storm.

Hvorfor denne PR er PARKERET, ikke merget

Opgavens regler kræver staging før merge for MQTT-/liveness-ændringer, og denne har desuden synlig dataeffekt: observers kan forsvinde fra listen. Den handler om broker-adfærd (EMQX → mosquitto-bridge → ingestor), som CI ikke kan reproducere.

Staging kan ikke nås fra den maskine, arbejdet kører på: docker-dæmonen kører ikke, ~/meshcore-staging-data findes ikke, der er ingen ~/.ssh/config og ingen remote docker-context. Deploy-jobbet kører på den self-hostede runner [self-hosted, meshcore-runner-2], som er fork-guarded fra her. Docker blev bevidst ikke startet: containerne har restart: unless-stopped, så en dæmonstart kunne rejse en ingestor, der forbinder til en live broker.

Konkret testplan ligger i STAGING-TESTPLAN.md under "#26". Det vigtigste punkt der: verificér at en LEVENDE observer stadig får last_seen opdateret — uden det bevis er staging-kørslen ikke gyldig.

🤖 Generated with Claude Code

@dborup
dborup merged commit 7a593f4 into master Sep 22, 2026
6 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants