Prometheus instrumentation

internal/helper/logging.go

@@ -4,10 +4,8 @@ import (
 	"bufio"
 	"net"
 	"net/http"
-	"strconv"
 	"time"
 
-	"github.com/prometheus/client_golang/prometheus"
 	log "github.com/sirupsen/logrus"
 
 	logging "gitlab.com/gitlab-org/gitlab-workhorse/internal/log"
@@ -15,35 +13,13 @@ import (
 
 var (
 	accessLogEntry *log.Entry
-
-	sessionsActive = prometheus.NewGauge(prometheus.GaugeOpts{
-		Name: "gitlab_workhorse_http_sessions_active",
-		Help: "Number of HTTP request-response cycles currently being handled by gitlab-workhorse.",
-	})
-
-	requestsTotal = prometheus.NewCounterVec(
-		prometheus.CounterOpts{
-			Name: "gitlab_workhorse_http_requests_total",
-			Help: "How many HTTP requests have been processed by gitlab-workhorse, partitioned by status code and HTTP method.",
-		},
-		[]string{"code", "method"},
-	)
 )
 
-func init() {
-	registerPrometheusMetrics()
-}
-
 // SetAccessLoggerEntry sets the access logger used in the system
 func SetAccessLoggerEntry(logEntry *log.Entry) {
 	accessLogEntry = logEntry
 }
 
-func registerPrometheusMetrics() {
-	prometheus.MustRegister(sessionsActive)
-	prometheus.MustRegister(requestsTotal)
-}
-
 type LoggingResponseWriter interface {
 	http.ResponseWriter
 
@@ -63,7 +39,6 @@ type hijackingResponseWriter struct {
 }
 
 func NewStatsCollectingResponseWriter(rw http.ResponseWriter) LoggingResponseWriter {
-	sessionsActive.Inc()
 	out := statsCollectingResponseWriter{
 		rw:      rw,
 		started: time.Now(),
@@ -135,7 +110,4 @@ func (l *statsCollectingResponseWriter) accessLogFields(r *http.Request) log.Fie
 
 func (l *statsCollectingResponseWriter) RequestFinished(r *http.Request) {
 	l.writeAccessLog(r)
-
-	sessionsActive.Dec()
-	requestsTotal.WithLabelValues(strconv.Itoa(l.status), r.Method).Inc()
 }

internal/upstream/metrics.go

+package upstream
+
+import (
+	"net/http"
+
+	"github.com/prometheus/client_golang/prometheus"
+	"github.com/prometheus/client_golang/prometheus/promhttp"
+)
+
+const (
+	namespace     = "gitlab_workhorse"
+	httpSubsystem = "http"
+)
+
+func secondsDurationBuckets() []float64 {
+	return []float64{
+		0.005, /* 5ms */
+		0.025, /* 25ms */
+		0.1,   /* 100ms */
+		0.5,   /* 500ms */
+		1.0,   /* 1s */
+		10.0,  /* 10s */
+		30.0,  /* 30s */
+		60.0,  /* 1m */
+		300.0, /* 10m */
+	}
+}
+
+func byteSizeBuckets() []float64 {
+	return []float64{
+		10,
+		64,
+		256,
+		1024,             /* 1kB */
+		64 * 1024,        /* 64kB */
+		256 * 1024,       /* 256kB */
+		1024 * 1024,      /* 1mB */
+		64 * 1024 * 1024, /* 64mB */
+	}
+}
+
+var (
+	httpInFlightRequests = prometheus.NewGauge(prometheus.GaugeOpts{
+		Namespace: namespace,
+		Subsystem: httpSubsystem,
+		Name:      "in_flight_requests",
+		Help:      "A gauge of requests currently being served by workhorse.",
+	})
+
+	httpRequestsTotal = prometheus.NewCounterVec(
+		prometheus.CounterOpts{
+			Namespace: namespace,
+			Subsystem: httpSubsystem,
+			Name:      "requests_total",
+			Help:      "A counter for requests to workhorse.",
+		},
+		[]string{"code", "method", "route"},
+	)
+
+	httpRequestDurationSeconds = prometheus.NewHistogramVec(
+		prometheus.HistogramOpts{
+			Namespace: namespace,
+			Subsystem: httpSubsystem,
+			Name:      "request_duration_seconds",
+			Help:      "A histogram of latencies for requests to workhorse.",
+			Buckets:   secondsDurationBuckets(),
+		},
+		[]string{"code", "method", "route"},
+	)
+
+	httpRequestSizeBytes = prometheus.NewHistogramVec(
+		prometheus.HistogramOpts{
+			Namespace: namespace,
+			Subsystem: httpSubsystem,
+			Name:      "request_size_bytes",
+			Help:      "A histogram of sizes of requests to workhorse.",
+			Buckets:   byteSizeBuckets(),
+		},
+		[]string{"code", "method", "route"},
+	)
+
+	httpResponseSizeBytes = prometheus.NewHistogramVec(
+		prometheus.HistogramOpts{
+			Namespace: namespace,
+			Subsystem: httpSubsystem,
+			Name:      "response_size_bytes",
+			Help:      "A histogram of response sizes for requests to workhorse.",
+			Buckets:   byteSizeBuckets(),
+		},
+		[]string{"code", "method", "route"},
+	)
+
+	httpTimeToWriteHeaderSeconds = prometheus.NewHistogramVec(
+		prometheus.HistogramOpts{
+			Namespace: namespace,
+			Subsystem: httpSubsystem,
+			Name:      "time_to_write_header_seconds",
+			Help:      "A histogram of request durations until the response headers are written.",
+			Buckets:   secondsDurationBuckets(),
+		},
+		[]string{"code", "method", "route"},
+	)
+)
+
+func init() {
+	prometheus.MustRegister(httpInFlightRequests)
+	prometheus.MustRegister(httpRequestsTotal)
+	prometheus.MustRegister(httpRequestDurationSeconds)
+	prometheus.MustRegister(httpRequestSizeBytes)
+	prometheus.MustRegister(httpTimeToWriteHeaderSeconds)
+}
+
+func instrumentRoute(next http.Handler, method string, regexpStr string) http.Handler {
+	var handler http.Handler
+
+	handler = next
+
+	handler = promhttp.InstrumentHandlerCounter(httpRequestsTotal.MustCurryWith(map[string]string{"route": regexpStr}), handler)
+	handler = promhttp.InstrumentHandlerDuration(httpRequestDurationSeconds.MustCurryWith(map[string]string{"route": regexpStr}), handler)
+	handler = promhttp.InstrumentHandlerInFlight(httpInFlightRequests, handler)
+	handler = promhttp.InstrumentHandlerRequestSize(httpRequestSizeBytes.MustCurryWith(map[string]string{"route": regexpStr}), handler)
+	handler = promhttp.InstrumentHandlerResponseSize(httpResponseSizeBytes.MustCurryWith(map[string]string{"route": regexpStr}), handler)
+	handler = promhttp.InstrumentHandlerTimeToWriteHeader(httpTimeToWriteHeaderSeconds.MustCurryWith(map[string]string{"route": regexpStr}), handler)
+
+	return handler
+}

internal/upstream/routes.go

@@ -4,10 +4,8 @@ import (
 	"net/http"
 	"path"
 	"regexp"
-	"time"
 
 	"github.com/gorilla/websocket"
-	"github.com/prometheus/client_golang/prometheus"
 
 	apipkg "gitlab.com/gitlab-org/gitlab-workhorse/internal/api"
 	"gitlab.com/gitlab-org/gitlab-workhorse/internal/artifacts"
@@ -42,20 +40,6 @@ const (
 	projectPattern    = `^/([^/]+/){1,}[^/]+/`
 )
 
-var (
-	routeRequestDurations = prometheus.NewHistogramVec(prometheus.HistogramOpts{
-		Name:    "gitlab_workhorse_request_duration_seconds",
-		Help:    "A histogram of request times in seconds",
-		Buckets: prometheus.ExponentialBuckets(0.01, 2.5, 10),
-	},
-		[]string{"method", "route"},
-	)
-)
-
-func init() {
-	prometheus.MustRegister(routeRequestDurations)
-}
-
 func compileRegexp(regexpStr string) *regexp.Regexp {
 	if len(regexpStr) == 0 {
 		return nil
@@ -64,19 +48,11 @@ func compileRegexp(regexpStr string) *regexp.Regexp {
 	return regexp.MustCompile(regexpStr)
 }
 
-func instrumentDuration(h http.Handler, method string, regexpStr string) http.Handler {
-	return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
-		start := time.Now()
-		h.ServeHTTP(w, r)
-		routeRequestDurations.WithLabelValues(method, regexpStr).Observe(time.Since(start).Seconds())
-	})
-}
-
 func route(method, regexpStr string, handler http.Handler, matchers ...matcherFunc) routeEntry {
 	return routeEntry{
 		method:   method,
 		regex:    compileRegexp(regexpStr),
-		handler:  instrumentDuration(denyWebsocket(handler), method, regexpStr),
+		handler:  instrumentRoute(denyWebsocket(handler), method, regexpStr),
 		matchers: matchers,
 	}
 }
@@ -85,7 +61,7 @@ func wsRoute(regexpStr string, handler http.Handler, matchers ...matcherFunc) ro
 	return routeEntry{
 		method:   "GET",
 		regex:    compileRegexp(regexpStr),
-		handler:  instrumentDuration(handler, "GET", regexpStr),
+		handler:  instrumentRoute(handler, "GET", regexpStr),
 		matchers: append(matchers, websocket.IsWebSocketUpgrade),
 	}
 }