From d959fadfa13de5427bdcf1bc071003d79d8e702a Mon Sep 17 00:00:00 2001 From: Rawad Hossain Date: Mon, 24 Aug 2026 16:09:56 +0600 Subject: [PATCH] enforcement latency metric Signed-off-by: Rawad Hossain --- docs/TEST_README.md | 3 + docs/book/src/operations/monitoring.md | 38 +++++++++++ .../nodereadinessrule_controller.go | 13 ++-- internal/metrics/metrics.go | 22 +++++++ internal/metrics/metrics_test.go | 66 +++++++++++++++++++ test/scale/promqueries.go | 15 +++++ .../scale/testdata/scalability_report.md.tmpl | 1 + 7 files changed, 154 insertions(+), 4 deletions(-) diff --git a/docs/TEST_README.md b/docs/TEST_README.md index 6eedcf4a..0d1a621a 100644 --- a/docs/TEST_README.md +++ b/docs/TEST_README.md @@ -271,6 +271,9 @@ After running the test scenario, you should see the following metrics: # Reconciliation latency curl -s http://localhost:8080/metrics | grep "node_readiness_reconciliation_latency_seconds" + + # Enforcement latency + curl -s http://localhost:8080/metrics | grep "node_readiness_enforcement_latency_seconds" ``` 6. **Failure Tracking:** diff --git a/docs/book/src/operations/monitoring.md b/docs/book/src/operations/monitoring.md index fe2b6d1b..9347aaa3 100644 --- a/docs/book/src/operations/monitoring.md +++ b/docs/book/src/operations/monitoring.md @@ -125,6 +125,44 @@ Number of currently-held nodes against blocking conditions per `NodeReadinessRul | `rule` | `NodeReadinessRule` name | Any non-dry-run rule name | | `condition` | Condition type declared in `spec.conditions` | Any condition type declared by the rule | +### `node_readiness_reconciliation_latency_seconds` + +*Deprecated: use [`node_readiness_enforcement_latency_seconds`](#node_readiness_enforcement_latency_seconds) instead. It uses the same latency measurement with simplified operation labels. `node_readiness_reconciliation_latency_seconds` is still published for compatibility.* + +Latency from a node condition change to completion of the corresponding taint operation. + +| Property | Value | +| --- | --- | +| Type | `histogram` | +| Labels | `rule`, `operation` | +| Buckets | `0.01, 0.05, 0.1, 0.5, 1, 2, 5, 10, 30, 60, 120, 300` seconds | +| Recorded when | The controller completes a taint add or remove operation | + +#### Labels + +| Label | Description | Values | +| --- | --- | --- | +| `rule` | `NodeReadinessRule` name | Any rule name | +| `operation` | Taint operation the latency was measured for | `add_taint`, `remove_taint` | + +### `node_readiness_enforcement_latency_seconds` + +Time elapsed between a node's condition transition and the controller's taint response. + +| Property | Value | +| --- | --- | +| Type | `histogram` | +| Labels | `rule`, `operation` | +| Buckets | `0.01, 0.05, 0.1, 0.5, 1, 2, 5, 10, 30, 60, 120, 300` seconds | +| Recorded when | The controller completes a taint add or remove operation | + +#### Labels + +| Label | Description | Values | +| --- | --- | --- | +| `rule` | `NodeReadinessRule` name | Any rule name | +| `operation` | Taint operation the latency was measured for | `add`, `remove` | + ### `node_readiness_bootstrap_completed_total` Total number of nodes that have completed bootstrap. diff --git a/internal/controller/nodereadinessrule_controller.go b/internal/controller/nodereadinessrule_controller.go index 84d67571..0f40bff4 100644 --- a/internal/controller/nodereadinessrule_controller.go +++ b/internal/controller/nodereadinessrule_controller.go @@ -219,7 +219,9 @@ func (r *RuleReconciler) reconcileDelete(ctx context.Context, rule *readinessv1a metrics.Failures.DeletePartialMatch(ruleLabel) metrics.ConditionEvaluationFailures.DeletePartialMatch(ruleLabel) metrics.TaintOperations.DeletePartialMatch(ruleLabel) + //nolint:staticcheck metrics.ReconciliationLatency.DeletePartialMatch(ruleLabel) + metrics.EnforcementLatency.DeletePartialMatch(ruleLabel) return ctrl.Result{}, nil } @@ -389,7 +391,7 @@ func (r *RuleReadinessController) evaluateRuleForNode(ctx context.Context, rule } } - recordLatency := func(operation string) { + recordLatency := func(operation metrics.ReconciliationOperation, enforcementOperation metrics.EnforcementOperation) { if !latestTransition.IsZero() { latency := time.Since(latestTransition.Time).Seconds() @@ -399,7 +401,10 @@ func (r *RuleReadinessController) evaluateRuleForNode(ctx context.Context, rule latency = 0 } - metrics.ReconciliationLatency.WithLabelValues(rule.Name, operation).Observe(latency) + // Deprecated: ReconciliationLatency is superseded by EnforcementLatency and will be removed in future releases. + //nolint:staticcheck + metrics.ReconciliationLatency.WithLabelValues(rule.Name, string(operation)).Observe(latency) + metrics.EnforcementLatency.WithLabelValues(rule.Name, string(enforcementOperation)).Observe(latency) } } @@ -421,7 +426,7 @@ func (r *RuleReadinessController) evaluateRuleForNode(ctx context.Context, rule // Record taint removal latency and taint operation counter. metrics.TaintOperations.WithLabelValues(rule.Name, string(metrics.TaintOperationRemove)).Inc() - recordLatency(string(metrics.ReconciliationOperationRemoveTaint)) + recordLatency(metrics.ReconciliationOperationRemoveTaint, metrics.EnforcementOperationRemove) if rule.Spec.EnforcementMode == readinessv1alpha1.EnforcementModeBootstrapOnly { // Only record the bootstrap duration if the node was created AFTER the rule. @@ -452,7 +457,7 @@ func (r *RuleReadinessController) evaluateRuleForNode(ctx context.Context, rule if added { // Record add taint latency and taint operation counter metrics.TaintOperations.WithLabelValues(rule.Name, string(metrics.TaintOperationAdd)).Inc() - recordLatency(string(metrics.ReconciliationOperationAddTaint)) + recordLatency(metrics.ReconciliationOperationAddTaint, metrics.EnforcementOperationAdd) } case !shouldRemoveTaint && currentlyHasTaint: diff --git a/internal/metrics/metrics.go b/internal/metrics/metrics.go index db418e48..845db168 100644 --- a/internal/metrics/metrics.go +++ b/internal/metrics/metrics.go @@ -48,6 +48,14 @@ const ( ReconciliationOperationAddTaint ReconciliationOperation = "add_taint" ) +// EnforcementOperation represents an enforcement operation. +type EnforcementOperation string + +const ( + EnforcementOperationRemove EnforcementOperation = "remove" + EnforcementOperationAdd EnforcementOperation = "add" +) + // NodeState defines node states. type NodeState string @@ -124,6 +132,8 @@ var ( // ReconciliationLatency tracks end-to-end latency from condition change to taint operation. // This measures how quickly the controller responds to node condition changes. + // + // Deprecated: Use EnforcementLatency instead. ReconciliationLatency will be removed in future releases. ReconciliationLatency = prometheus.NewHistogramVec( prometheus.HistogramOpts{ Name: "node_readiness_reconciliation_latency_seconds", @@ -133,6 +143,17 @@ var ( []string{"rule", "operation"}, // operation: add_taint, remove_taint ) + // EnforcementLatency tracks end-to-end latency from condition change to taint operation. + // This measures how quickly the controller enforces node readiness changes. + EnforcementLatency = prometheus.NewHistogramVec( + prometheus.HistogramOpts{ + Name: "node_readiness_enforcement_latency_seconds", + Help: "End-to-end latency from node condition change to taint operation completion", + Buckets: []float64{0.01, 0.05, 0.1, 0.5, 1, 2, 5, 10, 30, 60, 120, 300}, // 10ms to 5min + }, + []string{"rule", "operation"}, // operation: add, remove + ) + // NodesByState tracks nodes in each readiness state per rule. // Provides a quick overview of cluster health. NodesByState = prometheus.NewGaugeVec( @@ -185,6 +206,7 @@ func init() { metrics.Registry.MustRegister(BootstrapCompleted) metrics.Registry.MustRegister(BootstrapDuration) metrics.Registry.MustRegister(ReconciliationLatency) + metrics.Registry.MustRegister(EnforcementLatency) metrics.Registry.MustRegister(NodesByState) metrics.Registry.MustRegister(ConditionEvaluationFailures) metrics.Registry.MustRegister(RuleLastReconciliationTime) diff --git a/internal/metrics/metrics_test.go b/internal/metrics/metrics_test.go index 0a58a880..17494fea 100644 --- a/internal/metrics/metrics_test.go +++ b/internal/metrics/metrics_test.go @@ -20,6 +20,7 @@ import ( "strings" "testing" + "github.com/prometheus/client_golang/prometheus" "github.com/prometheus/client_golang/prometheus/testutil" "sigs.k8s.io/controller-runtime/pkg/metrics" ) @@ -53,3 +54,68 @@ node_readiness_build_info{version="unknown"} 1 t.Fatal("expected node_readiness_build_info to be registered with the controller-runtime metrics registry") } } + +func TestEnforcementLatency(t *testing.T) { + EnforcementLatency.Reset() + t.Cleanup(EnforcementLatency.Reset) + EnforcementLatency.WithLabelValues("test-rule", string(EnforcementOperationAdd)).Observe(0.2) + + expected := ` +# HELP node_readiness_enforcement_latency_seconds End-to-end latency from node condition change to taint operation completion +# TYPE node_readiness_enforcement_latency_seconds histogram +node_readiness_enforcement_latency_seconds_bucket{operation="add",rule="test-rule",le="0.01"} 0 +node_readiness_enforcement_latency_seconds_bucket{operation="add",rule="test-rule",le="0.05"} 0 +node_readiness_enforcement_latency_seconds_bucket{operation="add",rule="test-rule",le="0.1"} 0 +node_readiness_enforcement_latency_seconds_bucket{operation="add",rule="test-rule",le="0.5"} 1 +node_readiness_enforcement_latency_seconds_bucket{operation="add",rule="test-rule",le="1"} 1 +node_readiness_enforcement_latency_seconds_bucket{operation="add",rule="test-rule",le="2"} 1 +node_readiness_enforcement_latency_seconds_bucket{operation="add",rule="test-rule",le="5"} 1 +node_readiness_enforcement_latency_seconds_bucket{operation="add",rule="test-rule",le="10"} 1 +node_readiness_enforcement_latency_seconds_bucket{operation="add",rule="test-rule",le="30"} 1 +node_readiness_enforcement_latency_seconds_bucket{operation="add",rule="test-rule",le="60"} 1 +node_readiness_enforcement_latency_seconds_bucket{operation="add",rule="test-rule",le="120"} 1 +node_readiness_enforcement_latency_seconds_bucket{operation="add",rule="test-rule",le="300"} 1 +node_readiness_enforcement_latency_seconds_bucket{operation="add",rule="test-rule",le="+Inf"} 1 +node_readiness_enforcement_latency_seconds_sum{operation="add",rule="test-rule"} 0.2 +node_readiness_enforcement_latency_seconds_count{operation="add",rule="test-rule"} 1 +` + assertObservationReflected(t, EnforcementLatency, "node_readiness_enforcement_latency_seconds", expected) + + assertMetricRegistered(t, metrics.Registry, + "node_readiness_enforcement_latency_seconds", + "HISTOGRAM", + "End-to-end latency from node condition change to taint operation completion") +} + +// assertMetricRegistered checks that the metric is registered correctly. +func assertMetricRegistered(t *testing.T, registry prometheus.Gatherer, name, wantType, wantHelp string) { + t.Helper() + + gathered, err := registry.Gather() + if err != nil { + t.Fatalf("failed to gather metrics: %v", err) + } + + for _, mf := range gathered { + if mf.GetName() != name { + continue + } + if got := mf.GetType().String(); got != wantType { + t.Fatalf("expected %s to be a %s, got %s", name, wantType, got) + } + if got := mf.GetHelp(); got != wantHelp { + t.Fatalf("unexpected help text for %s: got %q, want %q", name, got, wantHelp) + } + return + } + t.Fatalf("expected %s to be registered with the controller-runtime metrics registry", name) +} + +// assertObservationReflected checks the collected metric. +func assertObservationReflected(t *testing.T, collector prometheus.Collector, name, expectedExposition string) { + t.Helper() + + if err := testutil.CollectAndCompare(collector, strings.NewReader(expectedExposition), name); err != nil { + t.Fatalf("unexpected collecting result:\n%s", err) + } +} diff --git a/test/scale/promqueries.go b/test/scale/promqueries.go index 6bbea3ff..7f2be97a 100644 --- a/test/scale/promqueries.go +++ b/test/scale/promqueries.go @@ -59,6 +59,21 @@ var metricQueries = []MetricQuery{ QueryTmpl: "histogram_quantile(0.99, sum(rate(node_readiness_reconciliation_latency_seconds_bucket{rule=\"security-agent-readiness-rule\"}[%ds])) by (le))", Unit: "s", }, + { + Key: "enforcement_latency_p50", + QueryTmpl: "histogram_quantile(0.50, sum(rate(node_readiness_enforcement_latency_seconds_bucket{rule=\"security-agent-readiness-rule\"}[%ds])) by (le))", + Unit: "s", + }, + { + Key: "enforcement_latency_p90", + QueryTmpl: "histogram_quantile(0.90, sum(rate(node_readiness_enforcement_latency_seconds_bucket{rule=\"security-agent-readiness-rule\"}[%ds])) by (le))", + Unit: "s", + }, + { + Key: "enforcement_latency_p99", + QueryTmpl: "histogram_quantile(0.99, sum(rate(node_readiness_enforcement_latency_seconds_bucket{rule=\"security-agent-readiness-rule\"}[%ds])) by (le))", + Unit: "s", + }, { Key: "workqueue_queue_duration_p50", diff --git a/test/scale/testdata/scalability_report.md.tmpl b/test/scale/testdata/scalability_report.md.tmpl index 8217dba9..37f06dbc 100644 --- a/test/scale/testdata/scalability_report.md.tmpl +++ b/test/scale/testdata/scalability_report.md.tmpl @@ -10,6 +10,7 @@ | :--- | :--- | :--- | :--- | | **Controller Reconcile Duration** | {{index .Metrics "reconcile_time_p50"}} | {{index .Metrics "reconcile_time_p90"}} | {{index .Metrics "reconcile_time_p99"}} | | **Reconciliation Latency** | {{index .Metrics "reconciliation_latency_p50"}} | {{index .Metrics "reconciliation_latency_p90"}} | {{index .Metrics "reconciliation_latency_p99"}} | +| **Enforcement Latency** | {{index .Metrics "enforcement_latency_p50"}} | {{index .Metrics "enforcement_latency_p90"}} | {{index .Metrics "enforcement_latency_p99"}} | | **Rule Evaluation Duration** | {{index .Metrics "rule_evaluation_duration_p50"}} | {{index .Metrics "rule_evaluation_duration_p90"}} | {{index .Metrics "rule_evaluation_duration_p99"}} | | **Workqueue Queue Duration** | {{index .Metrics "workqueue_queue_duration_p50"}} | {{index .Metrics "workqueue_queue_duration_p90"}} | {{index .Metrics "workqueue_queue_duration_p99"}} | | **Workqueue Work Duration** | {{index .Metrics "workqueue_work_duration_p50"}} | {{index .Metrics "workqueue_work_duration_p90"}} | {{index .Metrics "workqueue_work_duration_p99"}} |