From a293266f3f14636d85916875f5040f60928676ee Mon Sep 17 00:00:00 2001 From: Stefan Zimmermann <5945920+StefanZ8n@users.noreply.github.com> Date: Wed, 16 Sep 2026 12:25:26 +0200 Subject: [PATCH] Boot fill VMs by hypervisor power state, not heartbeat age MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit A run started within 30 s of the previous run's post-run shutdown found every agent heartbeat still fresh but every VM powered off. The boot pass trusted the heartbeats, skipped the VMs, and the run sat "running" with the fleet off until the boot watchdog power-cycled it five minutes later. The boot pass now asks the driver for each VM's power state: off → power on; on with a live agent → leave alone; on without one → power-cycle. The post-run shutdown also resets agent liveness in the store, so a powered-off VM never reads as having an online agent. Co-Authored-By: Claude Fable 5.1 --- CHANGELOG.md | 11 ++++ internal/orch/fill.go | 48 ++++++++++++++---- internal/orch/orchestrator_test.go | 81 ++++++++++++++++++++++++++++++ internal/store/managed_vms.go | 14 ++++++ 4 files changed, 145 insertions(+), 9 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 814c97d..6321063 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -4,6 +4,17 @@ All notable changes to GhostFleet are documented in this file. The format is based on [Keep a Changelog](https://keepachangelog.com/en/1.1.0/), and the project follows [Semantic Versioning](https://semver.org/). +## [Unreleased] + +### Fixed + +- A fill/incremental/verify run started within 30 s of the previous run's + post-run shutdown booted nothing: the boot pass trusted the still-fresh agent + heartbeats and skipped the powered-off VMs, leaving the run "running" until + the boot watchdog power-cycled the fleet five minutes later. The boot pass now + goes by the hypervisor's actual power state, and the post-run shutdown clears + agent liveness so a powered-off VM never shows an online agent. + ## [1.0.0] — 2026-09-15 First stable, public release. From this point the profile format and the REST diff --git a/internal/orch/fill.go b/internal/orch/fill.go index f74ae5e..740af94 100644 --- a/internal/orch/fill.go +++ b/internal/orch/fill.go @@ -122,19 +122,21 @@ func (o *Orchestrator) runFill(ctx context.Context, d *model.Deployment, run *mo } defer driver.Close() - // Boot the fleet. A VM whose agent heartbeated within agentFreshLimit is - // left untouched — the live agent picks the work order up on its next - // heartbeat. Every other VM gets a guaranteed fresh PXE boot: powered on, - // or power-cycled if it is already on, because a powered-on VM without a - // live agent is unreachable any other way. + // Boot the fleet, deciding per VM from the hypervisor's actual power + // state — never from the agent heartbeat alone. A powered-off VM is simply + // powered on. A powered-on VM whose agent heartbeated within + // agentFreshLimit is left untouched: the live agent picks the work order + // up on its next heartbeat. A powered-on VM without a live agent is + // unreachable any other way, so it gets a hard power-cycle for a fresh + // PXE boot. The power-state check matters because heartbeats stay fresh + // for up to 30 s after the previous run's post-fill shutdown; trusting + // them alone left a fleet powered off with a "running" incremental until + // the boot watchdog kicked in. bootAt := make(map[string]time.Time, len(vms)) bootTries := make(map[string]int, len(vms)) for _, vm := range vms { bootAt[vm.ID], bootTries[vm.ID] = start, 1 - if vm.AgentSeenAt != nil && time.Since(*vm.AgentSeenAt) < agentFreshLimit { - continue - } - o.powerCycle(ctx, driver, vm) + o.bootVM(ctx, driver, vm) } // writeStart marks when data first started flowing (after the VMs boot @@ -258,6 +260,28 @@ func (o *Orchestrator) runFill(ctx context.Context, d *model.Deployment, run *mo } } +// bootVM brings a VM into a state where its agent will pick up the run's work +// order: powers it on if it is off, leaves it alone if it is on with a live +// agent, and power-cycles it if it is on without one. +func (o *Orchestrator) bootVM(ctx context.Context, driver hypervisor.Driver, vm *model.ManagedVM) { + v, err := driver.GetVM(ctx, vm.Ref) + if err != nil { + slog.Warn("fill: reading VM power state failed, power-cycling", "vm", vm.Name, "err", err) + o.powerCycle(ctx, driver, vm) + return + } + if v != nil && v.State == hypervisor.StatePoweredOn { + if vm.AgentSeenAt != nil && time.Since(*vm.AgentSeenAt) < agentFreshLimit { + return // live agent; it picks up the work order on its next heartbeat + } + o.powerCycle(ctx, driver, vm) + return + } + if err := driver.PowerOn(ctx, vm.Ref); err != nil { + slog.Warn("fill: power on failed", "vm", vm.Name, "err", err) + } +} + // powerCycle forces a fresh PXE boot: hard off if the VM is running (tolerated // if it is gone or races off), then on. The temp OS is stateless and every // write is deterministic/idempotent, so a hard cycle is always safe. @@ -284,6 +308,12 @@ func (o *Orchestrator) applyAfterFill(ctx context.Context, driver hypervisor.Dri for _, vm := range vms { if err := driver.PowerOff(ctx, vm.Ref); err != nil { slog.Warn("fill: post-run power off failed", "vm", vm.Name, "err", err) + continue + } + // The agent died with the power; drop its liveness so neither the UI + // nor the next run's boot pass mistakes a fresh heartbeat for a live VM. + if err := o.store.ResetAgent(vm.ID); err != nil { + slog.Warn("fill: resetting agent state after power off", "vm", vm.Name, "err", err) } } } diff --git a/internal/orch/orchestrator_test.go b/internal/orch/orchestrator_test.go index 17a21d3..3531536 100644 --- a/internal/orch/orchestrator_test.go +++ b/internal/orch/orchestrator_test.go @@ -384,6 +384,87 @@ func TestFillPowerCyclesWedgedVMsOnEntry(t *testing.T) { } } +// TestFillPowersOnFreshAgentPoweredOffVMs: an incremental started right after +// the initial fill's post-run shutdown finds every agent heartbeat still +// fresh (<30 s) but every VM powered off. The boot pass must go by the power +// state and power the fleet on, not trust the heartbeats and boot nothing. +func TestFillPowersOnFreshAgentPoweredOffVMs(t *testing.T) { + origPoll := fillPollInterval + fillPollInterval = 10 * time.Millisecond + defer func() { fillPollInterval = origPoll }() + + f := setup(t) + f.orch.StartDeploy(f.dep, model.OnConflictAbort) + f.waitIdle(t) + vms, _ := f.store.ListManagedVMs(f.dep.ID) + + for _, vm := range vms { + f.driver.PowerOff(context.Background(), vm.Ref) + if err := f.store.TouchAgent(vm.ID); err != nil { + t.Fatal(err) + } + } + baseline := len(f.driver.PowerOps()) + + if _, err := f.orch.StartFill(f.dep, model.RunInitialFill); err != nil { + t.Fatalf("StartFill: %v", err) + } + deadline := time.Now().Add(5 * time.Second) + for time.Now().Before(deadline) { + if len(f.driver.PowerOps())-baseline >= len(vms) { + break + } + time.Sleep(5 * time.Millisecond) + } + f.orch.Cancel(f.dep.ID) + + on := map[string]bool{} + for _, op := range f.driver.PowerOps()[baseline:] { + if strings.HasPrefix(op, "off:") { + t.Fatalf("powered-off VM was power-cycled (%s); a plain power-on is enough", op) + } + if strings.HasPrefix(op, "on:") { + on[strings.TrimPrefix(op, "on:")] = true + } + } + for _, vm := range vms { + if !on[vm.Name] { + t.Errorf("%s: powered off with a fresh heartbeat, but never powered on", vm.Name) + } + } +} + +// TestFillAfterShutdownResetsAgent: the post-run shutdown clears agent +// liveness, so a powered-off VM never shows an online agent. +func TestFillAfterShutdownResetsAgent(t *testing.T) { + f := setup(t) + f.orch.StartDeploy(f.dep, model.OnConflictAbort) + f.waitIdle(t) + vms, _ := f.store.ListManagedVMs(f.dep.ID) + for _, vm := range vms { + if err := f.store.TouchAgent(vm.ID); err != nil { + t.Fatal(err) + } + } + driver, err := f.orch.OpenDriver(context.Background(), f.dep.ConnectionID) + if err != nil { + t.Fatal(err) + } + defer driver.Close() + f.dep.Spec.AfterFill = model.AfterFillShutdown + f.orch.applyAfterFill(context.Background(), driver, f.dep, vms) + + after, _ := f.store.ListManagedVMs(f.dep.ID) + for _, vm := range after { + if vm.AgentStatus != model.AgentNone || vm.AgentSeenAt != nil { + t.Errorf("%s: agent status %q seen %v after shutdown, want none/nil", vm.Name, vm.AgentStatus, vm.AgentSeenAt) + } + if f.driver.State(vm.Name) != hypervisor.StatePoweredOff { + t.Errorf("%s: not powered off", vm.Name) + } + } +} + // TestFillBootWatchdogFailsUnbootableVMAlone: a VM whose agent never // registers is power-cycled up to maxBootAttempts, then marked failed by // itself; the run finishes as a partial failure that names the culprit and diff --git a/internal/store/managed_vms.go b/internal/store/managed_vms.go index 67d514a..e0927e5 100644 --- a/internal/store/managed_vms.go +++ b/internal/store/managed_vms.go @@ -56,6 +56,20 @@ func (s *Store) TouchAgent(vmID string) error { return nil } +// ResetAgent marks the VM's agent as gone (never registered), e.g. after the +// VM was powered off: a stale-but-recent heartbeat must not read as alive. +func (s *Store) ResetAgent(vmID string) error { + res, err := s.db.Exec(`UPDATE managed_vms SET agent_status = ?, agent_seen_at = NULL WHERE id = ?`, + model.AgentNone, vmID) + if err != nil { + return err + } + if n, _ := res.RowsAffected(); n == 0 { + return ErrNotFound + } + return nil +} + // GetManagedVM returns one managed VM by ID. func (s *Store) GetManagedVM(id string) (*model.ManagedVM, error) { row := s.db.QueryRow(`SELECT `+managedVMCols+` FROM managed_vms WHERE id = ?`, id)