diff --git a/pkg/kmetrics/exec.go b/pkg/kmetrics/exec.go index d85fdf7a00..1e18b1ddf9 100644 --- a/pkg/kmetrics/exec.go +++ b/pkg/kmetrics/exec.go @@ -120,7 +120,7 @@ func runKustomizeBuild(ctx context.Context, sendMetrics bool, inputDir string, c resourceCount, err := kustomizeResourcesGenerated(output) if err == nil && sendMetrics { RecordKustomizeResourceCount(ctx, resourceCount) - RecordKustomizeExecutionTime(ctx, float64(executionTime)) + RecordKustomizeExecutionTime(ctx, float64(executionTime.Milliseconds())) } outputs <- output errors <- kustomizeErr @@ -139,14 +139,14 @@ func runKustomizeBuild(ctx context.Context, sendMetrics bool, inputDir string, c return <-outputs, <-errors } -func runCommand(cmd *exec.Cmd) (int64, string, error) { +func runCommand(cmd *exec.Cmd) (time.Duration, string, error) { var stdout bytes.Buffer var stderr bytes.Buffer cmd.Stdout = &stdout cmd.Stderr = &stderr now := time.Now() err := cmd.Run() - executionTime := time.Since(now).Nanoseconds() + executionTime := time.Since(now) if err != nil { return executionTime, stdout.String(), errors.New(stderr.String()) } diff --git a/pkg/kmetrics/metrics.go b/pkg/kmetrics/metrics.go index 128a93cd28..92c3f2b74f 100644 --- a/pkg/kmetrics/metrics.go +++ b/pkg/kmetrics/metrics.go @@ -67,6 +67,15 @@ var ( KustomizeExecutionTime metric.Float64Histogram ) +var ( + // KustomizeBuildLatencyBounds defines the millisecond bounds for the kustomize + // build latency histogram. These must match the pre-OTel-migration view + // aggregation (view.Distribution(0, 10, 20, ..., 10240)) that the Monarch + // metric descriptor was registered with; changing the bounds or the unit + // causes the exporter to fail with a bucket options mismatch. + KustomizeBuildLatencyBounds = []float64{0, 10, 20, 40, 80, 160, 320, 640, 1280, 2560, 5120, 10240} +) + // InitializeOTelKustomizeMetrics initializes OpenTelemetry Kustomize metrics instruments func InitializeOTelKustomizeMetrics() error { klog.V(5).Infof("METRIC DEBUG: Initializing OpenTelemetry kustomize metrics instruments") @@ -152,8 +161,9 @@ func InitializeOTelKustomizeMetrics() error { // Initialize histogram instrument KustomizeExecutionTime, err = meter.Float64Histogram( "kustomize_build_latency", - metric.WithDescription("Kustomize build latency"), + metric.WithDescription("Kustomize build latency in milliseconds"), metric.WithUnit("ms"), + metric.WithExplicitBucketBoundaries(KustomizeBuildLatencyBounds...), ) if err != nil { klog.V(5).ErrorS(err, "METRIC DEBUG: Failed to create KustomizeExecutionTime histogram") diff --git a/pkg/kmetrics/metrics_test.go b/pkg/kmetrics/metrics_test.go new file mode 100644 index 0000000000..ba0aa06b48 --- /dev/null +++ b/pkg/kmetrics/metrics_test.go @@ -0,0 +1,86 @@ +// Copyright 2026 Google LLC +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +package kmetrics + +import ( + "testing" + "time" + + "github.com/google/go-cmp/cmp" + "go.opentelemetry.io/otel" + sdkmetric "go.opentelemetry.io/otel/sdk/metric" + "go.opentelemetry.io/otel/sdk/metric/metricdata" + "go.opentelemetry.io/otel/sdk/resource" +) + +func TestInitializeOTelKustomizeMetrics_HistogramBuckets(t *testing.T) { + reader := sdkmetric.NewManualReader() + meterProvider := sdkmetric.NewMeterProvider( + sdkmetric.WithResource(resource.NewSchemaless()), + sdkmetric.WithReader(reader), + ) + otel.SetMeterProvider(meterProvider) + + if err := InitializeOTelKustomizeMetrics(); err != nil { + t.Fatalf("InitializeOTelKustomizeMetrics() failed: %v", err) + } + + ctx := t.Context() + // Record a 350ms build duration in milliseconds + executionTime := 350 * time.Millisecond + RecordKustomizeExecutionTime(ctx, float64(executionTime.Milliseconds())) + + var rm metricdata.ResourceMetrics + if err := reader.Collect(ctx, &rm); err != nil { + t.Fatalf("reader.Collect() failed: %v", err) + } + + var foundPoint *metricdata.HistogramDataPoint[float64] + for _, sm := range rm.ScopeMetrics { + for _, m := range sm.Metrics { + if m.Name == "kustomize_build_latency" { + if hist, ok := m.Data.(metricdata.Histogram[float64]); ok && len(hist.DataPoints) > 0 { + foundPoint = &hist.DataPoints[0] + } + } + } + } + + if foundPoint == nil { + t.Fatalf("Histogram %q was not found in collected metrics", "kustomize_build_latency") + } + + if diff := cmp.Diff(KustomizeBuildLatencyBounds, foundPoint.Bounds); diff != "" { + t.Errorf("Histogram %q bucket boundaries mismatch (-want +got):\n%s", "kustomize_build_latency", diff) + } + + // For 350ms and KustomizeBuildLatencyBounds [0, 10, 20, 40, 80, 160, 320, 640, ...]: + // Index 7: (320, 640] <-- 350ms must fall in this bucket + if len(foundPoint.BucketCounts) <= 7 { + t.Fatalf("Expected at least 8 bucket counts, got %d", len(foundPoint.BucketCounts)) + } + if foundPoint.BucketCounts[7] != 1 { + t.Errorf("BucketCounts[7] (interval (320, 640]) = %d, want 1. Full BucketCounts: %v", + foundPoint.BucketCounts[7], foundPoint.BucketCounts) + } + + // Verify the overflow (+Inf) bucket is empty. Before the fix, durations were + // recorded in nanoseconds against millisecond-scale default buckets, so every + // recording landed in the overflow bucket. + overflowIdx := len(foundPoint.BucketCounts) - 1 + if foundPoint.BucketCounts[overflowIdx] != 0 { + t.Errorf("BucketCounts[%d] (+Inf overflow bucket) = %d, want 0", overflowIdx, foundPoint.BucketCounts[overflowIdx]) + } +} diff --git a/pkg/kmetrics/record.go b/pkg/kmetrics/record.go index 61bb158688..c5e94a981b 100644 --- a/pkg/kmetrics/record.go +++ b/pkg/kmetrics/record.go @@ -48,7 +48,7 @@ func RecordKustomizeResourceCount(ctx context.Context, resourceCount int) { // RecordKustomizeExecutionTime produces measurement for KustomizeExecutionTime view func RecordKustomizeExecutionTime(ctx context.Context, executionTime float64) { - klog.V(5).Infof("METRIC DEBUG: Recording KustomizeExecutionTime: executionTime=%.3fs", executionTime) + klog.V(5).Infof("METRIC DEBUG: Recording KustomizeExecutionTime: executionTime=%.0fms", executionTime) KustomizeExecutionTime.Record(ctx, executionTime) } diff --git a/pkg/metrics/metrics.go b/pkg/metrics/metrics.go index f31053f7e9..db06440240 100644 --- a/pkg/metrics/metrics.go +++ b/pkg/metrics/metrics.go @@ -51,6 +51,17 @@ const ( InternalErrorsName = "internal_errors_total" ) +var ( + // DistributionBounds defines the bounds for a histogram distribution measuring short durations. + DistributionBounds = []float64{.005, .01, .025, .05, .1, .25, .5, 1, 2.5, 5, 10} + + // LongDistributionBounds defines the bounds for a histogram distribution measuring long durations. + // These must match the pre-registered Monarch metric descriptor for + // parser_duration_seconds and apply_duration_seconds; changing them causes + // the exporter to fail with a bucket options mismatch. + LongDistributionBounds = []float64{1, 5, 10, 30, 60, 300, 600, 1200, 1800, 3600, 5400} +) + var ( // APICallDuration metric measures the latency of API server calls. APICallDuration metric.Float64Histogram @@ -112,6 +123,7 @@ func InitializeOTelMetrics() error { APICallDurationName, metric.WithDescription("The duration of API server calls in seconds"), metric.WithUnit("s"), + metric.WithExplicitBucketBoundaries(DistributionBounds...), ) if err != nil { klog.V(5).ErrorS(err, "METRIC DEBUG: Failed to create APICallDuration histogram") @@ -123,6 +135,7 @@ func InitializeOTelMetrics() error { ReconcileDurationName, metric.WithDescription("The duration of reconcile events in seconds"), metric.WithUnit("s"), + metric.WithExplicitBucketBoundaries(DistributionBounds...), ) if err != nil { return err @@ -132,6 +145,7 @@ func InitializeOTelMetrics() error { ParserDurationName, metric.WithDescription("The duration of the parse-apply-watch loop in seconds"), metric.WithUnit("s"), + metric.WithExplicitBucketBoundaries(LongDistributionBounds...), ) if err != nil { return err @@ -141,6 +155,7 @@ func InitializeOTelMetrics() error { ApplyDurationName, metric.WithDescription("The duration of applier events in seconds"), metric.WithUnit("s"), + metric.WithExplicitBucketBoundaries(LongDistributionBounds...), ) if err != nil { return err @@ -150,6 +165,7 @@ func InitializeOTelMetrics() error { RemediateDurationName, metric.WithDescription("The duration of remediator reconciliation events"), metric.WithUnit("s"), + metric.WithExplicitBucketBoundaries(DistributionBounds...), ) if err != nil { return err diff --git a/pkg/metrics/metrics_test.go b/pkg/metrics/metrics_test.go new file mode 100644 index 0000000000..a33dfe5d62 --- /dev/null +++ b/pkg/metrics/metrics_test.go @@ -0,0 +1,145 @@ +// Copyright 2026 Google LLC +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +package metrics + +import ( + "testing" + "time" + + "github.com/google/go-cmp/cmp" + "go.opentelemetry.io/otel" + sdkmetric "go.opentelemetry.io/otel/sdk/metric" + "go.opentelemetry.io/otel/sdk/metric/metricdata" + "go.opentelemetry.io/otel/sdk/resource" +) + +func TestInitializeOTelMetrics_HistogramBuckets(t *testing.T) { + reader := sdkmetric.NewManualReader() + meterProvider := sdkmetric.NewMeterProvider( + sdkmetric.WithResource(resource.NewSchemaless()), + sdkmetric.WithReader(reader), + ) + otel.SetMeterProvider(meterProvider) + + if err := InitializeOTelMetrics(); err != nil { + t.Fatalf("InitializeOTelMetrics() failed: %v", err) + } + + ctx := t.Context() + startTime := time.Now().Add(-350 * time.Millisecond) + + RecordAPICallDuration(ctx, "get", "success", startTime) + RecordReconcileDuration(ctx, "success", startTime) + RecordParserDuration(ctx, "git", "root", "success", startTime) + RecordApplyDuration(ctx, "success", "abcdef", startTime) + RecordRemediateDuration(ctx, "success", startTime) + + var rm metricdata.ResourceMetrics + if err := reader.Collect(ctx, &rm); err != nil { + t.Fatalf("reader.Collect() failed: %v", err) + } + + expectedHistograms := map[string][]float64{ + APICallDurationName: DistributionBounds, + ReconcileDurationName: DistributionBounds, + ParserDurationName: LongDistributionBounds, + ApplyDurationName: LongDistributionBounds, + RemediateDurationName: DistributionBounds, + } + + foundHistograms := make(map[string][]float64) + for _, sm := range rm.ScopeMetrics { + for _, m := range sm.Metrics { + if hist, ok := m.Data.(metricdata.Histogram[float64]); ok { + if len(hist.DataPoints) > 0 { + foundHistograms[m.Name] = hist.DataPoints[0].Bounds + } + } + } + } + + for metricName, wantBounds := range expectedHistograms { + t.Run(metricName, func(t *testing.T) { + gotBounds, ok := foundHistograms[metricName] + if !ok { + t.Fatalf("Histogram %q was not found in collected metrics", metricName) + } + if diff := cmp.Diff(wantBounds, gotBounds); diff != "" { + t.Errorf("Histogram %q bucket boundaries mismatch (-want +got):\n%s", metricName, diff) + } + }) + } +} + +func TestRecordDuration_SubsecondBucketPlacement(t *testing.T) { + reader := sdkmetric.NewManualReader() + meterProvider := sdkmetric.NewMeterProvider( + sdkmetric.WithResource(resource.NewSchemaless()), + sdkmetric.WithReader(reader), + ) + otel.SetMeterProvider(meterProvider) + + if err := InitializeOTelMetrics(); err != nil { + t.Fatalf("InitializeOTelMetrics() failed: %v", err) + } + + ctx := t.Context() + // Record an exact 350ms duration (0.35s) + startTime := time.Now().Add(-350 * time.Millisecond) + RecordAPICallDuration(ctx, "get", "success", startTime) + + var rm metricdata.ResourceMetrics + if err := reader.Collect(ctx, &rm); err != nil { + t.Fatalf("reader.Collect() failed: %v", err) + } + + var foundPoint *metricdata.HistogramDataPoint[float64] + for _, sm := range rm.ScopeMetrics { + for _, m := range sm.Metrics { + if m.Name == APICallDurationName { + if hist, ok := m.Data.(metricdata.Histogram[float64]); ok && len(hist.DataPoints) > 0 { + foundPoint = &hist.DataPoints[0] + } + } + } + } + + if foundPoint == nil { + t.Fatalf("Metric %q was not recorded", APICallDurationName) + } + + // For 0.35s and DistributionBounds [.005, .01, .025, .05, .1, .25, .5, 1, 2.5, 5, 10]: + // Index 0: <= 0.005 + // Index 1: (0.005, 0.01] + // Index 2: (0.01, 0.025] + // Index 3: (0.025, 0.05] + // Index 4: (0.05, 0.1] + // Index 5: (0.1, 0.25] + // Index 6: (0.25, 0.5] <-- 0.35s must fall in this sub-second bucket + // Index 9: (2.5, 5.0] <-- Before fix, this was where it fell (le=5) + if len(foundPoint.BucketCounts) <= 6 { + t.Fatalf("Expected at least 7 bucket counts, got %d", len(foundPoint.BucketCounts)) + } + + if foundPoint.BucketCounts[6] != 1 { + t.Errorf("BucketCounts[6] (interval (0.25, 0.5]) = %d, want 1. Full BucketCounts: %v", + foundPoint.BucketCounts[6], foundPoint.BucketCounts) + } + + // Verify that the coarse 5-second bucket (index 9) is 0, confirming it didn't fall into the 5s bucket + if foundPoint.BucketCounts[9] != 0 { + t.Errorf("BucketCounts[9] (interval (2.5, 5.0]) = %d, want 0", foundPoint.BucketCounts[9]) + } +} diff --git a/pkg/resourcegroup/controllers/metrics/metrics.go b/pkg/resourcegroup/controllers/metrics/metrics.go index 0f413ba9a3..97615bfc51 100644 --- a/pkg/resourcegroup/controllers/metrics/metrics.go +++ b/pkg/resourcegroup/controllers/metrics/metrics.go @@ -82,6 +82,11 @@ var ( PipelineError metric.Int64Gauge ) +var ( + // RGReconcileDurationBounds defines the bounds for ResourceGroup reconcile duration histogram. + RGReconcileDurationBounds = []float64{0.05, 0.1, 0.25, 0.5, 1, 2.5, 5, 10} +) + // InitializeOTelResourceGroupMetrics initializes OpenTelemetry Resource Group metrics instruments func InitializeOTelResourceGroupMetrics() error { meter := otel.Meter("config-sync-resourcegroup") @@ -93,6 +98,7 @@ func InitializeOTelResourceGroupMetrics() error { RGReconcileDurationName, metric.WithDescription("Time duration in seconds of reconciling a ResourceGroup CR by the ResourceGroup controller"), metric.WithUnit("s"), + metric.WithExplicitBucketBoundaries(RGReconcileDurationBounds...), ) if err != nil { return err diff --git a/pkg/resourcegroup/controllers/metrics/metrics_test.go b/pkg/resourcegroup/controllers/metrics/metrics_test.go new file mode 100644 index 0000000000..ed5dd700d2 --- /dev/null +++ b/pkg/resourcegroup/controllers/metrics/metrics_test.go @@ -0,0 +1,70 @@ +// Copyright 2026 Google LLC +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. + +package metrics + +import ( + "testing" + "time" + + "github.com/google/go-cmp/cmp" + "go.opentelemetry.io/otel" + sdkmetric "go.opentelemetry.io/otel/sdk/metric" + "go.opentelemetry.io/otel/sdk/metric/metricdata" + "go.opentelemetry.io/otel/sdk/resource" +) + +func TestInitializeOTelResourceGroupMetrics_HistogramBuckets(t *testing.T) { + reader := sdkmetric.NewManualReader() + meterProvider := sdkmetric.NewMeterProvider( + sdkmetric.WithResource(resource.NewSchemaless()), + sdkmetric.WithReader(reader), + ) + otel.SetMeterProvider(meterProvider) + + if err := InitializeOTelResourceGroupMetrics(); err != nil { + t.Fatalf("InitializeOTelResourceGroupMetrics() failed: %v", err) + } + + ctx := t.Context() + startTime := time.Now().Add(-200 * time.Millisecond) + + RecordReconcileDuration(ctx, "FinishReconciling", startTime) + + var rm metricdata.ResourceMetrics + if err := reader.Collect(ctx, &rm); err != nil { + t.Fatalf("reader.Collect() failed: %v", err) + } + + var gotBounds []float64 + var found bool + for _, sm := range rm.ScopeMetrics { + for _, m := range sm.Metrics { + if m.Name == RGReconcileDurationName { + if hist, ok := m.Data.(metricdata.Histogram[float64]); ok && len(hist.DataPoints) > 0 { + gotBounds = hist.DataPoints[0].Bounds + found = true + } + } + } + } + + if !found { + t.Fatalf("Histogram %q was not found in collected metrics", RGReconcileDurationName) + } + + if diff := cmp.Diff(RGReconcileDurationBounds, gotBounds); diff != "" { + t.Errorf("Histogram %q bucket boundaries mismatch (-want +got):\n%s", RGReconcileDurationName, diff) + } +}