From f3068efcfb9f61586dcfae4b87bd084628d53428 Mon Sep 17 00:00:00 2001 From: Mike Spreitzer Date: Mon, 9 May 2022 23:00:17 -0400 Subject: [PATCH] Simplify and extend the benchmarks of timing histograms Replace the use of a clock abstraction with direct provision of the time-reading function. Add benchmarks of two ways to fetch and use a vector member. Following are the results using the revised benchmark suite. (base) mspreitz@mjs12 prometheusextension % go test -benchmem -run=^$ -bench Histogram . goos: darwin goarch: amd64 pkg: k8s.io/component-base/metrics/prometheusextension cpu: Intel(R) Core(TM) i9-9880H CPU @ 2.30GHz BenchmarkTimingHistogramDirect-16 28562178 39.47 ns/op 0 B/op 0 allocs/op BenchmarkTimingHistogramVecEltCached-16 29268819 39.41 ns/op 0 B/op 0 allocs/op BenchmarkTimingHistogramVecEltFetched-16 8345041 142.5 ns/op 32 B/op 1 allocs/op BenchmarkWeightedHistogram-16 49803134 24.22 ns/op 0 B/op 0 allocs/op BenchmarkHistogram-16 41756210 29.40 ns/op 0 B/op 0 allocs/op PASS ok k8s.io/component-base/metrics/prometheusextension 6.488s (base) mspreitz@mjs12 prometheusextension % go test -benchmem -run=^$ -bench Histogram . goos: darwin goarch: amd64 pkg: k8s.io/component-base/metrics/prometheusextension cpu: Intel(R) Core(TM) i9-9880H CPU @ 2.30GHz BenchmarkTimingHistogramDirect-16 28246786 39.60 ns/op 0 B/op 0 allocs/op BenchmarkTimingHistogramVecEltCached-16 29318173 39.44 ns/op 0 B/op 0 allocs/op BenchmarkTimingHistogramVecEltFetched-16 8441341 142.5 ns/op 32 B/op 1 allocs/op BenchmarkWeightedHistogram-16 48469184 24.21 ns/op 0 B/op 0 allocs/op BenchmarkHistogram-16 41001742 29.51 ns/op 0 B/op 0 allocs/op PASS ok k8s.io/component-base/metrics/prometheusextension 6.340s (base) mspreitz@mjs12 prometheusextension % go test -benchmem -run=^$ -bench Histogram . goos: darwin goarch: amd64 pkg: k8s.io/component-base/metrics/prometheusextension cpu: Intel(R) Core(TM) i9-9880H CPU @ 2.30GHz BenchmarkTimingHistogramDirect-16 28983674 40.82 ns/op 0 B/op 0 allocs/op BenchmarkTimingHistogramVecEltCached-16 29527742 43.83 ns/op 0 B/op 0 allocs/op BenchmarkTimingHistogramVecEltFetched-16 8238685 143.8 ns/op 32 B/op 1 allocs/op BenchmarkWeightedHistogram-16 49594070 24.24 ns/op 0 B/op 0 allocs/op BenchmarkHistogram-16 41100378 29.35 ns/op 0 B/op 0 allocs/op PASS ok k8s.io/component-base/metrics/prometheusextension 6.554s --- .../timing_histogram_test.go | 45 +++++++++++++++++-- 1 file changed, 42 insertions(+), 3 deletions(-) diff --git a/staging/src/k8s.io/component-base/metrics/prometheusextension/timing_histogram_test.go b/staging/src/k8s.io/component-base/metrics/prometheusextension/timing_histogram_test.go index 2fe900d3bc3..102cc5cf92b 100644 --- a/staging/src/k8s.io/component-base/metrics/prometheusextension/timing_histogram_test.go +++ b/staging/src/k8s.io/component-base/metrics/prometheusextension/timing_histogram_test.go @@ -202,8 +202,7 @@ func (ufc *unsyncFakeClock) SetTime(now time.Time) { func BenchmarkTimingHistogramDirect(b *testing.B) { b.StopTimer() now := time.Now() - clk := &unsyncFakeClock{now: now} - hist, err := NewTestableTimingHistogram(clk.Now, TimingHistogramOpts{ + hist, err := NewTestableTimingHistogram(func() time.Time { return now }, TimingHistogramOpts{ Namespace: "testns", Subsystem: "testsubsys", Name: "testhist", @@ -216,8 +215,48 @@ func BenchmarkTimingHistogramDirect(b *testing.B) { var x int b.StartTimer() for i := 0; i < b.N; i++ { - clk.now = clk.now.Add(time.Duration(31-x) * time.Microsecond) + now = now.Add(time.Duration(31-x) * time.Microsecond) hist.Set(float64(x)) x = (x + i) % 23 } } +func BenchmarkTimingHistogramVecEltCached(b *testing.B) { + b.StopTimer() + now := time.Now() + vec := NewTestableTimingHistogramVec(func() time.Time { return now }, TimingHistogramOpts{ + Namespace: "testns", + Subsystem: "testsubsys", + Name: "testhist", + Help: "Me", + Buckets: []float64{1, 2, 4, 8, 16}, + }, + "label1", "label2") + hist := vec.WithLabelValues("val1", "val2") + var x int + b.StartTimer() + for i := 0; i < b.N; i++ { + now = now.Add(time.Duration(31-x) * time.Microsecond) + hist.Set(float64(x)) + x = (x + i) % 23 + } +} + +func BenchmarkTimingHistogramVecEltFetched(b *testing.B) { + b.StopTimer() + now := time.Now() + vec := NewTestableTimingHistogramVec(func() time.Time { return now }, TimingHistogramOpts{ + Namespace: "testns", + Subsystem: "testsubsys", + Name: "testhist", + Help: "Me", + Buckets: []float64{1, 2, 4, 8, 16}, + }, + "label1", "label2") + var x int + b.StartTimer() + for i := 0; i < b.N; i++ { + now = now.Add(time.Duration(31-x) * time.Microsecond) + vec.WithLabelValues("val1", "val2").Set(float64(x)) + x = (x + i) % 23 + } +}