Startup convergence: re-invoke the reclaim verb, and boot before a resumed hibernate

docs/metrics.md

@@ -51,7 +51,7 @@ Prometheus endpoint with vk-cocoon-specific metrics:
 | `cocoon_vk_vm_inspect_transient_fail_total` | Counter | Transient VM inspect failures tolerated by the status refresher |
 | `cocoon_vk_pod_evict_failure_total` | Counter | Failed pod evictions |
 | `cocoon_vk_reconcile_adopt_by_name_total` | Counter | Startup reconcile adoptions matched by VM name |
-| `cocoon_vk_stale_create_reconcile_total{outcome}` | Counter | Creating placeholders routed through the stale-create verb at startup (`outcome=collected\|busy\|not-creating\|not-found\|error`) |
+| `cocoon_vk_stale_create_reconcile_total{outcome}` | Counter | Stale-create verb attempts by startup reconcile and its bounded watcher (`outcome=collected\|busy\|not-creating\|not-found\|error`) |
 | `cocoon_vk_hibernate_evidence_total{verdict}` | Counter | Fresh boots intercepted by hibernate evidence (`verdict=restored\|image_conflict\|source_conflict\|unavailable`) |
 | `cocoon_vk_startup_resume_total{op}` | Counter | Interrupted operations re-dispatched by startup reconcile (`op=hibernate\|post_clone\|ready_wait\|classify_drop_nic`) |
 

docs/reconcile.md

@@ -17,10 +17,13 @@ On every restart vk-cocoon:
    deadlocks its pod. `collected`/`not-found` free the name for a clean
    recreate; `busy` (an in-flight clone still owns the record) and
    transient verb or inspect errors hand the record to a bounded
-   background watcher that indexes it for adoption once it reaches
-   `running`, or applies the orphan policy if it dies without ever
-   running; a record that already left `creating` is adopted only when
-   `running`. Outcomes are counted on
+   background watcher. Each watcher tick re-invokes the verb:
+   `collected`/`not-found` free the name for a clean recreate; otherwise
+   an inspect indexes a committed `running` VM or applies the orphan
+   policy to a terminal record. An unresolved `creating`/`created` state
+   or transient error remains under bounded retry. A record that already
+   left `creating` is adopted only when `running`. Every verb attempt is
+   counted on
    `cocoon_vk_stale_create_reconcile_total`.
 4. Adopts each pod with a `vm.cocoonstack.io/id` annotation by matching
    the VMID against the runtime list.

provider/cocoon/create_test.go

