Adds optional Metrics (#46)

* Adds optional metrics and promteheus yaml file.

* Adds flag guarded latency measurements.

---------

Co-authored-by: Kartik Chopra <[email protected]>

cmd/boost/main.go

@@ -81,6 +81,12 @@ var flags = []cli.Flag{
 		Value:   "",
 		EnvVars: []string{"BUILDER_AUTH_TOKEN"},
 	},
+	&cli.BoolFlag{
+		Name:    "metrics",
+		Usage:   "enables metrics tracking for boost",
+		Value:   false,
+		EnvVars: []string{"METRICS"},
+	},
 }
 
 var (
@@ -208,11 +214,12 @@ func run() cli.ActionFunc {
 			}
 
 			svr.Handler = &boost.API{
-				Service:      service,
-				Log:          config.Log,
-				Worker:       masterWorker,
-				Rollup:       ru,
-				BuilderToken: c.String("buildertoken"),
+				Service:        service,
+				Log:            config.Log,
+				Worker:         masterWorker,
+				Rollup:         ru,
+				BuilderToken:   c.String("buildertoken"),
+				MetricsEnabled: c.Bool("metrics"),
 			}
 
 			config.Log.Info("http server listening")

docker-compose.yml

@@ -16,3 +16,10 @@ services:
     command: ['searcher']
     depends_on:
       - boost
+
+  prometheus:
+    image: prom/prometheus:v2.40.4
+    ports:
+      - 9090:9090
+    volumes:
+      - ./prometheus/prometheus.yml:/etc/prometheus/prometheus.yml

go.mod

@@ -8,6 +8,7 @@ require (
 	github.com/ethereum/go-ethereum v1.11.6
 	github.com/gorilla/websocket v1.5.0
 	github.com/lthibault/log v1.2.2
+	github.com/prometheus/client_golang v1.14.0
 	github.com/sirupsen/logrus v1.9.0
 	github.com/stretchr/testify v1.8.2
 	github.com/urfave/cli/v2 v2.17.2-0.20221006022127-8f469abc00aa
@@ -78,6 +79,11 @@ require (
 )
 
 require (
+	github.com/beorn7/perks v1.0.1 // indirect
+	github.com/matttproud/golang_protobuf_extensions v1.0.4 // indirect
 	github.com/pkg/errors v0.9.1 // indirect
+	github.com/prometheus/client_model v0.3.0 // indirect
+	github.com/prometheus/common v0.39.0 // indirect
+	github.com/prometheus/procfs v0.9.0 // indirect
 	golang.org/x/sys v0.6.0 // indirect
 )

go.sum

@@ -34,6 +34,7 @@ github.com/attestantio/go-eth2-client v0.16.0 h1:PdO+Z9il00oDSkURsR8miT4VV/11Y/a
 github.com/attestantio/go-eth2-client v0.16.0/go.mod h1:ES/aAi5Pog4l8ZCXRvAGnbLdSuoa0I9kZ6aet/aRC8g=
 github.com/benbjohnson/clock v1.1.0/go.mod h1:J11/hYXuz8f4ySSvYwY0FKfm+ezbsZBKZxNJlLklBHA=
 github.com/beorn7/perks v1.0.1 h1:VlbKKnNfV8bJzeqoa4cOKqO6bYr3WgKZxO8Z16+hsOM=
+github.com/beorn7/perks v1.0.1/go.mod h1:G2ZrVWU2WbWT9wwq4/hrbKbnv/1ERSJQ0ibhJ6rlkpw=
 github.com/btcsuite/btcd/btcec/v2 v2.2.0 h1:fzn1qaOt32TuLjFlkzYSsBC35Q3KUjT1SwPxiMSCF5k=
 github.com/btcsuite/btcd/btcec/v2 v2.2.0/go.mod h1:U7MHm051Al6XmscBQ0BoNydpOTsFAn707034b5nY8zU=
 github.com/btcsuite/btcd/chaincfg/chainhash v1.0.1 h1:q0rUy8C/TYNBQS1+CGKw68tLOFYSNEs0TFnxxnS9+4U=
@@ -110,6 +111,7 @@ github.com/golang/mock v1.1.1/go.mod h1:oTYuIxOrZwtPieC+H1uAHpcLFnEyAGVDL/k47Jfb
 github.com/golang/mock v1.6.0/go.mod h1:p6yTPP+5HYm5mzsMV8JkE6ZKdX+/wYM6Hr+LicevLPs=
 github.com/golang/protobuf v1.2.0/go.mod h1:6lQm79b+lXiMfvg/cZm0SGofjICqVBUtrP5yJMmIC1U=
 github.com/golang/protobuf v1.3.2/go.mod h1:6lQm79b+lXiMfvg/cZm0SGofjICqVBUtrP5yJMmIC1U=
+github.com/golang/protobuf v1.3.5/go.mod h1:6O5/vntMXwX2lRkT1hjjk0nAC1IDOTvTlVgjlRvqsdk=
 github.com/golang/protobuf v1.4.0-rc.1/go.mod h1:ceaxUfeHdC40wWswd/P6IGgMaK3YpKi5j83Wpe3EHw8=
 github.com/golang/protobuf v1.4.0-rc.1.0.20200221234624-67d41d38c208/go.mod h1:xKAWHe0F5eneWXFV3EuXVDTCmh+JuBKY0li0aMyXATA=
 github.com/golang/protobuf v1.4.0-rc.2/go.mod h1:LlEzMj4AhA7rCAGe4KMBDvJI+AwstrUpVNzEA03Pprs=
@@ -172,6 +174,7 @@ github.com/mattn/go-isatty v0.0.16 h1:bq3VjFmv/sOjHtdEhmkEV4x1AJtvUvOJ2PFAZ5+peK
 github.com/mattn/go-isatty v0.0.16/go.mod h1:kYGgaQfpe5nmfYZH+SKPsOc2e4SrIfOl2e/yFXSvRLM=
 github.com/mattn/go-runewidth v0.0.9 h1:Lm995f3rfxdpd6TSmuVCHVb/QhupuXlYr8sCI/QdE+0=
 github.com/matttproud/golang_protobuf_extensions v1.0.4 h1:mmDVorXM7PCGKw94cs5zkfA9PSy5pEvNWRP0ET0TIVo=
+github.com/matttproud/golang_protobuf_extensions v1.0.4/go.mod h1:BSXmuO+STAnVfrANrmjBb36TMTDstsz7MSK+HVaYKv4=
 github.com/minio/sha256-simd v1.0.0 h1:v1ta+49hkWZyvaKwrQB8elexRqm6Y0aMLjCNsrYxo6g=
 github.com/minio/sha256-simd v1.0.0/go.mod h1:OuYzVNI5vcoYIAmbIvHPl3N3jUzVedXbKy5RFepssQM=
 github.com/mitchellh/mapstructure v1.5.0 h1:jeMsZIYE/09sWLaz43PL7Gy6RuMjD2eJVyuac5Z2hdY=
@@ -201,10 +204,14 @@ github.com/pkg/errors v0.9.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINE
 github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM=
 github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4=
 github.com/prometheus/client_golang v1.14.0 h1:nJdhIvne2eSX/XRAFV9PcvFFRbrjbcTUj0VP62TMhnw=
+github.com/prometheus/client_golang v1.14.0/go.mod h1:8vpkKitgIVNcqrRBWh1C4TIUQgYNtG/XQE4E/Zae36Y=
 github.com/prometheus/client_model v0.0.0-20190812154241-14fe0d1b01d4/go.mod h1:xMI15A0UPsDsEKsMN9yxemIoYk6Tm2C1GtYGdfGttqA=
 github.com/prometheus/client_model v0.3.0 h1:UBgGFHqYdG/TPFD1B1ogZywDqEkwp3fBMvqdiQ7Xew4=
+github.com/prometheus/client_model v0.3.0/go.mod h1:LDGWKZIo7rky3hgvBe+caln+Dr3dPggB5dvjtD7w9+w=
 github.com/prometheus/common v0.39.0 h1:oOyhkDq05hPZKItWVBkJ6g6AtGxi+fy7F4JvUV8uhsI=
+github.com/prometheus/common v0.39.0/go.mod h1:6XBZ7lYdLCbkAVhwRsWTZn+IN5AB9F/NXd5w0BbEX0Y=
 github.com/prometheus/procfs v0.9.0 h1:wzCHvIvM5SxWqYvwgVL7yJY8Lz3PKn49KQtpgMYJfhI=
+github.com/prometheus/procfs v0.9.0/go.mod h1:+pB4zwohETzFnmlpe6yd2lSc+0/46IYZRB/chUwxUZY=
 github.com/prysmaticlabs/go-bitfield v0.0.0-20210809151128-385d8c5e3fb7 h1:0tVE4tdWQK9ZpYygoV7+vS6QkDvQVySboMVEIxBJmXw=
 github.com/prysmaticlabs/go-bitfield v0.0.0-20210809151128-385d8c5e3fb7/go.mod h1:wmuf/mdK4VMD+jA9ThwcUKjg3a2XWM9cVfFYjDyY4j4=
 github.com/richardartoul/molecule v1.0.1-0.20221107223329-32cfee06a052 h1:Qp27Idfgi6ACvFQat5+VJvlYToylpM/hcyLBI3WaKPA=
@@ -302,6 +309,7 @@ golang.org/x/net v0.8.0 h1:Zrh2ngAOFYneWTAIAPethzeaQLuHwhuBkuV6ZiRnUaQ=
 golang.org/x/oauth2 v0.0.0-20180821212333-d2e6202438be/go.mod h1:N/0e6XlmueqKjAGxoOufVs8QHGRruUQn6yWY3a++T0U=
 golang.org/x/sync v0.0.0-20180314180146-1d60e4601c6f/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM=
 golang.org/x/sync v0.0.0-20181108010431-42b317875d0f/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM=
+golang.org/x/sync v0.0.0-20181221193216-37e7f081c4d4/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM=
 golang.org/x/sync v0.0.0-20190423024810-112230192c58/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM=
 golang.org/x/sync v0.0.0-20201020160332-67f06af15bc9/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM=
 golang.org/x/sync v0.0.0-20210220032951-036812b2e83c/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM=

integrationtest/searcher_test.go

@@ -161,7 +161,7 @@ func TestConnectSearcher(t *testing.T) {
 
 		wg := sync.WaitGroup{}
 		wg.Add(1)
-		var currTime *int64
+		var currTime *time.Time
 		go func(t *testing.T) {
 			// Read from connection
 			mtype, r, err := conn.NextReader()
@@ -173,13 +173,13 @@ func TestConnectSearcher(t *testing.T) {
 			// Decode r into data
 			_ = json.NewDecoder(r).Decode(&data)
 			assert.Equal(t, data.Builder, "0xaa1488eae4b06a1fff840a2b6db167afc520758dc2c8af0dfb57037954df3431b747e2f900fe8805f05d635e9a29717b")
-			assert.GreaterOrEqual(t, data.SenderTimestamp, *currTime)
+			assert.GreaterOrEqual(t, data.SentTimestamp, *currTime)
 			assert.Equal(t, data.ClientTransactions, []string{searcherTxn.Hash().Hex()})
 			wg.Done()
 		}(t)
-		tnow := time.Now().Unix()
+		tnow := time.Now()
 		currTime = &tnow
-		service.SubmitBlock(context.TODO(), &block)
+		service.SubmitBlock(context.TODO(), &block, tnow)
 		wg.Wait()
 	})
 

pkg/api.go

@@ -10,6 +10,8 @@ import (
 
 	"github.com/ethereum/go-ethereum/common"
 	"github.com/gorilla/websocket"
+	"github.com/prometheus/client_golang/prometheus"
+	"github.com/prometheus/client_golang/prometheus/promhttp"
 	"github.com/sirupsen/logrus"
 
 	"github.com/attestantio/go-builder-client/api/capella"
@@ -46,13 +48,46 @@ type jsonError struct {
 }
 
 type API struct {
-	Service      BoostService
-	Worker       *Worker
-	Rollup       rollup.Rollup
-	Log          log.Logger
-	once         sync.Once
-	mux          http.Handler
-	BuilderToken string
+	Service        BoostService
+	Worker         *Worker
+	Rollup         rollup.Rollup
+	Log            log.Logger
+	once           sync.Once
+	mux            http.Handler
+	BuilderToken   string
+	MetricsEnabled bool
+	metrics        *metrics
+}
+
+type metrics struct {
+	Searchers        prometheus.Gauge
+	PayloadsRecieved prometheus.Counter
+	Duration         prometheus.HistogramVec
+}
+
+func NewMetrics(reg prometheus.Registerer) *metrics {
+	m := &metrics{
+		Searchers: prometheus.NewGauge(prometheus.GaugeOpts{
+			Namespace: "primev",
+			Name:      "number_of_searchers_connected",
+			Help:      "Number of connected searchers",
+		}),
+		PayloadsRecieved: prometheus.NewCounter(prometheus.CounterOpts{
+			Namespace: "primev",
+			Name:      "payloads_recieved",
+			Help:      "Number of payloads recieved",
+		}),
+		Duration: *prometheus.NewHistogramVec(prometheus.HistogramOpts{
+			Namespace: "primev",
+			Name:      "duration",
+			Help:      "Duration of the request",
+			Buckets:   []float64{0.0001, 0.0002, 0.0005, 0.001, 0.002, 0.005, 0.01, 0.02, 0.03, 0.05, 0.1, 0.15, 0.2, 0.5},
+		}, []string{"processing_type", "searcher_address"}),
+	}
+
+	reg.MustRegister(m.Searchers, m.PayloadsRecieved, m.Duration)
+
+	return m
 }
 
 func (a *API) init() {
@@ -77,6 +112,14 @@ func (a *API) init() {
 
 		router.HandleFunc(PathSearcherConnect, a.ConnectedSearcher)
 
+		if a.MetricsEnabled {
+			reg := prometheus.NewRegistry()
+			a.metrics = NewMetrics(reg)
+			a.metrics.Searchers.Set(0)
+			promHandler := promhttp.HandlerFor(reg, promhttp.HandlerOpts{})
+
+			router.Handle("/metrics", promHandler)
+		}
 		a.mux = router
 	})
 }
@@ -291,7 +334,7 @@ func (a *API) ConnectedSearcher(w http.ResponseWriter, r *http.Request) {
 				return
 			case data := <-searcherConsumeChannel:
 				metadata := data.InternalMetadata
-				metadata.SenderTimestamp = time.Now().Unix()
+				metadata.SentTimestamp = time.Now()
 				if _, ok := data.SearcherTxns[searcherID]; !ok {
 					data.SearcherTxns[searcherID] = []string{}
 				}
@@ -302,27 +345,41 @@ func (a *API) ConnectedSearcher(w http.ResponseWriter, r *http.Request) {
 					panic(err)
 				}
 				conn.WriteMessage(websocket.TextMessage, json)
+				if a.MetricsEnabled {
+					a.metrics.Duration.WithLabelValues("e2e", searcherAddressParam).Observe(time.Since(metadata.RecTimestamp).Seconds())
+				}
 			}
 		}
 	}(searcherAddressParam)
 
