Merge pull request #1660 from mslipper/feature/proxy-method-metrics

Add proxy method metrics

.changeset/fifty-bulldogs-march.md

+---
+'@eth-optimism/proxyd': minor
+---
+
+Updates proxyd to include additional error metrics.

go/proxyd/backend.go

@@ -31,7 +31,8 @@ var (
 		Name:      "backend_requests_total",
 		Help:      "Count of backend requests.",
 	}, []string{
-    "name",
+		"backend_name",
+		"method_name",
 	})
 
 	backendErrorsCtr = promauto.NewCounterVec(prometheus.CounterOpts{
@@ -39,7 +40,8 @@ var (
 		Name:      "backend_errors_total",
 		Help:      "Count of backend errors.",
 	}, []string{
-    "name",
+		"backend_name",
+    "method_name",
 	})
 
 	backendPermanentErrorsCtr = promauto.NewCounterVec(prometheus.CounterOpts{
@@ -47,7 +49,18 @@ var (
 		Name:      "backend_permanent_errors_total",
 		Help:      "Count of backend errors that mark a backend as offline.",
 	}, []string{
-    "name",
+		"backend_name",
+    "method_name",
+	})
+
+	backendResponseTimeSummary = promauto.NewSummaryVec(prometheus.SummaryOpts{
+		Namespace:  "proxyd",
+		Name:       "backend_response_time_seconds",
+		Help:       "Summary of backend response times broken down by backend and method name.",
+		Objectives: map[float64]float64{0.5: 0.05, 0.9: 0.01, 0.95: 0.005, 0.99: 0.001},
+	}, []string{
+		"backend_name",
+		"method_name",
 	})
 )
 
@@ -113,7 +126,7 @@ func NewBackend(name, baseURL string, opts ...BackendOpt) *Backend {
 	return backend
 }
 
-func (b *Backend) Forward(body []byte) (*RPCRes, error) {
+func (b *Backend) Forward(req *RPCReq) (*RPCRes, error) {
 	if time.Now().Unix()-atomic.LoadInt64(&b.lastPermError) < b.unhealthyRetryInterval {
 		return nil, ErrBackendOffline
 	}
@@ -122,7 +135,7 @@ func (b *Backend) Forward(body []byte) (*RPCRes, error) {
 	// <= to account for the first attempt not technically being
 	// a retry
 	for i := 0; i <= b.maxRetries; i++ {
-    resB, err := b.doForward(body)
+		resB, err := b.doForward(req)
 		if err != nil {
 			lastError = err
 			log.Warn("backend request failed, trying again", "err", err, "name", b.Name)
@@ -140,40 +153,47 @@ func (b *Backend) Forward(body []byte) (*RPCRes, error) {
 	}
 
 	atomic.StoreInt64(&b.lastPermError, time.Now().Unix())
-  backendPermanentErrorsCtr.WithLabelValues(b.Name).Inc()
+	backendPermanentErrorsCtr.WithLabelValues(b.Name, req.Method).Inc()
 	return nil, wrapErr(lastError, "permanent error forwarding request")
 }
 
-func (b *Backend) doForward(body []byte) ([]byte, error) {
-  req, err := http.NewRequest("POST", b.baseURL, bytes.NewReader(body))
+func (b *Backend) doForward(rpcReq *RPCReq) ([]byte, error) {
+	body, err := json.Marshal(rpcReq)
+	if err != nil {
+		return nil, wrapErr(err, "error marshaling request in forward")
+	}
+
+	httpReq, err := http.NewRequest("POST", b.baseURL, bytes.NewReader(body))
 	if err != nil {
-    backendErrorsCtr.WithLabelValues(b.Name).Inc()
+		backendErrorsCtr.WithLabelValues(b.Name, rpcReq.Method).Inc()
 		return nil, wrapErr(err, "error creating backend request")
 	}
 
 	if b.authPassword != "" {
-    req.SetBasicAuth(b.authUsername, b.authPassword)
+		httpReq.SetBasicAuth(b.authUsername, b.authPassword)
 	}
 
-  res, err := b.client.Do(req)
+	timer := prometheus.NewTimer(backendResponseTimeSummary.WithLabelValues(b.Name, rpcReq.Method))
+	defer timer.ObserveDuration()
+	defer backendRequestsCtr.WithLabelValues(b.Name, rpcReq.Method).Inc()
+	res, err := b.client.Do(httpReq)
 	if err != nil {
-    backendErrorsCtr.WithLabelValues(b.Name).Inc()
+		backendErrorsCtr.WithLabelValues(b.Name, rpcReq.Method).Inc()
 		return nil, wrapErr(err, "error in backend request")
 	}
 
 	if res.StatusCode != 200 {
-    backendErrorsCtr.WithLabelValues(b.Name).Inc()
+		backendErrorsCtr.WithLabelValues(b.Name, rpcReq.Method).Inc()
 		return nil, fmt.Errorf("response code %d", res.StatusCode)
 	}
 
 	defer res.Body.Close()
 	resB, err := ioutil.ReadAll(io.LimitReader(res.Body, b.maxResponseSize))
 	if err != nil {
-    backendErrorsCtr.WithLabelValues(b.Name).Inc()
+		backendErrorsCtr.WithLabelValues(b.Name, rpcReq.Method).Inc()
 		return nil, wrapErr(err, "error reading response body")
 	}
 
-  backendRequestsCtr.WithLabelValues(b.Name).Inc()
 	return resB, nil
 }
 
@@ -183,10 +203,10 @@ type BackendGroup struct {
 	i        int64
 }
 
-func (b *BackendGroup) Forward(body []byte) (*RPCRes, error) {
+func (b *BackendGroup) Forward(rpcReq *RPCReq) (*RPCRes, error) {
 	var outRes *RPCRes
 	for _, back := range b.backends {
-    res, err := back.Forward(body)
+		res, err := back.Forward(rpcReq)
 		if err == ErrBackendOffline {
 			log.Debug("skipping offline backend", "name", back.Name)
 			continue

go/proxyd/server.go

@@ -12,7 +12,6 @@ import (
   "io"
   "io/ioutil"
   "net/http"
-	"time"
 )
 
 var (
@@ -22,17 +21,11 @@ var (
 		Help:      "Count of total HTTP requests.",
 	})
 
-	httpRequestDurationHisto = promauto.NewHistogram(prometheus.HistogramOpts{
+	httpRequestDurationSummary = promauto.NewSummary(prometheus.SummaryOpts{
 		Namespace:  "proxyd",
-		Name:      "http_request_duration_histogram_seconds",
-		Help:      "Histogram of HTTP request durations.",
-		Buckets: []float64{
-			0,
-			0.1,
-			0.25,
-			0.75,
-			1,
-		},
+		Name:       "http_request_duration_seconds",
+		Help:       "Summary of HTTP request durations, in seconds.",
+		Objectives: map[float64]float64{0.5: 0.05, 0.9: 0.01, 0.95: 0.005, 0.99: 0.001},
 	})
 
 	rpcRequestsCtr = promauto.NewCounterVec(prometheus.CounterOpts{
@@ -142,7 +135,7 @@ func (s *Server) HandleRPC(w http.ResponseWriter, r *http.Request) {
 		return
 	}
 
-	backendRes, err := group.Forward(body)
+	backendRes, err := group.Forward(req)
 	if err != nil {
 		log.Error("error forwarding RPC request", "group", group.Name, "method", req.Method, "err", err)
 		rpcErrorsCtr.WithLabelValues("-32603").Inc()
@@ -181,9 +174,8 @@ func writeRPCError(w http.ResponseWriter, id *int, code int, msg string) {
 func instrumentedHdlr(h http.Handler) http.HandlerFunc {
 	return func(w http.ResponseWriter, r *http.Request) {
 		httpRequestsCtr.Inc()
-		start := time.Now()
+		timer := prometheus.NewTimer(httpRequestDurationSummary)
+		defer timer.ObserveDuration()
 		h.ServeHTTP(w, r)
-		dur := time.Since(start)
-		httpRequestDurationHisto.Observe(float64(dur) / float64(time.Second))
 	}
 }