Change the Timer API

This finally makes the (presumably) common simple case as simple as it
gets.

The still quite common (but less common) case of using a Gauge is
slightly more verbose now, but not needing to provide a separate
constructor is totally worth it.

Finally, the advanced use case is not really more verbose as in my
original suggestion. However, the logic to decide which Observer to
use is now all in the ObserverFunc handed in at construction
time. This is deliberate and desired. It makes sure the selection
mechanism is all spelled out there. No surprises buried deep in the
function code somewhere.

prometheus/example_timer_batch_test.go

@@ -0,0 +1,48 @@
+// Copyright 2014 The Prometheus Authors
+// 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 prometheus_test
+
+import (
+	"time"
+
+	"github.com/prometheus/client_golang/prometheus"
+)
+
+var (
+	// For periodic or batch processes that run much less frequently than
+	// the Prometheus scrape, it makes sense to use a Gauge to observe the
+	// duration.
+	// See https://prometheus.io/docs/practices/instrumentation/#batch-jobs
+	batchDuration = prometheus.NewGauge(prometheus.GaugeOpts{
+		Name: "example_batch_duration_seconds",
+		Help: "Duration of the last batch run.",
+	})
+)
+
+func performBatch() {
+	// The Set method of the Gauge is used to observe the duration.
+	timer := prometheus.NewTimer(prometheus.ObserverFunc(batchDuration.Set))
+	defer timer.ObserveDuration()
+
+	// Actually perform the batch of work.
+	// ...
+}
+
+func ExampleTimer_batch() {
+	// 10m is much longer than the usual scrape interval of Prometheus.
+	c := time.Tick(10 * time.Minute)
+	for _ = range c {
+		performBatch()
+	}
+}

prometheus/example_timer_complex_test.go

@@ -0,0 +1,69 @@
+// Copyright 2014 The Prometheus Authors
+// 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 prometheus_test
+
+import (
+	"net/http"
+
+	"github.com/prometheus/client_golang/prometheus"
+)
+
+var (
+	// apiRequestDuration tracks the duration separate for each HTTP status
+	// class (1xx, 2xx, ...). This creates a fair amount of time series on
+	// the Prometheus server. Usually, you would track the duration of
+	// serving HTTP request without partitioning by outcome. Do something
+	// like this only if needed. Also note how only status classes are
+	// tracked, not every single status code. The latter would create an
+	// even larger amount of time series. Request counters partitioned by
+	// status code are usually OK as each counter only creates one time
+	// series. Histograms are way more expensive, so partition with care and
+	// only where you really need separate latency tracking.
+	apiRequestDuration = prometheus.NewHistogramVec(
+		prometheus.HistogramOpts{
+			Name:    "api_request_duration_seconds",
+			Help:    "Histogram for the request duration of the public API, partitioned by status class.",
+			Buckets: prometheus.ExponentialBuckets(0.1, 1.5, 5),
+		},
+		[]string{"status_class"},
+	)
+)
+
+func handler(w http.ResponseWriter, r *http.Request) {
+	status := http.StatusOK
+	// The ObserverFunc gets called by the deferred ObserveDuration and
+	// decides wich Histogram's Observe method is called.
+	timer := prometheus.NewTimer(prometheus.ObserverFunc(func(v float64) {
+		switch {
+		case status >= http.StatusInternalServerError:
+			apiRequestDuration.WithLabelValues("5xx").Observe(v)
+		case status >= http.StatusBadRequest:
+			apiRequestDuration.WithLabelValues("4xx").Observe(v)
+		case status >= http.StatusMultipleChoices:
+			apiRequestDuration.WithLabelValues("3xx").Observe(v)
+		case status >= http.StatusOK:
+			apiRequestDuration.WithLabelValues("2xx").Observe(v)
+		default:
+			apiRequestDuration.WithLabelValues("1xx").Observe(v)
+		}
+	}))
+	defer timer.ObserveDuration()
+
+	// Handle the request. Set status accordingly.
+	// ...
+}
+
+func ExampleTimer_complex() {
+	http.HandleFunc("/api", handler)
+}

