...

Source file src/k8s.io/component-base/metrics/timing_histogram_test.go

Documentation: k8s.io/component-base/metrics

     1  /*
     2  Copyright 2019 The Kubernetes Authors.
     3  
     4  Licensed under the Apache License, Version 2.0 (the "License");
     5  you may not use this file except in compliance with the License.
     6  You may obtain a copy of the License at
     7  
     8      http://www.apache.org/licenses/LICENSE-2.0
     9  
    10  Unless required by applicable law or agreed to in writing, software
    11  distributed under the License is distributed on an "AS IS" BASIS,
    12  WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
    13  See the License for the specific language governing permissions and
    14  limitations under the License.
    15  */
    16  
    17  package metrics
    18  
    19  import (
    20  	"testing"
    21  	"time"
    22  
    23  	"github.com/blang/semver/v4"
    24  	"github.com/prometheus/client_golang/prometheus"
    25  	"github.com/stretchr/testify/assert"
    26  
    27  	apimachineryversion "k8s.io/apimachinery/pkg/version"
    28  	testclock "k8s.io/utils/clock/testing"
    29  )
    30  
    31  func TestTimingHistogram(t *testing.T) {
    32  	v115 := semver.MustParse("1.15.0")
    33  	var tests = []struct {
    34  		desc string
    35  		*TimingHistogramOpts
    36  		registryVersion     *semver.Version
    37  		expectedMetricCount int
    38  		expectedHelp        string
    39  	}{
    40  		{
    41  			desc: "Test non deprecated",
    42  			TimingHistogramOpts: &TimingHistogramOpts{
    43  				Namespace:    "namespace",
    44  				Name:         "metric_test_name",
    45  				Subsystem:    "subsystem",
    46  				Help:         "histogram help message",
    47  				Buckets:      DefBuckets,
    48  				InitialValue: 13,
    49  			},
    50  			registryVersion:     &v115,
    51  			expectedMetricCount: 1,
    52  			expectedHelp:        "EXPERIMENTAL: [ALPHA] histogram help message",
    53  		},
    54  		{
    55  			desc: "Test deprecated",
    56  			TimingHistogramOpts: &TimingHistogramOpts{
    57  				Namespace:         "namespace",
    58  				Name:              "metric_test_name",
    59  				Subsystem:         "subsystem",
    60  				Help:              "histogram help message",
    61  				DeprecatedVersion: "1.15.0",
    62  				Buckets:           DefBuckets,
    63  				InitialValue:      3,
    64  			},
    65  			registryVersion:     &v115,
    66  			expectedMetricCount: 1,
    67  			expectedHelp:        "EXPERIMENTAL: [ALPHA] (Deprecated since 1.15.0) histogram help message",
    68  		},
    69  		{
    70  			desc: "Test hidden",
    71  			TimingHistogramOpts: &TimingHistogramOpts{
    72  				Namespace:         "namespace",
    73  				Name:              "metric_test_name",
    74  				Subsystem:         "subsystem",
    75  				Help:              "histogram help message",
    76  				DeprecatedVersion: "1.14.0",
    77  				Buckets:           DefBuckets,
    78  				InitialValue:      5,
    79  			},
    80  			registryVersion:     &v115,
    81  			expectedMetricCount: 0,
    82  			expectedHelp:        "EXPERIMENTAL: histogram help message",
    83  		},
    84  	}
    85  
    86  	for _, test := range tests {
    87  		t.Run(test.desc, func(t *testing.T) {
    88  			registry := newKubeRegistry(apimachineryversion.Info{
    89  				Major:      "1",
    90  				Minor:      "15",
    91  				GitVersion: "v1.15.0-alpha-1.12345",
    92  			})
    93  			t0 := time.Now()
    94  			clk := testclock.NewFakePassiveClock(t0)
    95  			c := NewTestableTimingHistogram(clk.Now, test.TimingHistogramOpts)
    96  			registry.MustRegister(c)
    97  
    98  			metricChan := make(chan prometheus.Metric)
    99  			go func() {
   100  				c.Collect(metricChan)
   101  				close(metricChan)
   102  			}()
   103  			m1 := <-metricChan
   104  			gm1, ok := m1.(GaugeMetric)
   105  			if !ok || gm1 != c.PrometheusTimingHistogram {
   106  				t.Error("Unexpected metric", m1, c.PrometheusTimingHistogram)
   107  			}
   108  			m2, ok := <-metricChan
   109  			if ok {
   110  				t.Error("Unexpected second metric", m2)
   111  			}
   112  
   113  			ms, err := registry.Gather()
   114  			assert.Equalf(t, test.expectedMetricCount, len(ms), "Got %v metrics, Want: %v metrics", len(ms), test.expectedMetricCount)
   115  			assert.Nil(t, err, "Gather failed %v", err)
   116  
   117  			for _, metric := range ms {
   118  				assert.Equalf(t, test.expectedHelp, metric.GetHelp(), "Got %s as help message, want %s", metric.GetHelp(), test.expectedHelp)
   119  			}
   120  
   121  			// let's exercise the metric and check that it still works
   122  			v0 := test.TimingHistogramOpts.InitialValue
   123  			dt1 := time.Nanosecond
   124  			t1 := t0.Add(dt1)
   125  			clk.SetTime(t1)
   126  			var v1 float64 = 10
   127  			c.Set(v1)
   128  			dt2 := time.Hour
   129  			t2 := t1.Add(dt2)
   130  			clk.SetTime(t2)
   131  			var v2 float64 = 1e6
   132  			c.Add(v2 - v1)
   133  			dt3 := time.Microsecond
   134  			t3 := t2.Add(dt3)
   135  			clk.SetTime(t3)
   136  			c.Set(0)
   137  			expectedCount := uint64(dt1 + dt2 + dt3)
   138  			expectedSum := float64(dt1)*v0 + float64(dt2)*v1 + float64(dt3)*v2
   139  			ms, err = registry.Gather()
   140  			assert.Nil(t, err, "Gather failed %v", err)
   141  
   142  			for _, mf := range ms {
   143  				t.Logf("Considering metric family %s", mf.GetName())
   144  				for _, m := range mf.GetMetric() {
   145  					assert.Equalf(t, expectedCount, m.GetHistogram().GetSampleCount(), "Got %v, want %v as the sample count of metric %s", m.GetHistogram().GetSampleCount(), expectedCount, m.String())
   146  					assert.Equalf(t, expectedSum, m.GetHistogram().GetSampleSum(), "Got %v, want %v as the sample sum of metric %s", m.GetHistogram().GetSampleSum(), expectedSum, m.String())
   147  				}
   148  			}
   149  		})
   150  	}
   151  }
   152  
   153  func TestTimingHistogramVec(t *testing.T) {
   154  	v115 := semver.MustParse("1.15.0")
   155  	var tests = []struct {
   156  		desc string
   157  		*TimingHistogramOpts
   158  		labels              []string
   159  		registryVersion     *semver.Version
   160  		expectedMetricCount int
   161  		expectedHelp        string
   162  	}{
   163  		{
   164  			desc: "Test non deprecated",
   165  			TimingHistogramOpts: &TimingHistogramOpts{
   166  				Namespace:    "namespace",
   167  				Name:         "metric_test_name",
   168  				Subsystem:    "subsystem",
   169  				Help:         "histogram help message",
   170  				Buckets:      DefBuckets,
   171  				InitialValue: 5,
   172  			},
   173  			labels:              []string{"label_a", "label_b"},
   174  			registryVersion:     &v115,
   175  			expectedMetricCount: 1,
   176  			expectedHelp:        "EXPERIMENTAL: [ALPHA] histogram help message",
   177  		},
   178  		{
   179  			desc: "Test deprecated",
   180  			TimingHistogramOpts: &TimingHistogramOpts{
   181  				Namespace:         "namespace",
   182  				Name:              "metric_test_name",
   183  				Subsystem:         "subsystem",
   184  				Help:              "histogram help message",
   185  				DeprecatedVersion: "1.15.0",
   186  				Buckets:           DefBuckets,
   187  				InitialValue:      13,
   188  			},
   189  			labels:              []string{"label_a", "label_b"},
   190  			registryVersion:     &v115,
   191  			expectedMetricCount: 1,
   192  			expectedHelp:        "EXPERIMENTAL: [ALPHA] (Deprecated since 1.15.0) histogram help message",
   193  		},
   194  		{
   195  			desc: "Test hidden",
   196  			TimingHistogramOpts: &TimingHistogramOpts{
   197  				Namespace:         "namespace",
   198  				Name:              "metric_test_name",
   199  				Subsystem:         "subsystem",
   200  				Help:              "histogram help message",
   201  				DeprecatedVersion: "1.14.0",
   202  				Buckets:           DefBuckets,
   203  				InitialValue:      42,
   204  			},
   205  			labels:              []string{"label_a", "label_b"},
   206  			registryVersion:     &v115,
   207  			expectedMetricCount: 0,
   208  			expectedHelp:        "EXPERIMENTAL: histogram help message",
   209  		},
   210  	}
   211  
   212  	for _, test := range tests {
   213  		t.Run(test.desc, func(t *testing.T) {
   214  			registry := newKubeRegistry(apimachineryversion.Info{
   215  				Major:      "1",
   216  				Minor:      "15",
   217  				GitVersion: "v1.15.0-alpha-1.12345",
   218  			})
   219  			t0 := time.Now()
   220  			clk := testclock.NewFakePassiveClock(t0)
   221  			c := NewTestableTimingHistogramVec(clk.Now, test.TimingHistogramOpts, test.labels)
   222  			registry.MustRegister(c)
   223  			var v0 float64 = 3
   224  			cm1, err := c.WithLabelValuesChecked("1", "2")
   225  			if err != nil {
   226  				t.Error(err)
   227  			}
   228  			cm1.Set(v0)
   229  
   230  			if test.expectedMetricCount > 0 {
   231  				metricChan := make(chan prometheus.Metric, 2)
   232  				c.Collect(metricChan)
   233  				close(metricChan)
   234  				m1 := <-metricChan
   235  				if m1 != cm1.(prometheus.Metric) {
   236  					t.Error("Unexpected metric", m1, cm1)
   237  				}
   238  				m2, ok := <-metricChan
   239  				if ok {
   240  					t.Error("Unexpected second metric", m2)
   241  				}
   242  			}
   243  
   244  			ms, err := registry.Gather()
   245  			assert.Equalf(t, test.expectedMetricCount, len(ms), "Got %v metrics, Want: %v metrics", len(ms), test.expectedMetricCount)
   246  			assert.Nil(t, err, "Gather failed %v", err)
   247  			for _, metric := range ms {
   248  				if metric.GetHelp() != test.expectedHelp {
   249  					assert.Equalf(t, test.expectedHelp, metric.GetHelp(), "Got %s as help message, want %s", metric.GetHelp(), test.expectedHelp)
   250  				}
   251  			}
   252  
   253  			// let's exercise the metric and verify it still works
   254  			c.WithLabelValues("1", "3").Set(v0)
   255  			c.WithLabelValues("2", "3").Set(v0)
   256  			dt1 := time.Nanosecond
   257  			t1 := t0.Add(dt1)
   258  			clk.SetTime(t1)
   259  			c.WithLabelValues("1", "2").Add(5.0)
   260  			c.WithLabelValues("1", "3").Add(5.0)
   261  			c.WithLabelValues("2", "3").Add(5.0)
   262  			ms, err = registry.Gather()
   263  			assert.Nil(t, err, "Gather failed %v", err)
   264  
   265  			for _, mf := range ms {
   266  				t.Logf("Considering metric family %s", mf.String())
   267  				assert.Equalf(t, 3, len(mf.GetMetric()), "Got %v metrics, wanted 3 as the count for family %#+v", len(mf.GetMetric()), mf)
   268  				for _, m := range mf.GetMetric() {
   269  					expectedCount := uint64(dt1)
   270  					expectedSum := float64(dt1) * v0
   271  					assert.Equalf(t, expectedCount, m.GetHistogram().GetSampleCount(), "Got %v, expected histogram sample count to equal %d for metric %s", m.GetHistogram().GetSampleCount(), expectedCount, m.String())
   272  					assert.Equalf(t, expectedSum, m.GetHistogram().GetSampleSum(), "Got %v, expected histogram sample sum to equal %v for metric %s", m.GetHistogram().GetSampleSum(), expectedSum, m.String())
   273  				}
   274  			}
   275  		})
   276  	}
   277  }
   278  
   279  func TestTimingHistogramWithLabelValueAllowList(t *testing.T) {
   280  	labelAllowValues := map[string]string{
   281  		"namespace_subsystem_metric_allowlist_test,label_a": "allowed",
   282  	}
   283  	labels := []string{"label_a", "label_b"}
   284  	opts := &TimingHistogramOpts{
   285  		Namespace:    "namespace",
   286  		Name:         "metric_allowlist_test",
   287  		Subsystem:    "subsystem",
   288  		InitialValue: 7,
   289  	}
   290  	var tests = []struct {
   291  		desc               string
   292  		labelValues        [][]string
   293  		expectMetricValues map[string]uint64
   294  	}{
   295  		{
   296  			desc:        "Test no unexpected input",
   297  			labelValues: [][]string{{"allowed", "b1"}, {"allowed", "b2"}},
   298  			expectMetricValues: map[string]uint64{
   299  				"allowed b1": 1.0,
   300  				"allowed b2": 1.0,
   301  			},
   302  		},
   303  		{
   304  			desc:        "Test unexpected input",
   305  			labelValues: [][]string{{"allowed", "b1"}, {"not_allowed", "b1"}},
   306  			expectMetricValues: map[string]uint64{
   307  				"allowed b1":    1.0,
   308  				"unexpected b1": 1.0,
   309  			},
   310  		},
   311  	}
   312  
   313  	for _, test := range tests {
   314  		t.Run(test.desc, func(t *testing.T) {
   315  			SetLabelAllowListFromCLI(labelAllowValues)
   316  			registry := newKubeRegistry(apimachineryversion.Info{
   317  				Major:      "1",
   318  				Minor:      "15",
   319  				GitVersion: "v1.15.0-alpha-1.12345",
   320  			})
   321  			t0 := time.Now()
   322  			clk := testclock.NewFakePassiveClock(t0)
   323  			c := NewTestableTimingHistogramVec(clk.Now, opts, labels)
   324  			registry.MustRegister(c)
   325  			var v0 float64 = 13
   326  			for _, lv := range test.labelValues {
   327  				c.WithLabelValues(lv...).Set(v0)
   328  			}
   329  
   330  			dt1 := 3 * time.Hour
   331  			t1 := t0.Add(dt1)
   332  			clk.SetTime(t1)
   333  
   334  			for _, lv := range test.labelValues {
   335  				c.WithLabelValues(lv...).Add(1.0)
   336  			}
   337  			mfs, err := registry.Gather()
   338  			assert.Nil(t, err, "Gather failed %v", err)
   339  
   340  			for _, mf := range mfs {
   341  				if *mf.Name != BuildFQName(opts.Namespace, opts.Subsystem, opts.Name) {
   342  					continue
   343  				}
   344  				mfMetric := mf.GetMetric()
   345  				t.Logf("Consider metric family %s", mf.GetName())
   346  
   347  				for _, m := range mfMetric {
   348  					var aValue, bValue string
   349  					for _, l := range m.Label {
   350  						if *l.Name == "label_a" {
   351  							aValue = *l.Value
   352  						}
   353  						if *l.Name == "label_b" {
   354  							bValue = *l.Value
   355  						}
   356  					}
   357  					labelValuePair := aValue + " " + bValue
   358  					expectedCount, ok := test.expectMetricValues[labelValuePair]
   359  					assert.True(t, ok, "Got unexpected label values, lable_a is %v, label_b is %v", aValue, bValue)
   360  					expectedSum := float64(dt1) * v0 * float64(expectedCount)
   361  					expectedCount *= uint64(dt1)
   362  					actualCount := m.GetHistogram().GetSampleCount()
   363  					actualSum := m.GetHistogram().GetSampleSum()
   364  					assert.Equalf(t, expectedCount, actualCount, "Got %v, wanted %v as the count while setting label_a to %v and label b to %v", actualCount, expectedCount, aValue, bValue)
   365  					assert.Equalf(t, expectedSum, actualSum, "Got %v, wanted %v as the sum while setting label_a to %v and label b to %v", actualSum, expectedSum, aValue, bValue)
   366  				}
   367  			}
   368  		})
   369  	}
   370  }
   371  
   372  func BenchmarkTimingHistogram(b *testing.B) {
   373  	b.StopTimer()
   374  	now := time.Now()
   375  	th := NewTestableTimingHistogram(func() time.Time { return now }, &TimingHistogramOpts{
   376  		Namespace:    "testns",
   377  		Subsystem:    "testsubsys",
   378  		Name:         "testhist",
   379  		Help:         "Me",
   380  		Buckets:      []float64{1, 2, 4, 8, 16},
   381  		InitialValue: 3,
   382  	})
   383  	registry := NewKubeRegistry()
   384  	registry.MustRegister(th)
   385  	var x int
   386  	b.StartTimer()
   387  	for i := 0; i < b.N; i++ {
   388  		now = now.Add(time.Duration(31-x) * time.Microsecond)
   389  		th.Set(float64(x))
   390  		x = (x + i) % 23
   391  	}
   392  }
   393  
   394  func BenchmarkTimingHistogramVecEltCached(b *testing.B) {
   395  	b.StopTimer()
   396  	now := time.Now()
   397  	hv := NewTestableTimingHistogramVec(func() time.Time { return now }, &TimingHistogramOpts{
   398  		Namespace:    "testns",
   399  		Subsystem:    "testsubsys",
   400  		Name:         "testhist",
   401  		Help:         "Me",
   402  		Buckets:      []float64{1, 2, 4, 8, 16},
   403  		InitialValue: 3,
   404  	},
   405  		[]string{"label1", "label2"})
   406  	registry := NewKubeRegistry()
   407  	registry.MustRegister(hv)
   408  	th, err := hv.WithLabelValuesChecked("v1", "v2")
   409  	if err != nil {
   410  		b.Error(err)
   411  	}
   412  	var x int
   413  	b.StartTimer()
   414  	for i := 0; i < b.N; i++ {
   415  		now = now.Add(time.Duration(31-x) * time.Microsecond)
   416  		th.Set(float64(x))
   417  		x = (x + i) % 23
   418  	}
   419  }
   420  
   421  func BenchmarkTimingHistogramVecEltFetched(b *testing.B) {
   422  	b.StopTimer()
   423  	now := time.Now()
   424  	hv := NewTestableTimingHistogramVec(func() time.Time { return now }, &TimingHistogramOpts{
   425  		Namespace:    "testns",
   426  		Subsystem:    "testsubsys",
   427  		Name:         "testhist",
   428  		Help:         "Me",
   429  		Buckets:      []float64{1, 2, 4, 8, 16},
   430  		InitialValue: 3,
   431  	},
   432  		[]string{"label1", "label2"})
   433  	registry := NewKubeRegistry()
   434  	registry.MustRegister(hv)
   435  	var x int
   436  	b.StartTimer()
   437  	for i := 0; i < b.N; i++ {
   438  		now = now.Add(time.Duration(31-x) * time.Microsecond)
   439  		hv.WithLabelValues("v1", "v2").Set(float64(x))
   440  		x = (x + i) % 60
   441  	}
   442  }
   443  
   444  func TestUnregisteredVec(t *testing.T) {
   445  	hv := NewTestableTimingHistogramVec(time.Now, &TimingHistogramOpts{
   446  		Namespace:    "testns",
   447  		Subsystem:    "testsubsys",
   448  		Name:         "testhist",
   449  		Help:         "Me",
   450  		Buckets:      []float64{1, 2, 4, 8, 16},
   451  		InitialValue: 3,
   452  	},
   453  		[]string{"label1", "label2"})
   454  	gauge, err := hv.WithLabelValuesChecked("v1", "v2")
   455  	if gauge != noop {
   456  		t.Errorf("Expected noop but got %#+v", gauge)
   457  	}
   458  	if !ErrIsNotRegistered(err) {
   459  		t.Errorf("Expected errNotRegistered but got err=%v", err)
   460  	}
   461  }
   462  
   463  func TestBadValues(t *testing.T) {
   464  	hv := NewTestableTimingHistogramVec(time.Now, &TimingHistogramOpts{
   465  		Namespace:    "testns",
   466  		Subsystem:    "testsubsys",
   467  		Name:         "testhist",
   468  		Help:         "Me",
   469  		Buckets:      []float64{1, 2, 4, 8, 16},
   470  		InitialValue: 3,
   471  	},
   472  		[]string{"label1", "label2"})
   473  	registry := NewKubeRegistry()
   474  	registry.MustRegister(hv)
   475  	gauge, err := hv.WithLabelValuesChecked("v1")
   476  	if gauge != noop {
   477  		t.Errorf("Expected noop but got %#+v", gauge)
   478  	}
   479  	if err == nil {
   480  		t.Error("Expected an error but got nil")
   481  	}
   482  	if ErrIsNotRegistered(err) {
   483  		t.Error("Expected an error other than errNotRegistered but got that one")
   484  	}
   485  }
   486  

View as plain text