Compare commits
| Author | SHA1 | Date | |
|---|---|---|---|
|
|
bd18347c1c | ||
|
|
98bd1b71e9 | ||
|
|
6578a8b91e |
No files matched your search
+23
-1
@@ -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
|
||||
|
||||
@@ -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
|
||||
|
||||
@@ -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/`.
|
||||
@@ -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
|
||||
|
||||
@@ -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:
|
||||
|
||||
@@ -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 })
|
||||
|
||||
@@ -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
|
||||
}
|
||||
|
||||
@@ -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)
|
||||
}
|
||||
}
|
||||
@@ -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"
|
||||
}
|
||||
}
|
||||
Reference in new issue
Block a user