Compare commits

...
5 Commits
9 changed files with 275 additions and 65 deletions

No files matched your search

+23 -1
View File
@@ -1,4 +1,26 @@
## Unreleased — „Reboot guest" from the hub (D65 = A): `reboot_guest` joins the agent's closed list
## v0.171.0 (2026-10-30) — R-1344 decided from the night's measurement: a controller that runs but does not answer is RESTARTED — RELEASED (release-agent.sh from a clean clone of `bd18347`; agent sha256 c888ca7ba22a1f689059081575814a725e2edcecbb6bcc56829e9d9de88202a5, config bundle 95f977f6dc827185f2b5a2aa9e1c829db41a9f425d49eb40f317286d13c83d2b; binary-only signed agent_update on Tester 1, demo-hp, demo-felhom; vouched by the operator 2026-10-30 10:47:36 CET; `pinned.day0_agent` = 0.171.0). Live on Tester 1: the controller frozen (SIGSTOP) 09:24:50 UTC → Docker „unhealthy" 09:26:36 → the alarm 09:29:21 → the restart 09:31:22 → healthy 09:31:24; the hub mailed `controller_unresponsive` and `controller_unresponsive_restart` (hub 0.178.0), not `controller_restarted_by_agent`
- **The measurement (operator brief 2026-10-29 Part 2, read 2026-10-30).** Docker's own health record of the controller
on Tester 1 and demo-hp, every probe from 2026-10-29 11:12 to 2026-10-30 07:00 UTC: 4 733 probes through the night
chain (demo-hp's PBS vzdump, Tester 1's local vzdump, both DB dumps, tier-2, the off-site push, a restore test, two
controller updates). No failed probe, no 5-s timeout; slowest 303 ms (demo-hp, during the PBS vzdump). The only
„unhealthy" was the controller stopped by hand for a proof. A busy night never came near ONE failed probe.
- **So the alarm becomes a restart.** At `controllerUnresponsiveConfirm` = 6 unhealthy sweeps the alarm is raised, as
before. At `controllerUnresponsiveRestart` = 10 (2 minutes later; ~6.5 minutes after the first failed probe) the agent
restarts the controller's bootstrap unit — unless the controller's busy file is fresh (a backup, a restore, an
update, an export) or cannot be read, or the brake refuses (3 restarts in 15 minutes → the crash-loop pause, which
the hub mails). A swap, a parked guest, a locked guest and a vzdump keep resetting the count, as before. A refusal
keeps the alarm and is logged once per reason. After a restart the count starts again from zero.
- **The stanza** carries `unresponsive_restart_after_s` (120: the hub's alarm text says when the restart comes) and
`unresponsive_restart_at` (equals `last_restart_at` for that act; the hub mails `controller_unresponsive_restart`).
- **Refactor, no behaviour change:** the not-running restart's brake and its record are now `supervisorBrakeAllows`
and `recordSupervisorRestart`, shared by both restarts. The busy-file stale log line no longer says „operator reboot".
- Tests `TestSupervisor_UnresponsiveIsAlarmedThenRestarted`, `…Guards` (now also: never restarted),
`…RestartRefusals` (busy fresh, busy unreadable, the brake, a crash-loop pause), `…StaleBusyFileDoesNotShield` —
red first (build failure, then 3 behaviour failures); 7 mutants, each killed (one survivor — the count reset after a
restart — found and pinned).
## v0.170.0 (2026-10-29) — „Reboot guest" from the hub (D65 = A): `reboot_guest` joins the agent's closed list — RELEASED (release-agent.sh from a clean clone of `ca15a31`; agent sha256 da8d12a05ef607c338b9ba307e7a81b18253a3188721bbd8421ba36658a22404, config bundle 03f2ff6442fc3ca600b1f25f26767ce4da466a770a258f3e362cf95f6e76b543; signed agent_config_update + agent_update on Tester 1, demo-hp, demo-felhom; vouched by the operator 2026-10-29 18:57:48 CET; `pinned.day0_agent` = 0.170.0)
- **D65 = A (operator ruling 2026-10-29 15:50; felhom.eu `04` §6.1, `03`).** The agent's closed operator-action list is
now `restart_controller` and `reboot_guest` (arg: the vmid). No signature: a reboot destroys nothing. The act is the
+18
View File
@@ -1,5 +1,23 @@
# CONTEXT — felhom-agent working state
> **2026-10-30 (day, attended) — v0.171.0 RELEASED and VOUCHED (10:47:36 CET): R-1344 decided — a controller that runs
> but does not answer is RESTARTED.** The night's measurement (4 733 probes, slowest 303 ms, no failure) licensed it:
> alarm at `controllerUnresponsiveConfirm` = 6 unhealthy sweeps, restart at `controllerUnresponsiveRestart` = 10 —
> refused by a fresh/unreadable busy file (`controllerBusy`, shared with D65's reboot) or the brake
> (`supervisorBrakeAllows`, now shared with the not-running restart; `recordSupervisorRestart` records both). The stanza
> carries `unresponsive_restart_after_s` and `unresponsive_restart_at` (hub 0.178.0 mails
> `controller_unresponsive_restart`). Built from `bd18347` (`c888ca7b…`, bundle `95f977f6…`), binary-only signed
> updates on the three test boxes; live on Tester 1 (SIGSTOP → alarm 4.5 min → restart 6.5 min → healthy).
> `pinned.day0_agent` = 0.171.0. felhom.eu `REPORT-release-2026-10-30.md`.
> **2026-10-29 (evening, attended) — v0.170.0 RELEASED and VOUCHED (18:57:48 CET): `reboot_guest` (D65 = A).**
> `da8d12a0…`, bundle `03f2ff64…`, tag `v0.170.0`, from a clean clone of `ca15a31`; configs/ changed (one new read-only
> sudo vector: `cat` of the controller's `data/ctl/busy`), so per box a signed `agent_config_update` + `agent_update`
> (Tester 1, demo-hp, demo-felhom; capability probe 76/76). The agent's closed list is `restart_controller` +
> `reboot_guest` (`opreboot.go`; guards in felhom.eu `03`/`04` §6.1). Proven on Tester 1: refused during an off-site run
> (the controller's busy file), done in 67 s / 79 s, refused a second time inside the hour. `pinned.day0_agent` = 0.170.0.
> **R-1344 decided 2026-10-30: RESTART** (see the 2026-10-30 entry above).
> **2026-10-29 (afternoon, attended) — v0.169.0 RELEASED and VOUCHED (14:06:09 CET).** `fc066de6…`, bundle `3ca33f9c…`,
> from `637c92c`; `pinned.day0_agent` 0.169.0 (`db25eb0`). The agent's own closed operator-action list:
> `restart_controller <vmid>` (host-report reply → result on the next host report; the supervisor's guards; the brake
+17 -18
View File
@@ -1,29 +1,28 @@
# REPORT — v0.169.0 released and vouched: „Restart controller" from the hub (2026-10-29, attended)
# REPORT — v0.171.0 released and vouched: a controller that runs but does not answer is restarted (R-1344, 2026-10-30, attended)
**Plain words first.** The operator can now restart a box's controller from the hub's host page. The agent does it, so it
works when the controller is stopped or stuck. It uses the supervisor's own guards and brake: 3 restarts in 15 minutes,
then presses are refused for 30 minutes. A controller that runs but does not answer now raises an operator alarm
(`controller_unresponsive`); it is not restarted by itself yet — that waits for the night's measurement (R-1344).
**Plain words first.** The night's health log showed that a busy night (backups, dumps, updates) never makes the
controller miss even one health check — the slowest answer was 0.3 s against a 5 s limit. So the agent no longer only
alarms about a controller that runs but does not answer: 2 minutes after the alarm it restarts it, unless the
controller is busy with a backup, a restore or an update, or the restart brake holds.
## Commits
| Commit | CI (job id) | What |
|---|---|---|
| `637c92c` | 2504, 2507 green | The agent's closed list: `restart_controller <vmid>` on the host-report reply (`ControlEnvelope.OperatorActions`), the result on the next host report (`OperatorActionResults`). Guards: provisioned, running, parked, swap, lock, vzdump. The brake counts operator restarts with the supervisor's (`opBrakeUntil`). One audit line, one result per id, re-sent until the hub records it; a report is asked for at once. R-1344: 6 unhealthy sweeps → `unresponsive_since` in the stanza. Tests in `internal/localapi/opactions_test.go`, `supervisor_unresponsive_test.go`, `opactions_wiring_test.go`, each seen failing by its mutation. |
| `db25eb0` | 2513 green | v0.169.0 CHANGELOG; `pinned.day0_agent` = 0.169.0 (D50 pin), after the vouch. |
| `bd18347` | 2532 green | `controllerUnresponsiveRestart` = 10 sweeps; `restartUnresponsive` (busy file, then the brake); the brake and the restart record shared with the not-running restart (`supervisorBrakeAllows`, `recordSupervisorRestart`); stanza `unresponsive_restart_after_s`, `unresponsive_restart_at`. Tests red first (build failure, then 3 behaviour failures); 7 mutants, one survivor (the count reset after a restart) pinned by a new assertion. |
| `84726c9` | (read at the close-out) | v0.171.0 heading; `pinned.day0_agent` = 0.171.0. |
## Release
- `release-agent.sh 0.169.0` from a clean clone: sha256 `fc066de640007038ecfaed6a23e4301a27fc486f1d7851c36177acdd26c2df61`,
bundle `3ca33f9cbab3bdd4c1b7f8ac90aa21e43b64209f1cb45c77ac72b3405956041b`, tag `v0.169.0`, verified by download.
- Signed `agent_update` to the three test boxes; each committed.
- Vouched by the operator 14:06:09 CET (the page answered 504; the save went through — R-1346).
- `release-agent.sh 0.171.0` from a clean clone of `bd18347`: sha256 `c888ca7ba22a1f689059081575814a725e2edcecbb6bcc56829e9d9de88202a5`,
bundle `95f977f6dc827185f2b5a2aa9e1c829db41a9f425d49eb40f317286d13c83d2b`, tag `v0.171.0`, verified by download.
- configs/ unchanged → one signed `agent_update` per box (Tester 1, demo-hp, demo-felhom): all COMPLETED and
„update committed" (10:12–10:20 CET); no new error lines.
- Vouched by the operator 2026-10-30 10:47:36 CET (the save took 132 ms — felhom.eu R-1346, hub 0.178.0).
## Live proofs (Tester 1, through the hub endpoint the button posts, CC's `cc-hosts` token)
## Live proof (Tester 1, controller 0.349.0)
- 13:01–13:02 CET on rc builds: press 1 → the controller answered after 9 s; press 2 with the controller stopped by hand →
restarted 5 s after the stop; press 3 done; press 4 refused („3 restarts in 15 minutes").
- 14:49 CET on the release builds (agent 0.169.0, controller 0.348.0, hub 0.176.1): one press → „done — restarted; the
controller answered after 9 s", on the hub 16 s after the press; the box showed the controller „Up 12 seconds".
Evidence: felhom.eu `documentation/audits/release-2026-10-29b/` (`p1-restart/`, `final/`).
`docker kill --signal=SIGSTOP felhom-controller` 09:24:50 UTC → Docker „unhealthy" 09:26:36 → the agent's alarm
09:29:21 (6 sweeps) → „the controller does not answer — restarting the bootstrap unit" 09:31:22 (10 sweeps) → healthy
09:31:24. The hub mailed `controller_unresponsive_restart` and `controller_unresponsive` (09:42:56, with the next report)
and not `controller_restarted_by_agent`. Evidence: felhom.eu `documentation/audits/release-2026-10-30/p1-r1344/`.
+2 -2
View File
@@ -88,8 +88,8 @@
| `EnsureLeaf` | internal/localapi/cert.go | `EnsureLeaf(certPath, keyPath, host) (cert, fingerprint, generated, err)` | pinned self-signed leaf | `generated=true` invalidates every issued bootstrap pin — log LOUD (B.1) |
| `Server.RecoverStaleLockedGuests` | internal/localapi/stalelock.go | `RecoverStaleLockedGuests(ctx)` | startup stale vzdump-lock heal (F2-b) | Clears ONLY `backup`/`snapshot-delete`, only when no vzdump in-flight; A1 RESOLVED (v0.62.0): scan is pool-intersected (`ListLXC` ∩ `Client.Pool`), fail-safe skip on pool-read failure |
| `ControllerSwapper.Swap` + `ValidControllerImage` | internal/localapi/controllerswap.go | `Swap(ctx, vmid, target) *ControllerSwapState` | agent-owned controller image swap + rollback | Strict image regex (repo + 3-part semver); state file written BEFORE swap; no-healthcheck images need `verifyDwell` |
| `Server.ControllerSupervisorTick` + `ControllerParkedMarker` | internal/localapi/controllersupervisor.go | `ControllerSupervisorTick(ctx)` | R-523: restart a provisioned guest's not-running controller via its bootstrap unit | Two-sweep confirm; honours swapInFlight, the host-side park marker, guest lock + vzdump; 3 restarts/15 min → 30 min pause; record rides the report as `controller_supervisor` (the hub mints the events — the agent has no event channel) |
| `Server.OnEnvelope` / `OperatorActionResults` (operator actions) | internal/localapi/opactions.go | `OnEnvelope(ctx, env)`, `OperatorActionResults() []hub.OperatorActionResult` | 2026-10-29: the operator's actions for THIS agent from the host-report reply — a CLOSED list (`restart_controller` only, `TestOpActions_AgentClosedList`), once per id, the result re-sent until the reply stops listing it, the report requested at once (`SetOperatorActionTrigger`). The restart is the supervisor's act with its guards; the 3-in-15-min brake counts operator restarts too (30-min refusal, `opBrakeUntil`). A new verb is an operator decision AND a hub `store.hostOperatorActionNames` entry in the same release |
| `Server.ControllerSupervisorTick` + `ControllerParkedMarker` | internal/localapi/controllersupervisor.go | `ControllerSupervisorTick(ctx)` | R-523: restart a provisioned guest's not-running controller via its bootstrap unit | Two-sweep confirm; honours swapInFlight, the host-side park marker, guest lock + vzdump; 3 restarts/15 min → 30 min pause (`supervisorBrakeAllows` — every supervisor restart passes it; `recordSupervisorRestart` puts one on the record + R-539's slow counter); R-1344 (2026-10-30): a RUNNING controller whose Docker health reads „unhealthy" is alarmed at 6 sweeps and restarted at 10 (`restartUnresponsive`: the controller's busy file, then the brake); record rides the report as `controller_supervisor` (the hub mints the events — the agent has no event channel) |
| `Server.OnEnvelope` / `OperatorActionResults` (operator actions) | internal/localapi/opactions.go | `OnEnvelope(ctx, env)`, `OperatorActionResults() []hub.OperatorActionResult` | 2026-10-29: the operator's actions for THIS agent from the host-report reply — a CLOSED list (`restart_controller`, `reboot_guest` since D65 — `TestOpActions_AgentClosedList`), once per id, the result re-sent until the reply stops listing it, the report requested at once (`SetOperatorActionTrigger`). The restart is the supervisor's act with its guards; the 3-in-15-min brake counts operator restarts too (30-min refusal, `opBrakeUntil`). A new verb is an operator decision AND a hub `store.hostOperatorActionNames` entry in the same release |
| `MemoryOps` + `Server.readMemoryBounds` | internal/localapi/guestmemory.go | `readMemoryBounds(ctx, vmid) (memoryBounds, err)` | guest RAM resize (v0.90.0, R-24): GET/POST /guest/memory | NEW narrow seam (never extend `GuestAPI` — it breaks every fake); the AGENT is the boundary — bounds recomputed FRESH per request (min 2048 / max host_total−2048 / shrink floor max(2048, usage+512)); §8 UNITS TRAP (config `memory`=MB, status/node=bytes); verify maxmem==target after `SetConfig` before claiming success; SetConfig NEVER called on a refusal path |
### Proxmox client / hub / PBS / provisioning
+6
View File
@@ -218,6 +218,12 @@ type ControllerSupervisorGuest struct {
// looks like it). UnresponsiveSince is the episode's start; the hub keys on it MOVING (controller_unresponsive).
Unresponsive bool `json:"unresponsive"`
UnresponsiveSince string `json:"unresponsive_since,omitempty"` // RFC3339
// R-1344 restart (decided 2026-10-30 from the night's measurement): UnresponsiveRestartAfterS is how long after the
// alarm the agent restarts a controller that still does not answer (0 / absent = an older agent: alarm only — the
// hub's message says which). UnresponsiveRestartAt is the last such restart; the hub keys on it MOVING
// (controller_unresponsive_restart) and it equals LastRestartAt for that act.
UnresponsiveRestartAfterS int `json:"unresponsive_restart_after_s,omitempty"`
UnresponsiveRestartAt string `json:"unresponsive_restart_at,omitempty"` // RFC3339
}
// PBSDRStatus is the per-heartbeat PBS-DR-tier bridge state (slice 2). States:
+99 -17
View File
@@ -3,6 +3,7 @@ package localapi
import (
"context"
"encoding/json"
"fmt"
"os"
"path/filepath"
"sort"
@@ -87,10 +88,16 @@ const (
// R-1344 (operator brief 2026-10-29, Part 2) — a controller that RUNS but does not answer. Docker's own HEALTHCHECK
// (`curl -f localhost:8080/api/health`, every 30 s, timeout 5 s) reads „unhealthy" only after 3 failed probes (~90 s);
// controllerUnresponsiveConfirm more sweeps (3 minutes) make it an episode: logged, carried by the stanza, mailed by
// the hub (controller_unresponsive). ALARM ONLY — it is NOT restarted for this until the measurement (R-1344) shows a
// busy night (backups, updates) never reads unhealthy that long. Not counted during a swap, a parked guest, a locked
// guest or a vzdump.
// the hub (controller_unresponsive). Not counted during a swap, a parked guest, a locked guest or a vzdump.
controllerUnresponsiveConfirm = 6
// controllerUnresponsiveRestart (decided 2026-10-30 from the measurement): at this many consecutive unhealthy sweeps
// (5 minutes after Docker's „unhealthy", ~6.5 minutes after the first failed probe; 2 minutes after the alarm) the
// agent restarts the controller — the not-running restart's guards and brake, plus the controller's busy file. The
// numbers: Tester 1 and demo-hp, 2026-10-29 11:12 → 2026-10-30 07:00 UTC, 4 733 probes through the night chain (a
// PBS and a local vzdump, the DB dumps, tier-2, the off-site push, a restore test, two controller updates): no failed
// probe, slowest 303 ms against the 5 s timeout. A busy night never came near even ONE failed probe; ten sweeps is
// the margin. Pinned by TestSupervisor_UnresponsiveIsAlarmedThenRestarted.
controllerUnresponsiveRestart = 10
)
// controllerSupState is one guest's supervisor record. In-memory on purpose (the guest-power
@@ -119,6 +126,10 @@ type controllerSupState struct {
unhealthySeen int
unresponsive bool
unresponsiveSince time.Time
// unresponsiveRestartAt: the last restart for not answering (kept; the hub keys on it MOVING). unrespRefusal: the
// last reason the restart was refused, so a refusal is logged once per change, not every sweep.
unresponsiveRestartAt time.Time
unrespRefusal string
}
type controllerSupervisor struct {
@@ -354,9 +365,27 @@ func (s *Server) superviseOneController(ctx context.Context, vmid int, guestStat
return false
}
// Backoff.
if !s.supervisorBrakeAllows(vmid, now) {
return false
}
reason := "controller container " + status + " on " + strconv.Itoa(controllerSupervisorConfirm) + " consecutive sweeps"
s.logger.Warn("controller-supervisor: controller is NOT running — restarting the bootstrap unit",
"vmid", vmid, "status", status, "unit", bootstrapUnit)
if _, err := s.guestExec.GuestExec(ctx, vmid, "systemctl", "restart", bootstrapUnit); err != nil {
s.logger.Error("controller-supervisor: bootstrap restart failed", "vmid", vmid, "err", err)
reason += "; restart FAILED: " + err.Error()
}
s.recordSupervisorRestart(vmid, now, reason, nil)
return false
}
// supervisorBrakeAllows is the brake every supervisor restart passes (the not-running one and R-1344's): a crash-loop
// pause in force refuses; controllerCrashloopMax restarts inside controllerCrashloopWindow start one (logged, carried by
// the stanza, mailed by the hub as controller_crashloop) and refuse.
func (s *Server) supervisorBrakeAllows(vmid int, now time.Time) bool {
s.ctrlSup.mu.Lock()
st = s.supState(vmid)
st := s.supState(vmid)
if !st.crashloopSince.IsZero() {
if now.Sub(st.crashloopSince) < controllerCrashloopPause {
s.ctrlSup.mu.Unlock()
@@ -379,22 +408,23 @@ func (s *Server) superviseOneController(ctx context.Context, vmid int, guestStat
return false
}
s.ctrlSup.mu.Unlock()
return true
}
reason := "controller container " + status + " on " + strconv.Itoa(controllerSupervisorConfirm) + " consecutive sweeps"
s.logger.Warn("controller-supervisor: controller is NOT running — restarting the bootstrap unit",
"vmid", vmid, "status", status, "unit", bootstrapUnit)
if _, err := s.guestExec.GuestExec(ctx, vmid, "systemctl", "restart", bootstrapUnit); err != nil {
s.logger.Error("controller-supervisor: bootstrap restart failed", "vmid", vmid, "err", err)
reason += "; restart FAILED: " + err.Error()
}
// recordSupervisorRestart puts a restart the supervisor performed on the record: the brake's window, the totals, the
// reason, and R-539's slow counter (persisted; raised at most once per 24 hours — the hub mails on the raise MOVING).
// mark, when set, runs under the same lock (R-1344 stamps its own record there).
func (s *Server) recordSupervisorRestart(vmid int, now time.Time, reason string, mark func(st *controllerSupState)) {
s.ctrlSup.mu.Lock()
st = s.supState(vmid)
st := s.supState(vmid)
st.restarts = append(st.restarts, now)
st.restartsTotal++
st.lastRestartAt = now
st.lastReason = reason
st.notRunningSeen = 0
// R-539: the slow counter. Raise at most once per 24 hours — the hub mails on the raise MOVING.
if mark != nil {
mark(st)
}
st.restarts24h = append(pruneBefore(st.restarts24h, now.Add(-controllerSlowCrashloopWindow)), now)
n24 := len(st.restarts24h)
raised := false
@@ -410,7 +440,6 @@ func (s *Server) superviseOneController(ctx context.Context, vmid int, guestStat
s.logger.Warn("controller-supervisor: SLOW CRASH-LOOP — the controller keeps dying; still restarting it, raising controller_slow_crashloop",
"vmid", vmid, "restarts_24h", n24, "window", controllerSlowCrashloopWindow.String(), "threshold", controllerSlowCrashloopMax)
}
return false
}
// observeControllerHealth is R-1344's count for a RUNNING controller: Docker's health status, one read per sweep over
@@ -452,11 +481,60 @@ func (s *Server) observeControllerHealth(ctx context.Context, vmid int, parked b
if start {
st.unresponsive, st.unresponsiveSince = true, now
}
since := st.unresponsiveSince
s.ctrlSup.mu.Unlock()
if start {
s.logger.Error("controller-supervisor: the controller RUNS but does not answer its health check — raising controller_unresponsive; NOT restarting it (R-1344: alarm only until measured)",
"vmid", vmid, "unhealthy_sweeps", seen, "interval", controllerSupervisorInterval.String())
s.logger.Error("controller-supervisor: the controller RUNS but does not answer its health check — raising controller_unresponsive; restarting it if it stays so",
"vmid", vmid, "unhealthy_sweeps", seen, "interval", controllerSupervisorInterval.String(),
"restart_after_sweeps", controllerUnresponsiveRestart)
}
if seen >= controllerUnresponsiveRestart {
s.restartUnresponsive(ctx, vmid, seen, since, now)
}
}
// restartUnresponsive is R-1344's restart (decided 2026-10-30): the controller's busy file (fresh = a backup, a
// restore, an update or an export is running; unreadable = cannot be ruled out) refuses, then the brake every
// supervisor restart passes. The swap, the parked marker, the lock and the vzdump never reach here — they reset the
// count. A refusal keeps the alarm and is logged once per reason; the next sweep asks again.
func (s *Server) restartUnresponsive(ctx context.Context, vmid, seen int, since, now time.Time) {
refuse := func(why string) {
s.ctrlSup.mu.Lock()
st := s.supState(vmid)
changed := st.unrespRefusal != why
st.unrespRefusal = why
s.ctrlSup.mu.Unlock()
if changed {
s.logger.Warn("controller-supervisor: the controller does not answer, but the restart is refused — the alarm stays",
"vmid", vmid, "why", why, "unhealthy_sweeps", seen)
}
}
busy, what, err := s.controllerBusy(ctx, vmid)
if err != nil {
refuse("the controller's busy file cannot be read: " + err.Error())
return
}
if busy {
refuse("the controller is busy: " + what)
return
}
if !s.supervisorBrakeAllows(vmid, now) {
refuse("the restart brake")
return
}
reason := fmt.Sprintf("the controller ran but did not answer its health check for %d sweeps (since %s)",
seen, since.UTC().Format(time.RFC3339))
s.logger.Warn("controller-supervisor: the controller does not answer — restarting the bootstrap unit",
"vmid", vmid, "unhealthy_sweeps", seen, "since", since.UTC().Format(time.RFC3339), "unit", bootstrapUnit)
if _, err := s.guestExec.GuestExec(ctx, vmid, "systemctl", "restart", bootstrapUnit); err != nil {
s.logger.Error("controller-supervisor: bootstrap restart failed", "vmid", vmid, "err", err)
reason += "; restart FAILED: " + err.Error()
}
s.recordSupervisorRestart(vmid, now, reason, func(st *controllerSupState) {
st.unresponsiveRestartAt = now
st.unhealthySeen = 0
st.unrespRefusal = ""
})
}
func (s *Server) resetNotRunning(vmid int) {
@@ -517,6 +595,10 @@ func (s *Server) ControllerSupervisorStatus(_ context.Context) *hub.ControllerSu
if !st.unresponsiveSince.IsZero() {
g.UnresponsiveSince = st.unresponsiveSince.UTC().Format(time.RFC3339)
}
g.UnresponsiveRestartAfterS = (controllerUnresponsiveRestart - controllerUnresponsiveConfirm) * int(controllerSupervisorInterval/time.Second)
if !st.unresponsiveRestartAt.IsZero() {
g.UnresponsiveRestartAt = st.unresponsiveRestartAt.UTC().Format(time.RFC3339)
}
out.Guests = append(out.Guests, g)
}
sort.Slice(out.Guests, func(i, j int) bool { return out.Guests[i].VMID < out.Guests[j].VMID })
+3 -2
View File
@@ -137,7 +137,8 @@ func (s *Server) rebooter() interface {
// controllerBusy reads the controller's busy file. busy=true with the controller's reason when the file is fresh;
// a missing file is „not busy" (an idle controller, or one older than the file); any other read failure is an error
// (the caller refuses — it cannot prove no backup runs).
// (the caller refuses — it cannot prove no backup runs). Two callers: the operator's reboot (D65) and R-1344's restart
// of a controller that does not answer (controllersupervisor.go restartUnresponsive).
func (s *Server) controllerBusy(ctx context.Context, vmid int) (bool, string, error) {
out, err := s.guestExec.GuestExec(ctx, vmid, "cat", ControllerBusyMarkerGuestPath)
if err != nil {
@@ -152,7 +153,7 @@ func (s *Server) controllerBusy(ctx context.Context, vmid int) (bool, string, er
return false, "", fmt.Errorf("the controller's busy file does not start with a time: %q", lines[0])
}
if s.clock().Sub(at) > controllerBusyFresh {
s.logger.Info("operator reboot: the controller's busy file is stale — the controller stopped writing it; not busy",
s.logger.Info("controller-busy: the controller's busy file is stale — the controller stopped writing it; not busy",
"vmid", vmid, "written", at.UTC().Format(time.RFC3339))
return false, "", nil
}
+105 -23
View File
@@ -2,19 +2,25 @@ package localapi
import (
"context"
"errors"
"strings"
"testing"
"time"
)
// R-1344 (operator brief 2026-10-29, Part 2): a controller that RUNS but whose Docker health check reads „unhealthy" on
// controllerUnresponsiveConfirm consecutive sweeps is reported unresponsive (the stanza; the hub raises
// controller_unresponsive). ALARM ONLY: it is never restarted for it until the measurement licenses that.
// RED-PROOF: seen failing before the stanza carried it.
// R-1344 (operator brief 2026-10-29, Part 2; decided 2026-10-30 from the night's measurement): a controller that RUNS
// but whose Docker health check reads „unhealthy" on controllerUnresponsiveConfirm consecutive sweeps is reported
// unresponsive (the stanza; the hub raises controller_unresponsive). If it still reads „unhealthy" at
// controllerUnresponsiveRestart sweeps, the agent restarts it — with the not-running restart's guards and brake, plus
// the controller's own busy file. RED-PROOF: the restart tests seen failing before the restart existed.
func unrespServer(t *testing.T, health string) (*Server, *opExec, *fakeGuestPowerCtl) {
func unrespServer(t *testing.T, health string) (*Server, *rbExec, *fakeGuestPowerCtl, *supClock) {
t.Helper()
s, ex, ctl, _, _, _ := opServer(t, "running")
s, ex, ctl, clk, _, _ := opServer(t, "running")
ex.health = health
return s, ex, ctl
rb := &rbExec{opExec: ex}
s.guestExec = rb
return s, rb, ctl, clk
}
func sweep(s *Server, n int) {
@@ -23,8 +29,8 @@ func sweep(s *Server, n int) {
}
}
func TestSupervisor_UnresponsiveIsAlarmedNeverRestarted(t *testing.T) {
s, ex, _ := unrespServer(t, "unhealthy")
func TestSupervisor_UnresponsiveIsAlarmedThenRestarted(t *testing.T) {
s, ex, _, _ := unrespServer(t, "unhealthy")
sweep(s, controllerUnresponsiveConfirm-1)
if g := s.ControllerSupervisorStatus(context.Background()).Guests; len(g) != 1 || g[0].Unresponsive {
t.Fatalf("unresponsive before %d sweeps: %+v", controllerUnresponsiveConfirm, g)
@@ -34,41 +40,117 @@ func TestSupervisor_UnresponsiveIsAlarmedNeverRestarted(t *testing.T) {
if len(g) != 1 || !g[0].Unresponsive || g[0].UnresponsiveSince == "" {
t.Fatalf("after %d unhealthy sweeps: %+v", controllerUnresponsiveConfirm, g)
}
if g[0].UnresponsiveRestartAfterS != (controllerUnresponsiveRestart-controllerUnresponsiveConfirm)*int(controllerSupervisorInterval/time.Second) {
t.Fatalf("the stanza must tell the hub when the restart comes: %+v", g[0])
}
since := g[0].UnresponsiveSince
sweep(s, 10)
sweep(s, controllerUnresponsiveRestart-controllerUnresponsiveConfirm-1)
if n := ex.count(9201); n != 0 {
t.Fatalf("an unresponsive controller was RESTARTED (%d) — the restart waits for the measurement", n)
t.Fatalf("restarted after %d unhealthy sweeps — the restart waits for %d", controllerUnresponsiveRestart-1, controllerUnresponsiveRestart)
}
if g := s.ControllerSupervisorStatus(context.Background()).Guests; g[0].UnresponsiveSince != since {
t.Fatal("unresponsive_since moved while it stayed unresponsive — the hub would mail again")
}
// it answers again
ex.health = "healthy"
sweep(s, 1)
if n := ex.count(9201); n != 1 {
t.Fatalf("after %d unhealthy sweeps: %d restarts, want 1", controllerUnresponsiveRestart, n)
}
g = s.ControllerSupervisorStatus(context.Background()).Guests
if g[0].UnresponsiveRestartAt == "" || g[0].UnresponsiveRestartAt != g[0].LastRestartAt || g[0].Restarts24h != 1 ||
!strings.Contains(g[0].LastReason, "health check") {
t.Fatalf("the restart is not on the record the hub reads: %+v", g[0])
}
// A restart that did not help (still „unhealthy" on the next sweep) is not repeated at once: the count starts again.
sweep(s, 1)
if n := ex.count(9201); n != 1 {
t.Fatalf("restarted again on the sweep after a restart: %d restarts", n)
}
// The restarted controller starts, then answers: the episode ends, its record stays.
ex.health = "starting"
sweep(s, 1)
if g := s.ControllerSupervisorStatus(context.Background()).Guests; g[0].Unresponsive || g[0].UnresponsiveSince != since {
t.Fatalf("after it answered: %+v (unresponsive must clear; since stays as the record)", g[0])
t.Fatalf("after the restart: %+v (unresponsive must clear; since stays as the record)", g[0])
}
// A second episode needs the whole count again — never a restart on the first unhealthy read after one.
ex.health = "unhealthy"
sweep(s, controllerUnresponsiveRestart-1)
if n := ex.count(9201); n != 1 {
t.Fatalf("a second episode restarted early: %d restarts", n)
}
}
// Slow but answering (healthy / starting), a swap, a vzdump or a parked guest never counts.
// Slow but answering (healthy / starting), a swap, a vzdump, a locked or a parked guest never counts — and so is never
// restarted.
func TestSupervisor_UnresponsiveGuards(t *testing.T) {
for _, tc := range []struct {
name string
setup func(s *Server, ex *opExec, ctl *fakeGuestPowerCtl)
setup func(s *Server, ex *rbExec, ctl *fakeGuestPowerCtl)
}{
{"healthy", func(_ *Server, ex *opExec, _ *fakeGuestPowerCtl) { ex.health = "healthy" }},
{"starting", func(_ *Server, ex *opExec, _ *fakeGuestPowerCtl) { ex.health = "starting" }},
{"swap", func(s *Server, _ *opExec, _ *fakeGuestPowerCtl) { s.swapInFlight[9201] = true }},
{"vzdump", func(_ *Server, _ *opExec, ctl *fakeGuestPowerCtl) { ctl.backupRun = map[int]bool{9201: true} }},
{"locked", func(_ *Server, _ *opExec, ctl *fakeGuestPowerCtl) { ctl.locks[9201] = "backup" }},
{"healthy", func(_ *Server, ex *rbExec, _ *fakeGuestPowerCtl) { ex.health = "healthy" }},
{"starting", func(_ *Server, ex *rbExec, _ *fakeGuestPowerCtl) { ex.health = "starting" }},
{"swap", func(s *Server, _ *rbExec, _ *fakeGuestPowerCtl) { s.swapInFlight[9201] = true }},
{"vzdump", func(_ *Server, _ *rbExec, ctl *fakeGuestPowerCtl) { ctl.backupRun = map[int]bool{9201: true} }},
{"locked", func(_ *Server, _ *rbExec, ctl *fakeGuestPowerCtl) { ctl.locks[9201] = "backup" }},
} {
t.Run(tc.name, func(t *testing.T) {
s, ex, ctl := unrespServer(t, "unhealthy")
s, ex, ctl, _ := unrespServer(t, "unhealthy")
tc.setup(s, ex, ctl)
sweep(s, controllerUnresponsiveConfirm+2)
sweep(s, controllerUnresponsiveRestart+2)
if g := s.ControllerSupervisorStatus(context.Background()).Guests; len(g) == 1 && g[0].Unresponsive {
t.Fatalf("%s counted as unresponsive: %+v", tc.name, g[0])
}
if n := ex.count(9201); n != 0 {
t.Fatalf("%s: restarted %d times", tc.name, n)
}
})
}
}
// At the restart moment: the controller's busy file (fresh, or unreadable) and the brake refuse it; the alarm stays.
// RED-PROOF: each seen failing by deleting its guard.
func TestSupervisor_UnresponsiveRestartRefusals(t *testing.T) {
for _, tc := range []struct {
name string
setup func(s *Server, ex *rbExec, clk *supClock)
crashloop bool
}{
{"busy file fresh", func(_ *Server, ex *rbExec, clk *supClock) {
ex.busy = clk.t.Add(-20*time.Second).Format(time.RFC3339) + "\na backup, a restore or an off-site run is running\n"
}, false},
{"busy file unreadable", func(_ *Server, ex *rbExec, _ *supClock) { ex.busyErr = errors.New("pct exec: exit status 255") }, false},
{"brake: 3 restarts in 15 minutes", func(s *Server, _ *rbExec, clk *supClock) {
st := s.supState(9201)
st.restarts = []time.Time{clk.t.Add(-10 * time.Minute), clk.t.Add(-5 * time.Minute), clk.t.Add(-time.Minute)}
}, true},
{"crash-loop pause in force", func(s *Server, _ *rbExec, clk *supClock) {
s.supState(9201).crashloopSince = clk.t.Add(-5 * time.Minute)
}, true},
} {
t.Run(tc.name, func(t *testing.T) {
s, ex, _, clk := unrespServer(t, "unhealthy")
tc.setup(s, ex, clk)
sweep(s, controllerUnresponsiveRestart+3)
if n := ex.count(9201); n != 0 {
t.Fatalf("%s: restarted %d times", tc.name, n)
}
g := s.ControllerSupervisorStatus(context.Background()).Guests
if len(g) != 1 || !g[0].Unresponsive || g[0].UnresponsiveRestartAt != "" {
t.Fatalf("%s: the alarm must stay and no restart be recorded: %+v", tc.name, g)
}
if tc.crashloop && !g[0].Crashloop {
t.Fatalf("%s: the brake did not raise the crash-loop: %+v", tc.name, g[0])
}
})
}
}
// A busy file the controller stopped writing (older than controllerBusyFresh) is not „busy" — a hung controller must
// not shield itself with its last word.
func TestSupervisor_UnresponsiveStaleBusyFileDoesNotShield(t *testing.T) {
s, ex, _, clk := unrespServer(t, "unhealthy")
ex.busy = clk.t.Add(-10*time.Minute).Format(time.RFC3339) + "\nan app update is running\n"
sweep(s, controllerUnresponsiveRestart)
if n := ex.count(9201); n != 1 {
t.Fatalf("a stale busy file blocked the restart: %d restarts", n)
}
}
+2 -2
View File
@@ -25,9 +25,9 @@
"scripts/check-published-versions.py — asserts the newest N versions plus every pinned version"
],
"recorded": "2026-10-29",
"recorded_by": "CC 2026-10-29: day0_agent 0.169.0 (operator vouch 2026-10-29 14:06:09 CET, read from the hub log: agent=0.169.0, bundle 3ca33f9c… = the release; his browser got a 504 but the save went through); earlier 0.168.0 (vouch 10:21:56 CET); 0.167.0 (vouch 2026-10-27); 0.166.0 (vouch 2026-10-26 10:04:55 CET); D50 = A (operator 2026-10-25); earlier history: R-287 (2026-08-09), R-291 (2026-10-05)",
"recorded_by": "CC 2026-10-30: day0_agent 0.171.0 (operator vouch 2026-10-30 10:47:36 CET, read from the hub log: agent=0.171.0, bundle 95f977f6… = the release; the save took 132 ms with hub 0.178.0, R-1346); earlier 0.170.0 (operator vouch 2026-10-29 18:57:48 CET, read from the hub log: agent=0.170.0, bundle 03f2ff64… = the release; the save took 38.3 s, R-1346); earlier 0.169.0 (operator vouch 2026-10-29 14:06:09 CET, read from the hub log: agent=0.169.0, bundle 3ca33f9c… = the release; his browser got a 504 but the save went through); earlier 0.168.0 (vouch 10:21:56 CET); 0.167.0 (vouch 2026-10-27); 0.166.0 (vouch 2026-10-26 10:04:55 CET); D50 = A (operator 2026-10-25); earlier history: R-287 (2026-08-09), R-291 (2026-10-05)",
"pinned": {
"hub_min_agent": "0.158.1",
"day0_agent": "0.169.0"
"day0_agent": "0.171.0"
}
}