Consolidate backend metrics and add hedged request metric

CHANGELOG.md

@@ -1,5 +1,6 @@
 ## main / unreleased
 
+* [ENHANCEMENT] Added hedged request metric `backend_hedged_roundtrips_total` and general purpose `backend_request_duration_seconds` metric that will supersede soon to be deprecated storage specific metrics (eg `request_duration_seconds`). [#790](https://github.com/grafana/tempo/pull/790) (@JosephWoodward)
 * [CHANGE] Jsonnet: use dedicated configmaps for distributors and ingesters [#775](https://github.com/grafana/tempo/pull/775) (@kvrhdn)
 * [FEATURE] Added the ability to hedge requests with all backends [#750](https://github.com/grafana/tempo/pull/750) (@joe-elliott)
 * [ENHANCEMENT] Performance: improve compaction speed with concurrent reads and writes [#754](https://github.com/grafana/tempo/pull/754) (@mdisibio)

go.mod

@@ -10,7 +10,7 @@ require (
 	github.com/alecthomas/kong v0.2.11
 	github.com/cespare/xxhash v1.1.0
 	github.com/cortexproject/cortex v1.8.1-0.20210422151339-cf1c444e0905
-	github.com/cristalhq/hedgedhttp v0.4.0
+	github.com/cristalhq/hedgedhttp v0.6.0
 	github.com/drone/envsubst v1.0.3
 	github.com/dustin/go-humanize v1.0.0
 	github.com/go-kit/kit v0.10.0

go.sum

@@ -313,8 +313,8 @@ github.com/cpuguy83/go-md2man/v2 v2.0.0/go.mod h1:maD7wRr/U5Z6m/iR4s+kqSMx2CaBsr
 github.com/creack/pty v1.1.7/go.mod h1:lj5s0c3V2DBrqTV7llrYr5NG6My20zk30Fl46Y7DoTY=
 github.com/creack/pty v1.1.9/go.mod h1:oKZEueFk5CKHvIhNR5MUki03XCEU+Q6VDXinZuGJ33E=
 github.com/creack/pty v1.1.11/go.mod h1:oKZEueFk5CKHvIhNR5MUki03XCEU+Q6VDXinZuGJ33E=
-github.com/cristalhq/hedgedhttp v0.4.0 h1:J1z1zKJ1bEFpMLjZWgtX0inUWlWecNyouWRIQknGzgM=
-github.com/cristalhq/hedgedhttp v0.4.0/go.mod h1:XkqWU6qVMutbhW68NnzjWrGtH8NUx1UfYqGYtHVKIsI=
+github.com/cristalhq/hedgedhttp v0.6.0 h1:32REZ0SZ1q0xoRNpHP5ab+Qd3VseyURXjN3HFpBqTiE=
+github.com/cristalhq/hedgedhttp v0.6.0/go.mod h1:XkqWU6qVMutbhW68NnzjWrGtH8NUx1UfYqGYtHVKIsI=
 github.com/crossdock/crossdock-go v0.0.0-20160816171116-049aabb0122b/go.mod h1:v9FBN7gdVTpiD/+LZ7Po0UKvROyT87uLVxTHVky/dlQ=
 github.com/cznic/b v0.0.0-20180115125044-35e9bbe41f07/go.mod h1:URriBxXwVq5ijiJ12C7iIZqlA69nTlI+LgI6/pwftG8=
 github.com/cznic/fileutil v0.0.0-20180108211300-6a051e75936f/go.mod h1:8S58EK26zhXSxzv7NQFpnliaOQsmDUxvoQO3rt154Vg=

tempodb/backend/azure/azure_helpers.go

@@ -8,6 +8,8 @@ import (
 	"strings"
 	"time"
 
+	"github.com/grafana/tempo/tempodb/backend/instrumentation"
+
 	"github.com/Azure/azure-pipeline-go/pipeline"
 	blob "github.com/Azure/azure-storage-blob-go/azblob"
 	"github.com/cristalhq/hedgedhttp"
@@ -35,11 +37,13 @@ func GetContainerURL(ctx context.Context, cfg *Config, hedge bool) (blob.Contain
 	customTransport := http.DefaultTransport.(*http.Transport).Clone()
 
 	// add instrumentation
-	transport := newInstrumentedTransport(customTransport)
+	transport := instrumentation.NewAzureTransport(customTransport)
+	var stats *hedgedhttp.Stats
 
 	// hedge if desired (0 means disabled)
 	if hedge && cfg.HedgeRequestsAt != 0 {
-		transport = hedgedhttp.NewRoundTripper(cfg.HedgeRequestsAt, uptoHedgedRequests, transport)
+		transport, stats = hedgedhttp.NewRoundTripperAndStats(cfg.HedgeRequestsAt, uptoHedgedRequests, transport)
+		instrumentation.PublishHedgedMetrics(stats)
 	}
 
 	client := http.Client{Transport: transport}

tempodb/backend/gcs/gcs.go

@@ -11,6 +11,8 @@ import (
 	"strings"
 	"time"
 
+	"github.com/grafana/tempo/tempodb/backend/instrumentation"
+
 	"cloud.google.com/go/storage"
 	"github.com/cristalhq/hedgedhttp"
 	"github.com/google/uuid"
@@ -319,11 +321,13 @@ func createBucket(ctx context.Context, cfg *Config, hedge bool) (*storage.Bucket
 	}
 
 	// add instrumentation
-	transport = newInstrumentedTransport(transport)
+	transport = instrumentation.NewGCSTransport(transport)
+	var stats *hedgedhttp.Stats
 
 	// hedge if desired (0 means disabled)
 	if hedge && cfg.HedgeRequestsAt != 0 {
-		transport = hedgedhttp.NewRoundTripper(cfg.HedgeRequestsAt, uptoHedgedRequests, transport)
+		transport, stats = hedgedhttp.NewRoundTripperAndStats(cfg.HedgeRequestsAt, uptoHedgedRequests, transport)
+		instrumentation.PublishHedgedMetrics(stats)
 	}
 
 	// build client

tempodb/backend/instrumentation/backend_transports.go

@@ -0,0 +1,80 @@
+package instrumentation
+
+import (
+	"net/http"
+	"strconv"
+	"time"
+
+	"github.com/prometheus/client_golang/prometheus"
+	"github.com/prometheus/client_golang/prometheus/promauto"
+)
+
+var (
+	gcsRequestDuration = promauto.NewHistogramVec(prometheus.HistogramOpts{
+		Namespace: "tempodb",
+		Name:      "gcs_request_duration_seconds",
+		Help:      "Time spent doing GCS requests.",
+		Buckets:   prometheus.ExponentialBuckets(0.005, 4, 6),
+	}, []string{"operation", "status_code"})
+
+	s3RequestDuration = promauto.NewHistogramVec(prometheus.HistogramOpts{
+		Namespace: "tempodb",
+		Name:      "s3_request_duration_seconds",
+		Help:      "Time spent doing AWS S3 requests.",
+		Buckets:   prometheus.ExponentialBuckets(0.005, 4, 6),
+	}, []string{"operation", "status_code"})
+
+	azureRequestDuration = promauto.NewHistogramVec(prometheus.HistogramOpts{
+		Namespace: "tempodb",
+		Name:      "azure_request_duration_seconds",
+		Help:      "Time spent doing Azure requests.",
+		Buckets:   prometheus.ExponentialBuckets(0.005, 4, 6),
+	}, []string{"operation", "status_code"})
+
+	requestDuration = promauto.NewHistogramVec(prometheus.HistogramOpts{
+		Namespace: "tempodb",
+		Name:      "backend_request_duration_seconds",
+		Help:      "Time spent doing requests.",
+		Buckets:   prometheus.ExponentialBuckets(0.005, 4, 6),
+	}, []string{"operation", "status_code"})
+)
+
+type instrumentedTransport struct {
+	legacyObserver prometheus.ObserverVec
+	observer       prometheus.ObserverVec
+	next           http.RoundTripper
+}
+
+func NewGCSTransport(next http.RoundTripper) http.RoundTripper {
+	return instrumentedTransport{
+		next:           next,
+		observer:       requestDuration,
+		legacyObserver: gcsRequestDuration,
+	}
+}
+
+func NewS3Transport(next http.RoundTripper) http.RoundTripper {
+	return instrumentedTransport{
+		next:           next,
+		observer:       requestDuration,
+		legacyObserver: s3RequestDuration,
+	}
+}
+
+func NewAzureTransport(next http.RoundTripper) http.RoundTripper {
+	return instrumentedTransport{
+		next:           next,
+		observer:       requestDuration,
+		legacyObserver: azureRequestDuration,
+	}
+}
+
+func (i instrumentedTransport) RoundTrip(req *http.Request) (*http.Response, error) {
+	start := time.Now()
+	resp, err := i.next.RoundTrip(req)
+	if err == nil {
+		i.legacyObserver.WithLabelValues(req.Method, strconv.Itoa(resp.StatusCode)).Observe(time.Since(start).Seconds())
+		i.observer.WithLabelValues(req.Method, strconv.Itoa(resp.StatusCode)).Observe(time.Since(start).Seconds())
+	}
+	return resp, err
+}

tempodb/backend/instrumentation/hedged_requests.go

@@ -0,0 +1,33 @@
+package instrumentation
+
+import (
+	"time"
+
+	"github.com/cristalhq/hedgedhttp"
+	"github.com/prometheus/client_golang/prometheus"
+	"github.com/prometheus/client_golang/prometheus/promauto"
+)
+
+const (
+	hedgedMetricsPublishDuration = 10 * time.Second
+)
+
+var (
+	hedgedRequestsMetrics = promauto.NewCounter(
+		prometheus.CounterOpts{
+			Namespace: "tempodb",
+			Name:      "backend_hedged_roundtrips_total",
+			Help:      "Total number of hedged backend requests",
+		},
+	)
+)
+
+// PublishHedgedMetrics flushes metrics from hedged requests every 10 seconds
+func PublishHedgedMetrics(s *hedgedhttp.Stats) {
+	ticker := time.NewTicker(hedgedMetricsPublishDuration)
+	go func() {
+		for range ticker.C {
+			hedgedRequestsMetrics.Add(float64(s.Snapshot().RequestedRoundTrips))
+		}
+	}()
+}

tempodb/backend/s3/s3.go

@@ -9,6 +9,8 @@ import (
 	"net/http"
 	"strings"
 
+	"github.com/grafana/tempo/tempodb/backend/instrumentation"
+
 	log_util "github.com/cortexproject/cortex/pkg/util/log"
 	"github.com/cristalhq/hedgedhttp"
 	"github.com/go-kit/kit/log"
@@ -400,10 +402,12 @@ func createCore(cfg *Config, hedge bool) (*minio.Core, error) {
 	}
 
 	// add instrumentation
-	transport := newInstrumentedTransport(customTransport)
+	transport := instrumentation.NewS3Transport(customTransport)
+	var stats *hedgedhttp.Stats
 
 	if hedge && cfg.HedgeRequestsAt != 0 {
-		transport = hedgedhttp.NewRoundTripper(cfg.HedgeRequestsAt, uptoHedgedRequests, transport)
+		transport, stats = hedgedhttp.NewRoundTripperAndStats(cfg.HedgeRequestsAt, uptoHedgedRequests, transport)
+		instrumentation.PublishHedgedMetrics(stats)
 	}
 
 	opts := &minio.Options{