diff --git a/REPORT.md b/REPORT.md index 04fb978..9598249 100644 --- a/REPORT.md +++ b/REPORT.md @@ -1,148 +1,105 @@ -# REPORT — R-82 Slice B: one quiesce window, two backup tiers (v0.175.0) (2026-07-26) +# REPORT — R-88 Part 1: the quiesce failure breaker (v0.176.0) (2026-07-27) -**Overwritten** per the standing rule. Controller **v0.174.0 → v0.175.0**. -Full cross-repo arc: `felhom.eu/REPORT.md`. +**Overwritten** per the standing rule. Controller **v0.175.0 → v0.176.0**. **MinAgent UNCHANGED** — +this is controller-internal scheduling; no agent surface is touched. -**MinAgent UNCHANGED — deliberately.** This release degrades gracefully against ANY older agent. It -does not require agent v0.97.0. +## What was broken ---- +`internal/quiesce` had **no consecutive-failure counter, no backoff and no circuit breaker of any +kind**, and the loop driver is a plain 5-minute `time.Ticker`. A tier that was due and kept failing +was therefore re-quiesced every five minutes — and a quiesce cycle stops and restarts **every +customer app stack**. -## 1. Why the controller had to change +Observed live on demo-felhom 2026-07-27: three full cycles at 09:02:57, 09:07:58 and 09:12:57 +Budapest, each stopping and restarting `bookstack calibre-web docmost immich` (~19 s down per cycle, +~50 s per full cycle) against a PBS tier that could not succeed. **It stopped after three only +because PBS came back**, not because anything gave up. Had the outage lasted, so would the loop. -The agent gained per-target backup tiers (R-82 Slice A): local **daily** + offsite **weekly**. But -the **controller** owns quiescing — it polls `/backup/due`, stops the app stacks, calls `POST -/backup`, and restarts them. So the multi-tier schedule has to be reconciled here, and one night a -week both tiers come due at once. +## Phase 0 (read-only) — the three answers -Two quiesce cycles that night would mean **two app outages for one night's work** — undoing the -entire argument for weekly-over-daily, since the quiesce blip was the only real cost of the offsite -tier. +**P0.1 — case (a): agent-side.** The storage read **errored**; it was never an empty success. The +defect is a type boundary: `newestArchiveOn` (`localapi/server.go:1095-1111`) promises in its own +comment that *"errors … degrade to unknown, never to 'no backup'"*, but its `(time.Time, bool)` +signature **cannot represent unknown** — an error and a genuinely-empty storage both become +`(zero, false)`. `handleBackupDue` (`server.go:934-941`) then emits a *positive* claim: +`Due: true, Reason: "no successful backup recorded yet", AgeSecs: nil`. The fail-safe that does +exist (`targetStoragePresent` — "a storage-view error must never read as 'not there'") answers a +different question and behaved correctly. -## 2. The dedup rule — specified, not emergent +**Decisive for scoping: the errored path and the genuine-never path are byte-identical on the wire.** +Same `Due`, same `Reason`, same nil `AgeSecs` — the controller has nothing to discriminate on, so +Part 2 cannot be done here. It needs an agent wire change plus a compat rule both ways → own task. -| local due | PBS due | result | +**P0.2 — deliberate restarts, not self-update.** Four on 2026-07-27 (07:36:39, 07:54:06, 08:50:16, +11:31:52 CEST), all clean `Stopping → Stopped → Started`, `NRestarts=0`, `Result=success`, zero +self-update lines. No automatic mechanism arms the trigger — but ordinary operator/config work armed +it four times in one day, making the trigger **more** frequent than "only when ep0 is down", not less. + +**P0.3 — the loop alerted nobody.** Zero `backup_failed` events, and not because of the allowlist +(the hub carries that type). **`internal/quiesce` does not import `internal/notify` at all.** The +only trace was `07:13:27 info app_start_failed "Telepített alkalmazás nem fut: BookStack"` — a +customer-tier, Hungarian, info-severity *symptom* of the third cycle catching BookStack mid-restart. +Filed as **R-97**; out of scope here. + +## What shipped + +`internal/quiesce/breaker.go` — consecutive failures per **target**; a tier inside its backoff is +dropped from the due set **before any stack is stopped**. The gate is on the QUIESCE, not the backup, +because the harm was never the failing backup but the outage taken to attempt it. + +**Backoff `15m → 30m → 1h → 2h → 4h`, then 4h forever.** The cap is chosen against two real +constants: 4 h sits well inside the shortest tier cadence (local 24 h), so a recovered tier still +gets several attempts within its own cadence; and it equals the width of the window gate +`[W+2h, W+6h)`, so a tier at maximum backoff still gets at least one attempt inside any given +night's window rather than stepping over it. + +Bounded four ways, each with a test: **never permanent** (the cap bounds the interval, never stops +retrying — a latched breaker is a silent backup outage, worse than the loop); **never global**; +**never gates `TriggerNow`** (manual runs still record their outcome, so a manual success clears the +backoff); **`stillRunning` is not a failure** (a first full offsite snapshot legitimately runs for +hours). State is **in-memory on purpose** — a restart forgets the backoff and re-attempts, the cheap +direction to fail. + +**Part 3** — the invariant is written at the head of `scheduledRunAllowed`: a missing value means +UNKNOWN, and only a *positive* "never backed up" may fire the safety valve. Fourth instance of the +class (hub v0.12.0, v0.73.0, R-81, R-88), all four named in the comment. + +## Tests — 27 packages ok, 0 failed; `build` / `vet` / `test` each rc=0, run separately + +11 new: 7 breaker + 4 contract. Three red-proofs, each observed and restored: + +| Scenario | Mutation | Observed failure | |---|---|---| -| yes | no | one quiesce, local backup | -| no | yes | one quiesce, PBS backup | -| **yes** | **yes** | **ONE quiesce window, BOTH backups inside it** | -| no | no | no quiesce | +| **A** | remove the `dropBackedOffTiers` call | `R-88: 3 failing ticks stopped the apps 3 time(s); want 1 — the breaker did not defer anything` | +| **D** | flip the nil branch to `return false` | `CONTRACT VIOLATED: a never-backed-up box outside its window did NOT back up (0 stack stop(s)) — the safety valve was removed; a box only ever powered on outside its window would starve` | +| **F** | make the breaker global (any blocked tier halts all) | `R-88 Scenario F: the healthy local tier was backed up 2 time(s) across 4 ticks; want >= 3 — a broken tier must not halt a working one` | -## 3. What shipped +**Scenario A asserts a COUNT, not a log line** — the harm is the stop/start pairs, so the test counts +them, at the exact incident cadence: 3 failing ticks → **3 pairs before the fix, 1 after**. +(Deleting the D branch outright panics on the nil deref two lines down; `return false` is the +mutation a real over-correction would produce, so that is the one recorded.) -- **`quiesce.TieredBackend`** (optional extension to `Backend`) + `BackupTier`, - `ErrTiersUnsupported`. A backend that does not implement it drives the pre-R-82 path unchanged. -- **`agentapi`**: `BackupTiers`, `BackupDueFor`, `StartBackupFor`, `BackupStatusFor`. - `targetQuery("")` yields an **empty** suffix, so an untargeted call hits the untargeted route - byte-for-byte. -- **`Loop.resolveDueTiers`** — the dedup rule in one place, tiers in agent order. -- **`quiesceAndPollTiers` + `pollTier`** — one marker, one stop, N sequential backups, one resume. +**How Scenario D is preserved:** the nil branch of `scheduledRunAllowed` is untouched and still fires +the valve, so a genuinely never-backed-up box powered on only outside its window still backs up. +`TestContract_NeverBackedUp_RunsOutsideTheWindow` pins it; +`TestContract_RecentBackup_DefersOutsideTheWindow` is the control (without it the first test would +also pass against a gate that was simply disabled); and +`TestContract_BreakerNeverStarvesAFirstBackup` proves the breaker cannot starve a first backup either. -## 4. Two decisions worth stating plainly +## Deployed -**The app stays quiesced until the LAST tier snapshots.** Resuming after tier 1's snapshot would -leave the following tier capturing a **running** app — losing app-consistency on exactly the DR tier -we most want it on. The consequence is user-visible and documented: on the both-due night downtime is -*(first tier's full backup)* + *(last tier's snapshot)*, not one snapshot. Tiers therefore run -**fast-first** — vzdump holds a guest lock so they are necessarily sequential, and the agent -advertises primary (local) first. The reverse order would make downtime ≈ *(offsite backup)* + -*(local snapshot)*, far worse. +`gitea.dooplex.hu/admin/felhom-controller:0.176.0` — **demo-hp first, then demo-felhom**, both +`Up … (healthy)`, both logging `[quiesce] loop started (poll 5m0s, max-quiesce 30m0s)` with **no** +backoff or deferral lines across two full poll intervals. -**A manual "Mentés most" covers EVERY tier**, in one window, due-ness ignored. A manual run that -silently skipped the DR tier would be the same applied-and-empty fault in a different costume. +## NOT yet live-validated -## 5. Capability detection - -`GET /backup/tiers` 404 ⇒ pre-R-82 agent. This is the project's documented **route-probe** mechanism -(`internal/agentapi/features.go`). It is deliberately **not** a `featureProbes` row: that table -answers a yes/no at a UI entry point, whereas the loop needs the tier **list**, so a row would be a -second probe of the same route for no gain. The degrade logs **exactly once per process** — once -because it is a steady state during a rollout, never zero times because a silent degrade is -indistinguishable from multi-tier working. - -## 6. v0.175.0 — a tier that overruns the quiesce bound defers the rest - -Operator ruling 2026-07-26: *"let the first backup run as long as needed; other backups shouldn't -start until finished."* - -A first FULL offsite snapshot legitimately runs for **hours**. When `max_quiesce` elapses the app -resumes — correct, unchanged — but the loop then started the **next** tier while the first was still -uploading. That is now a `break`. - -Why it matters: vzdump still holds the guest lock, so the second start would be **refused by the -agent (409, v0.99.0)** or fail on the lock — and a failed backup never satisfies a cadence, so the -tier would stay permanently due and retry into the same wall every poll. - -## 7. Tests - -`go build ./... && go vet ./... && go test ./...` — **rc=0, 27 packages** (vet run unpiped; note -`grep FAIL` returns rc=1 when it finds nothing, which is not a failure signal — that idiom caused a -red commit elsewhere in this arc). - -+12 tests in `internal/quiesce/tiers_test.go`. Red-proofs observed and restored: - -- **Both-due night** — a per-tier cycle instead of one window fails with - `want EXACTLY 1 stop and 1 start, got stops=2 starts=2`. **The COUNT is the assertion**; asserting - only "both backups ran" would pass against a double-quiesce implementation. -- **New controller ↔ old agent** — treating `ErrTiersUnsupported` as "nothing due" fails with - `OLD AGENT: a backup MUST still be taken via the untargeted path; got started=[]`. The hollow - version of this test asserts only "no error", which passes while silently skipping the backup. -- **Overrun defer** — dropping the `break` fails with - `the second tier MUST NOT start while the first is still running; started=[local felhom-pbs]`. - -## 8. Deployment — DEPLOYED 2026-07-26 18:22 CEST (this section was stale; corrected) - -**Live on both boxes:** `felhom-controller:0.175.0`, healthy. - -### The correction, and why the record disagreed with itself - -This section previously read *"NOT live-validated — and NOT deployed"*. That was **true when -written** and went **stale 26 minutes later**: - -| CEST | event | -|---|---| -| 17:56:10 | this REPORT committed (`f5e1064`) — "not deployed", accurate at that moment | -| 18:22:56 | controller **0.175.0 deployed** to both boxes (container `StartedAt` 16:22:56 **UTC**) | -| 19:01:39 | the multi-tier quiesce cycle ran (controller log line `17:01:39` — **UTC**) | - -**The defect is mine and it is real:** `REPORT.md` is defined as "overwrite with the most recent -state", and I deployed without updating it. An artifact this project validates against was left -asserting the opposite of reality for the rest of the session. - -**One thing to be precise about, because it nearly became a second wrong conclusion:** the apparent -*contradiction* — a 17:01 quiesce log "before" a 17:56 commit — is a **timezone artifact, not -evidence of a false claim**. The controller logs **UTC**; git commit timestamps here are **CEST**. -Converted to one clock the ordering is consistent and unremarkable: REPORT 17:56 → deploy 18:22 → -quiesce 19:01. That host=CEST / controller=UTC mismatch is already recorded as a project trap and it -caught me once earlier the same day. - -So: a stale artifact (real, mine) — not a claim contradicted by its own evidence. - -## 9. Live validation - -**The multi-tier quiesce ran on demo-hp**, driven through the real UI endpoint -(`POST /api/guest-backup/trigger`, session auth + CSRF — the exact call "Mentés most" makes): - -``` -17:01:39Z manual backup requested — quiescing now -17:01:39Z backup due on 2 tier(s) — quiescing 1 stack(s): [paperless-ngx] <- ONE stop -17:01:46Z tier local: backup job ... started -17:02:56Z tier local: ... done — next tier may start (app still quiesced) <- app stays DOWN -17:02:56Z tier felhom-pbs: backup job backup-9201-felhom-pbs-... started -17:03:06Z tier felhom-pbs: ... snapshotted — resuming app early (8B.2) -17:03:06Z unquiescing (snapshotted (early resume, last tier)): restarting 1 stack(s) <- ONE start -``` - -**Exactly one stop/start pair with both backups inside it** — the assertion that matters, since -"both backups ran" would also pass against an implementation that quiesces twice. Tier order -local-first/PBS-last as designed; the app stayed quiesced *through* the non-last tier, preserving -app-consistency on the DR tier; it resumed at the **last** tier's snapshot rather than its upload. -**Total app downtime 1m27s for both tiers**, and paperless came back healthy. - -## 10. Still NOT live-validated - -1. A **scheduled** both-due night (this was the manual `TriggerNow` path; the scheduled path shares - `quiesceAndPollTiers` but has not been observed firing on its own). -2. The **degrade path** against a genuinely pre-R-82 agent in production — both boxes now run an - agent that serves `/backup/tiers`, so the fallback has not been exercised live. -3. The **overrun defer** firing on a real long-running offsite backup. +- **The loop was reproduced in UNIT TESTS ONLY.** Reproducing it live needs PBS unavailable, and ep0 + must not be taken down for it — a live DR tier on a box with no swap that already OOM'd once today + (R-90). No non-production controller was stood up. +- **No backoff has armed on real hardware** — both boxes are healthy, so what is verified live is the + negative: it does not fire spuriously. +- **Scenario C is not fixed and not testable here** → R-88 Part 2 (agent). +- demo-felhom's local tier becomes due ~2026-07-27 14:53 UTC; with a real age (~24 h, under + cadence+24 h) it should **defer** to the 02:30–06:30 UTC window rather than run — correct + behaviour, and it means the first live in-window backup under v0.176.0 lands tomorrow.