prometheus/example_timer_test.go

@@ -0,0 +1,40 @@
+// Copyright 2014 The Prometheus Authors
+// 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 prometheus_test
+
+import (
+	"math/rand"
+	"time"
+
+	"github.com/prometheus/client_golang/prometheus"
+)
+
+var (
+	requestDuration = prometheus.NewHistogram(prometheus.HistogramOpts{
+		Name:    "example_request_duration_seconds",
+		Help:    "Histogram for the runtime of a simple example function.",
+		Buckets: prometheus.LinearBuckets(0.01, 0.01, 10),
+	})
+)
+
+func ExampleTimer() {
+	// timer times this example function. It uses a Histogram, but a Summary
+	// would also work, as both implement Observer. Check out
+	// https://prometheus.io/docs/practices/histograms/ for differences.
+	timer := prometheus.NewTimer(requestDuration)
+	defer timer.ObserveDuration()
+
+	// Do something here that takes time.
+	time.Sleep(time.Duration(rand.NormFloat64()*10000+50000) * time.Microsecond)
+}

prometheus/timer.go

@@ -15,83 +15,58 @@ package prometheus
 
 import "time"
 
-// Observer is the interface that wraps the Observe method, used by Histogram
+// Observer is the interface that wraps the Observe method, which is used by
-// and Summary to add observations.
+// Histogram and Summary to add observations.
 type Observer interface {
 	Observe(float64)
 }
 
-// observerFunc is a function that implements Observer.
+// The ObserverFunc type is an adapter to allow the use of ordinary
-type observerFunc func(float64)
+// functions as Observers. If f is a function with the appropriate
+// signature, ObserverFunc(f) is an Observer that calls f.
+//
+// This adapter is usually used in connection with the Timer type, and there are
+// two general use cases:
+//
+// The most common one is to use a Gauge as the Observer for a Timer.
+// See the "Batch" Timer example.
+//
+// The more advanced use case is to create a function that dynamically decides
+// which Observer to use for observing the duration. See the "Complex" Timer
+// example.
+type ObserverFunc func(float64)
 
