From b4dfee4ebc6eadd73c1a10501898c978a527b777 Mon Sep 17 00:00:00 2001 From: Matthias Loibl Date: Fri, 26 Mar 2021 12:43:35 +0100 Subject: [PATCH] Add Exemplars for http_request_duration_seconds histogram Signed-off-by: Matthias Loibl A lot of these changes are actually changing the order of calling the middlwares. Going forward we need to make sure to first call the tracing middleware so that by the time our monitoring/instrumentation middleware gets hit the tracing spans are already populated. --- CHANGELOG.md | 1 + cmd/thanos/query_frontend.go | 10 ++-- go.mod | 2 +- go.sum | 9 ++- pkg/api/api.go | 11 +++- pkg/extprom/http/instrument_server.go | 84 +++++++++++++++++++++++---- pkg/receive/handler.go | 3 +- pkg/server/http/http.go | 4 +- 8 files changed, 100 insertions(+), 24 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index b087d0dc5e..be59d8dc2a 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -13,6 +13,7 @@ We use _breaking :warning:_ to mark changes that are not backward compatible (re ## Unreleased ### Added +- [#3977](https://github.com/thanos-io/thanos/pull/3903) Expose exemplars for `http_request_duration_seconds` histogram if tracing is enabled. - [#3903](https://github.com/thanos-io/thanos/pull/3903) Store: Returning custom grpc code when reaching series/chunk limits. - [3919](https://github.com/thanos-io/thanos/pull/3919) Allow to disable automatically setting CORS headers using `--web.disable-cors` flag in each component that exposes an API. diff --git a/cmd/thanos/query_frontend.go b/cmd/thanos/query_frontend.go index 68374b4500..8c11146c80 100644 --- a/cmd/thanos/query_frontend.go +++ b/cmd/thanos/query_frontend.go @@ -229,14 +229,14 @@ func runQueryFrontend( if !cfg.webDisableCORS { api.SetCORS(w) } - ins.NewHandler( + tracing.HTTPMiddleware( + tracer, name, - logMiddleware.HTTPMiddleware( + logger, + ins.NewHandler( name, - tracing.HTTPMiddleware( - tracer, + logMiddleware.HTTPMiddleware( name, - logger, gziphandler.GzipHandler(middleware.RequestID(f)), ), ), diff --git a/go.mod b/go.mod index f4a67d28fe..e4b866d860 100644 --- a/go.mod +++ b/go.mod @@ -46,7 +46,7 @@ require ( github.com/pkg/errors v0.9.1 github.com/pmezard/go-difflib v1.0.0 github.com/prometheus/alertmanager v0.21.1-0.20210310093010-0f9cab6991e6 - github.com/prometheus/client_golang v1.9.0 + github.com/prometheus/client_golang v1.10.0 github.com/prometheus/client_model v0.2.0 github.com/prometheus/common v0.18.0 github.com/prometheus/prometheus v1.8.2-0.20210315220929-1cba1741828b diff --git a/go.sum b/go.sum index 490cda85e3..c7e3495567 100644 --- a/go.sum +++ b/go.sum @@ -1048,8 +1048,9 @@ github.com/prometheus/client_golang v1.5.1/go.mod h1:e9GMxYsXl05ICDXkRhurwBS4Q3O github.com/prometheus/client_golang v1.6.0/go.mod h1:ZLOG9ck3JLRdB5MgO8f+lLTe83AXG6ro35rLTxvnIl4= github.com/prometheus/client_golang v1.7.1/go.mod h1:PY5Wy2awLA44sXw4AOSfFBetzPP4j5+D6mVACh+pe2M= github.com/prometheus/client_golang v1.8.0/go.mod h1:O9VU6huf47PktckDQfMTX0Y8tY0/7TSWwj+ITvv0TnM= -github.com/prometheus/client_golang v1.9.0 h1:Rrch9mh17XcxvEu9D9DEpb4isxjGBtcevQjKvxPRQIU= github.com/prometheus/client_golang v1.9.0/go.mod h1:FqZLKOZnGdFAhOK4nqGHa7D66IdsO+O441Eve7ptJDU= +github.com/prometheus/client_golang v1.10.0 h1:/o0BDeWzLWXNZ+4q5gXltUvaMpJqckTa+jTNoB+z4cg= +github.com/prometheus/client_golang v1.10.0/go.mod h1:WJM3cc3yu7XKBKa/I8WeZm+V3eltZnBwfENSU7mdogU= github.com/prometheus/client_model v0.0.0-20170216185247-6f3806018612/go.mod h1:MbSGuTsp3dbXC40dX6PRTWyKYBIrTGTE9sqQNg2J8bo= github.com/prometheus/client_model v0.0.0-20180712105110-5c3871d89910/go.mod h1:MbSGuTsp3dbXC40dX6PRTWyKYBIrTGTE9sqQNg2J8bo= github.com/prometheus/client_model v0.0.0-20190115171406-56726106282f/go.mod h1:MbSGuTsp3dbXC40dX6PRTWyKYBIrTGTE9sqQNg2J8bo= @@ -1092,8 +1093,9 @@ github.com/prometheus/procfs v0.0.6/go.mod h1:7Qr8sr6344vo1JqZ6HhLceV9o3AJ1Ff+Gx github.com/prometheus/procfs v0.0.8/go.mod h1:7Qr8sr6344vo1JqZ6HhLceV9o3AJ1Ff+GxbHq6oeK9A= github.com/prometheus/procfs v0.0.11/go.mod h1:lV6e/gmhEcM9IjHGsFOCxxuZ+z1YqCvr4OA4YeYWdaU= github.com/prometheus/procfs v0.1.3/go.mod h1:lV6e/gmhEcM9IjHGsFOCxxuZ+z1YqCvr4OA4YeYWdaU= -github.com/prometheus/procfs v0.2.0 h1:wH4vA7pcjKuZzjF7lM8awk4fnuJO6idemZXoKnULUx4= github.com/prometheus/procfs v0.2.0/go.mod h1:lV6e/gmhEcM9IjHGsFOCxxuZ+z1YqCvr4OA4YeYWdaU= +github.com/prometheus/procfs v0.6.0 h1:mxy4L2jP6qMonqmq+aTtOx1ifVWUgG/TAmntgbh3xv4= +github.com/prometheus/procfs v0.6.0/go.mod h1:cz+aTbrPOrUb4q7XlbU9ygM+/jj0fzG6c1xBZuNvfVA= github.com/prometheus/prometheus v1.8.2-0.20210315220929-1cba1741828b h1:TTOvmIV3W6IUIj3pYFs9gfCgueHlriLStMGBsnNdEX4= github.com/prometheus/prometheus v1.8.2-0.20210315220929-1cba1741828b/go.mod h1:MS/bpdil77lPbfQeKk6OqVQ9OLnpN3Rszd0hka0EOWE= github.com/prometheus/tsdb v0.7.1/go.mod h1:qhTCs0VvXwvX/y3TZrWD7rabWM+ijKTux40TwIPHuXU= @@ -1554,8 +1556,9 @@ golang.org/x/sys v0.0.0-20201201145000-ef89a241ccb3/go.mod h1:h1NjWce9XRLGQEsW7w golang.org/x/sys v0.0.0-20201214210602-f9fddec55a1e/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= golang.org/x/sys v0.0.0-20210104204734-6f8348627aad/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= golang.org/x/sys v0.0.0-20210119212857-b64e53b001e4/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= -golang.org/x/sys v0.0.0-20210124154548-22da62e12c0c h1:VwygUrnw9jn88c4u8GD3rZQbqrP/tgas88tPUbBxQrk= golang.org/x/sys v0.0.0-20210124154548-22da62e12c0c/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= +golang.org/x/sys v0.0.0-20210309074719-68d13333faf2 h1:46ULzRKLh1CwgRq2dC5SlBzEqqNCi8rreOZnNrbqcIY= +golang.org/x/sys v0.0.0-20210309074719-68d13333faf2/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs= golang.org/x/term v0.0.0-20201117132131-f5c789dd3221/go.mod h1:Nr5EML6q2oocZ2LXRh80K7BxOlk5/8JxuGnuhpl+muw= golang.org/x/term v0.0.0-20201126162022-7de9c90e9dd1 h1:v+OssWQX+hTHEmOBgwxdZxK4zHq3yOs8F9J7mk0PY8E= golang.org/x/term v0.0.0-20201126162022-7de9c90e9dd1/go.mod h1:bj7SfCRtBDWHUb9snDiAeCFNEtKQo2Wmx5Cou7ajbmo= diff --git a/pkg/api/api.go b/pkg/api/api.go index 1a39b71b2e..600eef31f2 100644 --- a/pkg/api/api.go +++ b/pkg/api/api.go @@ -216,7 +216,16 @@ func GetInstr( w.WriteHeader(http.StatusNoContent) } }) - return ins.NewHandler(name, logMiddleware.HTTPMiddleware(name, tracing.HTTPMiddleware(tracer, name, logger, gziphandler.GzipHandler(middleware.RequestID(hf))))) + + return tracing.HTTPMiddleware(tracer, name, logger, + ins.NewHandler(name, + logMiddleware.HTTPMiddleware(name, + gziphandler.GzipHandler( + middleware.RequestID(hf), + ), + ), + ), + ) } return instr } diff --git a/pkg/extprom/http/instrument_server.go b/pkg/extprom/http/instrument_server.go index df7217adfc..e35f6a9875 100644 --- a/pkg/extprom/http/instrument_server.go +++ b/pkg/extprom/http/instrument_server.go @@ -4,11 +4,16 @@ package http import ( + "fmt" "net/http" + "strings" + "time" + "github.com/opentracing/opentracing-go" "github.com/prometheus/client_golang/prometheus" "github.com/prometheus/client_golang/prometheus/promauto" "github.com/prometheus/client_golang/prometheus/promhttp" + "github.com/uber/jaeger-client-go" ) // InstrumentationMiddleware holds necessary metrics to instrument an http.Server @@ -21,9 +26,9 @@ type InstrumentationMiddleware interface { type nopInstrumentationMiddleware struct{} func (ins nopInstrumentationMiddleware) NewHandler(handlerName string, handler http.Handler) http.HandlerFunc { - return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + return func(w http.ResponseWriter, r *http.Request) { handler.ServeHTTP(w, r) - }) + } } // NewNopInstrumentationMiddleware provides a InstrumentationMiddleware which does nothing. @@ -90,17 +95,72 @@ func NewInstrumentationMiddleware(reg prometheus.Registerer, buckets []float64) // value. http_requests_total is a metric vector partitioned by HTTP method // (label name "method") and HTTP status code (label name "code"). func (ins *defaultInstrumentationMiddleware) NewHandler(handlerName string, handler http.Handler) http.HandlerFunc { - return promhttp.InstrumentHandlerDuration( - ins.requestDuration.MustCurryWith(prometheus.Labels{"handler": handlerName}), - promhttp.InstrumentHandlerRequestSize( - ins.requestSize.MustCurryWith(prometheus.Labels{"handler": handlerName}), - promhttp.InstrumentHandlerCounter( - ins.requestsTotal.MustCurryWith(prometheus.Labels{"handler": handlerName}), - promhttp.InstrumentHandlerResponseSize( - ins.responseSize.MustCurryWith(prometheus.Labels{"handler": handlerName}), - handler, - ), + return promhttp.InstrumentHandlerRequestSize( + ins.requestSize.MustCurryWith(prometheus.Labels{"handler": handlerName}), + promhttp.InstrumentHandlerCounter( + ins.requestsTotal.MustCurryWith(prometheus.Labels{"handler": handlerName}), + promhttp.InstrumentHandlerResponseSize( + ins.responseSize.MustCurryWith(prometheus.Labels{"handler": handlerName}), + http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + now := time.Now() + + wd := &responseWriterDelegator{w: w} + handler.ServeHTTP(wd, r) + + observer := ins.requestDuration.WithLabelValues( + wd.Status(), + handlerName, + strings.ToLower(r.Method), + ) + observer.Observe(time.Since(now).Seconds()) + + // If we find a tracingID we'll expose it as Exemplar. + span := opentracing.SpanFromContext(r.Context()) + if span != nil { + spanCtx, ok := span.Context().(jaeger.SpanContext) + if ok { + observer.(prometheus.ExemplarObserver).ObserveWithExemplar( + time.Since(now).Seconds(), + prometheus.Labels{ + "traceID": spanCtx.TraceID().String(), + }, + ) + } + } + }), ), ), ) } + +// responseWriterDelegator implements http.ResponseWriter and extracts the statusCode. +type responseWriterDelegator struct { + w http.ResponseWriter + written bool + statusCode int +} + +func (wd *responseWriterDelegator) Header() http.Header { + return wd.w.Header() +} + +func (wd *responseWriterDelegator) Write(bytes []byte) (int, error) { + return wd.w.Write(bytes) +} + +func (wd *responseWriterDelegator) WriteHeader(statusCode int) { + wd.written = true + wd.statusCode = statusCode + wd.w.WriteHeader(statusCode) +} + +func (wd *responseWriterDelegator) StatusCode() int { + if !wd.written { + return http.StatusOK + } + return wd.statusCode +} + +func (wd *responseWriterDelegator) Status() string { + return fmt.Sprintf("%d", wd.StatusCode()) +} diff --git a/pkg/receive/handler.go b/pkg/receive/handler.go index 80a168f30c..f634e5b8ab 100644 --- a/pkg/receive/handler.go +++ b/pkg/receive/handler.go @@ -157,10 +157,11 @@ func NewHandler(logger log.Logger, o *Options) *Handler { readyf := h.testReady instrf := func(name string, next func(w http.ResponseWriter, r *http.Request)) http.HandlerFunc { + next = ins.NewHandler(name, http.HandlerFunc(next)) if o.Tracer != nil { next = tracing.HTTPMiddleware(o.Tracer, name, logger, http.HandlerFunc(next)) } - return ins.NewHandler(name, http.HandlerFunc(next)) + return next } h.router.Post("/api/v1/receive", instrf("receive", readyf(middleware.RequestID(http.HandlerFunc(h.receiveHTTP))))) diff --git a/pkg/server/http/http.go b/pkg/server/http/http.go index 3cc6afa94a..891f04f5de 100644 --- a/pkg/server/http/http.go +++ b/pkg/server/http/http.go @@ -104,7 +104,9 @@ func registerProfiler(mux *http.ServeMux) { func registerMetrics(mux *http.ServeMux, g prometheus.Gatherer) { if g != nil { - mux.Handle("/metrics", promhttp.HandlerFor(g, promhttp.HandlerOpts{})) + mux.Handle("/metrics", promhttp.HandlerFor(g, promhttp.HandlerOpts{ + EnableOpenMetrics: true, + })) } }