+	a.Worker.lock.RLock()
+	numSearchers := len(a.Worker.connectedSearchers)
+	a.Worker.lock.RUnlock()
+	if a.MetricsEnabled {
+		a.metrics.Searchers.Set(float64(numSearchers))
+	}
 	a.Log.
-		WithField("searcher_count", len(a.Worker.connectedSearchers)).
+		WithField("searcher_count", numSearchers).
 		WithField("searcher_address", searcherAddressParam).
 		Info("new searcher connected")
 }
 
 // builder related handlers
 func (a *API) submitBlock(w http.ResponseWriter, r *http.Request) (int, error) {
+	now := time.Now()
 	var br capella.SubmitBlockRequest
 	if err := json.NewDecoder(r.Body).Decode(&br); err != nil {
 		return http.StatusBadRequest, err
 	}
 
-	if err := a.Service.SubmitBlock(r.Context(), &br); err != nil {
+	if err := a.Service.SubmitBlock(r.Context(), &br, now); err != nil {
 		return http.StatusBadRequest, err
 	}
 
+	if a.MetricsEnabled {
+		a.metrics.Duration.WithLabelValues("algo_processing", "N/A").Observe(time.Since(now).Seconds())
+		a.metrics.PayloadsRecieved.Inc()
+	}
 	return http.StatusOK, nil
 }
 

pkg/boost.go

@@ -13,7 +13,7 @@ import (
 )
 
 type Boost interface {
-	SubmitBlock(context.Context, *capella.SubmitBlockRequest) error
+	SubmitBlock(context.Context, *capella.SubmitBlockRequest, time.Time) error
 	GetWorkChannel() chan SuperPayload
 }
 
@@ -36,7 +36,8 @@ type Metadata struct {
 	BaseFee            uint32      `json:"baseFee"`
 	Transactions       Transaction `json:"standard_transactions"`
 	ClientTransactions []string    `json:"personal_transactions"`
-	SenderTimestamp    int64       `json:"sent_timestamp"`
+	SentTimestamp      time.Time   `json:"sent_timestamp"` // Timestamp of block sent to the searcher
+	RecTimestamp       time.Time   `json:"rec_timestamp"`  // Timestamp of block received by the builder instance
 }
 
 type SuperPayload struct {
@@ -69,7 +70,7 @@ func (rs *DefaultBoost) Log() log.Logger {
 	return rs.config.Log
 }
 
-func (as *DefaultBoost) SubmitBlock(ctx context.Context, msg *capella.SubmitBlockRequest) (err error) {
+func (as *DefaultBoost) SubmitBlock(ctx context.Context, msg *capella.SubmitBlockRequest, now time.Time) (err error) {
 	span, _ := tracer.StartSpanFromContext(ctx, "submit-block")
 	defer span.Finish()
 	defer func() {
@@ -82,7 +83,7 @@ func (as *DefaultBoost) SubmitBlock(ctx context.Context, msg *capella.SubmitBloc
 	var _txn types.Transaction
 	var blockMetadata SuperPayload
 	blockMetadata.SearcherTxns = make(map[string][]string)
-
+	blockMetadata.InternalMetadata.RecTimestamp = now
 	blockMetadata.InternalMetadata.BlockHash = msg.Message.BlockHash.String()
 	blockMetadata.InternalMetadata.Number = int64(msg.ExecutionPayload.BlockNumber)
 	blockMetadata.InternalMetadata.Builder = msg.Message.BuilderPubkey.String()

pkg/boost_test.go

@@ -5,6 +5,7 @@ import (
 	"encoding/json"
 	"fmt"
 	"testing"
+	"time"
 
 	"github.com/alecthomas/assert"
 	"github.com/attestantio/go-builder-client/api/capella"
@@ -147,7 +148,7 @@ func TestDefaultBoost_SubmitBlock(t *testing.T) {
 			if err != nil {
 				fmt.Println("error:", err)
 			}
-			err = service.SubmitBlock(context.TODO(), &msg)
+			err = service.SubmitBlock(context.TODO(), &msg, time.Now())
 			assert.Equal(t, err, tt.expectedErr)
 			if err != nil {
 				return

pkg/service.go

@@ -16,7 +16,7 @@ const (
 type BoostService interface {
 	// Primev APIs
 	// Example(context.Context, *types.ExRequest) error
-	SubmitBlock(context.Context, *capella.SubmitBlockRequest) error
+	SubmitBlock(context.Context, *capella.SubmitBlockRequest, time.Time) error
 }
 
 type DefaultService struct {

prometheus/prometheus.yml

@@ -0,0 +1,13 @@
+---
+global:
+  scrape_interval: 5s
+  evaluation_interval: 5s
+
+alerting:
+
+rule_files:
+
+scrape_configs:
+  - job_name: boost
+    static_configs:
+      - targets: ['boost:18550']