admin
ccefff4f39
The quiesce loop is silent by design when nothing is due, so 'no error lines' is not evidence. The observable that is: every /backup/due makes the agent read that tier's storage content, which lands in pveproxy/access.log. Both tiers polled every 5 min, both HTTP 200, tick phase consistent with the deploy restart.
125 lines
8.2 KiB
Markdown
125 lines
8.2 KiB
Markdown
# REPORT — R-88 Part 1: the quiesce failure breaker (v0.176.0) (2026-07-27)
|
||
|
||
**Overwritten** per the standing rule. Controller **v0.175.0 → v0.176.0**. **MinAgent UNCHANGED** —
|
||
this is controller-internal scheduling; no agent surface is touched.
|
||
|
||
## 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**.
|
||
|
||
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.
|
||
|
||
## Phase 0 (read-only) — the three answers
|
||
|
||
**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.
|
||
|
||
**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.
|
||
|
||
**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 |
|
||
|---|---|---|
|
||
| **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` |
|
||
|
||
**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.)
|
||
|
||
**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.
|
||
|
||
## Deployed
|
||
|
||
`gitea.dooplex.hu/admin/felhom-controller:0.176.0` — **demo-hp first, then demo-felhom**, both
|
||
`Up … (healthy)`, both image digests matching the DooPlex build byte-for-byte
|
||
(`sha256:98fcbc677bfa1ab8…`), both logging `[quiesce] loop started (poll 5m0s, max-quiesce 30m0s)`.
|
||
|
||
**Positive confirmation the loop still works, not merely the absence of complaints.** The quiesce
|
||
loop is *silent by design* when nothing is due (`len(dueTiers) == 0 → return nil`), so "no error
|
||
lines" proves nothing on its own. The observable that does prove it is the agent's per-tier
|
||
due-check: every `/backup/due` makes the agent read that tier's storage content (R-84 ground truth),
|
||
which lands in `pveproxy/access.log`. On demo-felhom after the deploy:
|
||
|
||
```
|
||
16:28:44 +0200 GET …/storage/local/content 200
|
||
16:28:45 +0200 GET …/storage/felhom-pbs/content 200
|
||
16:33:44 +0200 GET …/storage/local/content 200
|
||
16:33:45 +0200 GET …/storage/felhom-pbs/content 200
|
||
```
|
||
|
||
Both tiers polled every 5 minutes, both answering **200** — so the loop is ticking, both tiers are
|
||
being evaluated, and the storage reads succeed (real ages, no nil, no valve firing). The tick phase
|
||
shifted from `:02:57/:07:58/:12:57` to `:28:44/:33:44`, which is the 14:23:43 UTC restart resetting
|
||
the ticker — consistent with the deploy and nothing else. **Zero backoff or deferral lines on either
|
||
box**, and no vzdump attempted since the incident's last failure at 07:13:06 UTC.
|
||
|
||
## NOT yet live-validated
|
||
|
||
- **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.
|