-func (o observerFunc) Observe(value float64) {
+// Observe calls f(value). It implements Observer.
-	o(value)
+func (f ObserverFunc) Observe(value float64) {
+	f(value)
 }
 
 // Timer is a helper type to time functions. Use NewTimer to create new
-// instances. The most common usage pattern is to time a function with a
+// instances.
-// Histogram in the following way:
-//    func timeMe() {
-//        t := NewTimer().With(myHistogram)
-//        defer t.ObserveDuration()
-//        // Do something.
-//    }
-// See the documentation of the methods for special cases.
 type Timer struct {
 	begin    time.Time
 	observer Observer
 }
 
-// NewTimer creates a new Timer. To time anything, an Observer (i.e. a Histogram
+// NewTimer creates a new Timer. The provided Observer is used to observe a
-// or a Summary) or a Gague has to be bound to it, the former with the With
+// duration in seconds. Timer is usually used to time a function call in the
-// method, the latter with the WithGauge method.
+// following way:
-func NewTimer() *Timer {
+//    func TimeMe() {
-	return &Timer{begin: time.Now()}
+//        timer := NewTimer(myHistogram)
+//        defer timer.ObserveDuration()
+//        // Do actual work.
+//    }
+func NewTimer(o Observer) *Timer {
+	return &Timer{
+		begin:    time.Now(),
+		observer: o,
+	}
 }
 
-// With binds an Observer (i.e. a Histogram or a Summary) to the Timer and
+// ObserveDuration records the duration passed since the Timer was created with
-// returns the Timer for convenience. In most cases, the Observer to be used is
+// NewTimer. It calls the Observe method of the Observer provided during
-// already known at construction time, so it can be set immediately:
+// construction with the duration in seconds as an argument. ObserveDuration is
-//     t := NewTimer().With(myObserver)
+// usually called with a defer statement.
-//
-// With can also be called later, to bind an Observer for the first time or to
-// change the bound Observer. It can be called with nil to unbind a previously
-// bound Observer. Both is useful for recording with different Observers (or
-// none) depending on the outcome of the timed function. Note that timing
-// depending on the outcome can be confusing and should only be used after
-// careful consideration.
-//
-// The ObserveDuration method of the Timer records the duration by calling the
-// Observe method of the bound Observer with the time elapsed since NewTimer was
-// called (in seconds).
-//
-// Note that a Gauge bound with WithGauge overrides the Observer bound with With
-// and vice versa.
-func (t *Timer) With(o Observer) *Timer {
-	t.observer = o
-	return t
-}
-
-// WithGauge binds a Gauge to the Timer and returns the Timer for
-// convenience. This works in the same way as With works for Observers. To
-// record the time, the Set method of the Gauge is called (with the recorded
-// duration in seconds). Note that timing with Gauges is only useful for events
-// that happen less frequently than the scrape interval or for one-shot batch
-// jobs (where the recorded duration is pushed to a Pushgateway).
-//
-// Note that a Gauge bound with WithGauge overrides the Observer bound with With
-// and vice versa.
-func (t *Timer) WithGauge(g Gauge) *Timer {
-	t.observer = observerFunc(g.Set)
-	return t
-}
-
-// ObserveDuration records the duration passed since NewTimer was called. If an
-// Observer has been bound with the With method, ObserveDuration calls its
-// Observe method with the duration in seconds as an argument. If a Gauge has
-// been bound with the WithGauge method, ObserveDuration calls its Set method
-// with the duration in seconds as an argument. ObserveDuration is usually
-// called with a defer statement.
 func (t *Timer) ObserveDuration() {
 	if t.observer != nil {
 		t.observer.Observe(time.Since(t.begin).Seconds())

prometheus/timer_test.go

@@ -20,20 +20,16 @@ import (
 )
 
 func TestTimerObserve(t *testing.T) {
-	his := NewHistogram(HistogramOpts{
+	var (
-		Name: "test_histogram",
+		his   = NewHistogram(HistogramOpts{Name: "test_histogram"})
-	})
+		sum   = NewSummary(SummaryOpts{Name: "test_summary"})
-	sum := NewSummary(SummaryOpts{
+		gauge = NewGauge(GaugeOpts{Name: "test_gauge"})
-		Name: "test_summary",
+	)
-	})
-	gauge := NewGauge(GaugeOpts{
-		Name: "test_gauge",
-	})
 
 	func() {
-		hisTimer := NewTimer().With(his)
+		hisTimer := NewTimer(his)
-		sumTimer := NewTimer().With(sum)
+		sumTimer := NewTimer(sum)
-		gaugeTimer := NewTimer().WithGauge(gauge)
+		gaugeTimer := NewTimer(ObserverFunc(gauge.Set))
 		defer hisTimer.ObserveDuration()
 		defer sumTimer.ObserveDuration()
 		defer gaugeTimer.ObserveDuration()
@@ -57,51 +53,100 @@ func TestTimerObserve(t *testing.T) {
 }
 
 func TestTimerEmpty(t *testing.T) {
-	emptyTimer := NewTimer()
+	emptyTimer := NewTimer(nil)
 	emptyTimer.ObserveDuration()
 	// Do nothing, just demonstrate it works without panic.
 }
 
-func TestTimerUnset(t *testing.T) {
+func TestTimerConditionalTiming(t *testing.T) {
-	his := NewHistogram(HistogramOpts{
+	var (
-		Name: "test_histogram",
+		his = NewHistogram(HistogramOpts{
-	})
+			Name: "test_histogram",
+		})
+		timeMe = true
+		m      = &dto.Metric{}
+	)
 
-	func() {
+	timedFunc := func() {
-		timer := NewTimer().With(his)
+		timer := NewTimer(ObserverFunc(func(v float64) {
+			if timeMe {
+				his.Observe(v)
+			}
+		}))
 		defer timer.ObserveDuration()
-		timer.With(nil)
+	}
-	}()
 
-	m := &dto.Metric{}
+	timedFunc() // This will time.
 	his.Write(m)
-	if want, got := uint64(0), m.GetHistogram().GetSampleCount(); want != got {
+	if want, got := uint64(1), m.GetHistogram().GetSampleCount(); want != got {
+		t.Errorf("want %d observations for histogram, got %d", want, got)
+	}
+
+	timeMe = false
+	timedFunc() // This will not time again.
+	m.Reset()
+	his.Write(m)
+	if want, got := uint64(1), m.GetHistogram().GetSampleCount(); want != got {
 		t.Errorf("want %d observations for histogram, got %d", want, got)
 	}
 }
 
-func TestTimerChange(t *testing.T) {
+func TestTimerByOutcome(t *testing.T) {
-	his := NewHistogram(HistogramOpts{
+	var (
-		Name: "test_histogram",
+		his = NewHistogramVec(
-	})
+			HistogramOpts{Name: "test_histogram"},
-	sum := NewSummary(SummaryOpts{
+			[]string{"outcome"},
-		Name: "test_summary",
+		)
-	})
+		outcome = "foo"
+		m       = &dto.Metric{}
+	)
 
-	func() {
+	timedFunc := func() {
-		timer := NewTimer().With(his)
+		timer := NewTimer(ObserverFunc(func(v float64) {
+			his.WithLabelValues(outcome).Observe(v)
+		}))
 		defer timer.ObserveDuration()
-		timer.With(sum)
-	}()
 
-	m := &dto.Metric{}
+		if outcome == "foo" {
-	his.Write(m)
+			outcome = "bar"
+			return
+		}
+		outcome = "foo"
+	}
+
+	timedFunc()
+	his.WithLabelValues("foo").Write(m)
 	if want, got := uint64(0), m.GetHistogram().GetSampleCount(); want != got {
-		t.Errorf("want %d observations for histogram, got %d", want, got)
+		t.Errorf("want %d observations for 'foo' histogram, got %d", want, got)
 	}
 	m.Reset()
-	sum.Write(m)
+	his.WithLabelValues("bar").Write(m)
-	if want, got := uint64(1), m.GetSummary().GetSampleCount(); want != got {
+	if want, got := uint64(1), m.GetHistogram().GetSampleCount(); want != got {
-		t.Errorf("want %d observations for summary, got %d", want, got)
+		t.Errorf("want %d observations for 'bar' histogram, got %d", want, got)
 	}
+
+	timedFunc()
+	m.Reset()
+	his.WithLabelValues("foo").Write(m)
+	if want, got := uint64(1), m.GetHistogram().GetSampleCount(); want != got {
+		t.Errorf("want %d observations for 'foo' histogram, got %d", want, got)
+	}
+	m.Reset()
+	his.WithLabelValues("bar").Write(m)
+	if want, got := uint64(1), m.GetHistogram().GetSampleCount(); want != got {
+		t.Errorf("want %d observations for 'bar' histogram, got %d", want, got)
+	}
+
+	timedFunc()
+	m.Reset()
+	his.WithLabelValues("foo").Write(m)
+	if want, got := uint64(1), m.GetHistogram().GetSampleCount(); want != got {
+		t.Errorf("want %d observations for 'foo' histogram, got %d", want, got)
+	}
+	m.Reset()
+	his.WithLabelValues("bar").Write(m)
+	if want, got := uint64(2), m.GetHistogram().GetSampleCount(); want != got {
+		t.Errorf("want %d observations for 'bar' histogram, got %d", want, got)
+	}
+
 }