From 91ef55af1873b80bd4a2990824f0977eb1dae19f Mon Sep 17 00:00:00 2001 From: stuart nelson Date: Thu, 11 May 2017 22:27:31 +0200 Subject: [PATCH 1/4] Add time to write header handler middleware --- prometheus/promhttp/instrument_server.go | 47 +++++++++++++++++++ prometheus/promhttp/instrument_server_test.go | 16 ++++++- 2 files changed, 61 insertions(+), 2 deletions(-) diff --git a/prometheus/promhttp/instrument_server.go b/prometheus/promhttp/instrument_server.go index 1beab4b42..02d694253 100644 --- a/prometheus/promhttp/instrument_server.go +++ b/prometheus/promhttp/instrument_server.go @@ -108,6 +108,40 @@ func InstrumentHandlerCounter(counter *prometheus.CounterVec, next http.Handler) }) } +// InstrumentHandlerTimeToWriteHeader is a middleware that wraps the provided +// http.Handler to observe with the provided ObserverVec the request duration +// until the response headers are written. The ObserverVec must have zero, one, +// or two labels. The only allowed label names are "code" and "method". The +// function panics if any other instance labels are provided. The Observe +// method of the Observer in the ObserverVec is called with the request +// duration in seconds. Partitioning happens by HTTP status code and/or HTTP +// method if the respective instance label names are present in the +// ObserverVec. For unpartitioned observations, use an ObserverVec with zero +// labels. Note that partitioning of Histograms is expensive and should be used +// judiciously. +// +// If the wrapped Handler does not set a status code via WriteHeader, no value +// is reported. +// +// If the wrapped Handler panics before calling WriteHeader, no value is +// reported. +// +// See the example for InstrumentHandlerDuration for example usage. +func InstrumentHandlerTimeToWriteHeader(obs prometheus.ObserverVec, next http.Handler) http.HandlerFunc { + code, method := checkLabels(obs) + + return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + now := time.Now() + d := &wroteHeaderDelegator{ + delegator: newDelegator(w), + observeWriteHeader: func(status int) { + obs.With(labels(code, method, r.Method, status)).Observe(time.Since(now).Seconds()) + }, + } + next.ServeHTTP(d, r) + }) +} + // InstrumentHandlerRequestSize is a middleware that wraps the provided // http.Handler to observe the request size with the provided ObserverVec. // The ObserverVec must have zero, one, or two labels. The only allowed label @@ -415,6 +449,19 @@ type delegator interface { http.ResponseWriter } +type wroteHeaderDelegator struct { + observeWriteHeader func(int) + + delegator +} + +func (r *wroteHeaderDelegator) WriteHeader(code int) { + r.delegator.WriteHeader(code) + if r.observeWriteHeader != nil { + r.observeWriteHeader(code) + } +} + type responseWriterDelegator struct { http.ResponseWriter diff --git a/prometheus/promhttp/instrument_server_test.go b/prometheus/promhttp/instrument_server_test.go index ca9f4bf3c..3b99c49f7 100644 --- a/prometheus/promhttp/instrument_server_test.go +++ b/prometheus/promhttp/instrument_server_test.go @@ -48,6 +48,16 @@ func TestMiddlewareAPI(t *testing.T) { []string{"method"}, ) + writeHeaderVec := prometheus.NewHistogramVec( + prometheus.HistogramOpts{ + Name: "write_header_duration_seconds", + Help: "A histogram of time to first write latencies.", + Buckets: prometheus.DefBuckets, + ConstLabels: prometheus.Labels{"handler": "api"}, + }, + []string{}, + ) + responseSize := prometheus.NewHistogramVec( prometheus.HistogramOpts{ Name: "push_request_size_bytes", @@ -61,12 +71,14 @@ func TestMiddlewareAPI(t *testing.T) { w.Write([]byte("OK")) }) - reg.MustRegister(inFlightGauge, counter, histVec, responseSize) + reg.MustRegister(inFlightGauge, counter, histVec, responseSize, writeHeaderVec) chain := InstrumentHandlerInFlight(inFlightGauge, InstrumentHandlerCounter(counter, InstrumentHandlerDuration(histVec, - InstrumentHandlerResponseSize(responseSize, handler), + InstrumentHandlerTimeToWriteHeader(writeHeaderVec, + InstrumentHandlerResponseSize(responseSize, handler), + ), ), ), ) From 93a3ea26211dde6720baca4c3966a7b3d97e95c7 Mon Sep 17 00:00:00 2001 From: stuart nelson Date: Fri, 19 May 2017 16:14:46 +0200 Subject: [PATCH 2/4] Remove unnecessary comment --- prometheus/promhttp/instrument_server.go | 3 --- 1 file changed, 3 deletions(-) diff --git a/prometheus/promhttp/instrument_server.go b/prometheus/promhttp/instrument_server.go index 02d694253..1d5eb1ea6 100644 --- a/prometheus/promhttp/instrument_server.go +++ b/prometheus/promhttp/instrument_server.go @@ -120,9 +120,6 @@ func InstrumentHandlerCounter(counter *prometheus.CounterVec, next http.Handler) // labels. Note that partitioning of Histograms is expensive and should be used // judiciously. // -// If the wrapped Handler does not set a status code via WriteHeader, no value -// is reported. -// // If the wrapped Handler panics before calling WriteHeader, no value is // reported. // From 49ee595bbe5d6b327d6b6a49f05d7804e51560d0 Mon Sep 17 00:00:00 2001 From: stuart nelson Date: Fri, 19 May 2017 16:17:10 +0200 Subject: [PATCH 3/4] move observeWriteHeader method to base delegate --- prometheus/promhttp/instrument_server.go | 31 +++++++------------ prometheus/promhttp/instrument_server_test.go | 17 ++++++++++ 2 files changed, 28 insertions(+), 20 deletions(-) diff --git a/prometheus/promhttp/instrument_server.go b/prometheus/promhttp/instrument_server.go index 1d5eb1ea6..f1fbc28a6 100644 --- a/prometheus/promhttp/instrument_server.go +++ b/prometheus/promhttp/instrument_server.go @@ -129,12 +129,12 @@ func InstrumentHandlerTimeToWriteHeader(obs prometheus.ObserverVec, next http.Ha return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { now := time.Now() - d := &wroteHeaderDelegator{ - delegator: newDelegator(w), + d := newDelegator(&responseWriterDelegator{ + ResponseWriter: w, observeWriteHeader: func(status int) { obs.With(labels(code, method, r.Method, status)).Observe(time.Since(now).Seconds()) }, - } + }) next.ServeHTTP(d, r) }) } @@ -446,26 +446,14 @@ type delegator interface { http.ResponseWriter } -type wroteHeaderDelegator struct { - observeWriteHeader func(int) - - delegator -} - -func (r *wroteHeaderDelegator) WriteHeader(code int) { - r.delegator.WriteHeader(code) - if r.observeWriteHeader != nil { - r.observeWriteHeader(code) - } -} - type responseWriterDelegator struct { http.ResponseWriter - handler, method string - status int - written int64 - wroteHeader bool + handler, method string + status int + written int64 + wroteHeader bool + observeWriteHeader func(int) } func (r *responseWriterDelegator) Status() int { @@ -480,6 +468,9 @@ func (r *responseWriterDelegator) WriteHeader(code int) { r.status = code r.wroteHeader = true r.ResponseWriter.WriteHeader(code) + if r.observeWriteHeader != nil { + r.observeWriteHeader(code) + } } func (r *responseWriterDelegator) Write(b []byte) (int, error) { diff --git a/prometheus/promhttp/instrument_server_test.go b/prometheus/promhttp/instrument_server_test.go index 3b99c49f7..02cba2ef6 100644 --- a/prometheus/promhttp/instrument_server_test.go +++ b/prometheus/promhttp/instrument_server_test.go @@ -88,6 +88,23 @@ func TestMiddlewareAPI(t *testing.T) { chain.ServeHTTP(w, r) } +func TestInstrumentTimeToFirstWrite(t *testing.T) { + var i int + dobs := &responseWriterDelegator{ + ResponseWriter: httptest.NewRecorder(), + observeWriteHeader: func(status int) { + i = status + }, + } + d := newDelegator(dobs) + + d.WriteHeader(http.StatusOK) + + if i != http.StatusOK { + t.Fatalf("failed to execute observeWriteHeader") + } +} + func ExampleInstrumentHandlerDuration() { inFlightGauge := prometheus.NewGauge(prometheus.GaugeOpts{ Name: "in_flight_requests", From 1839263725bf493cacd34e674f0aec8d3357f3bc Mon Sep 17 00:00:00 2001 From: stuart nelson Date: Tue, 23 May 2017 19:55:45 +0200 Subject: [PATCH 4/4] Add observeWriteHeaderFunc to newObserver Constructor now accepts an additional parameter that sets the function to call, if not nil, when writing the header. --- prometheus/promhttp/delegator_1_7.go | 7 +++++-- prometheus/promhttp/delegator_1_8.go | 7 +++++-- prometheus/promhttp/instrument_server.go | 15 ++++++--------- prometheus/promhttp/instrument_server_test.go | 2 +- 4 files changed, 17 insertions(+), 14 deletions(-) diff --git a/prometheus/promhttp/delegator_1_7.go b/prometheus/promhttp/delegator_1_7.go index 5e38c7ca4..24b31503e 100644 --- a/prometheus/promhttp/delegator_1_7.go +++ b/prometheus/promhttp/delegator_1_7.go @@ -20,8 +20,11 @@ import ( "net/http" ) -func newDelegator(w http.ResponseWriter) delegator { - d := &responseWriterDelegator{ResponseWriter: w} +func newDelegator(w http.ResponseWriter, observeWriteHeaderFunc func(int)) delegator { + d := &responseWriterDelegator{ + ResponseWriter: w, + observeWriteHeader: observeWriteHeaderFunc, + } _, cn := w.(http.CloseNotifier) _, fl := w.(http.Flusher) diff --git a/prometheus/promhttp/delegator_1_8.go b/prometheus/promhttp/delegator_1_8.go index 98b565096..b7743fb87 100644 --- a/prometheus/promhttp/delegator_1_8.go +++ b/prometheus/promhttp/delegator_1_8.go @@ -22,8 +22,11 @@ import ( // newDelegator handles the four different methods of upgrading a // http.ResponseWriter to delegator. -func newDelegator(w http.ResponseWriter) delegator { - d := &responseWriterDelegator{ResponseWriter: w} +func newDelegator(w http.ResponseWriter, observeWriteHeaderFunc func(int)) delegator { + d := &responseWriterDelegator{ + ResponseWriter: w, + observeWriteHeader: observeWriteHeaderFunc, + } _, cn := w.(http.CloseNotifier) _, fl := w.(http.Flusher) diff --git a/prometheus/promhttp/instrument_server.go b/prometheus/promhttp/instrument_server.go index f1fbc28a6..ac419e555 100644 --- a/prometheus/promhttp/instrument_server.go +++ b/prometheus/promhttp/instrument_server.go @@ -63,7 +63,7 @@ func InstrumentHandlerDuration(obs prometheus.ObserverVec, next http.Handler) ht if code { return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { now := time.Now() - d := newDelegator(w) + d := newDelegator(w, nil) next.ServeHTTP(d, r) obs.With(labels(code, method, r.Method, d.Status())).Observe(time.Since(now).Seconds()) @@ -96,7 +96,7 @@ func InstrumentHandlerCounter(counter *prometheus.CounterVec, next http.Handler) if code { return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { - d := newDelegator(w) + d := newDelegator(w, nil) next.ServeHTTP(d, r) counter.With(labels(code, method, r.Method, d.Status())).Inc() }) @@ -129,11 +129,8 @@ func InstrumentHandlerTimeToWriteHeader(obs prometheus.ObserverVec, next http.Ha return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { now := time.Now() - d := newDelegator(&responseWriterDelegator{ - ResponseWriter: w, - observeWriteHeader: func(status int) { - obs.With(labels(code, method, r.Method, status)).Observe(time.Since(now).Seconds()) - }, + d := newDelegator(w, func(status int) { + obs.With(labels(code, method, r.Method, status)).Observe(time.Since(now).Seconds()) }) next.ServeHTTP(d, r) }) @@ -160,7 +157,7 @@ func InstrumentHandlerRequestSize(obs prometheus.ObserverVec, next http.Handler) if code { return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { - d := newDelegator(w) + d := newDelegator(w, nil) next.ServeHTTP(d, r) size := computeApproximateRequestSize(r) obs.With(labels(code, method, r.Method, d.Status())).Observe(float64(size)) @@ -193,7 +190,7 @@ func InstrumentHandlerRequestSize(obs prometheus.ObserverVec, next http.Handler) func InstrumentHandlerResponseSize(obs prometheus.ObserverVec, next http.Handler) http.Handler { code, method := checkLabels(obs) return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { - d := newDelegator(w) + d := newDelegator(w, nil) next.ServeHTTP(d, r) obs.With(labels(code, method, r.Method, d.Status())).Observe(float64(d.Written())) }) diff --git a/prometheus/promhttp/instrument_server_test.go b/prometheus/promhttp/instrument_server_test.go index 02cba2ef6..7d372c487 100644 --- a/prometheus/promhttp/instrument_server_test.go +++ b/prometheus/promhttp/instrument_server_test.go @@ -96,7 +96,7 @@ func TestInstrumentTimeToFirstWrite(t *testing.T) { i = status }, } - d := newDelegator(dobs) + d := newDelegator(dobs, nil) d.WriteHeader(http.StatusOK)