From f889aeedcee83e1a043a29ee4021c4f8ec697513 Mon Sep 17 00:00:00 2001 From: Rawad Hossain Date: Wed, 8 Jul 2026 19:57:28 +0600 Subject: [PATCH] extend histogram buckets --- api/v1alpha1/nodereadinessrule_types.go | 10 + api/v1alpha1/zz_generated.deepcopy.go | 2 + ...ness.node.x-k8s.io_nodereadinessrules.yaml | 10 + docs/book/src/operations/monitoring.md | 19 + internal/controller/helper.go | 12 +- internal/controller/node_controller.go | 139 +++++ internal/controller/node_controller_test.go | 91 +++ .../nodereadinessrule_controller.go | 122 +++- .../nodereadinessrule_controller_test.go | 528 ++++++++++++++++++ internal/metrics/metrics.go | 14 +- 10 files changed, 921 insertions(+), 26 deletions(-) diff --git a/api/v1alpha1/nodereadinessrule_types.go b/api/v1alpha1/nodereadinessrule_types.go index 5bba7232..5dfcd044 100644 --- a/api/v1alpha1/nodereadinessrule_types.go +++ b/api/v1alpha1/nodereadinessrule_types.go @@ -275,6 +275,16 @@ type NodeEvaluation struct { // // +required LastEvaluationTime metav1.Time `json:"lastEvaluationTime,omitempty,omitzero"` + + // taintAppliedAt is the timestamp when the controller applied the readiness taint to this Node. + // + // +optional + TaintAppliedAt metav1.Time `json:"taintAppliedAt,omitempty,omitzero"` + + // taintObservedAt is the timestamp when the readiness taint was first observed on this Node. + // + // +optional + TaintObservedAt metav1.Time `json:"taintObservedAt,omitempty,omitzero"` } // ConditionEvaluationResult provides a detailed report of the comparison between diff --git a/api/v1alpha1/zz_generated.deepcopy.go b/api/v1alpha1/zz_generated.deepcopy.go index e8c4e61d..9f1266f0 100644 --- a/api/v1alpha1/zz_generated.deepcopy.go +++ b/api/v1alpha1/zz_generated.deepcopy.go @@ -98,6 +98,8 @@ func (in *NodeEvaluation) DeepCopyInto(out *NodeEvaluation) { copy(*out, *in) } in.LastEvaluationTime.DeepCopyInto(&out.LastEvaluationTime) + in.TaintAppliedAt.DeepCopyInto(&out.TaintAppliedAt) + in.TaintObservedAt.DeepCopyInto(&out.TaintObservedAt) } // DeepCopy is an autogenerated deepcopy function, copying the receiver, creating a new NodeEvaluation. diff --git a/config/crd/bases/readiness.node.x-k8s.io_nodereadinessrules.yaml b/config/crd/bases/readiness.node.x-k8s.io_nodereadinessrules.yaml index ec6c49ad..3b145b64 100644 --- a/config/crd/bases/readiness.node.x-k8s.io_nodereadinessrules.yaml +++ b/config/crd/bases/readiness.node.x-k8s.io_nodereadinessrules.yaml @@ -440,6 +440,16 @@ spec: minLength: 1 pattern: ^[a-z0-9]([-a-z0-9]*[a-z0-9])?(\.[a-z0-9]([-a-z0-9]*[a-z0-9])?)*$ type: string + taintAppliedAt: + description: taintAppliedAt is the timestamp when the controller + applied the readiness taint to this Node. + format: date-time + type: string + taintObservedAt: + description: taintObservedAt is the timestamp when the readiness + taint was first observed on this Node. + format: date-time + type: string taintStatus: description: taintStatus represents the taint status on the Node, one of Present, Absent. diff --git a/docs/book/src/operations/monitoring.md b/docs/book/src/operations/monitoring.md index 2d568402..fb9249c5 100644 --- a/docs/book/src/operations/monitoring.md +++ b/docs/book/src/operations/monitoring.md @@ -69,6 +69,25 @@ Total number of failure events recorded by the controller. | `rule` | `NodeReadinessRule` name | Any rule name | | `reason` | Failure label recorded by the controller | `EvaluationError`, `AddTaintError`, `RemoveTaintError` | +### `node_readiness_bootstrap_hold_duration_seconds` + +Time from readiness taint application or observation to bootstrap completion. + +| Property | Value | +| --- | --- | +| Type | `histogram` | +| Labels | `rule`, `taint_origin` | +| Buckets | `1, 5, 10, 30, 60, 120, 300, 600, 1200, 1800, 3600` | +| Recorded when | The controller marks bootstrap as completed for a node under a bootstrap-only rule. | + +#### Labels + +| Label | Description | Values | +| --- | --- | --- | +| `rule` | `NodeReadinessRule` name | Any rule name | +| `taint_origin` | Origin of the readiness taint's anchor timestamp | `controller`, `adopted` | + + ### `node_readiness_build_info` *Available starting from the v0.6.0 release.* diff --git a/internal/controller/helper.go b/internal/controller/helper.go index 959741a3..72569f7f 100644 --- a/internal/controller/helper.go +++ b/internal/controller/helper.go @@ -25,17 +25,21 @@ import ( readinessv1alpha1 "sigs.k8s.io/node-readiness-controller/api/v1alpha1" ) -//nolint:godot const ( // bootstrapAnnotationPrefix is the common prefix for all bootstrap completion // annotations on a Node. The suffix is the rule's metadata.uid (RFC 4122 UUID, // ~36 chars), which is immutable for the object's lifetime and globally unique. // // Full key format: readiness.k8s.io/bootstrap-completed- - // Value format: {"rule-name":""} (for human readability) + // Value format: {"rule-name":""} (for human readability). bootstrapAnnotationPrefix = "readiness.k8s.io/bootstrap-completed-" ) +// bootstrapAnnotationPayload is the JSON value stored in a bootstrap-completion annotation. +type bootstrapAnnotationPayload struct { + RuleName string `json:"rule-name"` +} + // bootstrapAnnotationKey returns the annotation key for a rule's bootstrap // completion state, using the rule's UID as the suffix. func bootstrapAnnotationKey(uid types.UID) string { @@ -45,9 +49,7 @@ func bootstrapAnnotationKey(uid types.UID) string { // bootstrapAnnotationValue returns the JSON-encoded value to store in the // bootstrap annotation. It includes the rule name for human readability. func bootstrapAnnotationValue(ruleName string) string { - v := struct { - RuleName string `json:"rule-name"` - }{RuleName: ruleName} + v := bootstrapAnnotationPayload{RuleName: ruleName} b, err := json.Marshal(v) if err != nil { return `{"rule-name":""}` // should never happen diff --git a/internal/controller/node_controller.go b/internal/controller/node_controller.go index 24d8e6ff..5c318b5b 100644 --- a/internal/controller/node_controller.go +++ b/internal/controller/node_controller.go @@ -20,6 +20,8 @@ import ( "context" "errors" "fmt" + "strings" + "time" corev1 "k8s.io/api/core/v1" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" @@ -147,6 +149,16 @@ func (r *RuleReadinessController) processNodeAgainstAllRules(ctx context.Context continue } + // Recover a missing TaintAppliedAt/TaintObservedAt anchor before evaluating the rule. + // Skip repeated recovery checks once attempts are exhausted. + if rule.Spec.EnforcementMode == readinessv1alpha1.EnforcementModeBootstrapOnly && + r.hasTaintBySpec(node, rule.Spec.Taint) && + r.taintAnchorMissing(rule, node.Name) && + r.shouldAttemptTaintAppliedAtRecovery(rule.Name, node.Name) { + recovered := r.recoverTaintAppliedAtFromAPI(ctx, rule, node.Name) + r.recordTaintAppliedAtRecoveryOutcome(rule.Name, node.Name, recovered) + } + log.Info("Evaluating rule for node", "node", node.Name, "rule", rule.Name, @@ -192,6 +204,12 @@ func (r *RuleReadinessController) processNodeAgainstAllRules(ctx context.Context found := false for i := range latestRule.Status.NodeEvaluations { if latestRule.Status.NodeEvaluations[i].NodeName == node.Name { + if currEval.TaintAppliedAt.IsZero() && !latestRule.Status.NodeEvaluations[i].TaintAppliedAt.IsZero() { + currEval.TaintAppliedAt = latestRule.Status.NodeEvaluations[i].TaintAppliedAt + } + if currEval.TaintObservedAt.IsZero() && !latestRule.Status.NodeEvaluations[i].TaintObservedAt.IsZero() { + currEval.TaintObservedAt = latestRule.Status.NodeEvaluations[i].TaintObservedAt + } latestRule.Status.NodeEvaluations[i] = currEval found = true break @@ -250,6 +268,127 @@ func (r *RuleReadinessController) processNodeAgainstAllRules(ctx context.Context return errors.Join(errs...) } +const maxTaintAnchorRecoveryAttempts = 2 + +// Reports whether the cached evaluation is missing TaintAppliedAt or TaintObservedAt. +func (r *RuleReadinessController) taintAnchorMissing(rule *readinessv1alpha1.NodeReadinessRule, nodeName string) bool { + r.ruleCacheMutex.Lock() + defer r.ruleCacheMutex.Unlock() + + prevEval := r.getPreviousNodeEvaluation(rule, nodeName) + return prevEval == nil || prevEval.TaintAppliedAt.IsZero() && prevEval.TaintObservedAt.IsZero() +} + +// Reports whether recovery should still be attempted. +func (r *RuleReadinessController) shouldAttemptTaintAppliedAtRecovery(ruleName, nodeName string) bool { + r.taintAnchorRecoveryMutex.Lock() + defer r.taintAnchorRecoveryMutex.Unlock() + + return r.taintAnchorRecoveryAttempts[ruleName+"/"+nodeName] < maxTaintAnchorRecoveryAttempts +} + +// Records the outcome of a recovery attempt. +func (r *RuleReadinessController) recordTaintAppliedAtRecoveryOutcome(ruleName, nodeName string, recovered bool) { + key := ruleName + "/" + nodeName + + r.taintAnchorRecoveryMutex.Lock() + defer r.taintAnchorRecoveryMutex.Unlock() + + if recovered { + delete(r.taintAnchorRecoveryAttempts, key) + return + } + if r.taintAnchorRecoveryAttempts == nil { + r.taintAnchorRecoveryAttempts = make(map[string]int) + } + r.taintAnchorRecoveryAttempts[key]++ +} + +// Clears recovery tracking for a deleted rule. +func (r *RuleReadinessController) clearTaintAppliedAtRecoveryForRule(ruleName string) { + prefix := ruleName + "/" + + r.taintAnchorRecoveryMutex.Lock() + defer r.taintAnchorRecoveryMutex.Unlock() + + for key := range r.taintAnchorRecoveryAttempts { + if strings.HasPrefix(key, prefix) { + delete(r.taintAnchorRecoveryAttempts, key) + } + } +} + +// Clears recovery tracking for a rule/node pair. +func (r *RuleReadinessController) clearTaintAppliedAtRecoveryForNode(ruleName, nodeName string) { + r.taintAnchorRecoveryMutex.Lock() + defer r.taintAnchorRecoveryMutex.Unlock() + + delete(r.taintAnchorRecoveryAttempts, ruleName+"/"+nodeName) +} + +// Recovers a missing TaintAppliedAt/TaintObservedAt from the API and updates the cached rule. +// Returns true if an existing anchor was found. +func (r *RuleReadinessController) recoverTaintAppliedAtFromAPI(ctx context.Context, rule *readinessv1alpha1.NodeReadinessRule, nodeName string) bool { + log := ctrl.LoggerFrom(ctx) + + const ( + attempts = 3 + delay = 500 * time.Millisecond + ) + + for i := range attempts { + if i > 0 { + select { + case <-ctx.Done(): + return false + case <-time.After(delay): + } + } + + latestRule := &readinessv1alpha1.NodeReadinessRule{} + if err := r.Get(ctx, client.ObjectKey{Name: rule.Name}, latestRule); err != nil { + log.V(4).Info("Failed to refresh rule for TaintAppliedAt recovery", + "rule", rule.Name, "node", nodeName, "error", err.Error()) + continue + } + + for _, eval := range latestRule.Status.NodeEvaluations { + if eval.NodeName != nodeName { + continue + } + if eval.TaintAppliedAt.IsZero() && eval.TaintObservedAt.IsZero() { + continue + } + + r.ruleCacheMutex.Lock() + nodeEval := r.getOrCreateNodeEvaluation(rule, nodeName) + if nodeEval.TaintAppliedAt.IsZero() && !eval.TaintAppliedAt.IsZero() { + nodeEval.TaintAppliedAt = eval.TaintAppliedAt + } + if nodeEval.TaintObservedAt.IsZero() && !eval.TaintObservedAt.IsZero() { + nodeEval.TaintObservedAt = eval.TaintObservedAt + } + + if cachedRule, ok := r.ruleCache[rule.Name]; ok { + cachedNodeEval := r.getOrCreateNodeEvaluation(cachedRule, nodeName) + if cachedNodeEval.TaintAppliedAt.IsZero() && !eval.TaintAppliedAt.IsZero() { + cachedNodeEval.TaintAppliedAt = eval.TaintAppliedAt + } + if cachedNodeEval.TaintObservedAt.IsZero() && !eval.TaintObservedAt.IsZero() { + cachedNodeEval.TaintObservedAt = eval.TaintObservedAt + } + } + r.ruleCacheMutex.Unlock() + + log.V(4).Info("Recovered taint anchor(s) from API into stale cache entry", + "rule", rule.Name, "node", nodeName, + "taintAppliedAt", eval.TaintAppliedAt, "taintObservedAt", eval.TaintObservedAt) + return true + } + } + return false +} + // getConditionStatus gets the status of a condition on a node. // If the condition is not present, defaultStatus is returned with found=false. func (r *RuleReadinessController) getConditionStatus( diff --git a/internal/controller/node_controller_test.go b/internal/controller/node_controller_test.go index 3eeba977..a4163e55 100644 --- a/internal/controller/node_controller_test.go +++ b/internal/controller/node_controller_test.go @@ -375,6 +375,97 @@ var _ = Describe("Node Controller", func() { return false }, time.Second*2).Should(BeFalse()) }) + + It("should not retry recovery for an adopted taint", func() { + // The node already has the taint, so the first reconcile takes the adopt path. + // TaintObservedAt is set while TaintAppliedAt stays zero. + _, err := nodeReconciler.Reconcile(ctx, reconcile.Request{NamespacedName: namespacedName}) + Expect(err).NotTo(HaveOccurred()) + + updatedRule := &nodereadinessiov1alpha1.NodeReadinessRule{} + Expect(k8sClient.Get(ctx, types.NamespacedName{Name: ruleName}, updatedRule)).To(Succeed()) + + var eval *nodereadinessiov1alpha1.NodeEvaluation + for i := range updatedRule.Status.NodeEvaluations { + if updatedRule.Status.NodeEvaluations[i].NodeName == nodeName { + eval = &updatedRule.Status.NodeEvaluations[i] + } + } + Expect(eval).NotTo(BeNil()) + Expect(eval.TaintAppliedAt.IsZero()).To(BeTrue(), "TaintAppliedAt must stay zero for an adopted taint") + Expect(eval.TaintObservedAt.IsZero()).To(BeFalse(), "TaintObservedAt must be stamped for an adopted taint") + Expect(readinessController.taintAnchorMissing(updatedRule, nodeName)).To(BeFalse()) + + // Refresh the cache and record the recovery attempts so far. + readinessController.ruleCache[ruleName] = updatedRule + readinessController.taintAnchorRecoveryMutex.Lock() + attemptsBefore := readinessController.taintAnchorRecoveryAttempts[ruleName+"/"+nodeName] + readinessController.taintAnchorRecoveryMutex.Unlock() + + _, err = nodeReconciler.Reconcile(ctx, reconcile.Request{NamespacedName: namespacedName}) + Expect(err).NotTo(HaveOccurred()) + + readinessController.taintAnchorRecoveryMutex.Lock() + attemptsAfter := readinessController.taintAnchorRecoveryAttempts[ruleName+"/"+nodeName] + readinessController.taintAnchorRecoveryMutex.Unlock() + Expect(attemptsAfter).To(Equal(attemptsBefore), + "no additional recovery attempt should have been made once TaintObservedAt is known") + }) + + It("should self-heal the rule cache after recovering the taint anchor", func() { + // Reconcile #1: adopt the existing taint and persist TaintObservedAt to the API. + _, err := nodeReconciler.Reconcile(ctx, reconcile.Request{NamespacedName: namespacedName}) + Expect(err).NotTo(HaveOccurred()) + + readCachedEval := func() *nodereadinessiov1alpha1.NodeEvaluation { + readinessController.ruleCacheMutex.RLock() + defer readinessController.ruleCacheMutex.RUnlock() + cachedRule, ok := readinessController.ruleCache[ruleName] + if !ok { + return nil + } + for i := range cachedRule.Status.NodeEvaluations { + if cachedRule.Status.NodeEvaluations[i].NodeName == nodeName { + return &cachedRule.Status.NodeEvaluations[i] + } + } + return nil + } + + Expect(readCachedEval()).To(BeNil(), + "the persistent cache should still be stale immediately after the adopt reconcile") + + // Reconcile #2: recover TaintObservedAt from the API and update the cache. + _, err = nodeReconciler.Reconcile(ctx, reconcile.Request{NamespacedName: namespacedName}) + Expect(err).NotTo(HaveOccurred()) + + cachedEval := readCachedEval() + Expect(cachedEval).NotTo(BeNil(), + "the persistent cache should now contain a NodeEvaluation for this node") + Expect(cachedEval.TaintObservedAt.IsZero()).To(BeFalse(), + "the recovered TaintObservedAt should have been written into r.ruleCache directly") + Expect(cachedEval.TaintAppliedAt.IsZero()).To(BeTrue()) + + readinessController.ruleCacheMutex.RLock() + cachedRule := readinessController.ruleCache[ruleName] + readinessController.ruleCacheMutex.RUnlock() + Expect(readinessController.taintAnchorMissing(cachedRule, nodeName)).To(BeFalse(), + "the self-healed cache entry must no longer report the anchor as missing") + + readinessController.taintAnchorRecoveryMutex.Lock() + attemptsBefore := readinessController.taintAnchorRecoveryAttempts[ruleName+"/"+nodeName] + readinessController.taintAnchorRecoveryMutex.Unlock() + + // Reconcile #3: the cache is already healed, so no further recovery is needed. + _, err = nodeReconciler.Reconcile(ctx, reconcile.Request{NamespacedName: namespacedName}) + Expect(err).NotTo(HaveOccurred()) + + readinessController.taintAnchorRecoveryMutex.Lock() + attemptsAfter := readinessController.taintAnchorRecoveryAttempts[ruleName+"/"+nodeName] + readinessController.taintAnchorRecoveryMutex.Unlock() + Expect(attemptsAfter).To(Equal(attemptsBefore), + "no further recovery attempt should be needed once the cache has self-healed") + }) }) When("in continuous mode", func() { diff --git a/internal/controller/nodereadinessrule_controller.go b/internal/controller/nodereadinessrule_controller.go index 278d8d7a..8786a690 100644 --- a/internal/controller/nodereadinessrule_controller.go +++ b/internal/controller/nodereadinessrule_controller.go @@ -59,6 +59,10 @@ type RuleReadinessController struct { // Cache for efficient rule lookup ruleCacheMutex sync.RWMutex ruleCache map[string]*readinessv1alpha1.NodeReadinessRule // ruleName -> rule + + // taintAnchorRecoveryMutex guards taintAnchorRecoveryAttempts. + taintAnchorRecoveryMutex sync.Mutex + taintAnchorRecoveryAttempts map[string]int } // RuleReconciler handles NodeReadinessRule reconciliation. @@ -215,6 +219,7 @@ func (r *RuleReconciler) reconcileDelete(ctx context.Context, rule *readinessv1a metrics.EvaluationDuration.DeleteLabelValues(rule.Name) // For multi-label metrics, use DeletePartialMatch to wipe all combinations + metrics.BootstrapHoldDuration.DeletePartialMatch(ruleLabel) metrics.NodesByState.DeletePartialMatch(ruleLabel) metrics.Failures.DeletePartialMatch(ruleLabel) metrics.ConditionEvaluationFailures.DeletePartialMatch(ruleLabel) @@ -233,7 +238,14 @@ func (r *RuleReadinessController) cleanupDeletedNodes(ctx context.Context, rule existingNodes[node.Name] = true } - // Filter out deleted nodes + // Clear recovery tracking for deleted nodes. + for _, evaluation := range rule.Status.NodeEvaluations { + if !existingNodes[evaluation.NodeName] { + r.clearTaintAppliedAtRecoveryForNode(rule.Name, evaluation.NodeName) + } + } + + // Filter out deleted nodes from both node evaluations and failed nodes. newNodeEvaluations, newFailedNodes := filterStatusForExistingNodes( existingNodes, rule.Status.NodeEvaluations, @@ -248,16 +260,25 @@ func (r *RuleReadinessController) cleanupDeletedNodes(ctx context.Context, rule log.V(4).Info("Cleaning up deleted nodes from rule status", "rule", rule.Name, - "before", len(rule.Status.NodeEvaluations), - "after", len(newNodeEvaluations)) + "beforeNodeEvaluations", len(rule.Status.NodeEvaluations), + "afterNodeEvaluations", len(newNodeEvaluations), + "beforeFailedNodes", len(rule.Status.FailedNodes), + "afterFailedNodes", len(newFailedNodes)) - // Use retry on conflict to update status to avoid race conditions from node updates + // Use retry on conflict to update status to avoid race conditions from node updates. return retry.RetryOnConflict(retry.DefaultRetry, func() error { fresh := &readinessv1alpha1.NodeReadinessRule{} if err := r.Get(ctx, client.ObjectKey{Name: rule.Name}, fresh); err != nil { return err } + // Clear recovery tracking for any newly deleted nodes seen during the retry. + for _, evaluation := range fresh.Status.NodeEvaluations { + if !existingNodes[evaluation.NodeName] { + r.clearTaintAppliedAtRecoveryForNode(rule.Name, evaluation.NodeName) + } + } + freshNodeEvaluations, freshFailedNodes := filterStatusForExistingNodes( existingNodes, fresh.Status.NodeEvaluations, @@ -409,7 +430,11 @@ func (r *RuleReadinessController) evaluateRuleForNode(ctx context.Context, rule case shouldRemoveTaint && currentlyHasTaint: log.Info("Removing taint", "node", node.Name, "rule", rule.Name, "taint", rule.Spec.Taint.Key) + // Bootstrap-only: capture completion state before it flips, so the hold-duration + // metric below can be gated on "first completion only" (mirrors BootstrapDuration's guard). + var wasAlreadyCompleted bool if rule.Spec.EnforcementMode == readinessv1alpha1.EnforcementModeBootstrapOnly { + wasAlreadyCompleted = r.isBootstrapCompleted(ctx, node.Name, rule.Name, rule.GetUID()) err = r.removeTaintAndCompleteBootstrap(ctx, node, rule) } else { err = r.removeTaintBySpec(ctx, node, rule.Spec.Taint, rule.Name) @@ -424,6 +449,37 @@ func (r *RuleReadinessController) evaluateRuleForNode(ctx context.Context, rule recordLatency(string(metrics.ReconciliationOperationRemoveTaint)) if rule.Spec.EnforcementMode == readinessv1alpha1.EnforcementModeBootstrapOnly { + // Observe NRC-attributable hold time only on the first bootstrap completion. + // Skip repeated completions. + // + // Match BootstrapDuration's guard conditions. + if !wasAlreadyCompleted && + !node.CreationTimestamp.Time.Before(rule.CreationTimestamp.Time) && !latestTransition.IsZero() { + if prevEval := r.getPreviousNodeEvaluation(rule, node.Name); prevEval != nil { + var anchor metav1.Time + var taintOriginLabel string + switch { + case !prevEval.TaintAppliedAt.IsZero(): + anchor = prevEval.TaintAppliedAt + taintOriginLabel = "controller" + case !prevEval.TaintObservedAt.IsZero(): + anchor = prevEval.TaintObservedAt + taintOriginLabel = "adopted" + } + + if !anchor.IsZero() { + duration := latestTransition.Time.Sub(anchor.Time).Seconds() + + if duration < 0 { + log.Info("Skipping bootstrap hold duration metric due to negative duration", + "node", node.Name, "rule", rule.Name, "duration", duration) + } else { + metrics.BootstrapHoldDuration.WithLabelValues(rule.Name, taintOriginLabel).Observe(duration) + } + } + } + } + // Only record the bootstrap duration if the node was created AFTER the rule. // This prevents legacy nodes from poisoning the histogram with massive outliers. if !node.CreationTimestamp.Time.Before(rule.CreationTimestamp.Time) && !latestTransition.IsZero() { @@ -450,6 +506,17 @@ func (r *RuleReadinessController) evaluateRuleForNode(ctx context.Context, rule } if added { + // Bootstrap-only: record TaintAppliedAt/TaintObservedAt for hold duration tracking. + // Preserve the initial timestamps across repeated evaluations. + if rule.Spec.EnforcementMode == readinessv1alpha1.EnforcementModeBootstrapOnly { + nodeEval := r.getOrCreateNodeEvaluation(rule, node.Name) + if nodeEval.TaintAppliedAt.IsZero() { + now := metav1.Now() + nodeEval.TaintAppliedAt = now + nodeEval.TaintObservedAt = now + } + } + // Record add taint latency and taint operation counter metrics.TaintOperations.WithLabelValues(rule.Name, string(metrics.TaintOperationAdd)).Inc() recordLatency(string(metrics.ReconciliationOperationAddTaint)) @@ -463,6 +530,16 @@ func (r *RuleReadinessController) evaluateRuleForNode(ctx context.Context, rule r.EventRecorder.Eventf(node, nil, corev1.EventTypeNormal, "TaintAdopted", "AdoptTaint", "%s", message) } + // Record TaintObservedAt for adopted taints in bootstrap-only mode. + // TaintAppliedAt stays unset since NRC did not apply the taint. + // This also handles taints added externally after the first evaluation. + if rule.Spec.EnforcementMode == readinessv1alpha1.EnforcementModeBootstrapOnly { + nodeEval := r.getOrCreateNodeEvaluation(rule, node.Name) + if nodeEval.TaintObservedAt.IsZero() { + nodeEval.TaintObservedAt = metav1.Now() + } + } + default: log.Info("No taint action needed", "node", node.Name, "rule", rule.Name, "shouldRemove", shouldRemoveTaint, "hasTaint", currentlyHasTaint) @@ -486,30 +563,33 @@ func (r *RuleReadinessController) evaluateRuleForNode(ctx context.Context, rule return nil } -// updateNodeEvaluationStatus updates the evaluation status for a specific node. -func (r *RuleReadinessController) updateNodeEvaluationStatus( +// getOrCreateNodeEvaluation returns the existing NodeEvaluation for nodeName, +// creating and appending a new one if none exists yet. +func (r *RuleReadinessController) getOrCreateNodeEvaluation( rule *readinessv1alpha1.NodeReadinessRule, nodeName string, - conditionResults []readinessv1alpha1.ConditionEvaluationResult, - taintStatus readinessv1alpha1.TaintStatus, -) { - // Find existing evaluation or create new - var nodeEval *readinessv1alpha1.NodeEvaluation +) *readinessv1alpha1.NodeEvaluation { for i := range rule.Status.NodeEvaluations { if rule.Status.NodeEvaluations[i].NodeName == nodeName { - nodeEval = &rule.Status.NodeEvaluations[i] - break + return &rule.Status.NodeEvaluations[i] } } - if nodeEval == nil { - rule.Status.NodeEvaluations = append(rule.Status.NodeEvaluations, readinessv1alpha1.NodeEvaluation{ - NodeName: nodeName, - }) - nodeEval = &rule.Status.NodeEvaluations[len(rule.Status.NodeEvaluations)-1] - } + rule.Status.NodeEvaluations = append(rule.Status.NodeEvaluations, readinessv1alpha1.NodeEvaluation{ + NodeName: nodeName, + }) + return &rule.Status.NodeEvaluations[len(rule.Status.NodeEvaluations)-1] +} + +// updateNodeEvaluationStatus updates the evaluation status for a specific node. +func (r *RuleReadinessController) updateNodeEvaluationStatus( + rule *readinessv1alpha1.NodeReadinessRule, + nodeName string, + conditionResults []readinessv1alpha1.ConditionEvaluationResult, + taintStatus readinessv1alpha1.TaintStatus, +) { + nodeEval := r.getOrCreateNodeEvaluation(rule, nodeName) - // Update evaluation nodeEval.ConditionResults = conditionResults nodeEval.TaintStatus = taintStatus nodeEval.LastEvaluationTime = metav1.Now() @@ -614,6 +694,8 @@ func (r *RuleReadinessController) removeRuleFromCache(ctx context.Context, ruleN delete(r.ruleCache, ruleName) metrics.RulesTotal.Set(float64(len(r.ruleCache))) log.Info("Removed rule from cache", "rule", ruleName, "totalRules", len(r.ruleCache)) + + r.clearTaintAppliedAtRecoveryForRule(ruleName) } // updateRuleStatus updates the status of a NodeReadinessRule. diff --git a/internal/controller/nodereadinessrule_controller_test.go b/internal/controller/nodereadinessrule_controller_test.go index 07fb4b30..754f7d63 100644 --- a/internal/controller/nodereadinessrule_controller_test.go +++ b/internal/controller/nodereadinessrule_controller_test.go @@ -55,6 +55,12 @@ func histogramSampleCount(histogram interface{ Write(*dto.Metric) error }) uint6 return metric.GetHistogram().GetSampleCount() } +func histogramSampleSum(histogram interface{ Write(*dto.Metric) error }) float64 { + metric := &dto.Metric{} + Expect(histogram.Write(metric)).To(Succeed()) + return metric.GetHistogram().GetSampleSum() +} + // errorInjectingClient forces Patch to fail for selected nodes. type errorInjectingClient struct { client.Client @@ -2535,4 +2541,526 @@ var _ = Describe("NodeReadinessRule Controller", func() { Expect(readinessController.hasTaintBySpec(anyOfNode, rule.Spec.Taint)).To(BeFalse()) }) }) + + Context("Metric: bootstrap_hold_duration_seconds", func() { + const ( + nrcTaintKey = "readiness.k8s.io/nrc-duration-taint" + ) + + newBootstrapOnlyRule := func(name, labelKey string) *nodereadinessiov1alpha1.NodeReadinessRule { + return &nodereadinessiov1alpha1.NodeReadinessRule{ + ObjectMeta: metav1.ObjectMeta{ + Name: name, + Finalizers: []string{finalizerName}, + }, + Spec: nodereadinessiov1alpha1.NodeReadinessRuleSpec{ + Conditions: []nodereadinessiov1alpha1.ConditionRequirement{{Type: "Ready", RequiredStatus: corev1.ConditionTrue}}, + Taint: corev1.Taint{Key: nrcTaintKey, Effect: corev1.TaintEffectNoSchedule}, + NodeSelector: metav1.LabelSelector{MatchLabels: map[string]string{labelKey: "true"}}, + EnforcementMode: nodereadinessiov1alpha1.EnforcementModeBootstrapOnly, + }, + } + } + + // taintAppliedAtIsZero reports whether TaintAppliedAt is unset for nodeName. + taintAppliedAtIsZero := func(rule *nodereadinessiov1alpha1.NodeReadinessRule, nodeName string) bool { + for i := range rule.Status.NodeEvaluations { + if rule.Status.NodeEvaluations[i].NodeName == nodeName { + return rule.Status.NodeEvaluations[i].TaintAppliedAt.IsZero() + } + } + return true + } + + // taintObservedAtIsZero reports whether TaintObservedAt is unset for nodeName. + taintObservedAtIsZero := func(rule *nodereadinessiov1alpha1.NodeReadinessRule, nodeName string) bool { + for i := range rule.Status.NodeEvaluations { + if rule.Status.NodeEvaluations[i].NodeName == nodeName { + return rule.Status.NodeEvaluations[i].TaintObservedAt.IsZero() + } + } + return true + } + + It("should stamp TaintAppliedAt in status when NRC adds a taint", func() { + ruleName := "nrc-dur-stamp-rule" + nodeName := "nrc-dur-stamp-node" + labelKey := "nrc-dur-stamp" + + rule := newBootstrapOnlyRule(ruleName, labelKey) + Expect(k8sClient.Create(ctx, rule)).To(Succeed()) + defer func() { _ = k8sClient.Delete(ctx, rule) }() + + // Node without taint, condition NOT satisfied + node := &corev1.Node{ + ObjectMeta: metav1.ObjectMeta{ + Name: nodeName, + Labels: map[string]string{labelKey: "true"}, + }, + Status: corev1.NodeStatus{ + Conditions: []corev1.NodeCondition{ + {Type: "Ready", Status: corev1.ConditionFalse}, + }, + }, + } + Expect(k8sClient.Create(ctx, node)).To(Succeed()) + defer func() { _ = k8sClient.Delete(ctx, node) }() + + Expect(k8sClient.Get(ctx, types.NamespacedName{Name: ruleName}, rule)).To(Succeed()) + Expect(readinessController.evaluateRuleForNode(ctx, rule, node)).To(Succeed()) + + Expect(taintAppliedAtIsZero(rule, nodeName)).To(BeFalse()) + }) + + It("should emit a histogram observation when bootstrap completes with a TaintAppliedAt anchor", func() { + ruleName := "nrc-dur-observe-rule" + nodeName := "nrc-dur-observe-node" + labelKey := "nrc-dur-observe" + + rule := newBootstrapOnlyRule(ruleName, labelKey) + Expect(k8sClient.Create(ctx, rule)).To(Succeed()) + defer func() { _ = k8sClient.Delete(ctx, rule) }() + + // Node without taint, condition NOT satisfied + node := &corev1.Node{ + ObjectMeta: metav1.ObjectMeta{ + Name: nodeName, + Labels: map[string]string{labelKey: "true"}, + }, + Status: corev1.NodeStatus{ + Conditions: []corev1.NodeCondition{ + {Type: "Ready", Status: corev1.ConditionFalse}, + }, + }, + } + Expect(k8sClient.Create(ctx, node)).To(Succeed()) + defer func() { _ = k8sClient.Delete(ctx, node) }() + + Expect(k8sClient.Get(ctx, types.NamespacedName{Name: ruleName}, rule)).To(Succeed()) + Expect(readinessController.evaluateRuleForNode(ctx, rule, node)).To(Succeed()) + + Expect(taintAppliedAtIsZero(rule, nodeName)).To(BeFalse()) + + Expect(k8sClient.Get(ctx, types.NamespacedName{Name: nodeName}, node)).To(Succeed()) + node.Status.Conditions = []corev1.NodeCondition{ + {Type: "Ready", Status: corev1.ConditionTrue, LastTransitionTime: metav1.NewTime(time.Now().Add(2 * time.Second))}, + } + Expect(k8sClient.Status().Update(ctx, node)).To(Succeed()) + Expect(k8sClient.Get(ctx, types.NamespacedName{Name: nodeName}, node)).To(Succeed()) + + histogram := metrics.BootstrapHoldDuration.WithLabelValues(ruleName, "controller").(prometheus.Histogram) + before := histogramSampleCount(histogram) + + Expect(readinessController.evaluateRuleForNode(ctx, rule, node)).To(Succeed()) + + Expect(histogramSampleCount(histogram)).To(Equal(before + 1)) + }) + + It("should not re-observe the histogram when the taint is manually re-added after bootstrap already completed", func() { + ruleName := "nrc-dur-readd-rule" + nodeName := "nrc-dur-readd-node" + labelKey := "nrc-dur-readd" + + rule := newBootstrapOnlyRule(ruleName, labelKey) + Expect(k8sClient.Create(ctx, rule)).To(Succeed()) + defer func() { _ = k8sClient.Delete(ctx, rule) }() + + // Node without taint, condition NOT satisfied + node := &corev1.Node{ + ObjectMeta: metav1.ObjectMeta{ + Name: nodeName, + Labels: map[string]string{labelKey: "true"}, + }, + Status: corev1.NodeStatus{ + Conditions: []corev1.NodeCondition{ + {Type: "Ready", Status: corev1.ConditionFalse}, + }, + }, + } + Expect(k8sClient.Create(ctx, node)).To(Succeed()) + defer func() { _ = k8sClient.Delete(ctx, node) }() + + Expect(k8sClient.Get(ctx, types.NamespacedName{Name: ruleName}, rule)).To(Succeed()) + Expect(readinessController.evaluateRuleForNode(ctx, rule, node)).To(Succeed()) + + Expect(k8sClient.Get(ctx, types.NamespacedName{Name: nodeName}, node)).To(Succeed()) + node.Status.Conditions = []corev1.NodeCondition{ + {Type: "Ready", Status: corev1.ConditionTrue, LastTransitionTime: metav1.NewTime(time.Now().Add(2 * time.Second))}, + } + Expect(k8sClient.Status().Update(ctx, node)).To(Succeed()) + Expect(k8sClient.Get(ctx, types.NamespacedName{Name: nodeName}, node)).To(Succeed()) + + histogram := metrics.BootstrapHoldDuration.WithLabelValues(ruleName, "controller").(prometheus.Histogram) + before := histogramSampleCount(histogram) + + Expect(readinessController.evaluateRuleForNode(ctx, rule, node)).To(Succeed()) + Expect(histogramSampleCount(histogram)).To(Equal(before + 1)) + + afterFirstCompletion := histogramSampleCount(histogram) + + Expect(k8sClient.Get(ctx, types.NamespacedName{Name: nodeName}, node)).To(Succeed()) + node.Spec.Taints = append(node.Spec.Taints, corev1.Taint{Key: nrcTaintKey, Effect: corev1.TaintEffectNoSchedule}) + Expect(k8sClient.Update(ctx, node)).To(Succeed()) + Expect(k8sClient.Get(ctx, types.NamespacedName{Name: nodeName}, node)).To(Succeed()) + + Expect(readinessController.evaluateRuleForNode(ctx, rule, node)).To(Succeed()) + + Expect(histogramSampleCount(histogram)).To(Equal(afterFirstCompletion)) + }) + + It("should stamp TaintObservedAt when adopting a pre-existing taint", func() { + ruleName := "nrc-dur-adopt-rule" + nodeName := "nrc-dur-adopt-node" + labelKey := "nrc-dur-adopt" + + rule := newBootstrapOnlyRule(ruleName, labelKey) + Expect(k8sClient.Create(ctx, rule)).To(Succeed()) + defer func() { _ = k8sClient.Delete(ctx, rule) }() + + // Node already has the taint, condition NOT satisfied + node := &corev1.Node{ + ObjectMeta: metav1.ObjectMeta{ + Name: nodeName, + Labels: map[string]string{labelKey: "true"}, + }, + Spec: corev1.NodeSpec{ + Taints: []corev1.Taint{ + {Key: nrcTaintKey, Effect: corev1.TaintEffectNoSchedule}, + }, + }, + Status: corev1.NodeStatus{ + Conditions: []corev1.NodeCondition{ + {Type: "Ready", Status: corev1.ConditionFalse}, + }, + }, + } + Expect(k8sClient.Create(ctx, node)).To(Succeed()) + defer func() { _ = k8sClient.Delete(ctx, node) }() + + Expect(k8sClient.Get(ctx, types.NamespacedName{Name: ruleName}, rule)).To(Succeed()) + Expect(readinessController.evaluateRuleForNode(ctx, rule, node)).To(Succeed()) + + Expect(taintAppliedAtIsZero(rule, nodeName)).To(BeTrue()) + Expect(taintObservedAtIsZero(rule, nodeName)).To(BeFalse()) + Expect(k8sClient.Get(ctx, types.NamespacedName{Name: nodeName}, node)).To(Succeed()) + node.Status.Conditions = []corev1.NodeCondition{ + {Type: "Ready", Status: corev1.ConditionTrue, LastTransitionTime: metav1.NewTime(time.Now().Add(2 * time.Second))}, + } + Expect(k8sClient.Status().Update(ctx, node)).To(Succeed()) + Expect(k8sClient.Get(ctx, types.NamespacedName{Name: nodeName}, node)).To(Succeed()) + + appliedHistogram := metrics.BootstrapHoldDuration.WithLabelValues(ruleName, "controller").(prometheus.Histogram) + appliedBefore := histogramSampleCount(appliedHistogram) + adoptedHistogram := metrics.BootstrapHoldDuration.WithLabelValues(ruleName, "adopted").(prometheus.Histogram) + adoptedBefore := histogramSampleCount(adoptedHistogram) + + Expect(readinessController.evaluateRuleForNode(ctx, rule, node)).To(Succeed()) + + Expect(taintAppliedAtIsZero(rule, nodeName)).To(BeTrue()) + Expect(histogramSampleCount(appliedHistogram)).To(Equal(appliedBefore)) + Expect(histogramSampleCount(adoptedHistogram)).To(Equal(adoptedBefore + 1)) + }) + + It("should stamp TaintObservedAt when a taint appears after the first evaluation", func() { + ruleName := "nrc-dur-adopt-later-rule" + nodeName := "nrc-dur-adopt-later-node" + labelKey := "nrc-dur-adopt-later" + + rule := newBootstrapOnlyRule(ruleName, labelKey) + Expect(k8sClient.Create(ctx, rule)).To(Succeed()) + defer func() { _ = k8sClient.Delete(ctx, rule) }() + + node := &corev1.Node{ + ObjectMeta: metav1.ObjectMeta{ + Name: nodeName, + Labels: map[string]string{labelKey: "true"}, + }, + Status: corev1.NodeStatus{ + Conditions: []corev1.NodeCondition{ + {Type: "Ready", Status: corev1.ConditionFalse}, + }, + }, + } + Expect(k8sClient.Create(ctx, node)).To(Succeed()) + defer func() { _ = k8sClient.Delete(ctx, node) }() + + // The taint is added externally after the first evaluation. + Expect(k8sClient.Get(ctx, types.NamespacedName{Name: ruleName}, rule)).To(Succeed()) + rule.Status.NodeEvaluations = []nodereadinessiov1alpha1.NodeEvaluation{ + { + NodeName: nodeName, + ConditionResults: []nodereadinessiov1alpha1.ConditionEvaluationResult{ + { + Type: "Ready", + CurrentStatus: corev1.ConditionFalse, + RequiredStatus: corev1.ConditionTrue, + DefaultStatus: corev1.ConditionUnknown, + }, + }, + TaintStatus: nodereadinessiov1alpha1.TaintStatusAbsent, + LastEvaluationTime: metav1.Now(), + }, + } + Expect(k8sClient.Status().Update(ctx, rule)).To(Succeed()) + Expect(k8sClient.Get(ctx, types.NamespacedName{Name: ruleName}, rule)).To(Succeed()) + Expect(readinessController.getPreviousNodeEvaluation(rule, nodeName)).NotTo(BeNil(), + "precondition: isFirstEvaluation must be false for the reconcile below") + + Expect(k8sClient.Get(ctx, types.NamespacedName{Name: nodeName}, node)).To(Succeed()) + node.Spec.Taints = append(node.Spec.Taints, corev1.Taint{Key: nrcTaintKey, Effect: corev1.TaintEffectNoSchedule}) + Expect(k8sClient.Update(ctx, node)).To(Succeed()) + Expect(k8sClient.Get(ctx, types.NamespacedName{Name: nodeName}, node)).To(Succeed()) + + Expect(readinessController.evaluateRuleForNode(ctx, rule, node)).To(Succeed()) + + Expect(taintAppliedAtIsZero(rule, nodeName)).To(BeTrue()) + Expect(taintObservedAtIsZero(rule, nodeName)).To(BeFalse()) + + Expect(k8sClient.Get(ctx, types.NamespacedName{Name: nodeName}, node)).To(Succeed()) + node.Status.Conditions = []corev1.NodeCondition{ + {Type: "Ready", Status: corev1.ConditionTrue, LastTransitionTime: metav1.NewTime(time.Now().Add(2 * time.Second))}, + } + Expect(k8sClient.Status().Update(ctx, node)).To(Succeed()) + Expect(k8sClient.Get(ctx, types.NamespacedName{Name: nodeName}, node)).To(Succeed()) + + appliedHistogram := metrics.BootstrapHoldDuration.WithLabelValues(ruleName, "controller").(prometheus.Histogram) + appliedBefore := histogramSampleCount(appliedHistogram) + adoptedHistogram := metrics.BootstrapHoldDuration.WithLabelValues(ruleName, "adopted").(prometheus.Histogram) + adoptedBefore := histogramSampleCount(adoptedHistogram) + + Expect(readinessController.evaluateRuleForNode(ctx, rule, node)).To(Succeed()) + + Expect(taintAppliedAtIsZero(rule, nodeName)).To(BeTrue()) + Expect(histogramSampleCount(appliedHistogram)).To(Equal(appliedBefore)) + Expect(histogramSampleCount(adoptedHistogram)).To(Equal(adoptedBefore + 1)) + }) + + It("should not re-observe an adopted taint after bootstrap completes", func() { + ruleName := "nrc-dur-adopt-readd-rule" + nodeName := "nrc-dur-adopt-readd-node" + labelKey := "nrc-dur-adopt-readd" + + rule := newBootstrapOnlyRule(ruleName, labelKey) + Expect(k8sClient.Create(ctx, rule)).To(Succeed()) + defer func() { _ = k8sClient.Delete(ctx, rule) }() + + node := &corev1.Node{ + ObjectMeta: metav1.ObjectMeta{ + Name: nodeName, + Labels: map[string]string{labelKey: "true"}, + }, + Spec: corev1.NodeSpec{ + Taints: []corev1.Taint{ + {Key: nrcTaintKey, Effect: corev1.TaintEffectNoSchedule}, + }, + }, + Status: corev1.NodeStatus{ + Conditions: []corev1.NodeCondition{ + {Type: "Ready", Status: corev1.ConditionFalse}, + }, + }, + } + Expect(k8sClient.Create(ctx, node)).To(Succeed()) + defer func() { _ = k8sClient.Delete(ctx, node) }() + + Expect(k8sClient.Get(ctx, types.NamespacedName{Name: ruleName}, rule)).To(Succeed()) + Expect(readinessController.evaluateRuleForNode(ctx, rule, node)).To(Succeed()) + + Expect(k8sClient.Get(ctx, types.NamespacedName{Name: nodeName}, node)).To(Succeed()) + node.Status.Conditions = []corev1.NodeCondition{ + {Type: "Ready", Status: corev1.ConditionTrue, LastTransitionTime: metav1.NewTime(time.Now().Add(2 * time.Second))}, + } + Expect(k8sClient.Status().Update(ctx, node)).To(Succeed()) + Expect(k8sClient.Get(ctx, types.NamespacedName{Name: nodeName}, node)).To(Succeed()) + + histogram := metrics.BootstrapHoldDuration.WithLabelValues(ruleName, "adopted").(prometheus.Histogram) + before := histogramSampleCount(histogram) + + Expect(readinessController.evaluateRuleForNode(ctx, rule, node)).To(Succeed()) + Expect(histogramSampleCount(histogram)).To(Equal(before + 1)) + + afterFirstCompletion := histogramSampleCount(histogram) + + Expect(k8sClient.Get(ctx, types.NamespacedName{Name: nodeName}, node)).To(Succeed()) + node.Spec.Taints = append(node.Spec.Taints, corev1.Taint{Key: nrcTaintKey, Effect: corev1.TaintEffectNoSchedule}) + Expect(k8sClient.Update(ctx, node)).To(Succeed()) + Expect(k8sClient.Get(ctx, types.NamespacedName{Name: nodeName}, node)).To(Succeed()) + + Expect(readinessController.evaluateRuleForNode(ctx, rule, node)).To(Succeed()) + + Expect(histogramSampleCount(histogram)).To(Equal(afterFirstCompletion)) + }) + + It("should NOT stamp TaintAppliedAt for a Continuous mode rule", func() { + ruleName := "nrc-dur-continuous-rule" + nodeName := "nrc-dur-continuous-node" + labelKey := "nrc-dur-continuous" + + rule := &nodereadinessiov1alpha1.NodeReadinessRule{ + ObjectMeta: metav1.ObjectMeta{ + Name: ruleName, + Finalizers: []string{finalizerName}, + }, + Spec: nodereadinessiov1alpha1.NodeReadinessRuleSpec{ + Conditions: []nodereadinessiov1alpha1.ConditionRequirement{{Type: "Ready", RequiredStatus: corev1.ConditionTrue}}, + Taint: corev1.Taint{Key: nrcTaintKey, Effect: corev1.TaintEffectNoSchedule}, + NodeSelector: metav1.LabelSelector{MatchLabels: map[string]string{labelKey: "true"}}, + EnforcementMode: nodereadinessiov1alpha1.EnforcementModeContinuous, + }, + } + Expect(k8sClient.Create(ctx, rule)).To(Succeed()) + defer func() { _ = k8sClient.Delete(ctx, rule) }() + + // Node without taint, condition NOT satisfied. + node := &corev1.Node{ + ObjectMeta: metav1.ObjectMeta{ + Name: nodeName, + Labels: map[string]string{labelKey: "true"}, + }, + Status: corev1.NodeStatus{ + Conditions: []corev1.NodeCondition{ + {Type: "Ready", Status: corev1.ConditionFalse}, + }, + }, + } + Expect(k8sClient.Create(ctx, node)).To(Succeed()) + defer func() { _ = k8sClient.Delete(ctx, node) }() + + Expect(k8sClient.Get(ctx, types.NamespacedName{Name: ruleName}, rule)).To(Succeed()) + Expect(readinessController.evaluateRuleForNode(ctx, rule, node)).To(Succeed()) + + Expect(taintAppliedAtIsZero(rule, nodeName)).To(BeTrue()) + }) + + It("should use LastTransitionTime to calculate BootstrapHoldDuration", func() { + ruleName := "nrc-dur-clock-anchor-rule" + nodeName := "nrc-dur-clock-anchor-node" + labelKey := "nrc-dur-clock-anchor" + + rule := newBootstrapOnlyRule(ruleName, labelKey) + Expect(k8sClient.Create(ctx, rule)).To(Succeed()) + defer func() { _ = k8sClient.Delete(ctx, rule) }() + + // Node without taint, condition NOT satisfied. + node := &corev1.Node{ + ObjectMeta: metav1.ObjectMeta{ + Name: nodeName, + Labels: map[string]string{labelKey: "true"}, + }, + Status: corev1.NodeStatus{ + Conditions: []corev1.NodeCondition{ + {Type: "Ready", Status: corev1.ConditionFalse}, + }, + }, + } + Expect(k8sClient.Create(ctx, node)).To(Succeed()) + defer func() { _ = k8sClient.Delete(ctx, node) }() + + Expect(k8sClient.Get(ctx, types.NamespacedName{Name: ruleName}, rule)).To(Succeed()) + Expect(readinessController.evaluateRuleForNode(ctx, rule, node)).To(Succeed()) + Expect(taintAppliedAtIsZero(rule, nodeName)).To(BeFalse()) + + // Backdate TaintAppliedAt to verify the duration uses LastTransitionTime + backdated := metav1.NewTime(time.Now().Add(-1 * time.Hour)) + for i := range rule.Status.NodeEvaluations { + if rule.Status.NodeEvaluations[i].NodeName == nodeName { + rule.Status.NodeEvaluations[i].TaintAppliedAt = backdated + } + } + + transitionTime := metav1.NewTime(backdated.Add(2 * time.Second)) + Expect(k8sClient.Get(ctx, types.NamespacedName{Name: nodeName}, node)).To(Succeed()) + node.Status.Conditions = []corev1.NodeCondition{ + {Type: "Ready", Status: corev1.ConditionTrue, LastTransitionTime: transitionTime}, + } + Expect(k8sClient.Status().Update(ctx, node)).To(Succeed()) + Expect(k8sClient.Get(ctx, types.NamespacedName{Name: nodeName}, node)).To(Succeed()) + + histogram := metrics.BootstrapHoldDuration.WithLabelValues(ruleName, "controller").(prometheus.Histogram) + sumBefore := histogramSampleSum(histogram) + countBefore := histogramSampleCount(histogram) + + Expect(readinessController.evaluateRuleForNode(ctx, rule, node)).To(Succeed()) + + Expect(histogramSampleCount(histogram)).To(Equal(countBefore + 1)) + observed := histogramSampleSum(histogram) - sumBefore + + Expect(observed).To(BeNumerically(">=", 0)) + Expect(observed).To(BeNumerically("<", 10)) + }) + + It("should skip BootstrapHoldDuration when LastTransitionTime is unset", func() { + ruleName := "nrc-dur-zero-transition-rule" + nodeName := "nrc-dur-zero-transition-node" + labelKey := "nrc-dur-zero-transition" + + rule := newBootstrapOnlyRule(ruleName, labelKey) + Expect(k8sClient.Create(ctx, rule)).To(Succeed()) + defer func() { _ = k8sClient.Delete(ctx, rule) }() + + node := &corev1.Node{ + ObjectMeta: metav1.ObjectMeta{ + Name: nodeName, + Labels: map[string]string{labelKey: "true"}, + }, + Status: corev1.NodeStatus{ + Conditions: []corev1.NodeCondition{ + {Type: "Ready", Status: corev1.ConditionFalse}, + }, + }, + } + Expect(k8sClient.Create(ctx, node)).To(Succeed()) + defer func() { _ = k8sClient.Delete(ctx, node) }() + + Expect(k8sClient.Get(ctx, types.NamespacedName{Name: ruleName}, rule)).To(Succeed()) + Expect(readinessController.evaluateRuleForNode(ctx, rule, node)).To(Succeed()) + Expect(taintAppliedAtIsZero(rule, nodeName)).To(BeFalse()) + + Expect(k8sClient.Get(ctx, types.NamespacedName{Name: nodeName}, node)).To(Succeed()) + node.Status.Conditions = []corev1.NodeCondition{ + {Type: "Ready", Status: corev1.ConditionTrue}, + } + Expect(k8sClient.Status().Update(ctx, node)).To(Succeed()) + Expect(k8sClient.Get(ctx, types.NamespacedName{Name: nodeName}, node)).To(Succeed()) + + histogram := metrics.BootstrapHoldDuration.WithLabelValues(ruleName, "controller").(prometheus.Histogram) + before := histogramSampleCount(histogram) + + Expect(readinessController.evaluateRuleForNode(ctx, rule, node)).To(Succeed()) + + Expect(histogramSampleCount(histogram)).To(Equal(before)) + }) + + It("should clean up BootstrapHoldDuration label values on rule deletion", func() { + ruleName := "nrc-dur-del-rule" + labelKey := "nrc-dur-del" + + rule := newBootstrapOnlyRule(ruleName, labelKey) + Expect(k8sClient.Create(ctx, rule)).To(Succeed()) + + metrics.BootstrapHoldDuration.WithLabelValues(ruleName, "controller").Observe(1.0) + + histogram := metrics.BootstrapHoldDuration.WithLabelValues(ruleName, "controller").(prometheus.Histogram) + Expect(histogramSampleCount(histogram)).To(BeNumerically(">", 0)) + + // Trigger reconcile to populate cache, then delete the rule. + _, err := ruleReconciler.Reconcile(ctx, reconcile.Request{NamespacedName: types.NamespacedName{Name: ruleName}}) + Expect(err).NotTo(HaveOccurred()) + + Expect(k8sClient.Delete(ctx, rule)).To(Succeed()) + + Eventually(func() bool { + _, err := ruleReconciler.Reconcile(ctx, reconcile.Request{NamespacedName: types.NamespacedName{Name: ruleName}}) + Expect(err).NotTo(HaveOccurred()) + readinessController.ruleCacheMutex.RLock() + _, exists := readinessController.ruleCache[ruleName] + readinessController.ruleCacheMutex.RUnlock() + return !exists + }).Should(BeTrue()) + + // After DeleteLabelValues, GetMetricWith returns a fresh zero value series. + freshHistogram := metrics.BootstrapHoldDuration.WithLabelValues(ruleName, "controller").(prometheus.Histogram) + Expect(histogramSampleCount(freshHistogram)).To(Equal(uint64(0))) + }) + }) }) diff --git a/internal/metrics/metrics.go b/internal/metrics/metrics.go index db418e48..0c96bd7e 100644 --- a/internal/metrics/metrics.go +++ b/internal/metrics/metrics.go @@ -117,11 +117,22 @@ var ( prometheus.HistogramOpts{ Name: "node_readiness_bootstrap_duration_seconds", Help: "Time from node creation to bootstrap completion (taint removal) for bootstrap-only rules", - Buckets: []float64{1, 5, 10, 30, 60, 120, 300, 600, 1200}, // 1s to 20min + Buckets: []float64{1, 5, 10, 30, 60, 120, 300, 600, 1200, 1800, 3600}, // 1s to 60min }, []string{"rule"}, ) + // BootstrapHoldDuration tracks the time from the readiness taint's anchor timestamp to bootstrap completion. + // Measures NRC hold time only; skipped when no anchor is available. + BootstrapHoldDuration = prometheus.NewHistogramVec( + prometheus.HistogramOpts{ + Name: "node_readiness_bootstrap_hold_duration_seconds", + Help: "Time from readiness taint application or observation to bootstrap completion. Measures only NRC-attributable hold time.", + Buckets: []float64{1, 5, 10, 30, 60, 120, 300, 600, 1200, 1800, 3600}, + }, + []string{"rule", "taint_origin"}, // taint_origin: controller, adopted + ) + // ReconciliationLatency tracks end-to-end latency from condition change to taint operation. // This measures how quickly the controller responds to node condition changes. ReconciliationLatency = prometheus.NewHistogramVec( @@ -184,6 +195,7 @@ func init() { metrics.Registry.MustRegister(Failures) metrics.Registry.MustRegister(BootstrapCompleted) metrics.Registry.MustRegister(BootstrapDuration) + metrics.Registry.MustRegister(BootstrapHoldDuration) metrics.Registry.MustRegister(ReconciliationLatency) metrics.Registry.MustRegister(NodesByState) metrics.Registry.MustRegister(ConditionEvaluationFailures)