diff --git a/cocoonset/agents.go b/cocoonset/agents.go index 79a9dcd..e3ebeae 100644 --- a/cocoonset/agents.go +++ b/cocoonset/agents.go @@ -173,10 +173,8 @@ func (r *Reconciler) rebuildSubAgent(ctx context.Context, logger *log.Fields, po return false, 0, err } metrics.SubAgentDeadLetterTotal.WithLabelValues(cs.Namespace, cs.Name).Inc() - if r.Recorder != nil { - r.Recorder.Eventf(cs, corev1.EventTypeWarning, "SubAgentDeadLetter", - "slot %d exhausted %d rebuilds; pod %s left in dead-letter", slot, maxRebuildAttempts, pod.Name) - } + r.emitEventf(cs, corev1.EventTypeWarning, "SubAgentDeadLetter", + "slot %d exhausted %d rebuilds; pod %s left in dead-letter", slot, maxRebuildAttempts, pod.Name) return false, 0, nil } if wait := backoffDelay(entry.Count); wait > 0 { @@ -196,10 +194,8 @@ func (r *Reconciler) rebuildSubAgent(ctx context.Context, logger *log.Fields, po return false, 0, fmt.Errorf("delete terminal sub-agent slot %d: %w", slot, err) } metrics.SubAgentRebuildTotal.WithLabelValues(cs.Namespace, cs.Name).Inc() - if r.Recorder != nil { - r.Recorder.Eventf(cs, corev1.EventTypeNormal, "SubAgentRebuilding", - "slot %d attempt %d/%d", slot, next[slot].Count, maxRebuildAttempts) - } + r.emitEventf(cs, corev1.EventTypeNormal, "SubAgentRebuilding", + "slot %d attempt %d/%d", slot, next[slot].Count, maxRebuildAttempts) return true, 0, nil } diff --git a/cocoonset/delete.go b/cocoonset/delete.go index 54e38e5..f6edfed 100644 --- a/cocoonset/delete.go +++ b/cocoonset/delete.go @@ -61,7 +61,7 @@ func (r *Reconciler) reconcileDelete(ctx context.Context, cs *cocoonv1.CocoonSet // :hibernate is always orphaned at teardown — drop unconditionally. :latest // is kept when shouldKeepLatestTag says vk-cocoon pushed it for retag. if r.Registry != nil { - for _, name := range vmNamesForGC(cs) { + for _, name := range parseVMNamesAnnotation(cs.Annotations[annotationDeleteVMNames]) { // Non-fatal, but log at error: a persistent delete failure (e.g. the // registry SA lacking delete permission) silently leaks snapshots. if err := r.Registry.DeleteManifest(ctx, name, meta.HibernateSnapshotTag); err != nil { @@ -117,11 +117,6 @@ func (r *Reconciler) stashDeleteVMNames(ctx context.Context, cs *cocoonv1.Cocoon }) } -// vmNamesForGC returns the canonical GC list, read from the stashed annotation. -func vmNamesForGC(cs *cocoonv1.CocoonSet) []string { - return parseVMNamesAnnotation(cs.Annotations[annotationDeleteVMNames]) -} - // statusVMNames collects the non-empty VM names recorded in the CocoonSet // status, agents first then toolboxes, preserving insertion order. func statusVMNames(cs *cocoonv1.CocoonSet) []string { diff --git a/cocoonset/pods.go b/cocoonset/pods.go index 74829bb..c8b5d8c 100644 --- a/cocoonset/pods.go +++ b/cocoonset/pods.go @@ -266,9 +266,6 @@ func vmSpecMatches(got, want meta.VMSpec) bool { } func resourcesMatch(pod *corev1.Pod, want corev1.ResourceRequirements) bool { - if len(pod.Spec.Containers) == 0 { - return false - } got := pod.Spec.Containers[0].Resources // Only CPU and memory: K8s defaulting copies the injected // ephemeral-storage into both Limits and Requests, which would always diff --git a/cocoonset/reconciler.go b/cocoonset/reconciler.go index 28e584d..ecbe808 100644 --- a/cocoonset/reconciler.go +++ b/cocoonset/reconciler.go @@ -99,8 +99,8 @@ func (r *Reconciler) Reconcile(ctx context.Context, req ctrl.Request) (ctrl.Resu if reason := mainPodFailedReason(classified.main); reason != "" { return r.handleFailedMainAgent(ctx, &cs, classified, reason) } - if cs.Status.Phase == cocoonv1.CocoonSetPhaseFailed && meta.IsPodReady(classified.main) && r.Recorder != nil { - r.Recorder.Eventf(&cs, corev1.EventTypeNormal, "RecoveredFromFailure", + if cs.Status.Phase == cocoonv1.CocoonSetPhaseFailed && meta.IsPodReady(classified.main) { + r.emitEventf(&cs, corev1.EventTypeNormal, "RecoveredFromFailure", "main pod %s/%s is Ready again", classified.main.Namespace, classified.main.Name) } } @@ -216,11 +216,14 @@ func (r *Reconciler) observeMainPodFailed(cs *cocoonv1.CocoonSet, pod *corev1.Po phase := cmp.Or(string(cs.Status.Phase), string(cocoonv1.CocoonSetPhasePending)) metrics.LifecycleStateFailedObservedTotal.WithLabelValues(phase).Inc() } - if r.Recorder == nil { - return - } msg := cmp.Or(pod.Annotations[meta.AnnotationLifecycleStateMessage], string(pod.Status.Phase)) - r.Recorder.Eventf(cs, corev1.EventTypeWarning, reason, "main pod %s/%s: %s", pod.Namespace, pod.Name, msg) + r.emitEventf(cs, corev1.EventTypeWarning, reason, "main pod %s/%s: %s", pod.Namespace, pod.Name, msg) +} + +func (r *Reconciler) emitEventf(cs *cocoonv1.CocoonSet, eventType, reason, format string, args ...any) { + if r.Recorder != nil { + r.Recorder.Eventf(cs, eventType, reason, format, args...) + } } // mainPodFailedReason maps a pod's terminal signal to the Event reason that diff --git a/cocoonset/slotrelease.go b/cocoonset/slotrelease.go index 19b8770..891f0fd 100644 --- a/cocoonset/slotrelease.go +++ b/cocoonset/slotrelease.go @@ -113,26 +113,28 @@ func (r *Reconciler) reconcileWake(ctx context.Context, cs *cocoonv1.CocoonSet, // surface it but keep waiting — a seat may free up. if msg := podUnschedulable(main); msg != "" { metrics.SlotReleaseWakeUnschedulableTotal.WithLabelValues(cs.Namespace, cs.Name).Inc() - if r.Recorder != nil { - r.Recorder.Eventf(cs, corev1.EventTypeWarning, "WakeNoCapacity", "main pod %s unschedulable: %s", main.Name, msg) - } + r.emitEventf(cs, corev1.EventTypeWarning, "WakeNoCapacity", "main pod %s unschedulable: %s", main.Name, msg) } return true, ctrl.Result{RequeueAfter: requeueSuspendPoll}, r.patchStatus(ctx, cs, buildStatus(cs, classified, cocoonv1.CocoonSetPhaseWaking)) case waking && vmLive(main): vmName := meta.ParseVMSpec(main).VMName - logger.Infof(ctx, "wake %s/%s: restored on %s, dropping hibernate snapshot", cs.Namespace, cs.Name, main.Spec.NodeName) if err := r.Registry.DeleteManifest(ctx, vmName, meta.HibernateSnapshotTag); err != nil { return true, ctrl.Result{}, fmt.Errorf("wake: drop hibernate snapshot %s: %w", vmName, err) } - placement := "pool" - if hint != "" && hint == main.Spec.NodeName { - placement = "hint-node" - } - metrics.SlotReleaseWakeTotal.WithLabelValues(cs.Namespace, cs.Name, placement).Inc() - if err := r.patchAnnotation(ctx, cs, meta.AnnotationHibernatedOnNode, ""); err != nil { - return true, ctrl.Result{}, err + // The hint is the wake's in-flight marker; a stale-status Requeue + // re-entry arrives hint-less and must not re-score the landing as pool. + if hint != "" { + logger.Infof(ctx, "wake %s/%s: restored on %s, dropping hibernate snapshot", cs.Namespace, cs.Name, main.Spec.NodeName) + placement := "pool" + if hint == main.Spec.NodeName { + placement = "hint-node" + } + metrics.SlotReleaseWakeTotal.WithLabelValues(cs.Namespace, cs.Name, placement).Inc() + if err := r.patchAnnotation(ctx, cs, meta.AnnotationHibernatedOnNode, ""); err != nil { + return true, ctrl.Result{}, err + } } // Auto-derived phase; the requeued pass settles Running/Scaling. return true, ctrl.Result{Requeue: true}, r.patchStatus(ctx, cs, buildStatus(cs, classified, "")) diff --git a/cocoonset/slotrelease_test.go b/cocoonset/slotrelease_test.go index c9d48db..1fd98b4 100644 --- a/cocoonset/slotrelease_test.go +++ b/cocoonset/slotrelease_test.go @@ -7,6 +7,7 @@ import ( "strings" "testing" + "github.com/prometheus/client_golang/prometheus/testutil" corev1 "k8s.io/api/core/v1" apierrors "k8s.io/apimachinery/pkg/api/errors" "k8s.io/apimachinery/pkg/types" @@ -16,6 +17,7 @@ import ( cocoonv1 "github.com/cocoonstack/cocoon-common/apis/v1" "github.com/cocoonstack/cocoon-common/meta" + "github.com/cocoonstack/cocoon-operator/metrics" ) var ( @@ -516,6 +518,45 @@ func TestWakeLeavesSuspendedPlaceholderToNormalFlow(t *testing.T) { } } +func TestWakeScoresPlacementOnceAcrossStaleStatusReentry(t *testing.T) { + // The completion arm Requeues; a re-entry off a stale Waking status is + // hint-less and must not score the same landing a second time as pool. + cs := relCocoonSet(func(cs *cocoonv1.CocoonSet) { + cs.Spec.Suspend = false + cs.Status.Phase = cocoonv1.CocoonSetPhaseWaking + cs.Annotations = map[string]string{meta.AnnotationHibernatedOnNode: "node-a"} + }) + main := migMainPod(t, cs, "node-a", "vmid-new", true) // landed back on the hinted node + reg := &fakeRegistry{present: map[string]bool{relHibernateTagKey: true}} + cli := relClient(t, cs, main) + r := &Reconciler{Client: cli, Scheme: testScheme(t), Registry: reg} + + score := func(placement string) float64 { + return testutil.ToFloat64(metrics.SlotReleaseWakeTotal.WithLabelValues("ns", "demo", placement)) + } + hintNode0, pool0 := score("hint-node"), score("pool") + + if _, _, err := r.reconcileWake(t.Context(), cs, singlePod(main)); err != nil { + t.Fatalf("first pass: %v", err) + } + if got := score("hint-node") - hintNode0; got != 1 { + t.Errorf("landing on the hinted node must score hint-node once, got %v", got) + } + + // The hint patch has landed; the status write has not. + stale := mustGetCS(t, cli) + stale.Status.Phase = cocoonv1.CocoonSetPhaseWaking + if _, _, err := r.reconcileWake(t.Context(), &stale, singlePod(main)); err != nil { + t.Fatalf("re-entry pass: %v", err) + } + if got := score("hint-node") - hintNode0; got != 1 { + t.Errorf("re-entry must not re-score the wake, hint-node delta=%v", got) + } + if got := score("pool") - pool0; got != 0 { + t.Errorf("re-entry must not score the hint-node landing as pool, pool delta=%v", got) + } +} + func relCocoonSet(mods ...func(*cocoonv1.CocoonSet)) *cocoonv1.CocoonSet { return newCocoonSet("demo", append([]func(*cocoonv1.CocoonSet){func(cs *cocoonv1.CocoonSet) { cs.Generation = 1 diff --git a/cocoonset/toolboxes.go b/cocoonset/toolboxes.go index 362be47..c89f115 100644 --- a/cocoonset/toolboxes.go +++ b/cocoonset/toolboxes.go @@ -88,23 +88,20 @@ func (r *Reconciler) ensureToolboxes(ctx context.Context, cs *cocoonv1.CocoonSet } func (r *Reconciler) triageToolbox(ctx context.Context, logger *log.Fields, pod *corev1.Pod, cs *cocoonv1.CocoonSet, tb cocoonv1.ToolboxSpec) (bool, error) { + var reason string switch { case podIsTerminal(pod): - logger.Infof(ctx, "toolbox %s/%s %q terminal (phase=%s lifecycle=%s), deleting for recreate", - pod.Namespace, pod.Name, tb.Name, pod.Status.Phase, meta.ReadLifecycleState(pod)) - if err := r.Delete(ctx, pod); err != nil && !apierrors.IsNotFound(err) { - return false, fmt.Errorf("delete terminal toolbox %s: %w", tb.Name, err) - } - return true, nil + reason = fmt.Sprintf("terminal (phase=%s lifecycle=%s)", pod.Status.Phase, meta.ReadLifecycleState(pod)) case !podSpecMatchesToolbox(pod, cs, tb): - logger.Infof(ctx, "toolbox %s/%s %q spec drifted, deleting for recreate", pod.Namespace, pod.Name, tb.Name) - if err := r.Delete(ctx, pod); err != nil && !apierrors.IsNotFound(err) { - return false, fmt.Errorf("delete drifted toolbox %s: %w", tb.Name, err) - } - return true, nil + reason = "spec drifted" default: return false, nil } + logger.Infof(ctx, "toolbox %s/%s %q %s, deleting for recreate", pod.Namespace, pod.Name, tb.Name, reason) + if err := r.Delete(ctx, pod); err != nil && !apierrors.IsNotFound(err) { + return false, fmt.Errorf("delete toolbox %s for recreate: %w", tb.Name, err) + } + return true, nil } func (r *Reconciler) checkToolboxCollision(ctx context.Context, cs *cocoonv1.CocoonSet, tbPod *corev1.Pod, tbName string) error { diff --git a/go.mod b/go.mod index 0ba4447..d55fc94 100644 --- a/go.mod +++ b/go.mod @@ -44,6 +44,7 @@ require ( github.com/klauspost/compress v1.18.6 // indirect github.com/kr/pretty v0.3.1 // indirect github.com/kr/text v0.2.0 // indirect + github.com/kylelemons/godebug v1.1.0 // indirect github.com/mailru/easyjson v0.7.7 // indirect github.com/mattn/go-colorable v0.1.13 // indirect github.com/mattn/go-isatty v0.0.20 // indirect diff --git a/hibernation/hibernate.go b/hibernation/hibernate.go index 08c9fb2..893f431 100644 --- a/hibernation/hibernate.go +++ b/hibernation/hibernate.go @@ -33,18 +33,13 @@ func (r *Reconciler) reconcileHibernate(ctx context.Context, hib *cocoonv1.Cocoo return ctrl.Result{}, err } if err == nil && present { - if r.firstTransitionAt(hib) { - observePhaseExit(hib, "ok") - r.emitEventf(hib, corev1.EventTypeNormal, "Hibernated", "snapshot %s pushed to the registry", vmName) - } + r.announcePhaseExitf(hib, "ok", corev1.EventTypeNormal, "Hibernated", "snapshot %s pushed to the registry", vmName) return ctrl.Result{}, r.setPhase(ctx, hib, cocoonv1.CocoonHibernationPhaseHibernated, vmName) } } if phaseDeadlineExceeded(hib, cocoonv1.CocoonHibernationPhaseHibernating, hibernateTimeout) { - if r.firstTransitionAt(hib) { - observePhaseExit(hib, "timeout") - r.emitEventf(hib, corev1.EventTypeWarning, "HibernateTimedOut", "snapshot %s not confirmed in the registry within %s", vmName, hibernateTimeout) - } + r.announcePhaseExitf(hib, "timeout", corev1.EventTypeWarning, "HibernateTimedOut", + "snapshot %s not confirmed in the registry within %s", vmName, hibernateTimeout) return ctrl.Result{}, r.markFailed(ctx, hib, fmt.Sprintf("hibernate not confirmed within %s", hibernateTimeout)) } diff --git a/hibernation/reconciler.go b/hibernation/reconciler.go index 55ca058..5c7a8f8 100644 --- a/hibernation/reconciler.go +++ b/hibernation/reconciler.go @@ -306,6 +306,15 @@ func (r *Reconciler) emitEventf(hib *cocoonv1.CocoonHibernation, eventType, reas } } +// announcePhaseExitf observes the phase-duration exit and emits its event, once per Ready transition. +func (r *Reconciler) announcePhaseExitf(hib *cocoonv1.CocoonHibernation, result, eventType, reason, format string, args ...any) { + if !r.firstTransitionAt(hib) { + return + } + observePhaseExit(hib, result) + r.emitEventf(hib, eventType, reason, format, args...) +} + // announceRetryFromFailed emits a Normal event when a reconcile re-enters // hibernate/wake after a prior Failed phase. func (r *Reconciler) announceRetryFromFailed(hib *cocoonv1.CocoonHibernation, desire cocoonv1.HibernationDesire) { diff --git a/hibernation/wake.go b/hibernation/wake.go index 7c0c4cb..1dac990 100644 --- a/hibernation/wake.go +++ b/hibernation/wake.go @@ -30,18 +30,13 @@ func (r *Reconciler) reconcileWake(ctx context.Context, hib *cocoonv1.CocoonHibe if err := r.Registry.DeleteManifest(ctx, vmName, meta.HibernateSnapshotTag); err != nil { logger.Errorf(ctx, err, "delete hibernation snapshot %s", vmName) } - if r.firstTransitionAt(hib) { - observePhaseExit(hib, "ok") - r.emitEventf(hib, corev1.EventTypeNormal, "WokenActive", "pod %s/%s is running", pod.Namespace, pod.Name) - } + r.announcePhaseExitf(hib, "ok", corev1.EventTypeNormal, "WokenActive", "pod %s/%s is running", pod.Namespace, pod.Name) return ctrl.Result{}, r.setPhase(ctx, hib, cocoonv1.CocoonHibernationPhaseActive, vmName) } if phaseDeadlineExceeded(hib, cocoonv1.CocoonHibernationPhaseWaking, wakeTimeout) { - if r.firstTransitionAt(hib) { - observePhaseExit(hib, "timeout") - r.emitEventf(hib, corev1.EventTypeWarning, "WakeTimedOut", "vk-cocoon did not report the container running within %s", wakeTimeout) - } + r.announcePhaseExitf(hib, "timeout", corev1.EventTypeWarning, "WakeTimedOut", + "vk-cocoon did not report the container running within %s", wakeTimeout) return ctrl.Result{}, r.markFailed(ctx, hib, fmt.Sprintf("wake timed out after %s; vk-cocoon never reported the container running", wakeTimeout)) } diff --git a/metrics/metrics.go b/metrics/metrics.go index ba166b4..4498de4 100644 --- a/metrics/metrics.go +++ b/metrics/metrics.go @@ -79,7 +79,7 @@ var ( Namespace: metricNamespace, Subsystem: metricSubsystem, Name: "slot_release_wake_total", - Help: "Number of released-seat wakes that reached a live VM, by placement (hint-node=landed back on the hibernated-on node, pool=rescheduled elsewhere). Every release wake restores via registry pull.", + Help: "Number of released-seat wakes that reached a live VM, by placement (hint-node=landed back on the hibernated-on node, pool=rescheduled elsewhere). A hint-node landing restores from the node-local snapshot; pool pulls from the registry.", }, []string{labelNamespace, labelCocoonSet, "placement"}, )