diff --git a/spinifex/handlers/ec2/instance/service_impl.go b/spinifex/handlers/ec2/instance/service_impl.go index 7e0e62d3d..c9fd35904 100644 --- a/spinifex/handlers/ec2/instance/service_impl.go +++ b/spinifex/handlers/ec2/instance/service_impl.go @@ -2475,6 +2475,41 @@ func (s *InstanceServiceImpl) StoppedInstanceNode(instanceID string) string { return instance.LastNode } +// startLocalRecord answers a start for an instance this node holds locally but +// the stopped store does not, reading the record's state rather than its mere +// presence. Only an error-state record is started here: it is what a failed +// recovery leaves behind, it never reaches the stopped store, and refusing it +// as "already running" is what dead-ends the instance. +// +// Every other state stays a refusal. A local record in any startable state is +// a claim another caller is part-way through — it inserts the instance before +// it launches — so starting it here would put two launches on one volume. +func (s *InstanceServiceImpl) startLocalRecord(ctx context.Context, local *vm.VM, accountID string) (*StartStoppedInstanceOutput, error) { + if !IsInstanceVisible(accountID, local.AccountID) { + slog.WarnContext(ctx, "StartStoppedInstance: instance not visible", + "instanceId", local.ID, "callerAccount", accountID, "ownerAccount", local.AccountID) + return nil, errors.New(awserrors.ErrorInvalidInstanceIDNotFound) + } + + status := s.vmMgr.Status(local) + switch status { + case vm.StateError: + slog.InfoContext(ctx, "StartStoppedInstance: starting an error-state record the stopped store does not hold", + "instanceId", local.ID) + if err := s.StartInstance(ctx, local, spxtypes.EC2InstanceCommand{ID: local.ID}); err != nil { + return nil, err + } + return &StartStoppedInstanceOutput{Status: "running", InstanceID: local.ID}, nil + case vm.StateTerminated: + slog.WarnContext(ctx, "StartStoppedInstance: local record is terminated", "instanceId", local.ID) + return nil, errors.New(awserrors.ErrorInvalidInstanceIDNotFound) + default: + slog.WarnContext(ctx, "StartStoppedInstance: instance already being started locally", + "instanceId", local.ID, "status", string(status)) + return nil, errors.New(awserrors.ErrorIncorrectInstanceState) + } +} + // StartStoppedInstance picks up a stopped instance from shared KV, re-launches // it on this daemon node, then removes it from shared KV. func (s *InstanceServiceImpl) StartStoppedInstance(ctx context.Context, input *StartStoppedInstanceInput, accountID string) (*StartStoppedInstanceOutput, error) { @@ -2500,15 +2535,11 @@ func (s *InstanceServiceImpl) StartStoppedInstance(ctx context.Context, input *S return nil, errors.New(awserrors.ErrorServerInternal) } if instance == nil { - // Disambiguate a genuinely-absent record from a local race: if this - // node's vmMgr already shows the instance running, a winning claim - // started it here between another caller's checks and this Load, so - // the correct taxonomy is IncorrectInstanceState, not NotFound. A - // cross-node winner is invisible to this node's vmMgr and still - // falls through to NotFound. - if _, ok := s.vmMgr.Get(input.InstanceID); ok { - slog.WarnContext(ctx, "StartStoppedInstance: instance already running locally", "instanceId", input.InstanceID) - return nil, errors.New(awserrors.ErrorIncorrectInstanceState) + // No shared record, but this node may still hold a local one, and what + // that record says decides the answer. A cross-node winner is invisible + // here and falls through to NotFound. + if local, ok := s.vmMgr.Get(input.InstanceID); ok { + return s.startLocalRecord(ctx, local, accountID) } slog.WarnContext(ctx, "StartStoppedInstance: instance not found in shared KV", "instanceId", input.InstanceID) return nil, errors.New(awserrors.ErrorInvalidInstanceIDNotFound) diff --git a/spinifex/handlers/ec2/instance/service_impl_test.go b/spinifex/handlers/ec2/instance/service_impl_test.go index 3ab17ce86..84e934291 100644 --- a/spinifex/handlers/ec2/instance/service_impl_test.go +++ b/spinifex/handlers/ec2/instance/service_impl_test.go @@ -2415,6 +2415,106 @@ func TestStartStoppedInstance_NotFoundButRunningLocally(t *testing.T) { assert.Equal(t, awserrors.ErrorIncorrectInstanceState, err.Error()) } +// TestStartStoppedInstance_LocalErrorRecordIsStarted is the failed-recovery +// case: the shared KV never holds a StateError record, so the old membership +// check read the dead local record as proof the instance was already running +// and refused the only remedy the operator had. The record's state decides now, +// and an error-state record is startable. +func TestStartStoppedInstance_LocalErrorRecordIsStarted(t *testing.T) { + id := "i-recovery-failed" + store := &vmmock.StateStore{Stopped: map[string]*vm.VM{}} + mgr := vm.NewManager() + var transitions []vm.InstanceState + mgr.SetDeps(vm.Deps{ + NodeID: "test-node", + // Mounting is a no-op so the launch reaches the manager's unwired + // resolver and fails deterministically without a qemu process. + VolumeMounter: raceVolumeMounter{}, + TransitionState: func(v *vm.VM, to vm.InstanceState) error { + transitions = append(transitions, to) + v.Status = to + return nil + }, + }) + mgr.Insert(&vm.VM{ID: id, Status: vm.StateError, AccountID: "acc", InstanceType: "t3.micro"}) + svc := &InstanceServiceImpl{ + stoppedStore: store, + resourceMgr: &fakeResourceCapacityProvider{}, + vmMgr: mgr, + } + + _, err := svc.StartStoppedInstance(context.Background(), &StartStoppedInstanceInput{InstanceID: id}, "acc") + + // The launch itself cannot succeed without a hypervisor behind it; what + // matters is that the start was attempted rather than refused as running. + if err != nil { + assert.NotEqual(t, awserrors.ErrorIncorrectInstanceState, err.Error(), + "an error-state record must not be reported as already running") + } + assert.Contains(t, transitions, vm.StatePending, + "the instance must be moved out of error state for the launch") +} + +// TestStartStoppedInstance_LocalStoppedRecordIsRefused holds the other side of +// the same check. A claim inserts the instance locally before it launches, so a +// local stopped record with nothing in the store is a start already under way, +// and starting it again would put two launches on one volume. +func TestStartStoppedInstance_LocalStoppedRecordIsRefused(t *testing.T) { + id := "i-mid-claim" + store := &vmmock.StateStore{Stopped: map[string]*vm.VM{}} + mgr := vm.NewManager() + mgr.Insert(&vm.VM{ID: id, Status: vm.StateStopped, AccountID: "acc", InstanceType: "t3.micro"}) + svc := &InstanceServiceImpl{ + stoppedStore: store, + resourceMgr: &fakeResourceCapacityProvider{}, + vmMgr: mgr, + } + + _, err := svc.StartStoppedInstance(context.Background(), &StartStoppedInstanceInput{InstanceID: id}, "acc") + + require.Error(t, err) + assert.Equal(t, awserrors.ErrorIncorrectInstanceState, err.Error()) +} + +// TestStartStoppedInstance_LocalTerminatedRecordIsNotFound keeps the third case +// separate: a terminated record is gone, not busy and not startable. +func TestStartStoppedInstance_LocalTerminatedRecordIsNotFound(t *testing.T) { + id := "i-gone" + store := &vmmock.StateStore{Stopped: map[string]*vm.VM{}} + mgr := vm.NewManager() + mgr.Insert(&vm.VM{ID: id, Status: vm.StateTerminated, AccountID: "acc"}) + svc := &InstanceServiceImpl{ + stoppedStore: store, + resourceMgr: &fakeResourceCapacityProvider{}, + vmMgr: mgr, + } + + _, err := svc.StartStoppedInstance(context.Background(), &StartStoppedInstanceInput{InstanceID: id}, "acc") + + require.Error(t, err) + assert.Equal(t, awserrors.ErrorInvalidInstanceIDNotFound, err.Error()) +} + +// TestStartStoppedInstance_LocalRecordOfAnotherAccount holds the visibility +// rule on the local path too: reading another account's record must answer the +// same way an absent one does. +func TestStartStoppedInstance_LocalRecordOfAnotherAccount(t *testing.T) { + id := "i-someone-elses" + store := &vmmock.StateStore{Stopped: map[string]*vm.VM{}} + mgr := vm.NewManager() + mgr.Insert(&vm.VM{ID: id, Status: vm.StateError, AccountID: "owner-acc"}) + svc := &InstanceServiceImpl{ + stoppedStore: store, + resourceMgr: &fakeResourceCapacityProvider{}, + vmMgr: mgr, + } + + _, err := svc.StartStoppedInstance(context.Background(), &StartStoppedInstanceInput{InstanceID: id}, "other-acc") + + require.Error(t, err) + assert.Equal(t, awserrors.ErrorInvalidInstanceIDNotFound, err.Error()) +} + func TestStartStoppedInstance_NotStopped(t *testing.T) { id := "i-running" store := &vmmock.StateStore{Stopped: map[string]*vm.VM{ diff --git a/spinifex/vm/crash_recovery.go b/spinifex/vm/crash_recovery.go index d2c54b3a2..a25f92b39 100644 --- a/spinifex/vm/crash_recovery.go +++ b/spinifex/vm/crash_recovery.go @@ -40,6 +40,31 @@ func RestartBackoff(restartCount int) time.Duration { return delay } +// recordCrash counts one failure against the restart window. Both a QEMU crash +// and a failed startup recovery spend the same budget, because both leave the +// instance in StateError with the manager owed a restart. +func recordCrash(v *VM, reason string, now time.Time) { + v.Health.CrashCount++ + v.Health.LastCrashTime = now + v.Health.LastCrashReason = reason + if v.Health.FirstCrashTime.IsZero() { + v.Health.FirstCrashTime = now + } +} + +// rollRestartWindow expires a stale window and reports whether the instance has +// restart budget left inside the current one. A window that has run out is what +// makes StateError terminal rather than a state the manager retries out of. +func rollRestartWindow(v *VM, now time.Time) bool { + if !v.Health.FirstCrashTime.IsZero() && now.Sub(v.Health.FirstCrashTime) > RestartWindow { + slog.Info("Crash window expired, resetting counters", "instance", v.ID) + v.Health.CrashCount = 1 + v.Health.FirstCrashTime = now + v.Health.RestartCount = 0 + } + return v.Health.CrashCount <= MaxRestartsInWindow +} + // ClassifyCrashReason extracts a human-readable crash reason from cmd.Wait()'s // error, distinguishing OOM kills, segfaults, aborts, and other signals. func ClassifyCrashReason(waitErr error) string { @@ -104,14 +129,7 @@ func (m *Manager) HandleCrash(instance *VM, waitErr error) { } now := time.Now() - m.UpdateState(instance.ID, func(v *VM) { - v.Health.CrashCount++ - v.Health.LastCrashTime = now - v.Health.LastCrashReason = reason - if v.Health.FirstCrashTime.IsZero() { - v.Health.FirstCrashTime = now - } - }) + m.UpdateState(instance.ID, func(v *VM) { recordCrash(v, reason, now) }) if m.deps.Resources != nil && instance.InstanceType != "" { slog.Info("Deallocating resources for crashed instance", @@ -164,19 +182,12 @@ func (m *Manager) MaybeRestart(instance *VM) { exceeded bool ) m.UpdateState(instance.ID, func(v *VM) { - health := &v.Health - if !health.FirstCrashTime.IsZero() && now.Sub(health.FirstCrashTime) > RestartWindow { - slog.Info("Crash window expired, resetting counters", "instance", v.ID) - health.CrashCount = 1 - health.FirstCrashTime = now - health.RestartCount = 0 - } - if health.CrashCount > MaxRestartsInWindow { + if !rollRestartWindow(v, now) { exceeded = true - crashCount = health.CrashCount + crashCount = v.Health.CrashCount return } - restartCount = health.RestartCount + restartCount = v.Health.RestartCount }) if exceeded { slog.Error("Instance exceeded max restarts in window, leaving in error state", diff --git a/spinifex/vm/restore.go b/spinifex/vm/restore.go index 069cc8d74..6bf52be17 100644 --- a/spinifex/vm/restore.go +++ b/spinifex/vm/restore.go @@ -140,14 +140,14 @@ func (m *Manager) classifyRestoredInstances() []*VM { instance.Status = StatePending } - // Recovery-failed instances stay in StateError until the operator - // explicitly retries or terminates. Skip relaunch and resource - // re-allocation; resources were already released by stopCleanup - // when MarkRecoveryFailed fired on the previous daemon run. The - // per-instance command topic is still bound, because an operator who - // cannot reach the instance cannot retry or terminate it either. - if instance.Status == StateError { - slog.Warn("Instance in error state; skipping recovery relaunch (operator must retry or terminate)", + // A recovery-failed instance is retried while its restart window still + // allows one: the usual cause is a dependency that was not ready at + // boot, which is over by the next attempt. Once the budget is spent it + // stays in StateError for the operator. Either way the per-instance + // command topic is bound, because an operator who cannot reach the + // instance cannot retry or terminate it either. + if instance.Status == StateError && !m.resumeRecoveryFailed(instance) { + slog.Warn("Instance in error state and out of restart budget; skipping recovery relaunch (operator must retry or terminate)", "instance", instance.ID, "managedBy", instance.ManagedBy, "instanceType", instance.InstanceType) if m.deps.Hooks.OnInstanceRecovering != nil { m.deps.Hooks.OnInstanceRecovering(instance) @@ -244,6 +244,22 @@ func (m *Manager) classifyRestoredInstances() []*VM { return toLaunch } +// resumeRecoveryFailed returns an instance in StateError to Pending so this +// restore relaunches it, spending one restart from the same window a crash +// restart spends. Returns false when the window has run out, which is what +// keeps a genuinely broken instance from relaunching on every daemon start. +func (m *Manager) resumeRecoveryFailed(instance *VM) bool { + if !rollRestartWindow(instance, time.Now()) { + return false + } + instance.Health.RestartCount++ + instance.Status = StatePending + slog.Info("Retrying recovery-failed instance", + "instance", instance.ID, "restartCount", instance.Health.RestartCount, + "failures", instance.Health.CrashCount, "lastReason", instance.Health.LastCrashReason) + return true +} + // markUnschedulable flips an instance to Stopped with InsufficientInstanceCapacity // so DescribeInstances reports a useful error when the node can no longer host the type. // DesiredStopped is stamped so a future restore's drain-relaunch path (which diff --git a/spinifex/vm/restore_test.go b/spinifex/vm/restore_test.go index e565633e9..628f93117 100644 --- a/spinifex/vm/restore_test.go +++ b/spinifex/vm/restore_test.go @@ -1278,9 +1278,10 @@ func TestReconnectInstance(t *testing.T) { }) } -// An instance left in StateError is not relaunched, but the operator is told to -// retry or terminate it — which needs the per-instance command topic bound, or -// the terminate never reaches a responder and the record is stranded for good. +// An instance left in StateError with its restart budget spent is not +// relaunched, but the operator is told to retry or terminate it — which needs +// the per-instance command topic bound, or the terminate never reaches a +// responder and the record is stranded for good. func TestClassifyRestoredInstances_ErrorStateStillAnnouncesForCommands(t *testing.T) { t.Setenv("XDG_RUNTIME_DIR", t.TempDir()) var announced []string @@ -1294,7 +1295,13 @@ func TestClassifyRestoredInstances_ErrorStateStillAnnouncesForCommands(t *testin OnInstanceRecovering: func(v *VM) { announced = append(announced, v.ID) }, }, }) - v := &VM{ID: "i-errored", Status: StateError, InstanceType: "t3.micro", Instance: &ec2.Instance{}} + v := &VM{ + ID: "i-errored", + Status: StateError, + InstanceType: "t3.micro", + Health: InstanceHealthState{CrashCount: MaxRestartsInWindow + 1, FirstCrashTime: time.Now()}, + Instance: &ec2.Instance{}, + } m.Replace(map[string]*VM{v.ID: v}) toLaunch := m.classifyRestoredInstances() diff --git a/spinifex/vm/shutdown.go b/spinifex/vm/shutdown.go index ac1c76907..518fc1cc6 100644 --- a/spinifex/vm/shutdown.go +++ b/spinifex/vm/shutdown.go @@ -333,6 +333,11 @@ func (m *Manager) MarkRecoveryFailed(instance *VM, reason string) { return } } + // Counted like a crash so the next restore can retry this instance against a + // budget that runs out, rather than either never retrying or retrying forever. + now := time.Now() + m.UpdateState(instance.ID, func(v *VM) { recordCrash(v, reason, now) }) + slog.Error("Instance marked recovery_failed; volumes and ENIs preserved for operator action", "instanceId", instance.ID, "reason", reason) diff --git a/spinifex/vm/shutdown_test.go b/spinifex/vm/shutdown_test.go index 71d0f2323..e143b26d2 100644 --- a/spinifex/vm/shutdown_test.go +++ b/spinifex/vm/shutdown_test.go @@ -1259,13 +1259,10 @@ func TestMarkRecoveryFailed_NoOpOnTerminal(t *testing.T) { } } -// TestClassifyRestoredInstances_StateErrorSkipsRelaunch verifies the -// restore-side companion fix: an instance already in StateError (from a -// prior recovery failure) must NOT be queued for relaunch and must NOT -// have its resources re-allocated. Without this, every daemon restart -// would re-trigger the failing recovery loop and eventually re-destroy -// volumes once the loop hit the terminateCleanup path. -func TestClassifyRestoredInstances_StateErrorSkipsRelaunch(t *testing.T) { +// recoveryFailedManager builds a manager holding one instance left in +// StateError by a failed recovery, with health counters the caller controls. +func recoveryFailedManager(t *testing.T, health InstanceHealthState, hooks ManagerHooks) (*Manager, *countingResourceController, *VM) { + t.Helper() m := NewManager() rc := &countingResourceController{} m.SetDeps(Deps{ @@ -1273,6 +1270,7 @@ func TestClassifyRestoredInstances_StateErrorSkipsRelaunch(t *testing.T) { StateStore: newFakeStateStore(), InstanceTypes: fakeInstanceTypeResolver{"t3.micro": {VCPUs: 2, MemoryMiB: 1024}}, Resources: rc, + Hooks: hooks, }) code := "Server.RecoveryFailed" @@ -1281,18 +1279,86 @@ func TestClassifyRestoredInstances_StateErrorSkipsRelaunch(t *testing.T) { ID: "i-recovery-error", Status: StateError, InstanceType: "t3.micro", + Health: health, Instance: &ec2.Instance{StateReason: &ec2.StateReason{Code: &code, Message: &msg}}, } m.Insert(v) + return m, rc, v +} + +// TestClassifyRestoredInstances_StateErrorRetriesWithinTheWindow covers the +// usual cause of a failed recovery: a dependency that was not ready at boot and +// is ready by the next attempt. The instance relaunches, spending one restart. +func TestClassifyRestoredInstances_StateErrorRetriesWithinTheWindow(t *testing.T) { + m, rc, v := recoveryFailedManager(t, InstanceHealthState{ + CrashCount: 1, + FirstCrashTime: time.Now(), + }, ManagerHooks{}) toLaunch := m.classifyRestoredInstances() - assert.Empty(t, toLaunch, "StateError instance must not be queued for relaunch") + assert.Len(t, toLaunch, 1, "a recovery-failed instance with budget left must be relaunched") + assert.Equal(t, StatePending, m.Status(v), "the retry must leave StateError") + assert.Equal(t, 1, rc.allocations, + "the relaunch needs the resources stopCleanup released") + assert.Equal(t, 1, v.Health.RestartCount, "the retry must be counted") +} + +// TestClassifyRestoredInstances_StateErrorStopsAfterTheWindow is the other half: +// an instance that keeps failing stops relaunching, so a broken instance cannot +// consume a restart on every daemon start. It stays in StateError for the +// operator, and the command topic is still announced so they can reach it. +func TestClassifyRestoredInstances_StateErrorStopsAfterTheWindow(t *testing.T) { + var announced []string + m, rc, v := recoveryFailedManager(t, InstanceHealthState{ + CrashCount: MaxRestartsInWindow + 1, + FirstCrashTime: time.Now(), + }, ManagerHooks{OnInstanceRecovering: func(inst *VM) { announced = append(announced, inst.ID) }}) + + toLaunch := m.classifyRestoredInstances() + + assert.Empty(t, toLaunch, "a recovery-failed instance out of budget must not be relaunched") assert.Zero(t, rc.allocations, - "StateError instance must not re-allocate resources (already released by stopCleanup)") + "a skipped instance must not re-allocate resources (already released by stopCleanup)") _, ok := m.Get(v.ID) - assert.True(t, ok, "StateError instance must stay in the local map for operator action") + assert.True(t, ok, "the instance must stay in the local map for operator action") assert.Equal(t, StateError, m.Status(v), "status must be preserved") + assert.Equal(t, []string{v.ID}, announced, + "the command topic must still be bound, or the operator cannot retry or terminate") +} + +// TestClassifyRestoredInstances_StateErrorRetriesAfterTheWindowExpires proves +// the bound is a window and not a permanent ceiling: an instance that failed +// long ago is retried again rather than written off forever. +func TestClassifyRestoredInstances_StateErrorRetriesAfterTheWindowExpires(t *testing.T) { + m, _, v := recoveryFailedManager(t, InstanceHealthState{ + CrashCount: MaxRestartsInWindow + 1, + FirstCrashTime: time.Now().Add(-2 * RestartWindow), + }, ManagerHooks{}) + + toLaunch := m.classifyRestoredInstances() + + assert.Len(t, toLaunch, 1, "an expired window must allow the instance to be retried") + assert.Equal(t, StatePending, m.Status(v), "the retry must leave StateError") +} + +// TestMarkRecoveryFailed_CountsAgainstTheRestartWindow wires the two halves +// together: without this count the retry above has nothing to bound it, and a +// permanently-broken instance would relaunch on every restart forever. +func TestMarkRecoveryFailed_CountsAgainstTheRestartWindow(t *testing.T) { + m, _, _, _, _ := shutdownTestManager(t) + instance := &VM{ + ID: "i-counted", + Status: StateRunning, + Instance: &ec2.Instance{}, + } + m.Insert(instance) + + m.MarkRecoveryFailed(instance, "recovery_launch_failed") + + assert.Equal(t, 1, instance.Health.CrashCount, "a failed recovery must count like a crash") + assert.False(t, instance.Health.FirstCrashTime.IsZero(), "the window must have a start") + assert.Equal(t, "recovery_launch_failed", instance.Health.LastCrashReason) } // countingResourceController counts how often Allocate fires so a test