Lost power commands are visible; jobs not started in job_start_timeout fail

pxeBoot dropped the errors of its BMC calls, so a command lost while the
rack or region restarted produced an empty, success-looking event and the
job waited forever. Errors now go into the event (pxe boot failed), and a
watchdog fails jobs the machine has not started within job_start_timeout
(default 30m: real servers take 4-5 minutes to POST, longer in bulk).

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>

CHANGELOG.md

@@ -87,6 +87,11 @@ publish a tag that has no section here.
 - Release notes from `CHANGELOG.md`.
 
 ### Fixed
+- A deploy whose power command was lost (rack or region restarting) stayed pending forever and the
+  event looked like a success: power errors are now part of the event (`pxe boot failed`), and a
+  job the machine has not started within `job_start_timeout` (default 30m, room for servers that
+  take 4-5 minutes to POST) fails with a hint.
+- CentOS Stream 9 image URL (the 502 was a missing file name).
 - Rack controllers' dnsmasq had no upstream DNS on Debian (it looks for a resolvconf file that is
   usually missing) and refused every name outside the cluster domain; the generated configuration
   now forwards to systemd-resolved's stub (keeping split DNS) or the host's resolv.conf servers.

cmd/rollcall/config.go

@@ -47,6 +47,10 @@ type Config struct {
 	TLSNames  []string `json:"tls_names"`  // extra names/addresses for the region certificate
 	AdminHTTP string   `json:"admin_http"` // admin API over plain HTTP: allow (default) | loopback | deny
 
+	// a deploy/release job the machine has not started by then fails (default 30m;
+	// servers can take 4-5 minutes to POST, longer when many boot together)
+	JobStartTimeout string `json:"job_start_timeout"`
+
 	// external IPAM authority (NetBox; Infoblox at sites that run it)
 	IPAM IPAMConfig `json:"ipam"`
 }

cmd/rollcall/deploy.go

@@ -731,3 +731,50 @@ func (a *App) handlePhoneHome(w http.ResponseWriter, r *http.Request) {
 	log.Printf("phone-home %s: %s", j.MachineID, detail)
 	writeJSON(w, 200, obj{"ok": true})
 }
+
+// jobStartTimeout: a deploy or release job the machine has not picked up by then
+// is failed, so a lost power command or a machine that did not PXE-boot is
+// visible instead of an endless "pending". Real servers spend 4-5 minutes in
+// POST on a cold start (more after a firmware or memory change), and many
+// machines booting at once share the PXE and image servers: the default leaves
+// room for that; job_start_timeout in config.json changes it.
+const jobStartTimeout = 30 * time.Minute
+
+func (a *App) jobStartTimeout() time.Duration {
+	if d, err := time.ParseDuration(a.cfg.JobStartTimeout); err == nil && d >= time.Minute {
+		return d
+	}
+	return jobStartTimeout
+}
+
+// staleJobs picks the pending jobs created before cutoff.
+func staleJobs(active map[string]*Job, cutoff time.Time) []*Job {
+	var out []*Job
+	for _, j := range active {
+		if j.State == "pending" && j.Created.Before(cutoff) {
+			out = append(out, j)
+		}
+	}
+	sort.Slice(out, func(i, k int) bool { return out[i].Created.Before(out[k].Created) })
+	return out
+}
+
+func (a *App) jobWatchdog() {
+	for range time.Tick(time.Minute) {
+		ctx, cancel := context.WithTimeout(context.Background(), 30*time.Second)
+		active, err := a.store.ActiveJobs(ctx)
+		if err == nil {
+			limit := a.jobStartTimeout()
+			for _, j := range staleJobs(active, time.Now().Add(-limit)) {
+				m, err := a.store.Get(ctx, j.MachineID)
+				if err != nil {
+					continue
+				}
+				msg := fmt.Sprintf("the machine did not start the job within %s: check its power, that it PXE-boots on the provisioning network, and its console for a hung POST (events show the power command's result; job_start_timeout raises the limit)", limit)
+				_ = a.store.FinishJob(ctx, j.ID, "failed", msg)
+				a.afterJob(ctx, m, j, "failed", msg)
+			}
+		}
+		cancel()
+	}
+}

cmd/rollcall/network_test.go

@@ -6,6 +6,7 @@ import (
 	"path/filepath"
 	"strings"
 	"testing"
+	"time"
 )
 
 func labSubnet() Subnet {
@@ -275,3 +276,16 @@ func TestSecondarySubnetPolicyRouting(t *testing.T) {
 		t.Errorf("gateway-less subnet got policy routing:\n%s", b)
 	}
 }
+
+func TestStaleJobs(t *testing.T) {
+	now := time.Now()
+	active := map[string]*Job{
+		"m1": {ID: "old", State: "pending", Created: now.Add(-45 * time.Minute)},
+		"m2": {ID: "new", State: "pending", Created: now.Add(-5 * time.Minute)},
+		"m3": {ID: "running", State: "running", Created: now.Add(-60 * time.Minute)},
+	}
+	got := staleJobs(active, now.Add(-jobStartTimeout))
+	if len(got) != 1 || got[0].ID != "old" {
+		t.Errorf("stale jobs: %+v", got)
+	}
+}

cmd/rollcall/server.go

@@ -725,6 +725,7 @@ func serve(cfgPath string) error {
 	if err := app.startIPAM(); err != nil {
 		return fmt.Errorf("ipam: %w", err)
 	}
+	go app.jobWatchdog()
 	handler := app.routes()
 	if cfg.TLSListen != "" {
 		names := append([]string{}, cfg.TLSNames...)

cmd/rollcall/stateless.go

@@ -803,8 +803,18 @@ func (a *App) pxeBoot(ctx context.Context, m *Machine) (string, bool) {
 	} else {
 		o2, e2 = a.power(ctx, m, "cycle", "")
 	}
-	_ = a.store.AddEvent(ctx, m.ID, "pxe boot", strings.TrimSpace(o1+"\n"+o2))
+	detail := strings.TrimSpace(o1 + "\n" + o2)
-	return strings.TrimSpace(o1 + "\n" + o2), e1 == nil && e2 == nil
+	ev := "pxe boot"
+	if e1 != nil || e2 != nil { // a lost or failed power command must not look like success
+		ev = "pxe boot failed"
+		for _, e := range []error{e1, e2} {
+			if e != nil {
+				detail = strings.TrimSpace(detail + "\n" + e.Error())
+			}
+		}
+	}
+	_ = a.store.AddEvent(ctx, m.ID, ev, detail)
+	return detail, e1 == nil && e2 == nil
 }
 
 func (a *App) handleUnassign(w http.ResponseWriter, r *http.Request) {