Extend Counters, Summaries and Histograms with creation timestamp (#1313

)

* Extend Counters, Summaries and Histograms with creation timestamp

Signed-off-by: Arthur Silva Sens <[email protected]>

* Backport created timestamp to existing tests

Signed-off-by: Arthur Silva Sens <[email protected]>

* Last touches (readability and consistency)

Changes:

* Comments for "now" are more explicit and not inlined.
* populateMetrics is simpler and bit more efficient without timestamp to time to timestamp conversionts for more common code.
* Test consistency and simplicity - the fewer variables the better.
* Fixed inconsistency for v2 and MetricVec - let's pass opt.now consistently.
* We don't need TestCounterXXXTimestamp - we test CT in many other places already.
* Added more involved test for counter vectors with created timestamp.
* Refactored normalization for simplicity.
* Make histogram, summaries now consistent.
* Simplified histograms CT flow and implemented proper CT on reset.

TODO for next PRs:
* NewConstSummary and NewConstHistogram - ability to specify CTs there.

Signed-off-by: bwplotka <[email protected]>

* Update prometheus/counter_test.go

Co-authored-by: Arthur Silva Sens <[email protected]>
Signed-off-by: Bartlomiej Plotka <[email protected]>

---------

Signed-off-by: Arthur Silva Sens <[email protected]>
Signed-off-by: bwplotka <[email protected]>
Signed-off-by: Bartlomiej Plotka <[email protected]>
Co-authored-by: bwplotka <[email protected]>

go.mod

@@ -7,7 +7,7 @@ require (
 	github.com/cespare/xxhash/v2 v2.2.0
 	github.com/davecgh/go-spew v1.1.1
 	github.com/json-iterator/go v1.1.12
-	github.com/prometheus/client_model v0.4.0
+	github.com/prometheus/client_model v0.4.1-0.20230718164431-9a2bf3000d16
 	github.com/prometheus/common v0.44.0
 	github.com/prometheus/procfs v0.11.1
 	golang.org/x/sys v0.11.0

go.sum

@@ -34,8 +34,8 @@ github.com/mwitkow/go-conntrack v0.0.0-20190716064945-2f068394615f/go.mod h1:qRW
 github.com/pkg/diff v0.0.0-20210226163009-20ebb0f2a09e/go.mod h1:pJLUxLENpZxwdsKMEsNbx1VGcRFpLqf3715MtcvvzbA=
 github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM=
 github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4=
-github.com/prometheus/client_model v0.4.0 h1:5lQXD3cAg1OXBf4Wq03gTrXHeaV0TQvGfUooCfx1yqY=
-github.com/prometheus/client_model v0.4.0/go.mod h1:oMQmHW1/JoDwqLtg57MGgP/Fb1CJEYF2imWWhWtMkYU=
+github.com/prometheus/client_model v0.4.1-0.20230718164431-9a2bf3000d16 h1:v7DLqVdK4VrYkVD5diGdl4sxJurKJEMnODWRJlxV9oM=
+github.com/prometheus/client_model v0.4.1-0.20230718164431-9a2bf3000d16/go.mod h1:oMQmHW1/JoDwqLtg57MGgP/Fb1CJEYF2imWWhWtMkYU=
 github.com/prometheus/common v0.44.0 h1:+5BrQJwiBB9xsMygAB3TNvpQKOwlkc25LbISbrdOOfY=
 github.com/prometheus/common v0.44.0/go.mod h1:ofAIvZbQ1e/nugmZGz4/qCb9Ap1VoSTIO7x0VV9VvuY=
 github.com/prometheus/procfs v0.11.1 h1:xRC8Iq1yyca5ypa9n1EZnWZkt7dwcoRPQwX/5gwaUuI=

prometheus/counter.go

@@ -20,6 +20,7 @@ import (
 	"time"
 
 	dto "github.com/prometheus/client_model/go"
+	"google.golang.org/protobuf/types/known/timestamppb"
 )
 
 // Counter is a Metric that represents a single numerical value that only ever
@@ -90,8 +91,12 @@ func NewCounter(opts CounterOpts) Counter {
 		nil,
 		opts.ConstLabels,
 	)
-	result := &counter{desc: desc, labelPairs: desc.constLabelPairs, now: time.Now}
+	if opts.now == nil {
+		opts.now = time.Now
+	}
+	result := &counter{desc: desc, labelPairs: desc.constLabelPairs, now: opts.now}
 	result.init(result) // Init self-collection.
+	result.createdTs = timestamppb.New(opts.now())
 	return result
 }
 
