Compare commits

...
3 Commits
9 changed files with 272 additions and 64 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
## Unreleased — R-1344 decided from the night's measurement: a controller that runs but does not answer is RESTARTED
- **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
+8
View File
@@ -1,5 +1,13 @@
# CONTEXT — felhom-agent working state
> **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 (the stuck-controller restart) is still ALARM ONLY** — the night's health log is read on 2026-10-30.
> **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
+24 -17
View File
@@ -1,29 +1,36 @@
# REPORT — v0.169.0 released and vouched: „Restart controller" from the hub (2026-10-29, attended)
# REPORT — v0.170.0 released and vouched: „Reboot guest" from the hub (D65 = A, 2026-10-29 evening, 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 operator can now reboot a box's guest from the hub's host page, beside „Restart controller".
The agent does it (`pct reboot` of that guest — never the host). It refuses during a backup, a restore, an update or a
controller swap, more than once an hour, and under the restart brake. The result says when the guest and the controller
were back. The controller that starts after the reboot tells the household for a day that Felhom support restarted
the box.
## 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. |
| `ca15a31` | 2520, 2524 green | `reboot_guest` in the closed list (`opreboot.go`): guards (provisioned, running, not locked, not parked; the heavy-operation gate held until the guest is up; `jobBlocker`; the controller's busy file, fresh ≤ 90 s, fail closed on any read error but „no file"; one per hour per guest, persisted; the restart brake counts it); `rebootInFlight` keeps the guest-power watchdog and the supervisor away; the result with both times; `GET /guest/operator-reboot` for the household line; one new read-only sudo vector (`cat` of the controller's busy file) + capability `controller-busy-read`. 19 mutants, each killed (one survivor found and fixed: a duplicate swap check). |
| `6578a8b` | 2525 green | v0.170.0 CHANGELOG heading; `pinned.day0_agent` = 0.170.0 (D50), after the vouch. |
## 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.170.0` from a clean clone of `ca15a31`: sha256 `da8d12a05ef607c338b9ba307e7a81b18253a3188721bbd8421ba36658a22404`,
bundle `03f2ff6442fc3ca600b1f25f26767ce4da466a770a258f3e362cf95f6e76b543`, tag `v0.170.0`, verified by download.
- configs/ changed, so per box a signed `agent_config_update` AND `agent_update` (Tester 1, demo-hp, demo-felhom): all
six COMPLETED; each box „config bundle INSTALLED", capability probe 76/76 ok, „update committed".
- Vouched by the operator 2026-10-29 18:57:48 CET (the save took 38.3 s — felhom.eu R-1346).
## Live proofs (Tester 1, through the hub endpoint the button posts, CC's `cc-hosts` token)
## Live proofs (Tester 1, through the hub endpoint the button posts, CC's `cc-hosts` token; controller 0.349.0-rc.1)
- 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".
- **Refused during an off-site run:** `offsite_backup_now` pressed 18:03:36 UTC → the controller's busy file 11 s later →
„Reboot guest" → „refused: the controller is busy — a backup, a restore or an off-site run is running"; the guest kept
its 13 h uptime.
- **The reboot:** pressed 18:05:08 UTC → „done — rebooted; the guest was up after 67 s, the controller answered after
79 s", on the hub 88 s after the press. Box walk after: 10 containers, none unhealthy, 0 errors, login and file manager
200. The household dashboard: „A Felhom ügyfélszolgálata 19:05-kor újraindította a dobozt."
- **A second press inside the hour:** „refused: guest 9201 was rebooted from the hub at 18:05 UTC — at most one reboot
per hour (next from 19:05 UTC)".
- The release-build reboot: see felhom.eu `REPORT-release-2026-10-29c.md`.
Evidence: felhom.eu `documentation/audits/release-2026-10-29b/` (`p1-restart/`, `final/`).
Evidence: felhom.eu `documentation/audits/release-2026-10-29c/`.
+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-29: day0_agent 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.170.0"
}
}