R-1344 decided from the night's measurement: a controller that runs but does not answer is restarted at 10 unhealthy sweeps (alarm at 6) — busy file + the brake refuse; stanza carries unresponsive_restart_after_s / unresponsive_restart_at

internal/localapi/controllersupervisor.go

@@ -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 })

internal/localapi/opreboot.go

@@ -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
 	}

internal/localapi/supervisor_unresponsive_test.go

@@ -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)
+	}
+}