@@ -106,10 +111,12 @@ type counter struct {
 	selfCollector
 	desc *Desc
 
+	createdTs  *timestamppb.Timestamp
 	labelPairs []*dto.LabelPair
 	exemplar   atomic.Value // Containing nil or a *dto.Exemplar.
 
-	now func() time.Time // To mock out time.Now() for testing.
+	// now is for testing purposes, by default it's time.Now.
+	now func() time.Time
 }
 
 func (c *counter) Desc() *Desc {
@@ -159,8 +166,7 @@ func (c *counter) Write(out *dto.Metric) error {
 		exemplar = e.(*dto.Exemplar)
 	}
 	val := c.get()
-
-	return populateMetric(CounterValue, val, c.labelPairs, exemplar, out)
+	return populateMetric(CounterValue, val, c.labelPairs, exemplar, out, c.createdTs)
 }
 
 func (c *counter) updateExemplar(v float64, l Labels) {
@@ -200,13 +206,17 @@ func (v2) NewCounterVec(opts CounterVecOpts) *CounterVec {
 		opts.VariableLabels,
 		opts.ConstLabels,
 	)
+	if opts.now == nil {
+		opts.now = time.Now
+	}
 	return &CounterVec{
 		MetricVec: NewMetricVec(desc, func(lvs ...string) Metric {
 			if len(lvs) != len(desc.variableLabels.names) {
 				panic(makeInconsistentCardinalityError(desc.fqName, desc.variableLabels.names, lvs))
 			}
-			result := &counter{desc: desc, labelPairs: MakeLabelPairs(desc, lvs), now: time.Now}
+			result := &counter{desc: desc, labelPairs: MakeLabelPairs(desc, lvs), now: opts.now}
 			result.init(result) // Init self-collection.
+			result.createdTs = timestamppb.New(opts.now())
 			return result
 		}),
 	}

prometheus/counter_test.go

@@ -26,10 +26,13 @@ import (
 )
 
 func TestCounterAdd(t *testing.T) {
+	now := time.Now()
+
 	counter := NewCounter(CounterOpts{
 		Name:        "test",
 		Help:        "test help",
 		ConstLabels: Labels{"a": "1", "b": "2"},
+		now:         func() time.Time { return now },
 	}).(*counter)
 	counter.Inc()
 	if expected, got := 0.0, math.Float64frombits(counter.valBits); expected != got {
@@ -66,7 +69,10 @@ func TestCounterAdd(t *testing.T) {
 			{Name: proto.String("a"), Value: proto.String("1")},
 			{Name: proto.String("b"), Value: proto.String("2")},
 		},
-		Counter: &dto.Counter{Value: proto.Float64(67.42)},
+		Counter: &dto.Counter{
+			Value:            proto.Float64(67.42),
+			CreatedTimestamp: timestamppb.New(now),
+		},
 	}
 	if !proto.Equal(expected, m) {
 		t.Errorf("expected %q, got %q", expected, m)
@@ -139,9 +145,12 @@ func expectPanic(t *testing.T, op func(), errorMsg string) {
 }
 
 func TestCounterAddInf(t *testing.T) {
+	now := time.Now()
+
 	counter := NewCounter(CounterOpts{
 		Name: "test",
 		Help: "test help",
+		now:  func() time.Time { return now },
 	}).(*counter)
 
 	counter.Inc()
@@ -173,7 +182,8 @@ func TestCounterAddInf(t *testing.T) {
 
 	expected := &dto.Metric{
 		Counter: &dto.Counter{
-			Value: proto.Float64(math.Inf(1)),
+			Value:            proto.Float64(math.Inf(1)),
+			CreatedTimestamp: timestamppb.New(now),
 		},
 	}
 
@@ -183,9 +193,12 @@ func TestCounterAddInf(t *testing.T) {
 }
 
 func TestCounterAddLarge(t *testing.T) {
+	now := time.Now()
+
 	counter := NewCounter(CounterOpts{
 		Name: "test",
 		Help: "test help",
+		now:  func() time.Time { return now },
 	}).(*counter)
 
 	// large overflows the underlying type and should therefore be stored in valBits.
@@ -203,7 +216,8 @@ func TestCounterAddLarge(t *testing.T) {
 
 	expected := &dto.Metric{
 		Counter: &dto.Counter{
-			Value: proto.Float64(large),
+			Value:            proto.Float64(large),
+			CreatedTimestamp: timestamppb.New(now),
 		},
 	}
 
@@ -213,10 +227,14 @@ func TestCounterAddLarge(t *testing.T) {
 }
 
 func TestCounterAddSmall(t *testing.T) {
+	now := time.Now()
+
 	counter := NewCounter(CounterOpts{
 		Name: "test",
 		Help: "test help",
+		now:  func() time.Time { return now },
 	}).(*counter)
+
 	small := 0.000000000001
 	counter.Add(small)
 	if expected, got := small, math.Float64frombits(counter.valBits); expected != got {
@@ -231,7 +249,8 @@ func TestCounterAddSmall(t *testing.T) {
 
 	expected := &dto.Metric{
 		Counter: &dto.Counter{
-			Value: proto.Float64(small),
+			Value:            proto.Float64(small),
+			CreatedTimestamp: timestamppb.New(now),
 		},
 	}
 
@@ -246,8 +265,8 @@ func TestCounterExemplar(t *testing.T) {
 	counter := NewCounter(CounterOpts{
 		Name: "test",
 		Help: "test help",
+		now:  func() time.Time { return now },
 	}).(*counter)
-	counter.now = func() time.Time { return now }
 
 	ts := timestamppb.New(now)
 	if err := ts.CheckValid(); err != nil {
@@ -298,3 +317,72 @@ func TestCounterExemplar(t *testing.T) {
 		t.Error("adding exemplar with oversized labels succeeded")
 	}
 }
+
+func TestCounterVecCreatedTimestampWithDeletes(t *testing.T) {
+	now := time.Now()
+
+	counterVec := NewCounterVec(CounterOpts{
+		Name: "test",
+		Help: "test help",
+		now:  func() time.Time { return now },
+	}, []string{"label"})
+
+	// First use of "With" should populate CT.
+	counterVec.WithLabelValues("1")
+	expected := map[string]time.Time{"1": now}
+
+	now = now.Add(1 * time.Hour)
+	expectCTsForMetricVecValues(t, counterVec.MetricVec, dto.MetricType_COUNTER, expected)
+
+	// Two more labels at different times.
+	counterVec.WithLabelValues("2")
+	expected["2"] = now
+
+	now = now.Add(1 * time.Hour)
+
+	counterVec.WithLabelValues("3")
+	expected["3"] = now
+
+	now = now.Add(1 * time.Hour)
+	expectCTsForMetricVecValues(t, counterVec.MetricVec, dto.MetricType_COUNTER, expected)
+
+	// Recreate metric instance should reset created timestamp to now.
+	counterVec.DeleteLabelValues("1")
+	counterVec.WithLabelValues("1")
+	expected["1"] = now
+
+	now = now.Add(1 * time.Hour)
+	expectCTsForMetricVecValues(t, counterVec.MetricVec, dto.MetricType_COUNTER, expected)
+}
+
+func expectCTsForMetricVecValues(t testing.TB, vec *MetricVec, typ dto.MetricType, ctsPerLabelValue map[string]time.Time) {
+	t.Helper()
+
+	for val, ct := range ctsPerLabelValue {
+		var metric dto.Metric
+		m, err := vec.GetMetricWithLabelValues(val)
+		if err != nil {
+			t.Fatal(err)
+		}
+
+		if err := m.Write(&metric); err != nil {
+			t.Fatal(err)
+		}
+
+		var gotTs time.Time
+		switch typ {
+		case dto.MetricType_COUNTER:
+			gotTs = metric.Counter.CreatedTimestamp.AsTime()
+		case dto.MetricType_HISTOGRAM:
+			gotTs = metric.Histogram.CreatedTimestamp.AsTime()
+		case dto.MetricType_SUMMARY:
+			gotTs = metric.Summary.CreatedTimestamp.AsTime()
+		default:
+			t.Fatalf("unknown metric type %v", typ)
+		}
+
+		if !gotTs.Equal(ct) {
+			t.Errorf("expected created timestamp for %s with label value %q: %s, got %s", typ, val, ct, gotTs)
+		}
+	}
+}

prometheus/example_metricvec_test.go

@@ -14,6 +14,8 @@
 package prometheus_test
 
 import (
+	"fmt"
+
 	"google.golang.org/protobuf/proto"
 
 	dto "github.com/prometheus/client_model/go"
@@ -124,7 +126,7 @@ func ExampleMetricVec() {
 	if err != nil || len(metricFamilies) != 1 {
 		panic("unexpected behavior of custom test registry")
 	}
-	printlnNormalized(metricFamilies[0])
+	fmt.Println(toNormalizedJSON(metricFamilies[0]))
 
 	// Output:
 	// {"name":"library_version_info","help":"Versions of the libraries used in this binary.","type":"GAUGE","metric":[{"label":[{"name":"library","value":"k8s.io/client-go"},{"name":"version","value":"0.18.8"}],"gauge":{"value":1}},{"label":[{"name":"library","value":"prometheus/client_golang"},{"name":"version","value":"1.7.1"}],"gauge":{"value":1}}]}

prometheus/examples_test.go

@@ -153,6 +153,22 @@ func ExampleCounterVec() {
 	httpReqs.DeleteLabelValues("200", "GET")
 	// Same thing with the more verbose Labels syntax.
 	httpReqs.Delete(prometheus.Labels{"method": "GET", "code": "200"})
+
+	// Just for demonstration, let's check the state of the counter vector
+	// by registering it with a custom registry and then let it collect the
+	// metrics.
+	reg := prometheus.NewRegistry()
+	reg.MustRegister(httpReqs)
+
+	metricFamilies, err := reg.Gather()
+	if err != nil || len(metricFamilies) != 1 {
+		panic("unexpected behavior of custom test registry")
+	}
+
+	fmt.Println(toNormalizedJSON(sanitizeMetricFamily(metricFamilies[0])))
+
+	// Output:
+	// {"name":"http_requests_total","help":"How many HTTP requests processed, partitioned by status code and HTTP method.","type":"COUNTER","metric":[{"label":[{"name":"code","value":"404"},{"name":"method","value":"POST"}],"counter":{"value":42,"createdTimestamp":"1970-01-01T00:00:10Z"}}]}
 }
 
 func ExampleRegister() {
@@ -320,10 +336,10 @@ func ExampleSummary() {
 	metric := &dto.Metric{}
 	temps.Write(metric)
 
-	printlnNormalized(metric)
+	fmt.Println(toNormalizedJSON(sanitizeMetric(metric)))
 
 	// Output:
-	// {"summary":{"sampleCount":"1000","sampleSum":29969.50000000001,"quantile":[{"quantile":0.5,"value":31.1},{"quantile":0.9,"value":41.3},{"quantile":0.99,"value":41.9}]}}
+	// {"summary":{"sampleCount":"1000","sampleSum":29969.50000000001,"quantile":[{"quantile":0.5,"value":31.1},{"quantile":0.9,"value":41.3},{"quantile":0.99,"value":41.9}],"createdTimestamp":"1970-01-01T00:00:10Z"}}
 }
 
 func ExampleSummaryVec() {
@@ -355,10 +371,11 @@ func ExampleSummaryVec() {
 	if err != nil || len(metricFamilies) != 1 {
 		panic("unexpected behavior of custom test registry")
 	}
-	printlnNormalized(metricFamilies[0])
+
+	fmt.Println(toNormalizedJSON(sanitizeMetricFamily(metricFamilies[0])))
 
 	// Output:
-	// {"name":"pond_temperature_celsius","help":"The temperature of the frog pond.","type":"SUMMARY","metric":[{"label":[{"name":"species","value":"leiopelma-hochstetteri"}],"summary":{"sampleCount":"0","sampleSum":0,"quantile":[{"quantile":0.5,"value":"NaN"},{"quantile":0.9,"value":"NaN"},{"quantile":0.99,"value":"NaN"}]}},{"label":[{"name":"species","value":"lithobates-catesbeianus"}],"summary":{"sampleCount":"1000","sampleSum":31956.100000000017,"quantile":[{"quantile":0.5,"value":32.4},{"quantile":0.9,"value":41.4},{"quantile":0.99,"value":41.9}]}},{"label":[{"name":"species","value":"litoria-caerulea"}],"summary":{"sampleCount":"1000","sampleSum":29969.50000000001,"quantile":[{"quantile":0.5,"value":31.1},{"quantile":0.9,"value":41.3},{"quantile":0.99,"value":41.9}]}}]}
+	// {"name":"pond_temperature_celsius","help":"The temperature of the frog pond.","type":"SUMMARY","metric":[{"label":[{"name":"species","value":"leiopelma-hochstetteri"}],"summary":{"sampleCount":"0","sampleSum":0,"quantile":[{"quantile":0.5,"value":"NaN"},{"quantile":0.9,"value":"NaN"},{"quantile":0.99,"value":"NaN"}],"createdTimestamp":"1970-01-01T00:00:10Z"}},{"label":[{"name":"species","value":"lithobates-catesbeianus"}],"summary":{"sampleCount":"1000","sampleSum":31956.100000000017,"quantile":[{"quantile":0.5,"value":32.4},{"quantile":0.9,"value":41.4},{"quantile":0.99,"value":41.9}],"createdTimestamp":"1970-01-01T00:00:10Z"}},{"label":[{"name":"species","value":"litoria-caerulea"}],"summary":{"sampleCount":"1000","sampleSum":29969.50000000001,"quantile":[{"quantile":0.5,"value":31.1},{"quantile":0.9,"value":41.3},{"quantile":0.99,"value":41.9}],"createdTimestamp":"1970-01-01T00:00:10Z"}}]}
 }
 
 func ExampleNewConstSummary() {
@@ -382,7 +399,7 @@ func ExampleNewConstSummary() {
 	// internally).
 	metric := &dto.Metric{}
 	s.Write(metric)
-	printlnNormalized(metric)
+	fmt.Println(toNormalizedJSON(metric))
 
 	// Output:
 	// {"label":[{"name":"code","value":"200"},{"name":"method","value":"get"},{"name":"owner","value":"example"}],"summary":{"sampleCount":"4711","sampleSum":403.34,"quantile":[{"quantile":0.5,"value":42.3},{"quantile":0.9,"value":323.3}]}}
@@ -405,10 +422,11 @@ func ExampleHistogram() {
 	// internally).
 	metric := &dto.Metric{}
 	temps.Write(metric)
-	printlnNormalized(metric)
+
+	fmt.Println(toNormalizedJSON(sanitizeMetric(metric)))
 
 	// Output:
-	// {"histogram":{"sampleCount":"1000","sampleSum":29969.50000000001,"bucket":[{"cumulativeCount":"192","upperBound":20},{"cumulativeCount":"366","upperBound":25},{"cumulativeCount":"501","upperBound":30},{"cumulativeCount":"638","upperBound":35},{"cumulativeCount":"816","upperBound":40}]}}
+	// {"histogram":{"sampleCount":"1000","sampleSum":29969.50000000001,"bucket":[{"cumulativeCount":"192","upperBound":20},{"cumulativeCount":"366","upperBound":25},{"cumulativeCount":"501","upperBound":30},{"cumulativeCount":"638","upperBound":35},{"cumulativeCount":"816","upperBound":40}],"createdTimestamp":"1970-01-01T00:00:10Z"}}
 }
 
 func ExampleNewConstHistogram() {
@@ -432,7 +450,7 @@ func ExampleNewConstHistogram() {
 	// internally).
 	metric := &dto.Metric{}
 	h.Write(metric)
-	printlnNormalized(metric)
+	fmt.Println(toNormalizedJSON(metric))
 
 	// Output:
 	// {"label":[{"name":"code","value":"200"},{"name":"method","value":"get"},{"name":"owner","value":"example"}],"histogram":{"sampleCount":"4711","sampleSum":403.34,"bucket":[{"cumulativeCount":"121","upperBound":25},{"cumulativeCount":"2403","upperBound":50},{"cumulativeCount":"3221","upperBound":100},{"cumulativeCount":"4233","upperBound":200}]}}
@@ -470,7 +488,7 @@ func ExampleNewConstHistogram_WithExemplar() {
 	// internally).
 	metric := &dto.Metric{}
 	h.Write(metric)
-	printlnNormalized(metric)
+	fmt.Println(toNormalizedJSON(metric))
 
 	// Output:
 	// {"label":[{"name":"code","value":"200"},{"name":"method","value":"get"},{"name":"owner","value":"example"}],"histogram":{"sampleCount":"4711","sampleSum":403.34,"bucket":[{"cumulativeCount":"121","upperBound":25,"exemplar":{"label":[{"name":"testName","value":"testVal"}],"value":24,"timestamp":"2006-01-02T15:04:05Z"}},{"cumulativeCount":"2403","upperBound":50,"exemplar":{"label":[{"name":"testName","value":"testVal"}],"value":42,"timestamp":"2006-01-02T15:04:05Z"}},{"cumulativeCount":"3221","upperBound":100,"exemplar":{"label":[{"name":"testName","value":"testVal"}],"value":89,"timestamp":"2006-01-02T15:04:05Z"}},{"cumulativeCount":"4233","upperBound":200,"exemplar":{"label":[{"name":"testName","value":"testVal"}],"value":157,"timestamp":"2006-01-02T15:04:05Z"}}]}}
@@ -632,7 +650,7 @@ func ExampleNewMetricWithTimestamp() {
 	// internally).
 	metric := &dto.Metric{}
 	s.Write(metric)
-	printlnNormalized(metric)
+	fmt.Println(toNormalizedJSON(metric))
 
 	// Output:
 	// {"gauge":{"value":298.15},"timestampMs":"1257894000012"}

prometheus/expvar_collector_test.go

@@ -81,7 +81,7 @@ func ExampleNewExpvarCollector() {
 		if !strings.Contains(m.Desc().String(), "expvar_memstats") {
 			metric.Reset()
 			m.Write(&metric)
-			metricStrings = append(metricStrings, protoToNormalizedJSON(&metric))
+			metricStrings = append(metricStrings, toNormalizedJSON(&metric))
 		}
 	}
 	sort.Strings(metricStrings)