diff --git a/api/v1alpha1/constants.go b/api/v1alpha1/constants.go index eea2361a..d3d3338c 100644 --- a/api/v1alpha1/constants.go +++ b/api/v1alpha1/constants.go @@ -25,4 +25,9 @@ const ( // the K8s Node was already cordoned before the controller cordoned // it for a reboot. Used to restore prior cordon state after update. AnnotationWasCordoned = "bootc.dev/was-cordoned" + + // AnnotationLastObservedState records the last BootcNode Idle condition + // state for which the controller considered emitting an event. It is + // observability bookkeeping only and is never used to drive reconciliation. + AnnotationLastObservedState = "bootc.dev/last-observed-state" ) diff --git a/config/rbac/role.yaml b/config/rbac/role.yaml index c3d94239..1313d71a 100644 --- a/config/rbac/role.yaml +++ b/config/rbac/role.yaml @@ -4,13 +4,6 @@ kind: ClusterRole metadata: name: manager-role rules: -- apiGroups: - - "" - resources: - - events - verbs: - - create - - patch - apiGroups: - "" resources: @@ -34,6 +27,14 @@ rules: - pods/eviction verbs: - create +- apiGroups: + - "" + - events.k8s.io + resources: + - events + verbs: + - create + - patch - apiGroups: - apps resources: diff --git a/internal/controller/bootcnodepool_controller.go b/internal/controller/bootcnodepool_controller.go index 966f6d55..bcb9848f 100644 --- a/internal/controller/bootcnodepool_controller.go +++ b/internal/controller/bootcnodepool_controller.go @@ -43,7 +43,7 @@ type drainStatus struct { ctx context.Context // the drain goroutine's context; checked to distinguish cancellation from real errors cancel context.CancelFunc // to abort on targetDigest change or node removal startTime time.Time // for stall detection - isStalled bool //nolint:unused // used by drain stall detection + isStalled bool // set after the one-shot drain stall event is emitted } // TagResolver resolves a container image reference to a digest. @@ -83,6 +83,7 @@ type BootcNodePoolReconciler struct { // +kubebuilder:rbac:groups="",resources=pods/eviction,verbs=create // +kubebuilder:rbac:groups=apps,resources=daemonsets,verbs=get // +kubebuilder:rbac:groups="",resources=events,verbs=create;patch +// +kubebuilder:rbac:groups=events.k8s.io,resources=events,verbs=create;patch // SetupWithManager sets up the controller with the Manager. func (r *BootcNodePoolReconciler) SetupWithManager(mgr ctrl.Manager) error { @@ -253,7 +254,8 @@ func (r *BootcNodePoolReconciler) Reconcile( return ctrl.Result{}, nil } - // Snapshot status so we can detect changes and write once at the end. + // Snapshot status so we can detect changes, write once at the end, and + // emit events only for persisted transitions. statusOrig := pool.Status.DeepCopy() // Start with conditions in a healthy state; sync functions only set @@ -270,10 +272,10 @@ func (r *BootcNodePoolReconciler) Reconcile( // the end. // Resolve the target digest from the image ref. - resolveResult, err := r.resolveTargetDigest(ctx, &pool) + resolveResult, tagTargetChanged, err := r.resolveTargetDigest(ctx, &pool) if err != nil { if isInvalidSpecError(err) { - return r.setInvalidSpecCondition(ctx, &pool, err) + return r.setInvalidSpecCondition(ctx, &pool, statusOrig, err) } return ctrl.Result{}, fmt.Errorf("resolving target digest: %w", err) } @@ -281,13 +283,11 @@ func (r *BootcNodePoolReconciler) Reconcile( // complete handles the boilerplate exit logic for the happy path and writes // the pool status if anything changed. complete := func(result ctrl.Result) (ctrl.Result, error) { - if !reflect.DeepEqual(pool.Status, *statusOrig) { - if err := r.Status().Update(ctx, &pool); err != nil { - return ctrl.Result{}, fmt.Errorf("updating pool status: %w", err) - } + if err := r.updatePoolStatus(ctx, &pool, statusOrig, tagTargetChanged); err != nil { + return ctrl.Result{}, fmt.Errorf("updating pool status: %w", err) } - return resolveResult, nil + return result, nil } if pool.Status.TargetDigest == "" { @@ -299,7 +299,7 @@ func (r *BootcNodePoolReconciler) Reconcile( ownedBootcNodes, err := r.syncMembership(ctx, &pool) if err != nil { if isInvalidSpecError(err) { - return r.setInvalidSpecCondition(ctx, &pool, err) + return r.setInvalidSpecCondition(ctx, &pool, statusOrig, err) } return ctrl.Result{}, fmt.Errorf("syncing membership: %w", err) } @@ -307,15 +307,20 @@ func (r *BootcNodePoolReconciler) Reconcile( // From this point on, let's not re-Get/List() BootcNodes anymore and // just use `ownedBootcNodes` so that we have a consistent view for this // reconciliation run. + r.recordNodeEvents(ctx, &pool, ownedBootcNodes) // Drive the rollout state machine. rs, err := r.driveRollout(ctx, &pool, ownedBootcNodes) if err != nil { if isInvalidSpecError(err) { - return r.setInvalidSpecCondition(ctx, &pool, err) + return r.setInvalidSpecCondition(ctx, &pool, statusOrig, err) } return ctrl.Result{}, fmt.Errorf("driving rollout: %w", err) } + resolveResult.RequeueAfter = earlierRequeue( + resolveResult.RequeueAfter, + r.recordDrainStalls(&pool, ownedBootcNodes), + ) // Early-return paths above (TargetDigest empty, InvalidSpec) skip // aggregation. In-flight updates may complete during error conditions @@ -387,12 +392,12 @@ func (r *BootcNodePoolReconciler) handlePoolDeletion( func (r *BootcNodePoolReconciler) resolveTargetDigest( ctx context.Context, pool *bootcv1alpha1.BootcNodePool, -) (ctrl.Result, error) { +) (ctrl.Result, bool, error) { log := logf.FromContext(ctx) ref, err := parseImageRef(pool.Spec.Image.Ref) if err != nil { - return ctrl.Result{}, newInvalidSpecError( + return ctrl.Result{}, false, newInvalidSpecError( fmt.Sprintf("invalid image ref %q: %v", pool.Spec.Image.Ref, err), ) } @@ -403,7 +408,7 @@ func (r *BootcNodePoolReconciler) resolveTargetDigest( // Reset the NextTagResolutionTime in case we pass from a tag referenced image to a digested one. // Otherwise, it simply a nop pool.Status.NextTagResolutionTime = nil - return ctrl.Result{}, nil + return ctrl.Result{}, false, nil } // Tag ref — check if resolution is due. @@ -412,14 +417,16 @@ func (r *BootcNodePoolReconciler) resolveTargetDigest( now.Before(pool.Status.NextTagResolutionTime.Time) { remaining := pool.Status.NextTagResolutionTime.Sub(now) log.V(1).Info("Tag resolution not yet due", "remaining", remaining) - return ctrl.Result{RequeueAfter: remaining}, nil + return ctrl.Result{RequeueAfter: remaining}, false, nil } digest, err := r.TagResolver.Resolve(ctx, pool.Spec.Image.Ref) + tagTargetChanged := false if err != nil { log.Error(err, "Failed to resolve tag", "ref", pool.Spec.Image.Ref) setPoolDegraded(pool, bootcv1alpha1.PoolTagResolutionError, err.Error()) } else { + tagTargetChanged = pool.Status.TargetDigest != "" && pool.Status.TargetDigest != digest if pool.Status.TargetDigest != digest { log.Info("Resolved tag to new digest", "ref", pool.Spec.Image.Ref, "digest", digest) } @@ -428,7 +435,7 @@ func (r *BootcNodePoolReconciler) resolveTargetDigest( next := metav1.NewTime(now.Add(r.TagResolutionInterval)) pool.Status.NextTagResolutionTime = &next - return ctrl.Result{RequeueAfter: r.TagResolutionInterval}, nil + return ctrl.Result{RequeueAfter: r.TagResolutionInterval}, tagTargetChanged, nil } // parseImageRef parses an image reference string into a named @@ -457,15 +464,36 @@ func isInvalidSpecError(err error) bool { return errors.As(err, &e) } +// updatePoolStatus writes a changed pool status and then records events for +// meaningful transitions. Events are supplemental: a failed status write +// returns before any event is emitted. +func (r *BootcNodePoolReconciler) updatePoolStatus( + ctx context.Context, + pool *bootcv1alpha1.BootcNodePool, + previous *bootcv1alpha1.BootcNodePoolStatus, + tagTargetChanged bool, +) error { + if reflect.DeepEqual(pool.Status, *previous) { + return nil + } + if err := r.Status().Update(ctx, pool); err != nil { + return err + } + + r.recordPoolEvents(pool, previous, tagTargetChanged) + return nil +} + // setInvalidSpecCondition sets Degraded/InvalidSpec on the pool and // returns (Result, nil) so Reconcile stops without requeueing. func (r *BootcNodePoolReconciler) setInvalidSpecCondition( ctx context.Context, pool *bootcv1alpha1.BootcNodePool, + previous *bootcv1alpha1.BootcNodePoolStatus, specErr error, ) (ctrl.Result, error) { setPoolDegraded(pool, bootcv1alpha1.PoolInvalidSpec, specErr.Error()) - if err := r.Status().Update(ctx, pool); err != nil { + if err := r.updatePoolStatus(ctx, pool, previous, false); err != nil { return ctrl.Result{}, fmt.Errorf("updating pool status: %w", err) } return ctrl.Result{}, nil diff --git a/internal/controller/events.go b/internal/controller/events.go new file mode 100644 index 00000000..20211446 --- /dev/null +++ b/internal/controller/events.go @@ -0,0 +1,441 @@ +// SPDX-License-Identifier: Apache-2.0 + +package controller + +import ( + "context" + "fmt" + "strings" + "time" + "unicode/utf8" + + corev1 "k8s.io/api/core/v1" + apimeta "k8s.io/apimachinery/pkg/api/meta" + metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" + "k8s.io/apimachinery/pkg/runtime" + "sigs.k8s.io/controller-runtime/pkg/client" + logf "sigs.k8s.io/controller-runtime/pkg/log" + + bootcv1alpha1 "github.com/bootc-dev/bootc-operator/api/v1alpha1" +) + +const ( + eventReasonImageUpdateAvailable = "ImageUpdateAvailable" + eventReasonRolloutStarted = "RolloutStarted" + eventReasonRolloutCompleted = "RolloutCompleted" + eventReasonDrainFailed = "DrainFailed" + eventReasonDrainTakingTooLong = "DrainTakingTooLong" + + eventActionResolveImage = "ResolveImage" + eventActionRollout = "Rollout" + eventActionPoolDegraded = "PoolDegraded" + eventActionNodeUpdate = "NodeUpdate" + eventActionDrain = "Drain" + + drainStallThreshold = 5 * time.Minute + eventNoteLimit = 1024 + eventNoteSuffix = "..." +) + +// EventNote renders the human-readable message of a Kubernetes Event. Each +// implementation owns a small set of well-defined fields and is responsible for +// producing a message that fits the events.k8s.io/v1 1 KiB note limit. Notes +// assembled entirely from bounded fields (image references, digests) are safe by +// construction; notes that embed unbounded free text (condition messages, error +// strings) cap themselves with capNote. +type EventNote interface { + Note() string +} + +// shortDigest abbreviates a "sha256:" digest to a human-friendly prefix +// ("sha256:" plus 12 hex characters), which is enough to disambiguate images in +// event messages while keeping them concise. Values that are already short are +// returned unchanged. +func shortDigest(digest string) string { + const shortLen = len("sha256:") + 12 + if len(digest) > shortLen { + return digest[:shortLen] + } + return digest +} + +type poolImageUpdateNote struct { + ImageRef string + NewDigest string + PreviousDigest string +} + +func (n poolImageUpdateNote) Note() string { + return fmt.Sprintf( + "Image tag %s resolved to new digest %s (previously %s)", + n.ImageRef, + shortDigest(n.NewDigest), + shortDigest(n.PreviousDigest), + ) +} + +type poolRolloutStartedNote struct { + TargetDigest string +} + +func (n poolRolloutStartedNote) Note() string { + return fmt.Sprintf("Rollout started toward digest %s", shortDigest(n.TargetDigest)) +} + +type poolRolloutCompletedNote struct { + TargetDigest string +} + +func (n poolRolloutCompletedNote) Note() string { + return fmt.Sprintf("Rollout completed at digest %s", shortDigest(n.TargetDigest)) +} + +// poolDegradedNote wraps a pool's Degraded condition message, which is not +// length-bounded, so it caps itself. +type poolDegradedNote struct { + Message string +} + +func (n poolDegradedNote) Note() string { + return capNote(n.Message) +} + +type nodeStagingNote struct { + Image string +} + +func (n nodeStagingNote) Note() string { + return fmt.Sprintf("Staging image %s", n.Image) +} + +type nodeStagedNote struct { + Image string +} + +func (n nodeStagedNote) Note() string { + return fmt.Sprintf("Image %s is staged and awaiting reboot", n.Image) +} + +type nodeRebootingNote struct { + Image string +} + +func (n nodeRebootingNote) Note() string { + return fmt.Sprintf("Rebooting into image %s", n.Image) +} + +type nodeIdleNote struct { + Image string +} + +func (n nodeIdleNote) Note() string { + return fmt.Sprintf("Node is up to date with image %s", n.Image) +} + +// drainFailedNote embeds an error string, which is not length-bounded, so it +// caps itself. +type drainFailedNote struct { + Err error +} + +func (n drainFailedNote) Note() string { + return capNote(fmt.Sprintf("Failed to drain node: %v; the drain will be retried", n.Err)) +} + +type drainStalledNote struct { + Threshold time.Duration +} + +func (n drainStalledNote) Note() string { + return fmt.Sprintf( + "Drain has been running for more than %s; it may be blocked by a PodDisruptionBudget", + n.Threshold, + ) +} + +func (r *BootcNodePoolReconciler) recordPoolEvents( + pool *bootcv1alpha1.BootcNodePool, + previous *bootcv1alpha1.BootcNodePoolStatus, + tagTargetChanged bool, +) { + if tagTargetChanged { + r.recordEvent( + pool, + nil, + corev1.EventTypeNormal, + eventReasonImageUpdateAvailable, + eventActionResolveImage, + poolImageUpdateNote{ + ImageRef: pool.Spec.Image.Ref, + NewDigest: pool.Status.TargetDigest, + PreviousDigest: previous.TargetDigest, + }, + ) + } + + oldUpToDate := apimeta.FindStatusCondition(previous.Conditions, bootcv1alpha1.PoolUpToDate) + newUpToDate := apimeta.FindStatusCondition(pool.Status.Conditions, bootcv1alpha1.PoolUpToDate) + targetChanged := previous.TargetDigest != "" && + previous.TargetDigest != pool.Status.TargetDigest && + pool.Status.TargetDigest != "" + poolRolloutInProgress := conditionEnteredReason( + oldUpToDate, + newUpToDate, + metav1.ConditionFalse, + bootcv1alpha1.PoolRolloutInProgress, + ) || (targetChanged && newUpToDate != nil && + newUpToDate.Status == metav1.ConditionFalse && + newUpToDate.Reason == bootcv1alpha1.PoolRolloutInProgress) + if poolRolloutInProgress { + r.recordEvent( + pool, + nil, + corev1.EventTypeNormal, + eventReasonRolloutStarted, + eventActionRollout, + poolRolloutStartedNote{TargetDigest: pool.Status.TargetDigest}, + ) + } + + rolloutCompleted := oldUpToDate != nil && + oldUpToDate.Status != metav1.ConditionTrue && + newUpToDate != nil && + newUpToDate.Status == metav1.ConditionTrue + if rolloutCompleted { + r.recordEvent( + pool, + nil, + corev1.EventTypeNormal, + eventReasonRolloutCompleted, + eventActionRollout, + poolRolloutCompletedNote{TargetDigest: pool.Status.TargetDigest}, + ) + } + + oldDegraded := apimeta.FindStatusCondition(previous.Conditions, bootcv1alpha1.PoolDegraded) + newDegraded := apimeta.FindStatusCondition(pool.Status.Conditions, bootcv1alpha1.PoolDegraded) + if degradedConditionChanged(oldDegraded, newDegraded) { + r.recordEvent( + pool, + nil, + corev1.EventTypeWarning, + newDegraded.Reason, + eventActionPoolDegraded, + poolDegradedNote{Message: newDegraded.Message}, + ) + } +} + +func conditionEnteredReason( + previous, current *metav1.Condition, + status metav1.ConditionStatus, + reason string, +) bool { + if current == nil || current.Status != status || current.Reason != reason { + return false + } + return previous == nil || previous.Status != status || previous.Reason != reason +} + +func degradedConditionChanged(previous, current *metav1.Condition) bool { + if current == nil || current.Status != metav1.ConditionTrue { + return false + } + return previous == nil || + previous.Status != metav1.ConditionTrue || + previous.Reason != current.Reason || + previous.Message != current.Message +} + +// recordNodeEvents emits an event once for each observed Staging, Staged, +// Rebooting, or return-to-idle transition. A controller-owned annotation +// persists the last observation so unrelated reconciles and controller restarts +// do not repeat events. Annotation write failures are logged but never block a +// rollout. +func (r *BootcNodePoolReconciler) recordNodeEvents( + ctx context.Context, + pool *bootcv1alpha1.BootcNodePool, + nodes map[string]*bootcv1alpha1.BootcNode, +) { + log := logf.FromContext(ctx) + for _, node := range nodes { + previous := node.Annotations[bootcv1alpha1.AnnotationLastObservedState] + observation, reason, note := nodeEvent(node, previous) + if observation == "" || previous == observation { + continue + } + + if note != nil { + r.recordEvent( + node, + pool, + corev1.EventTypeNormal, + reason, + eventActionNodeUpdate, + note, + ) + } + + modified := node.DeepCopy() + if modified.Annotations == nil { + modified.Annotations = map[string]string{} + } + modified.Annotations[bootcv1alpha1.AnnotationLastObservedState] = observation + if err := r.Patch(ctx, modified, client.MergeFrom(node)); err != nil { + // Emit first so a transient marker write failure cannot permanently + // hide the transition. A retry may aggregate the same event into an + // EventSeries, which is preferable to losing it. + log.Error(err, "Failed to persist last observed node state", "node", node.Name) + continue + } + *node = *modified + } +} + +// nodeEvent maps a BootcNode's Idle condition to the event that should be +// recorded for it. It returns the observation to persist, the event reason, and +// the note to emit. A nil note means the transition should be tracked (so it is +// not re-evaluated) but no event is emitted. previousObservation is the last +// persisted observation and is used to emit a return-to-idle event only when the +// node was previously mid-rollout. +func nodeEvent( + node *bootcv1alpha1.BootcNode, + previousObservation string, +) (observation, reason string, note EventNote) { + idle := apimeta.FindStatusCondition(node.Status.Conditions, bootcv1alpha1.NodeIdle) + if idle == nil { + return "", "", nil + } + + observation = fmt.Sprintf("%s:%s:%s", idle.Status, idle.Reason, node.Spec.DesiredImage) + if idle.Status != metav1.ConditionFalse { + // The node is idle. Only announce it when it just finished a rollout; + // otherwise (freshly created or already idle) record the observation + // silently so restarts do not emit a spurious event. + if idle.Reason == bootcv1alpha1.NodeReasonIdle && isActiveObservation(previousObservation) { + return observation, + bootcv1alpha1.NodeReasonIdle, + nodeIdleNote{Image: node.Spec.DesiredImage} + } + return observation, "", nil + } + + switch idle.Reason { + case bootcv1alpha1.NodeReasonStaging: + return observation, + bootcv1alpha1.NodeReasonStaging, + nodeStagingNote{Image: node.Spec.DesiredImage} + case bootcv1alpha1.NodeReasonStaged: + return observation, + bootcv1alpha1.NodeReasonStaged, + nodeStagedNote{Image: node.Spec.DesiredImage} + case bootcv1alpha1.NodeReasonRebooting: + return observation, + bootcv1alpha1.NodeReasonRebooting, + nodeRebootingNote{Image: node.Spec.DesiredImage} + default: + return observation, "", nil + } +} + +// isActiveObservation reports whether a persisted observation represents a node +// that was mid-rollout (Idle=False). Observations are formatted as +// "::". +func isActiveObservation(observation string) bool { + return strings.HasPrefix(observation, string(metav1.ConditionFalse)+":") +} + +func (r *BootcNodePoolReconciler) recordDrainFailedEvent( + pool *bootcv1alpha1.BootcNodePool, + node *bootcv1alpha1.BootcNode, + err error, +) { + r.recordEvent( + node, + pool, + corev1.EventTypeWarning, + eventReasonDrainFailed, + eventActionDrain, + drainFailedNote{Err: err}, + ) +} + +// recordDrainStalls emits one warning per drain that crosses the stall +// threshold and returns when the next active drain should be checked. The +// existing in-memory drain state is sufficient because drains are restarted +// after a controller restart. +func (r *BootcNodePoolReconciler) recordDrainStalls( + pool *bootcv1alpha1.BootcNodePool, + nodes map[string]*bootcv1alpha1.BootcNode, +) time.Duration { + now := time.Now() + var stalledNodes []*bootcv1alpha1.BootcNode + var nextCheck time.Duration + + r.drainsMu.Lock() + for nodeName, status := range r.drains { + if status.isStalled { + continue + } + + remaining := drainStallThreshold - now.Sub(status.startTime) + if remaining > 0 { + nextCheck = earlierRequeue(nextCheck, remaining) + continue + } + + status.isStalled = true + if node, ok := nodes[nodeName]; ok { + stalledNodes = append(stalledNodes, node) + } + } + r.drainsMu.Unlock() + + for _, node := range stalledNodes { + r.recordEvent( + node, + pool, + corev1.EventTypeWarning, + eventReasonDrainTakingTooLong, + eventActionDrain, + drainStalledNote{Threshold: drainStallThreshold}, + ) + } + + return nextCheck +} + +func earlierRequeue(current, candidate time.Duration) time.Duration { + if candidate <= 0 { + return current + } + if current <= 0 || candidate < current { + return candidate + } + return current +} + +func (r *BootcNodePoolReconciler) recordEvent( + regarding, related runtime.Object, + eventType, reason, action string, + note EventNote, +) { + r.Recorder.Eventf(regarding, related, eventType, reason, action, "%s", note.Note()) +} + +// capNote keeps a note within the events.k8s.io/v1 1 KiB limit and never splits +// a UTF-8 sequence. It is only needed for notes built from unbounded free text +// (condition messages, error strings); notes assembled from bounded fields fit +// by construction. +func capNote(note string) string { + note = strings.ToValidUTF8(note, "�") + if len(note) <= eventNoteLimit { + return note + } + + limit := eventNoteLimit - len(eventNoteSuffix) + for limit > 0 && !utf8.RuneStart(note[limit]) { + limit-- + } + return note[:limit] + eventNoteSuffix +} diff --git a/internal/controller/events_test.go b/internal/controller/events_test.go new file mode 100644 index 00000000..ee9ba1eb --- /dev/null +++ b/internal/controller/events_test.go @@ -0,0 +1,864 @@ +// SPDX-License-Identifier: Apache-2.0 + +package controller + +import ( + "context" + "errors" + "fmt" + "strings" + "testing" + "time" + "unicode/utf8" + + . "github.com/onsi/gomega" + corev1 "k8s.io/api/core/v1" + eventsv1 "k8s.io/api/events/v1" + metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" + "k8s.io/apimachinery/pkg/runtime" + "k8s.io/apimachinery/pkg/types" + "sigs.k8s.io/controller-runtime/pkg/client" + + bootcv1alpha1 "github.com/bootc-dev/bootc-operator/api/v1alpha1" + testutil "github.com/bootc-dev/bootc-operator/test/util" +) + +type capturedEvent struct { + regarding string + related string + eventType string + reason string + action string + note string +} + +type capturingEventRecorder struct { + events []capturedEvent +} + +type patchFailingClient struct { + client.Client + err error +} + +func (c *patchFailingClient) Patch( + context.Context, + client.Object, + client.Patch, + ...client.PatchOption, +) error { + return c.err +} + +type staticTagResolver struct { + digest string +} + +func (r staticTagResolver) Resolve(context.Context, string) (string, error) { + return r.digest, nil +} + +func (r *capturingEventRecorder) Eventf( + regarding runtime.Object, + related runtime.Object, + eventType, reason, action, note string, + args ...interface{}, +) { + event := capturedEvent{ + eventType: eventType, + reason: reason, + action: action, + note: fmt.Sprintf(note, args...), + } + if object, ok := regarding.(metav1.Object); ok { + event.regarding = object.GetName() + } + if object, ok := related.(metav1.Object); ok { + event.related = object.GetName() + } + r.events = append(r.events, event) +} + +func TestRecordPoolEvents(t *testing.T) { + condition := func(conditionType string, status metav1.ConditionStatus, reason, message string) metav1.Condition { + return metav1.Condition{ + Type: conditionType, + Status: status, + Reason: reason, + Message: message, + } + } + + tests := []struct { + name string + imageRef string + previous bootcv1alpha1.BootcNodePoolStatus + current bootcv1alpha1.BootcNodePoolStatus + tagChanged bool + wantEvents []capturedEvent + }{ + { + name: "moving tag retargets active rollout", + imageRef: testutil.ImageTaggedRef, + previous: bootcv1alpha1.BootcNodePoolStatus{ + TargetDigest: testDigestA, + Conditions: []metav1.Condition{ + condition( + bootcv1alpha1.PoolUpToDate, + metav1.ConditionFalse, + bootcv1alpha1.PoolRolloutInProgress, + "0/1 updated", + ), + }, + }, + current: bootcv1alpha1.BootcNodePoolStatus{ + TargetDigest: testDigestB, + Conditions: []metav1.Condition{ + condition( + bootcv1alpha1.PoolUpToDate, + metav1.ConditionFalse, + bootcv1alpha1.PoolRolloutInProgress, + "0/1 updated", + ), + }, + }, + tagChanged: true, + wantEvents: []capturedEvent{ + { + regarding: "pool-events", + eventType: corev1.EventTypeNormal, + reason: eventReasonImageUpdateAvailable, + action: eventActionResolveImage, + note: fmt.Sprintf( + "Image tag %s resolved to new digest %s (previously %s)", + testutil.ImageTaggedRef, + shortDigest(testDigestB), + shortDigest(testDigestA), + ), + }, + { + regarding: "pool-events", + eventType: corev1.EventTypeNormal, + reason: eventReasonRolloutStarted, + action: eventActionRollout, + note: "Rollout started toward digest " + shortDigest(testDigestB), + }, + }, + }, + { + name: "digest retarget starts a new active rollout", + imageRef: testImageDigestRefB, + previous: bootcv1alpha1.BootcNodePoolStatus{ + TargetDigest: testDigestA, + Conditions: []metav1.Condition{ + condition( + bootcv1alpha1.PoolUpToDate, + metav1.ConditionFalse, + bootcv1alpha1.PoolRolloutInProgress, + "0/1 updated", + ), + }, + }, + current: bootcv1alpha1.BootcNodePoolStatus{ + TargetDigest: testDigestB, + Conditions: []metav1.Condition{ + condition( + bootcv1alpha1.PoolUpToDate, + metav1.ConditionFalse, + bootcv1alpha1.PoolRolloutInProgress, + "0/1 updated", + ), + }, + }, + wantEvents: []capturedEvent{{ + regarding: "pool-events", + eventType: corev1.EventTypeNormal, + reason: eventReasonRolloutStarted, + action: eventActionRollout, + note: "Rollout started toward digest " + shortDigest(testDigestB), + }}, + }, + { + name: "rollout starts", + imageRef: testImageDigestRefB, + previous: bootcv1alpha1.BootcNodePoolStatus{ + TargetDigest: testDigestB, + Conditions: []metav1.Condition{ + condition( + bootcv1alpha1.PoolUpToDate, + metav1.ConditionTrue, + bootcv1alpha1.PoolAllUpdated, + "", + ), + }, + }, + current: bootcv1alpha1.BootcNodePoolStatus{ + TargetDigest: testDigestB, + Conditions: []metav1.Condition{ + condition( + bootcv1alpha1.PoolUpToDate, + metav1.ConditionFalse, + bootcv1alpha1.PoolRolloutInProgress, + "0/1 updated", + ), + }, + }, + wantEvents: []capturedEvent{{ + regarding: "pool-events", + eventType: corev1.EventTypeNormal, + reason: eventReasonRolloutStarted, + action: eventActionRollout, + note: "Rollout started toward digest " + shortDigest(testDigestB), + }}, + }, + { + name: "unpausing starts rollout", + imageRef: testImageDigestRefB, + previous: bootcv1alpha1.BootcNodePoolStatus{ + TargetDigest: testDigestB, + Conditions: []metav1.Condition{ + condition( + bootcv1alpha1.PoolUpToDate, + metav1.ConditionFalse, + bootcv1alpha1.PoolPaused, + "0/1 updated", + ), + }, + }, + current: bootcv1alpha1.BootcNodePoolStatus{ + TargetDigest: testDigestB, + Conditions: []metav1.Condition{ + condition( + bootcv1alpha1.PoolUpToDate, + metav1.ConditionFalse, + bootcv1alpha1.PoolRolloutInProgress, + "0/1 updated", + ), + }, + }, + wantEvents: []capturedEvent{{ + regarding: "pool-events", + eventType: corev1.EventTypeNormal, + reason: eventReasonRolloutStarted, + action: eventActionRollout, + note: "Rollout started toward digest " + shortDigest(testDigestB), + }}, + }, + { + name: "rollout completes", + imageRef: testImageDigestRefB, + previous: bootcv1alpha1.BootcNodePoolStatus{ + TargetDigest: testDigestB, + Conditions: []metav1.Condition{ + condition( + bootcv1alpha1.PoolUpToDate, + metav1.ConditionFalse, + bootcv1alpha1.PoolRolloutInProgress, + "0/1 updated", + ), + }, + }, + current: bootcv1alpha1.BootcNodePoolStatus{ + TargetDigest: testDigestB, + Conditions: []metav1.Condition{ + condition( + bootcv1alpha1.PoolUpToDate, + metav1.ConditionTrue, + bootcv1alpha1.PoolAllUpdated, + "", + ), + }, + }, + wantEvents: []capturedEvent{{ + regarding: "pool-events", + eventType: corev1.EventTypeNormal, + reason: eventReasonRolloutCompleted, + action: eventActionRollout, + note: "Rollout completed at digest " + shortDigest(testDigestB), + }}, + }, + { + name: "initially up to date is not a completed rollout", + imageRef: testImageDigestRefB, + previous: bootcv1alpha1.BootcNodePoolStatus{TargetDigest: testDigestB}, + current: bootcv1alpha1.BootcNodePoolStatus{ + TargetDigest: testDigestB, + Conditions: []metav1.Condition{ + condition( + bootcv1alpha1.PoolUpToDate, + metav1.ConditionTrue, + bootcv1alpha1.PoolAllUpdated, + "", + ), + }, + }, + }, + { + name: "pool becomes degraded", + imageRef: testImageDigestRefB, + previous: bootcv1alpha1.BootcNodePoolStatus{ + Conditions: []metav1.Condition{ + condition( + bootcv1alpha1.PoolDegraded, + metav1.ConditionFalse, + bootcv1alpha1.PoolHealthy, + "", + ), + }, + }, + current: bootcv1alpha1.BootcNodePoolStatus{ + Conditions: []metav1.Condition{ + condition( + bootcv1alpha1.PoolDegraded, + metav1.ConditionTrue, + bootcv1alpha1.PoolInvalidSpec, + "invalid maxUnavailable", + ), + }, + }, + wantEvents: []capturedEvent{{ + regarding: "pool-events", + eventType: corev1.EventTypeWarning, + reason: bootcv1alpha1.PoolInvalidSpec, + action: eventActionPoolDegraded, + note: "invalid maxUnavailable", + }}, + }, + { + name: "degraded reason changes", + imageRef: testImageDigestRefB, + previous: bootcv1alpha1.BootcNodePoolStatus{ + Conditions: []metav1.Condition{ + condition( + bootcv1alpha1.PoolDegraded, + metav1.ConditionTrue, + bootcv1alpha1.PoolNodeConflict, + "overlapping selector", + ), + }, + }, + current: bootcv1alpha1.BootcNodePoolStatus{ + Conditions: []metav1.Condition{ + condition( + bootcv1alpha1.PoolDegraded, + metav1.ConditionTrue, + bootcv1alpha1.PoolRolloutHalted, + "two unhealthy nodes", + ), + }, + }, + wantEvents: []capturedEvent{{ + regarding: "pool-events", + eventType: corev1.EventTypeWarning, + reason: bootcv1alpha1.PoolRolloutHalted, + action: eventActionPoolDegraded, + note: "two unhealthy nodes", + }}, + }, + { + name: "unchanged degraded state", + imageRef: testImageDigestRefB, + previous: bootcv1alpha1.BootcNodePoolStatus{ + Conditions: []metav1.Condition{ + condition( + bootcv1alpha1.PoolDegraded, + metav1.ConditionTrue, + bootcv1alpha1.PoolNodeConflict, + "overlapping selector", + ), + }, + }, + current: bootcv1alpha1.BootcNodePoolStatus{ + Conditions: []metav1.Condition{ + condition( + bootcv1alpha1.PoolDegraded, + metav1.ConditionTrue, + bootcv1alpha1.PoolNodeConflict, + "overlapping selector", + ), + }, + }, + }, + } + + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + g := NewWithT(t) + recorder := &capturingEventRecorder{} + reconciler := &BootcNodePoolReconciler{Recorder: recorder} + pool := testutil.NewPool("pool-events", tt.imageRef, testutil.WithWorkerSelector()) + pool.Status = tt.current + + reconciler.recordPoolEvents(pool, &tt.previous, tt.tagChanged) + + g.Expect(recorder.events).To(Equal(tt.wantEvents)) + }) + } +} + +func TestResolveTargetDigestReportsTagChange(t *testing.T) { + g := NewWithT(t) + pool := testutil.NewPool( + "tag-change", + testutil.ImageTaggedRef, + testutil.WithWorkerSelector(), + ) + pool.Status.TargetDigest = testDigestA + reconciler := &BootcNodePoolReconciler{ + TagResolver: staticTagResolver{digest: testDigestB}, + TagResolutionInterval: time.Hour, + } + + result, changed, err := reconciler.resolveTargetDigest(context.Background(), pool) + + g.Expect(err).NotTo(HaveOccurred()) + g.Expect(changed).To(BeTrue()) + g.Expect(pool.Status.TargetDigest).To(Equal(testDigestB)) + g.Expect(result.RequeueAfter).To(Equal(time.Hour)) +} + +func TestNodeEvent(t *testing.T) { + tests := []struct { + name string + status metav1.ConditionStatus + reason string + previous string + wantObservation string + wantReason string + wantNote string + }{ + { + name: "first observed idle does not emit", + status: metav1.ConditionTrue, + reason: bootcv1alpha1.NodeReasonIdle, + wantObservation: "True:Idle:" + testImageDigestRefB, + }, + { + name: "idle after rollout emits", + status: metav1.ConditionTrue, + reason: bootcv1alpha1.NodeReasonIdle, + previous: "False:Rebooting:" + testImageDigestRefB, + wantObservation: "True:Idle:" + testImageDigestRefB, + wantReason: bootcv1alpha1.NodeReasonIdle, + wantNote: "Node is up to date with image " + testImageDigestRefB, + }, + { + name: "idle after idle does not re-emit", + status: metav1.ConditionTrue, + reason: bootcv1alpha1.NodeReasonIdle, + previous: "True:Idle:" + testImageDigestRefB, + wantObservation: "True:Idle:" + testImageDigestRefB, + }, + { + name: "staging", + status: metav1.ConditionFalse, + reason: bootcv1alpha1.NodeReasonStaging, + wantObservation: "False:Staging:" + testImageDigestRefB, + wantReason: bootcv1alpha1.NodeReasonStaging, + wantNote: "Staging image " + testImageDigestRefB, + }, + { + name: "staged", + status: metav1.ConditionFalse, + reason: bootcv1alpha1.NodeReasonStaged, + wantObservation: "False:Staged:" + testImageDigestRefB, + wantReason: bootcv1alpha1.NodeReasonStaged, + wantNote: "Image " + testImageDigestRefB + " is staged and awaiting reboot", + }, + { + name: "rebooting", + status: metav1.ConditionFalse, + reason: bootcv1alpha1.NodeReasonRebooting, + wantObservation: "False:Rebooting:" + testImageDigestRefB, + wantReason: bootcv1alpha1.NodeReasonRebooting, + wantNote: "Rebooting into image " + testImageDigestRefB, + }, + { + name: "unknown reason does not emit", + status: metav1.ConditionFalse, + reason: "Unknown", + wantObservation: "False:Unknown:" + testImageDigestRefB, + }, + } + + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + g := NewWithT(t) + node := testutil.NewNode( + "node-events", + testImageDigestRefB, + testutil.WithNodeCondition(bootcv1alpha1.NodeIdle, tt.status, tt.reason), + ) + + observation, reason, note := nodeEvent(node, tt.previous) + + g.Expect(observation).To(Equal(tt.wantObservation)) + g.Expect(reason).To(Equal(tt.wantReason)) + if tt.wantNote == "" { + g.Expect(note).To(BeNil()) + } else { + g.Expect(note).NotTo(BeNil()) + g.Expect(note.Note()).To(Equal(tt.wantNote)) + } + }) + } +} + +func TestRecordNodeEventBeforeMarkerPatch(t *testing.T) { + g := NewWithT(t) + recorder := &capturingEventRecorder{} + reconciler := &BootcNodePoolReconciler{ + Client: &patchFailingClient{err: errors.New("temporary API error")}, + Recorder: recorder, + } + pool := testutil.NewPool( + "node-patch-events", + testImageDigestRefB, + testutil.WithWorkerSelector(), + ) + node := testutil.NewNode( + "node-patch-events-worker", + testImageDigestRefB, + testutil.WithNodeCondition( + bootcv1alpha1.NodeIdle, + metav1.ConditionFalse, + bootcv1alpha1.NodeReasonStaging, + ), + ) + + reconciler.recordNodeEvents( + context.Background(), + pool, + map[string]*bootcv1alpha1.BootcNode{node.Name: node}, + ) + + g.Expect(recorder.events).To(Equal([]capturedEvent{{ + regarding: node.Name, + related: pool.Name, + eventType: corev1.EventTypeNormal, + reason: bootcv1alpha1.NodeReasonStaging, + action: eventActionNodeUpdate, + note: "Staging image " + testImageDigestRefB, + }})) + g.Expect(node.Annotations).NotTo(HaveKey(bootcv1alpha1.AnnotationLastObservedState)) +} + +func TestRecordDrainFailedEvent(t *testing.T) { + g := NewWithT(t) + recorder := &capturingEventRecorder{} + reconciler := &BootcNodePoolReconciler{Recorder: recorder} + pool := testutil.NewPool("drain-events", testImageDigestRefB, testutil.WithWorkerSelector()) + node := testutil.NewNode("drain-events-worker", testImageDigestRefB) + + reconciler.recordDrainFailedEvent(pool, node, errors.New("timed out waiting for eviction")) + + g.Expect(recorder.events).To(Equal([]capturedEvent{ + { + regarding: node.Name, + related: pool.Name, + eventType: corev1.EventTypeWarning, + reason: eventReasonDrainFailed, + action: eventActionDrain, + note: "Failed to drain node: timed out waiting for eviction; the drain will be retried", + }, + })) +} + +func TestShortDigest(t *testing.T) { + tests := []struct { + name string + digest string + want string + }{ + { + name: "full digest is abbreviated", + digest: testDigestA, + want: testDigestA[:len("sha256:")+12], + }, + { + name: "short value is unchanged", + digest: "sha256:abc", + want: "sha256:abc", + }, + { + name: "empty value is unchanged", + digest: "", + want: "", + }, + } + + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + g := NewWithT(t) + g.Expect(shortDigest(tt.digest)).To(Equal(tt.want)) + }) + } +} + +func TestCapNote(t *testing.T) { + tests := []struct { + name string + note string + want string + truncated bool + }{ + {name: "short note", note: "drain failed", want: "drain failed"}, + { + name: "note at limit", + note: strings.Repeat("a", eventNoteLimit), + want: strings.Repeat("a", eventNoteLimit), + }, + {name: "long ASCII note", note: strings.Repeat("a", eventNoteLimit+1), truncated: true}, + {name: "long UTF-8 note", note: strings.Repeat("界", eventNoteLimit), truncated: true}, + {name: "invalid UTF-8", note: string([]byte{'a', 0xff, 'b'}), want: "a\uFFFDb"}, + } + + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + g := NewWithT(t) + note := capNote(tt.note) + + g.Expect(len(note)).To(BeNumerically("<=", eventNoteLimit)) + g.Expect(utf8.ValidString(note)).To(BeTrue()) + if tt.want != "" { + g.Expect(note).To(Equal(tt.want)) + } + if tt.truncated { + g.Expect(note).To(HaveSuffix(eventNoteSuffix)) + } + }) + } +} + +func TestRecordDrainStalls(t *testing.T) { + g := NewWithT(t) + recorder := &capturingEventRecorder{} + pool := testutil.NewPool("drain-stall", testImageDigestRefB, testutil.WithWorkerSelector()) + stalledNode := testutil.NewNode("drain-stall-worker", testImageDigestRefB) + freshNode := testutil.NewNode("drain-fresh-worker", testImageDigestRefB) + stalledStatus := &drainStatus{startTime: time.Now().Add(-drainStallThreshold)} + freshStatus := &drainStatus{startTime: time.Now()} + reconciler := &BootcNodePoolReconciler{ + Recorder: recorder, + drains: map[string]*drainStatus{ + stalledNode.Name: stalledStatus, + freshNode.Name: freshStatus, + }, + } + + nextCheck := reconciler.recordDrainStalls( + pool, + map[string]*bootcv1alpha1.BootcNode{ + stalledNode.Name: stalledNode, + freshNode.Name: freshNode, + }, + ) + + g.Expect(stalledStatus.isStalled).To(BeTrue()) + g.Expect(freshStatus.isStalled).To(BeFalse()) + g.Expect(nextCheck).To(BeNumerically(">", drainStallThreshold-time.Second)) + g.Expect(nextCheck).To(BeNumerically("<=", drainStallThreshold)) + g.Expect(recorder.events).To(Equal([]capturedEvent{{ + regarding: stalledNode.Name, + related: pool.Name, + eventType: corev1.EventTypeWarning, + reason: eventReasonDrainTakingTooLong, + action: eventActionDrain, + note: fmt.Sprintf( + "Drain has been running for more than %s; it may be blocked by a PodDisruptionBudget", + drainStallThreshold, + ), + }})) + + // The isStalled marker suppresses duplicate events on later reconciles. + reconciler.recordDrainStalls( + pool, + map[string]*bootcv1alpha1.BootcNode{stalledNode.Name: stalledNode}, + ) + g.Expect(recorder.events).To(HaveLen(1)) +} + +func TestEarlierRequeue(t *testing.T) { + tests := []struct { + name string + current time.Duration + candidate time.Duration + want time.Duration + }{ + {name: "uses first deadline", candidate: 5 * time.Minute, want: 5 * time.Minute}, + { + name: "uses earlier deadline", + current: time.Hour, + candidate: 5 * time.Minute, + want: 5 * time.Minute, + }, + { + name: "keeps earlier deadline", + current: time.Minute, + candidate: 5 * time.Minute, + want: time.Minute, + }, + {name: "ignores absent candidate", current: time.Hour, want: time.Hour}, + } + + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + g := NewWithT(t) + g.Expect(earlierRequeue(tt.current, tt.candidate)).To(Equal(tt.want)) + }) + } +} + +func TestRolloutAndNodeEvents(t *testing.T) { + g := NewWithT(t) + g.SetDefaultEventuallyTimeout(pollTimeout) + g.SetDefaultEventuallyPollingInterval(pollInterval) + ctx := context.Background() + + const ( + poolName = "rollout-events" + nodeName = "rollout-events-worker" + ) + + node := testutil.NewK8sNode(nodeName, testutil.WorkerLabels()) + g.Expect(k8sClient.Create(ctx, node)).To(Succeed()) + t.Cleanup(func() { + _ = k8sClient.Delete(ctx, node) + }) + + pool := testutil.NewPool(poolName, testImageDigestRefB, testutil.WithWorkerSelector()) + g.Expect(k8sClient.Create(ctx, pool)).To(Succeed()) + t.Cleanup(func() { + _ = k8sClient.Delete(ctx, pool) + }) + + var bootcNode bootcv1alpha1.BootcNode + g.Eventually(func() error { + return k8sClient.Get(ctx, client.ObjectKey{Name: nodeName}, &bootcNode) + }).Should(Succeed()) + + g.Eventually(func() ([]eventsv1.Event, error) { + return eventsForObject(ctx, "BootcNodePool", poolName, pool.UID) + }).Should(ContainElement(And( + HaveField("Type", corev1.EventTypeNormal), + HaveField("Reason", eventReasonRolloutStarted), + HaveField("Action", eventActionRollout), + HaveField("Note", "Rollout started toward digest "+shortDigest(testDigestB)), + ))) + + nodeTransitions := []struct { + reason string + note string + }{ + { + reason: bootcv1alpha1.NodeReasonStaging, + note: "Staging image " + testImageDigestRefB, + }, + { + reason: bootcv1alpha1.NodeReasonStaged, + note: "Image " + testImageDigestRefB + " is staged and awaiting reboot", + }, + { + reason: bootcv1alpha1.NodeReasonRebooting, + note: "Rebooting into image " + testImageDigestRefB, + }, + } + for _, transition := range nodeTransitions { + simulateDaemonStatus(g, ctx, nodeName, testDigestA, transition.reason) + g.Eventually(func() ([]eventsv1.Event, error) { + return eventsForObject(ctx, "BootcNode", nodeName, bootcNode.UID) + }).Should(ContainElement(And( + HaveField("Type", corev1.EventTypeNormal), + HaveField("Reason", transition.reason), + HaveField("Action", eventActionNodeUpdate), + HaveField("Note", transition.note), + HaveField("Related", And( + Not(BeNil()), + HaveField("Name", poolName), + )), + ))) + } + + simulateDaemonStatus(g, ctx, nodeName, testDigestB, bootcv1alpha1.NodeReasonIdle) + g.Eventually(func() ([]eventsv1.Event, error) { + return eventsForObject(ctx, "BootcNodePool", poolName, pool.UID) + }).Should(ContainElement(And( + HaveField("Type", corev1.EventTypeNormal), + HaveField("Reason", eventReasonRolloutCompleted), + HaveField("Action", eventActionRollout), + HaveField("Note", "Rollout completed at digest "+shortDigest(testDigestB)), + ))) + + g.Eventually(func() ([]eventsv1.Event, error) { + return eventsForObject(ctx, "BootcNode", nodeName, bootcNode.UID) + }).Should(ContainElement(And( + HaveField("Type", corev1.EventTypeNormal), + HaveField("Reason", bootcv1alpha1.NodeReasonIdle), + HaveField("Action", eventActionNodeUpdate), + HaveField("Note", "Node is up to date with image "+testImageDigestRefB), + HaveField("Related", And( + Not(BeNil()), + HaveField("Name", poolName), + )), + ))) + + g.Consistently(func() (map[string]int, error) { + events, err := eventsForObject(ctx, "BootcNode", nodeName, bootcNode.UID) + if err != nil { + return nil, err + } + counts := map[string]int{} + for _, event := range events { + occurrences := 1 + if event.Series != nil { + occurrences = int(event.Series.Count) + } + counts[event.Reason] += occurrences + } + return counts, nil + }, time.Second, pollInterval).Should(Equal(map[string]int{ + bootcv1alpha1.NodeReasonStaging: 1, + bootcv1alpha1.NodeReasonStaged: 1, + bootcv1alpha1.NodeReasonRebooting: 1, + bootcv1alpha1.NodeReasonIdle: 1, + })) +} + +func TestInvalidSpecEmitsWarningEvent(t *testing.T) { + g := NewWithT(t) + g.SetDefaultEventuallyTimeout(pollTimeout) + g.SetDefaultEventuallyPollingInterval(pollInterval) + ctx := context.Background() + + pool := testutil.NewPool("invalid-spec-event", "myos:latest", testutil.WithWorkerSelector()) + g.Expect(k8sClient.Create(ctx, pool)).To(Succeed()) + t.Cleanup(func() { + _ = k8sClient.Delete(ctx, pool) + }) + + g.Eventually(func() ([]eventsv1.Event, error) { + return eventsForObject(ctx, "BootcNodePool", pool.Name, pool.UID) + }).Should(ContainElement(And( + HaveField("Type", "Warning"), + HaveField("Reason", bootcv1alpha1.PoolInvalidSpec), + HaveField("Action", "PoolDegraded"), + HaveField("Note", ContainSubstring("invalid image ref")), + ))) +} + +func eventsForObject( + ctx context.Context, + kind, name string, + uid types.UID, +) ([]eventsv1.Event, error) { + var eventList eventsv1.EventList + if err := k8sClient.List( + ctx, + &eventList, + client.InNamespace(metav1.NamespaceDefault), + ); err != nil { + return nil, err + } + + return testutil.FilterEventsByObject(eventList.Items, kind, name, uid), nil +} diff --git a/internal/controller/rollout.go b/internal/controller/rollout.go index 14dfc3b1..0780f7d4 100644 --- a/internal/controller/rollout.go +++ b/internal/controller/rollout.go @@ -77,7 +77,7 @@ func (r *BootcNodePoolReconciler) driveRollout( // Process drain results first. This isn't really ordering dependent, // but it feels natural to do this upfront before classifying. - if err := r.collectDrainResults(ctx, ownedBootcNodes); err != nil { + if err := r.collectDrainResults(ctx, pool, ownedBootcNodes); err != nil { return nil, fmt.Errorf("collecting drain results: %w", err) } @@ -352,6 +352,7 @@ func (r *BootcNodePoolReconciler) ensureDrain( // BootcNode. func (r *BootcNodePoolReconciler) collectDrainResults( ctx context.Context, + pool *bootcv1alpha1.BootcNodePool, ownedBootcNodes map[string]*bootcv1alpha1.BootcNode, ) error { log := logf.FromContext(ctx) @@ -384,6 +385,9 @@ func (r *BootcNodePoolReconciler) collectDrainResults( // selectDrainCandidates picks the still-slotted Staged // node, and ensureDrain starts a new goroutine. log.Info("Drain failed, will retry", "node", nodeName, "error", drainErr) + if bn, ok := ownedBootcNodes[nodeName]; ok { + r.recordDrainFailedEvent(pool, bn, drainErr) + } } continue } diff --git a/internal/controller/rollout_envtest_test.go b/internal/controller/rollout_envtest_test.go index b6eec7f8..62b92722 100644 --- a/internal/controller/rollout_envtest_test.go +++ b/internal/controller/rollout_envtest_test.go @@ -13,6 +13,7 @@ import ( apimeta "k8s.io/apimachinery/pkg/api/meta" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" "k8s.io/apimachinery/pkg/util/intstr" + "k8s.io/client-go/util/retry" "sigs.k8s.io/controller-runtime/pkg/client" bootcv1alpha1 "github.com/bootc-dev/bootc-operator/api/v1alpha1" @@ -471,56 +472,64 @@ func simulateDaemonStatus( ctx context.Context, nodeName, bootedDigest, idleReason string, ) { - var bn bootcv1alpha1.BootcNode - g.Expect(k8sClient.Get(ctx, client.ObjectKey{Name: nodeName}, &bn)).To(Succeed()) + g.Expect(retry.RetryOnConflict(retry.DefaultRetry, func() error { + var bn bootcv1alpha1.BootcNode + if err := k8sClient.Get(ctx, client.ObjectKey{Name: nodeName}, &bn); err != nil { + return err + } - bn.Status.Booted = &bootcv1alpha1.ImageInfo{ - Image: "quay.io/example/myos@" + bootedDigest, - ImageDigest: bootedDigest, - } + bn.Status.Booted = &bootcv1alpha1.ImageInfo{ + Image: "quay.io/example/myos@" + bootedDigest, + ImageDigest: bootedDigest, + } - idleStatus := metav1.ConditionFalse - if idleReason == bootcv1alpha1.NodeReasonIdle { - idleStatus = metav1.ConditionTrue - } - apimeta.SetStatusCondition(&bn.Status.Conditions, metav1.Condition{ - Type: bootcv1alpha1.NodeIdle, - Status: idleStatus, - Reason: idleReason, - }) - // Clear Degraded when simulating a healthy status. - apimeta.SetStatusCondition(&bn.Status.Conditions, metav1.Condition{ - Type: bootcv1alpha1.NodeDegraded, - Status: metav1.ConditionFalse, - Reason: bootcv1alpha1.NodeReasonHealthy, - }) + idleStatus := metav1.ConditionFalse + if idleReason == bootcv1alpha1.NodeReasonIdle { + idleStatus = metav1.ConditionTrue + } + apimeta.SetStatusCondition(&bn.Status.Conditions, metav1.Condition{ + Type: bootcv1alpha1.NodeIdle, + Status: idleStatus, + Reason: idleReason, + }) + // Clear Degraded when simulating a healthy status. + apimeta.SetStatusCondition(&bn.Status.Conditions, metav1.Condition{ + Type: bootcv1alpha1.NodeDegraded, + Status: metav1.ConditionFalse, + Reason: bootcv1alpha1.NodeReasonHealthy, + }) - g.Expect(k8sClient.Status().Update(ctx, &bn)).To(Succeed()) + return k8sClient.Status().Update(ctx, &bn) + })).To(Succeed()) } // simulateDaemonDegraded writes BootcNode status as if the daemon had // reported the given booted digest with Degraded=True (e.g. staging failed). func simulateDaemonDegraded(g Gomega, ctx context.Context, nodeName, bootedDigest string) { - var bn bootcv1alpha1.BootcNode - g.Expect(k8sClient.Get(ctx, client.ObjectKey{Name: nodeName}, &bn)).To(Succeed()) + g.Expect(retry.RetryOnConflict(retry.DefaultRetry, func() error { + var bn bootcv1alpha1.BootcNode + if err := k8sClient.Get(ctx, client.ObjectKey{Name: nodeName}, &bn); err != nil { + return err + } - bn.Status.Booted = &bootcv1alpha1.ImageInfo{ - Image: "quay.io/example/myos@" + bootedDigest, - ImageDigest: bootedDigest, - } - apimeta.SetStatusCondition(&bn.Status.Conditions, metav1.Condition{ - Type: bootcv1alpha1.NodeIdle, - Status: metav1.ConditionFalse, - Reason: bootcv1alpha1.NodeReasonStaging, - }) - apimeta.SetStatusCondition(&bn.Status.Conditions, metav1.Condition{ - Type: bootcv1alpha1.NodeDegraded, - Status: metav1.ConditionTrue, - Reason: bootcv1alpha1.NodeReasonError, - Message: "simulated staging failure", - }) + bn.Status.Booted = &bootcv1alpha1.ImageInfo{ + Image: "quay.io/example/myos@" + bootedDigest, + ImageDigest: bootedDigest, + } + apimeta.SetStatusCondition(&bn.Status.Conditions, metav1.Condition{ + Type: bootcv1alpha1.NodeIdle, + Status: metav1.ConditionFalse, + Reason: bootcv1alpha1.NodeReasonStaging, + }) + apimeta.SetStatusCondition(&bn.Status.Conditions, metav1.Condition{ + Type: bootcv1alpha1.NodeDegraded, + Status: metav1.ConditionTrue, + Reason: bootcv1alpha1.NodeReasonError, + Message: "simulated staging failure", + }) - g.Expect(k8sClient.Status().Update(ctx, &bn)).To(Succeed()) + return k8sClient.Status().Update(ctx, &bn) + })).To(Succeed()) } // setNodeReady sets the Ready condition on a K8s Node to True. In diff --git a/test/e2e/bootcnode_test.go b/test/e2e/bootcnode_test.go index b873be12..dac6fda2 100644 --- a/test/e2e/bootcnode_test.go +++ b/test/e2e/bootcnode_test.go @@ -13,10 +13,12 @@ import ( "time" . "github.com/onsi/gomega" - "github.com/onsi/gomega/types" + gtypes "github.com/onsi/gomega/types" corev1 "k8s.io/api/core/v1" + eventsv1 "k8s.io/api/events/v1" meta "k8s.io/apimachinery/pkg/api/meta" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" + k8stypes "k8s.io/apimachinery/pkg/types" "sigs.k8s.io/controller-runtime/pkg/client" bootcv1alpha1 "github.com/bootc-dev/bootc-operator/api/v1alpha1" @@ -135,6 +137,9 @@ func TestUpdateReboot(t *testing.T) { t.Logf("Node %q is Idle with original image", nodeName) + var bootcNode bootcv1alpha1.BootcNode + g.Expect(env.Client.Get(ctx, client.ObjectKey{Name: nodeName}, &bootcNode)).To(Succeed()) + // Phase 2: Patch pool to update image. updateRef := env.NodeImageUpdateDigestedPullSpec() @@ -159,6 +164,47 @@ func TestUpdateReboot(t *testing.T) { t.Logf("Node %q is Rebooting", nodeName) + nodeEvents := []struct { + reason string + note string + }{ + { + reason: bootcv1alpha1.NodeReasonStaging, + note: "Staging image " + updateRef, + }, + { + reason: bootcv1alpha1.NodeReasonStaged, + note: "Image " + updateRef + " is staged and awaiting reboot", + }, + { + reason: bootcv1alpha1.NodeReasonRebooting, + note: "Rebooting into image " + updateRef, + }, + } + for _, expected := range nodeEvents { + g.Eventually(fetchEvents(ctx, env.Client, "BootcNode", nodeName, bootcNode.UID)). + Should(ContainElement(And( + HaveField("Type", corev1.EventTypeNormal), + HaveField("Reason", expected.reason), + HaveField("Action", "NodeUpdate"), + HaveField("Note", expected.note), + HaveField("Related", And( + Not(BeNil()), + HaveField("UID", pool.UID), + )), + ))) + } + g.Eventually(fetchEvents(ctx, env.Client, "BootcNodePool", pool.Name, pool.UID)). + Should(ContainElement(And( + HaveField("Type", corev1.EventTypeNormal), + HaveField("Reason", "RolloutStarted"), + HaveField("Action", "Rollout"), + HaveField( + "Note", + "Rollout started toward digest "+testutil.ShortDigest(env.NodeImageUpdateDigest()), + ), + ))) + // Verify pool status during rollout. g.Eventually(fetchPoolStatus(ctx, env.Client, pool)).Should(And( HaveField("NodeCount", BeEquivalentTo(1)), @@ -195,6 +241,16 @@ func TestUpdateReboot(t *testing.T) { // Verify pool status after rollout completes. g.Eventually(fetchPoolStatus(ctx, env.Client, pool)). Should(poolAllUpdated(1, env.NodeImageUpdateDigest())) + g.Eventually(fetchEvents(ctx, env.Client, "BootcNodePool", pool.Name, pool.UID)). + Should(ContainElement(And( + HaveField("Type", corev1.EventTypeNormal), + HaveField("Reason", "RolloutCompleted"), + HaveField("Action", "Rollout"), + HaveField( + "Note", + "Rollout completed at digest "+testutil.ShortDigest(env.NodeImageUpdateDigest()), + ), + ))) // Phase 5: Verify node is schedulable (uncordoned after reboot). g.Eventually(func() (bool, error) { @@ -313,6 +369,22 @@ func TestTagResolution(t *testing.T) { t.Logf("Tag re-resolved to update digest %s", env.NodeImageUpdateDigest()) + g.Eventually(fetchEvents(ctx, env.Client, "BootcNodePool", pool.Name, pool.UID)). + Should(ContainElement(And( + HaveField("Type", corev1.EventTypeNormal), + HaveField("Reason", "ImageUpdateAvailable"), + HaveField("Action", "ResolveImage"), + HaveField( + "Note", + fmt.Sprintf( + "Image tag %s resolved to new digest %s (previously %s)", + env.NodeImageTagRef(), + testutil.ShortDigest(env.NodeImageUpdateDigest()), + testutil.ShortDigest(env.NodeImageDigest()), + ), + ), + ))) + // Wait for node to reach Idle with the update image. g.Eventually(func() (bootcv1alpha1.BootcNodeStatus, error) { var bn bootcv1alpha1.BootcNode @@ -751,7 +823,23 @@ func fetchPoolStatus( } } -func poolAllUpdated(nodeCount int32, deployedDigest string) types.GomegaMatcher { +func fetchEvents( + ctx context.Context, + c client.Client, + kind, name string, + uid k8stypes.UID, +) func() ([]eventsv1.Event, error) { + return func() ([]eventsv1.Event, error) { + var eventList eventsv1.EventList + if err := c.List(ctx, &eventList); err != nil { + return nil, err + } + + return testutil.FilterEventsByObject(eventList.Items, kind, name, uid), nil + } +} + +func poolAllUpdated(nodeCount int32, deployedDigest string) gtypes.GomegaMatcher { return And( HaveField("NodeCount", BeEquivalentTo(nodeCount)), HaveField("UpdatedCount", BeEquivalentTo(nodeCount)), diff --git a/test/util/events.go b/test/util/events.go new file mode 100644 index 00000000..652e8ad2 --- /dev/null +++ b/test/util/events.go @@ -0,0 +1,35 @@ +// SPDX-License-Identifier: Apache-2.0 + +package testutil + +import ( + eventsv1 "k8s.io/api/events/v1" + "k8s.io/apimachinery/pkg/types" +) + +// ShortDigest abbreviates a "sha256:" digest the same way the controller +// does when rendering event notes ("sha256:" plus 12 hex characters). +func ShortDigest(digest string) string { + const shortLen = len("sha256:") + 12 + if len(digest) > shortLen { + return digest[:shortLen] + } + return digest +} + +// FilterEventsByObject returns events regarding the identified object. +func FilterEventsByObject( + items []eventsv1.Event, + kind, name string, + uid types.UID, +) []eventsv1.Event { + events := make([]eventsv1.Event, 0, len(items)) + for _, event := range items { + if event.Regarding.Kind == kind && + event.Regarding.Name == name && + event.Regarding.UID == uid { + events = append(events, event) + } + } + return events +}