@@ -1689,6 +1689,10 @@ type fakeRuntime struct {
 
 	netResizeCalls []netResizeCall
 	netResizeErr   error
+	// netResizeNeedsStart fails NetResize until Start ran — a dead VMM whose record still reads running.
+	netResizeNeedsStart bool
+
+	startCalls []string
 
 	// mu guards snapshots, imagesPresent, and the call ledgers so
 	// singleflight tests can drive concurrent ensure* callers under -race.
@@ -1704,8 +1708,10 @@ type fakeRuntime struct {
 	onRemove func()
 
 	staleCreateOutcomes map[string]vm.StaleCreateOutcome // by vmID; absent → collected
-	staleCreateCalls    []string
-	staleCreateErr      error
+	// staleCreateSeq is consumed per vmID before staleCreateOutcomes — scripts an owner that exits mid-watch.
+	staleCreateSeq   map[string][]vm.StaleCreateOutcome
+	staleCreateCalls []string
+	staleCreateErr   error
 	// onExec, when set, fires at Exec entry — lets tests block or mutate state mid-exec.
 	onExec          func()
 	removeErr       error
@@ -1780,10 +1786,16 @@ func (f *fakeRuntime) Remove(_ context.Context, vmID string) error {
 }
 
 func (f *fakeRuntime) ReconcileStaleCreate(_ context.Context, vmID string) (vm.StaleCreateOutcome, error) {
+	f.mu.Lock()
+	defer f.mu.Unlock()
 	f.staleCreateCalls = append(f.staleCreateCalls, vmID)
 	if f.staleCreateErr != nil {
 		return "", f.staleCreateErr
 	}
+	if seq := f.staleCreateSeq[vmID]; len(seq) > 0 {
+		f.staleCreateSeq[vmID] = seq[1:]
+		return seq[0], nil
+	}
 	if o, ok := f.staleCreateOutcomes[vmID]; ok {
 		return o, nil
 	}
@@ -1899,7 +1911,12 @@ func (f *fakeRuntime) ImageImport(ctx context.Context, name string) (io.WriteClo
 	return nopWriteCloser{}, wait, nil
 }
 
-func (f *fakeRuntime) Start(_ context.Context, _ string) error { return nil }
+func (f *fakeRuntime) Start(_ context.Context, vmID string) error {
+	f.mu.Lock()
+	defer f.mu.Unlock()
+	f.startCalls = append(f.startCalls, vmID)
+	return nil
+}
 
 type netResizeCall struct {
 	vmID   string
@@ -1911,6 +1928,9 @@ func (f *fakeRuntime) NetResize(ctx context.Context, vmID string, target int) er
 		return err
 	}
 	f.netResizeCalls = append(f.netResizeCalls, netResizeCall{vmID: vmID, target: target})
+	if f.netResizeNeedsStart && len(f.started()) == 0 {
+		return fmt.Errorf("cocoon vm net %s: vm is not running: vm not running", vmID)
+	}
 	return f.netResizeErr
 }
 
@@ -1977,6 +1997,18 @@ func (f *fakeRuntime) registerSnapshot(name string) {
 	f.snapshots[name] = &vm.Snapshot{Name: name}
 }
 
+func (f *fakeRuntime) staleCalls() []string {
+	f.mu.Lock()
+	defer f.mu.Unlock()
+	return slices.Clone(f.staleCreateCalls)
+}
+
+func (f *fakeRuntime) started() []string {
+	f.mu.Lock()
+	defer f.mu.Unlock()
+	return slices.Clone(f.startCalls)
+}
+
 type nopWriteCloser struct{}
 
 func (nopWriteCloser) Write(p []byte) (int, error) { return len(p), nil }

provider/cocoon/reconcile.go

@@ -124,29 +124,18 @@ func (p *Provider) reconcileStaleCreates(ctx context.Context, vms []vm.VM) []vm.
 		}
 		g.Go(func() error {
 			outcome, err := p.Runtime.ReconcileStaleCreate(ctx, v.ID)
+			recordStaleCreateOutcome(outcome, err)
 			if err != nil {
-				metrics.StaleCreateReconcileTotal.WithLabelValues("error").Inc()
 				logger.Errorf(ctx, err, "reconcile creating placeholder %s (%s); watching for commit", v.ID, v.Name)
 				p.watchBusyCreate(v.ID)
 				return nil
 			}
-			metrics.StaleCreateReconcileTotal.WithLabelValues(string(outcome)).Inc()
 			switch outcome {
 			case vm.StaleCreateNotCreating:
-				fresh, inspectErr := p.Runtime.Inspect(ctx, v.ID)
-				switch {
-				case errors.Is(inspectErr, vm.ErrVMNotFound):
-					// Gone between the verb and the inspect.
-				case inspectErr != nil:
-					logger.Errorf(ctx, inspectErr, "re-inspect %s after not-creating; watching for commit", v.ID)
+				if fresh, settled := p.classifySettledCreate(ctx, v.ID); !settled {
 					p.watchBusyCreate(v.ID)
-				case fresh.State == vm.StateRunning:
+				} else if fresh != nil {
 					keep[i] = fresh
-				case inFlightCreate(fresh.State):
-					p.watchBusyCreate(v.ID)
-				default:
-					logger.Warnf(ctx, "placeholder %s (%s) left creating as %s without running; applying orphan policy", v.ID, v.Name, fresh.State)
-					p.handleOrphan(ctx, fresh)
 				}
 			case vm.StaleCreateBusy:
 				logger.Warnf(ctx, "creating placeholder %s (%s) is owned by an in-flight operation; watching for commit", v.ID, v.Name)
@@ -167,8 +156,9 @@ func (p *Provider) reconcileStaleCreates(ctx context.Context, vms []vm.VM) []vm.
 	return kept
 }
 
-// watchBusyCreate polls an unclassified creating record: the event watcher
-// only reacts to deletions and stops, so a clone that commits is invisible.
+// watchBusyCreate re-invokes the reclaim verb on an unclassified creating
+// record: only the verb tells a live owner from one that died holding the
+// name, and nothing else re-delivers either outcome.
 func (p *Provider) watchBusyCreate(vmID string) {
 	p.goBackground(func() {
 		ctx := p.lifecycleCtx
@@ -179,28 +169,54 @@ func (p *Provider) watchBusyCreate(vmID string) {
 			if !commonk8s.SleepCtx(ctx, delay) {
 				return
 			}
-			v, err := p.Runtime.Inspect(ctx, vmID)
-			switch {
-			case errors.Is(err, vm.ErrVMNotFound):
-				return
-			case err == nil && v.State == vm.StateRunning:
-				logger.Infof(ctx, "in-flight create %s (%s) committed; indexing for adoption", vmID, v.Name)
-				p.indexOrphanByName(v)
+			outcome, err := p.Runtime.ReconcileStaleCreate(ctx, vmID)
+			recordStaleCreateOutcome(outcome, err)
+			if err != nil {
+				logger.Errorf(ctx, err, "re-reconcile creating placeholder %s", vmID)
+			} else if outcome == vm.StaleCreateCollected || outcome == vm.StaleCreateNotFound {
+				logger.Infof(ctx, "in-flight create %s resolved as %s; CreatePod recreates", vmID, outcome)
 				return
-			case err == nil && !inFlightCreate(v.State):
-				logger.Warnf(ctx, "in-flight create %s (%s) ended %s without running; applying orphan policy", vmID, v.Name, v.State)
-				p.handleOrphan(ctx, v)
+			}
+			// A failing verb must not strand a clone that did commit.
+			if fresh, settled := p.classifySettledCreate(ctx, vmID); settled {
+				if fresh != nil {
+					logger.Infof(ctx, "in-flight create %s (%s) committed; indexing for adoption", vmID, fresh.Name)
+					p.indexOrphanByName(fresh)
+				}
 				return
 			}
 			if time.Now().After(deadline) {
-				logger.Warnf(ctx, "in-flight create %s did not leave creating within budget; giving up", vmID)
+				logger.Warnf(ctx, "in-flight create %s did not resolve within budget; giving up", vmID)
 				return
 			}
 			delay = min(delay*2, maxDelay)
 		}
 	})
 }
 
+// classifySettledCreate resolves a record past the verb: (vm, true) committed
+// and adoptable, (nil, true) settled with nothing to adopt, (nil, false) still
+// transitional — ask again.
+func (p *Provider) classifySettledCreate(ctx context.Context, vmID string) (*vm.VM, bool) {
+	logger := log.WithFunc("Provider.classifySettledCreate")
+	fresh, err := p.Runtime.Inspect(ctx, vmID)
+	switch {
+	case errors.Is(err, vm.ErrVMNotFound):
+		return nil, true
+	case err != nil:
+		logger.Errorf(ctx, err, "re-inspect creating placeholder %s; watching for commit", vmID)
+		return nil, false
+	case fresh.State == vm.StateRunning:
+		return fresh, true
+	case inFlightCreate(fresh.State):
+		return nil, false
+	default:
+		logger.Warnf(ctx, "placeholder %s (%s) left creating as %s without running; applying orphan policy", vmID, fresh.Name, fresh.State)
+		p.handleOrphan(ctx, fresh)
+		return nil, true
+	}
+}
+
 // reconcileStaleHibernate clears stale VMID/IP from a hibernated pod whose
 // VM is already gone, so wake can start clean.
 func (p *Provider) reconcileStaleHibernate(ctx context.Context, pod *corev1.Pod) {
@@ -290,3 +306,11 @@ func podItems(list *corev1.PodList) []corev1.Pod {
 func inFlightCreate(state string) bool {
 	return state == vm.StateCreating || state == vm.StateCreated
 }
+
+func recordStaleCreateOutcome(outcome vm.StaleCreateOutcome, err error) {
+	label := string(outcome)
+	if err != nil {
+		label = "error"
+	}
+	metrics.StaleCreateReconcileTotal.WithLabelValues(label).Inc()
+}

provider/cocoon/reconcile_test.go

@@ -28,8 +28,8 @@ func TestStartupReconcileSkeletonCollectedNotAdopted(t *testing.T) {
 	if err := p.StartupReconcile(t.Context()); err != nil {
 		t.Fatalf("StartupReconcile: %v", err)
 	}
-	if len(rt.staleCreateCalls) != 1 || rt.staleCreateCalls[0] != "skel-vmid" {
-		t.Errorf("reconcile-stale-create calls = %v, want [skel-vmid]", rt.staleCreateCalls)
+	if calls := rt.staleCalls(); len(calls) != 1 || calls[0] != "skel-vmid" {
+		t.Errorf("reconcile-stale-create calls = %v, want [skel-vmid]", calls)
 	}
 	if got := p.vmByName("vk-ns-demo-0"); got != nil {
 		t.Errorf("skeleton must not be indexed by name, got %#v", got)
@@ -136,6 +136,49 @@ func TestStartupReconcileBusyCreateDeadOnArrivalGetsOrphanPolicy(t *testing.T) {
 	}
 }
 
+func TestWatchBusyCreateReclaimsAfterOwnerDies(t *testing.T) {
+	// The owner is alive at startup (busy) and dies without committing: the
+	// record stays creating forever, and only re-asking the verb can free the name.
+	rt := &fakeRuntime{
+		listVMs: []vm.VM{{ID: "inflight-vmid", Name: "vk-ns-demo-0", State: vm.StateCreating}},
+		staleCreateSeq: map[string][]vm.StaleCreateOutcome{
+			"inflight-vmid": {vm.StaleCreateBusy, vm.StaleCreateBusy, vm.StaleCreateCollected},
+		},
+		inspectVM: &vm.VM{ID: "inflight-vmid", Name: "vk-ns-demo-0", State: vm.StateCreating},
+	}
+	p := newTestProvider(t)
+	p.NodeName = "cocoon-pool"
+	p.Runtime = rt
+	p.Clientset = fake.NewSimpleClientset()
+	p.deferredRecheckInitialDelay = time.Millisecond
+	p.deferredRecheckMaxDelay = 2 * time.Millisecond
+	p.deferredRecheckBudget = 2 * time.Second
+
+	if err := p.StartupReconcile(t.Context()); err != nil {
+		t.Fatalf("StartupReconcile: %v", err)
+	}
+	// The startup pass is call 1; the watcher must keep asking past it.
+	deadline := time.Now().Add(2 * time.Second)
+	for time.Now().Before(deadline) && len(rt.staleCalls()) < 3 {
+		time.Sleep(2 * time.Millisecond)
+	}
+	if calls := rt.staleCalls(); len(calls) < 3 {
+		t.Fatalf("verb calls = %v, want the watcher to re-invoke until the record resolves", calls)
+	}
+	// collected ends the watch: the count must not keep climbing.
+	time.Sleep(50 * time.Millisecond)
+	p.Close()
+	if calls := rt.staleCalls(); len(calls) != 3 {
+		t.Errorf("verb calls = %v, want the watch to stop once the record was collected", calls)
+	}
+	if got := p.vmByName("vk-ns-demo-0"); got != nil {
+		t.Errorf("reclaimed record must not be indexed, got %#v", got)
+	}
+	if rt.removedID != "" {
+		t.Errorf("vk must not rm the record itself (the verb owns reclaim), removed %q", rt.removedID)
+	}
+}
+
 func TestStartupReconcileSkeletonNotCreatingReinspectsAndAdopts(t *testing.T) {
 	pod := newPodWithSpec(meta.VMSpec{VMName: "vk-ns-demo-0", Mode: "clone"})
 	pod.Spec.NodeName = "cocoon-pool"

provider/cocoon/resume.go

@@ -65,12 +65,12 @@ func (p *Provider) dispatchResume(key string, pod *corev1.Pod, v *vm.VM, op stri
 	switch op {
 	case resumeOpHibernate:
 		run(func() {
-			// Boot a crashed VM first; nothing re-delivers the hibernate later.
-			if v.State != vm.StateRunning {
-				if err := p.Runtime.Start(p.lifecycleCtx, v.ID); err != nil {
-					p.failOp(p.lifecycleCtx, pod, "ResumeStartFailed", "reconcile", err)
-					return
-				}
+			// Boot unconditionally: the record still reads running after a
+			// SIGKILLed VMM, and Start no-ops on a live VM. Nothing re-delivers
+			// the hibernate later.
+			if err := p.Runtime.Start(p.lifecycleCtx, v.ID); err != nil {
+				p.failOp(p.lifecycleCtx, pod, "ResumeStartFailed", "reconcile", err)
+				return
 			}
 			if err := p.hibernate(p.lifecycleCtx, pod, v); err != nil {
 				return

provider/cocoon/resume_test.go

@@ -236,6 +236,46 @@ func TestStartupDispatchOwedWork(t *testing.T) {
 	}
 }
 
+func TestStartupResumeHibernateStartsVMWhoseRecordStillReadsRunning(t *testing.T) {
+	// A SIGKILLed VMM leaves the record reading running: gating Start on the
+	// listed state skips the boot and every hibernate step fails not-running.
+	const (
+		vmName = "vk-ns-demo-0"
+		vmID   = "resume-vmid"
+	)
+	pod := newPodWithSpec(meta.VMSpec{
+		VMName:  vmName,
+		Mode:    "clone",
+		OS:      string(cocoonv1.OSWindows),
+		Backend: string(cocoonv1.BackendCloudHypervisor),
+	})
+	pod.Spec.NodeName = "cocoon-pool"
+	meta.VMRuntime{VMID: vmID, IP: "10.0.0.9"}.Apply(pod)
+	meta.HibernateState(true).Apply(pod)
+
+	rt := &fakeRuntime{
+		listVMs:             []vm.VM{{ID: vmID, Name: vmName, State: vm.StateRunning, IP: "10.0.0.9"}},
+		netResizeNeedsStart: true,
+	}
+	p := newTestProvider(t)
+	p.NodeName = "cocoon-pool"
+	p.Runtime = rt
+	p.Clientset = fake.NewSimpleClientset(pod)
+
+	if err := p.StartupReconcile(t.Context()); err != nil {
+		t.Fatalf("StartupReconcile: %v", err)
+	}
+	awaitLifecycle(t, p, "ns", "demo-0", meta.LifecycleStateHibernated)
+	p.Close()
+
+	if got := rt.started(); len(got) != 1 || got[0] != vmID {
+		t.Errorf("start calls = %v, want [%s]", got, vmID)
+	}
+	if rt.snapshotSaveCount != 1 {
+		t.Errorf("snapshot saves = %d, want 1", rt.snapshotSaveCount)
+	}
+}
+
 func TestStartupDispatchResumesSACWhenDoneMarkerPredatesIt(t *testing.T) {
 	// post-clone-state=done is written before SAC runs, so done alone must
 	// not skip the SAC pass: a failing dialer proves it was re-attempted.

provider/cocoon/update_test.go

@@ -336,7 +336,9 @@ func TestFinalizeDropNICWakeSkipsLifecycleWhenHibernateRequested(t *testing.T) {
 	}()
 
 	time.AfterFunc(10*time.Millisecond, func() {
-		meta.HibernateState(true).Apply(pod)
+		hib := pod.DeepCopy()
+		meta.HibernateState(true).Apply(hib)
+		p.trackPod(hib, nil)
 		p.setVMIP("ns", "demo-0", v.ID, "172.20.1.228")
 	})