Skip to content

Observability & Performance Improvements #43

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Draft
ckartik wants to merge 2 commits into
base: development
Choose a base branch
from
Draft

Observability & Performance Improvements #43

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
2a54981
Moves to using zerolog for api.
ckartik Jun 26, 2023
df905d5
adds a log for block recieved.
ckartik Jun 26, 2023
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 0 additions & 1 deletion cmd/boost/main.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -209,7 +209,6 @@ func run() cli.ActionFunc {

svr.Handler = &boost.API{
Service: service,
Log: config.Log,
Worker: masterWorker,
Rollup: ru,
BuilderToken: c.String("buildertoken"),
Expand Down
5 changes: 3 additions & 2 deletions go.mod
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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
Copy link
Contributor

@floodcode floodcode Jul 10, 2023

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We probably don't need this import any more if we don't use it

github.com/rs/zerolog v1.29.1
github.com/sirupsen/logrus v1.9.0
Copy link
Contributor

@floodcode floodcode Jul 10, 2023

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This one too

github.com/stretchr/testify v1.8.2
github.com/urfave/cli/v2 v2.17.2-0.20221006022127-8f469abc00aa
Expand Down Expand Up @@ -46,7 +47,7 @@ require (
github.com/holiman/uint256 v1.2.2 // indirect
github.com/klauspost/cpuid/v2 v2.1.2 // indirect
github.com/mattn/go-colorable v0.1.13 // indirect
github.com/mattn/go-isatty v0.0.16 // indirect
github.com/mattn/go-isatty v0.0.19 // indirect
github.com/minio/sha256-simd v1.0.0 // indirect
github.com/mitchellh/mapstructure v1.5.0 // indirect
github.com/outcaste-io/ristretto v0.2.1 // indirect
Expand Down Expand Up @@ -79,5 +80,5 @@ require (

require (
github.com/pkg/errors v0.9.1 // indirect
golang.org/x/sys v0.6.0 // indirect
golang.org/x/sys v0.9.0 // indirect
)
13 changes: 11 additions & 2 deletions go.sum
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -52,6 +52,7 @@ github.com/cockroachdb/logtags v0.0.0-20230118201751-21c54148d20b h1:r6VH0faHjZe
github.com/cockroachdb/pebble v0.0.0-20230209160836-829675f94811 h1:ytcWPaNPhNoGMWEhDvS3zToKcDpRsLuRolQJBVGdozk=
github.com/cockroachdb/redact v1.1.3 h1:AKZds10rFSIj7qADf0g46UixK8NNLwWTNdCIGS5wfSQ=
github.com/codahale/rfc6979 v0.0.0-20141003034818-6a90f24967eb/go.mod h1:ZjrT6AXHbDs86ZSdt/osfBi5qfexBrKUdONk989Wnk4=
github.com/coreos/go-systemd/v22 v22.5.0/go.mod h1:Y58oyj3AT4RCenI/lSvhwexgC+NSVTIJ3seZv2GcEnc=
github.com/cpuguy83/go-md2man/v2 v2.0.2 h1:p1EgwI/C7NhT0JmVkwCD2ZBK8j4aeHQX2pMHHBfMQ6w=
github.com/cpuguy83/go-md2man/v2 v2.0.2/go.mod h1:tgQtvFlXSQOSOSIRvRPT7W67SCa46tRHOmNcaadrF8o=
github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
Expand Down Expand Up @@ -102,6 +103,7 @@ github.com/go-stack/stack v1.8.1/go.mod h1:dcoOX6HbPZSZptuspn9bctJ+N/CnF5gGygcUP
github.com/go-task/slim-sprig v0.0.0-20210107165309-348f09dbbbc0/go.mod h1:fyg7847qk6SyHyPtNmDHnmrv/HOrqktSC+C9fM+CJOE=
github.com/goccy/go-yaml v1.9.2 h1:2Njwzw+0+pjU2gb805ZC1B/uBuAs2VcZ3K+ZgHwDs7w=
github.com/goccy/go-yaml v1.9.2/go.mod h1:U/jl18uSupI5rdI2jmuCswEA2htH9eXfferR3KfscvA=
github.com/godbus/dbus/v5 v5.0.4/go.mod h1:xhWf0FNVPg57R7Z0UbKHbJfkEywrmjJnf7w5xrFpKfA=
github.com/gofrs/flock v0.8.1 h1:+gYjHKf32LDeiEEFhQaotPbLuUXjY5ZqxKgXy7n59aw=
github.com/gogo/protobuf v1.3.2 h1:Ov1cvc58UF3b5XjBnZv7+opcTcQFZebYjWzi34vdm4Q=
github.com/golang-jwt/jwt/v4 v4.3.0 h1:kHL1vqdqWNfATmA0FNMdmZNMyZI1U6O31X4rlIPoBog=
Expand Down Expand Up @@ -164,12 +166,14 @@ github.com/lthibault/log v1.2.2 h1:t/annjqaDlUPQlHBbPV2dlD4T8c4R7UPJIXda7C3j3k=
github.com/lthibault/log v1.2.2/go.mod h1:Qf1+O6GWWx7bLGFGkGTfUMDCvJ/uz2R7Vqa2U1AzD1U=
github.com/mattn/go-colorable v0.1.8/go.mod h1:u6P/XSegPjTcexA+o6vUJrdnUu04hMope9wVRipJSqc=
github.com/mattn/go-colorable v0.1.9/go.mod h1:u6P/XSegPjTcexA+o6vUJrdnUu04hMope9wVRipJSqc=
github.com/mattn/go-colorable v0.1.12/go.mod h1:u5H1YNBxpqRaxsYJYSkiCWKzEfiAb1Gb520KVy5xxl4=
github.com/mattn/go-colorable v0.1.13 h1:fFA4WZxdEF4tXPZVKMLwD8oUnCTTo08duU7wxecdEvA=
github.com/mattn/go-colorable v0.1.13/go.mod h1:7S9/ev0klgBDR4GtXTXX8a3vIGJpMovkB8vQcUbaXHg=
github.com/mattn/go-isatty v0.0.12/go.mod h1:cbi8OIDigv2wuxKPP5vlRcQ1OAZbq2CE4Kysco4FUpU=
github.com/mattn/go-isatty v0.0.14/go.mod h1:7GGIvUiUoEMVVmxf/4nioHXj79iQHKdU27kJ6hsGG94=
github.com/mattn/go-isatty v0.0.16 h1:bq3VjFmv/sOjHtdEhmkEV4x1AJtvUvOJ2PFAZ5+peKQ=
github.com/mattn/go-isatty v0.0.16/go.mod h1:kYGgaQfpe5nmfYZH+SKPsOc2e4SrIfOl2e/yFXSvRLM=
github.com/mattn/go-isatty v0.0.19 h1:JITubQf0MOLdlGRuRq+jtsDlekdYPia9ZFsB8h/APPA=
github.com/mattn/go-isatty v0.0.19/go.mod h1:W+V8PltTTMOvKvAeJH7IuucS94S2C6jfK/D7dTCTo3Y=
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/minio/sha256-simd v1.0.0 h1:v1ta+49hkWZyvaKwrQB8elexRqm6Y0aMLjCNsrYxo6g=
Expand Down Expand Up @@ -210,6 +214,9 @@ github.com/prysmaticlabs/go-bitfield v0.0.0-20210809151128-385d8c5e3fb7/go.mod h
github.com/richardartoul/molecule v1.0.1-0.20221107223329-32cfee06a052 h1:Qp27Idfgi6ACvFQat5+VJvlYToylpM/hcyLBI3WaKPA=
github.com/rogpeppe/go-internal v1.9.0 h1:73kH8U+JUqXU8lRuOHeVHaa/SZPifC7BkcraZVejAe8=
github.com/rs/cors v1.7.0 h1:+88SsELBHx5r+hZ8TCkggzSstaWNbDvThkVK8H6f9ik=
github.com/rs/xid v1.4.0/go.mod h1:trrq9SKmegXys3aeAKXMUTdJsYXVwGY3RLcfgqegfbg=
github.com/rs/zerolog v1.29.1 h1:cO+d60CHkknCbvzEWxP0S9K6KqyTjrCNUy1LdQLCGPc=
github.com/rs/zerolog v1.29.1/go.mod h1:Le6ESbR7hc+DP6Lt1THiV8CQSdkkNrd3R0XbEgp3ZBU=
github.com/russross/blackfriday/v2 v2.1.0 h1:JIOH55/0cWyOuilr9/qlrm0BSXldqnqwMsf35Ld67mk=
github.com/russross/blackfriday/v2 v2.1.0/go.mod h1:+Rmxgy9KzJVeS9/2gXHxylqXiyQDYRxCVz55jmeOWTM=
github.com/secure-systems-lab/go-securesystemslib v0.3.1/go.mod h1:o8hhjkbNl2gOamKUA/eNW3xUrntHT9L4W89W1nfj43U=
Expand Down Expand Up @@ -334,14 +341,16 @@ golang.org/x/sys v0.0.0-20210423082822-04245dca01da/go.mod h1:h1NjWce9XRLGQEsW7w
golang.org/x/sys v0.0.0-20210510120138-977fb7262007/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
golang.org/x/sys v0.0.0-20210615035016-665e8c7367d1/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
golang.org/x/sys v0.0.0-20210630005230-0f9fa26af87c/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
golang.org/x/sys v0.0.0-20210927094055-39ccf1dd6fa6/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
golang.org/x/sys v0.0.0-20211216021012-1d35b9e2eb4e/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
golang.org/x/sys v0.0.0-20220627191245-f75cf1eec38b/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
golang.org/x/sys v0.0.0-20220704084225-05e143d24a9e/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
golang.org/x/sys v0.0.0-20220715151400-c0bba94af5f8/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
golang.org/x/sys v0.0.0-20220811171246-fbc7d0a398ab/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
golang.org/x/sys v0.0.0-20220908164124-27713097b956/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
golang.org/x/sys v0.6.0 h1:MVltZSvRTcU2ljQOhs94SXPftV6DCNnZViHeQps87pQ=
golang.org/x/sys v0.6.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
golang.org/x/sys v0.9.0 h1:KS/R3tvhPqvJvwcKfnBHJwwthS11LRhmM5D59eEXa0s=
golang.org/x/sys v0.9.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
golang.org/x/term v0.0.0-20201126162022-7de9c90e9dd1/go.mod h1:bj7SfCRtBDWHUb9snDiAeCFNEtKQo2Wmx5Cou7ajbmo=
golang.org/x/term v0.0.0-20210927222741-03fcf44c2211/go.mod h1:jbD1KX2456YbFQfuXm/mYQcufACuNUgVhRMnK/tPxf8=
golang.org/x/text v0.3.0/go.mod h1:NqM8EUOU14njkJ3fqMW+pc6Ldnwhi/IjpwHt7yyuwOQ=
Expand Down
1 change: 0 additions & 1 deletion integrationtest/searcher_test.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -52,7 +52,6 @@ func TestConnectSearcher(t *testing.T) {
api := &boost.API{
Service: service,
Worker: boost.NewWorker(service.GetWorkChannel(), config.Log),
Log: config.Log,
}

go api.Worker.Run(context.Background())
Expand Down
64 changes: 30 additions & 34 deletions pkg/api.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -10,13 +10,12 @@ import (

"github.com/ethereum/go-ethereum/common"
"github.com/gorilla/websocket"
"github.com/sirupsen/logrus"

"github.com/attestantio/go-builder-client/api/capella"

"github.com/lthibault/log"
"github.com/primev/builder-boost/pkg/rollup"
"github.com/primev/builder-boost/pkg/utils"
"github.com/rs/zerolog/log"
)

// Context Keys
Expand Down Expand Up @@ -49,18 +48,13 @@ type API struct {
Service BoostService
Worker *Worker
Rollup rollup.Rollup
Log log.Logger
once sync.Once
mux http.Handler
BuilderToken string
}

func (a *API) init() {
a.once.Do(func() {
if a.Log == nil {
a.Log = log.New()
}

// router := chi.NewRouter()
// router.Use(middleware.Logger)
// TODO(@floodcode): Add CORS middleware
Expand Down Expand Up @@ -90,7 +84,7 @@ func (a *API) authenticateBuilder(next http.Handler) http.Handler {
return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
authToken := r.Header.Get("X-Builder-Token")
if authToken != a.BuilderToken {
a.Log.Error("failed to authenticate builder request")
log.Error().Msg("failed to authenticate builder request")
w.WriteHeader(http.StatusUnauthorized)
return
}
Expand All @@ -105,7 +99,7 @@ func (a *API) authSearcher(next http.Handler) http.Handler {
builderAddress := a.Rollup.GetBuilderAddress()
searcherAddress, ok := utils.VerifyAuthenticationToken(authToken, builderAddress.Hex())
if !ok {
a.Log.WithField("token", authToken).Error("token is not valid")
log.Error().Str("token", authToken).Msg("token is not valid")
w.WriteHeader(http.StatusBadRequest)
w.Write([]byte("token is not valid"))
return
Expand Down Expand Up @@ -166,7 +160,7 @@ func (a *API) handleSearcherCommitment(w http.ResponseWriter, r *http.Request) {
// 2. The searcher behind the token has active subscription
// 3. The searcher behind the token is not already connected
func (a *API) ConnectedSearcher(w http.ResponseWriter, r *http.Request) {
a.Log.Info("searcher called")
log.Info().Msg("searcher called")
ws := websocket.Upgrader{
ReadBufferSize: 1028,
WriteBufferSize: 1028,
Expand All @@ -176,7 +170,7 @@ func (a *API) ConnectedSearcher(w http.ResponseWriter, r *http.Request) {
// Use verification scheme on token
token := r.URL.Query().Get("token")
if token == "" {
a.Log.WithField("token", token).Error("token is not valid")
log.Error().Str("token", token).Msg("token is not valid")
w.WriteHeader(http.StatusBadRequest)
w.Write([]byte("token is not valid"))
return
Expand All @@ -185,7 +179,7 @@ func (a *API) ConnectedSearcher(w http.ResponseWriter, r *http.Request) {

searcherAddress, ok := utils.VerifyAuthenticationToken(token, builderAddress.Hex())
if !ok {
a.Log.WithField("token", token).Error("token is not valid")
log.Error().Str("token", token).Msg("token is not valid")
w.WriteHeader(http.StatusBadRequest)
w.Write([]byte("token is not valid"))
return
Expand All @@ -194,36 +188,39 @@ func (a *API) ConnectedSearcher(w http.ResponseWriter, r *http.Request) {
_, err := a.Rollup.GetMinimalStake(builderAddress)
if err != nil {
if errors.Is(rollup.ErrNoMinimalStakeSet, err) {
a.Log.WithError(err).WithField("builder_address", builderAddress).Error("no minimal stake is set, in order to allow searchers to connect, set minimal stake in the rollup contract")
log.Error().Err(err).Str("builder_address", builderAddress.String()).Msg("no minimal stake is set, in order to allow searchers to connect, set minimal stake in the rollup contract")
w.WriteHeader(http.StatusInternalServerError)
return
}
a.Log.WithError(err).Error("failed to get minimal stake")
log.Error().Err(err).Msg("failed to get minimal stake")
w.WriteHeader(http.StatusInternalServerError)
return
}

commitment := a.Rollup.GetCommitment(searcherAddress)
blockNumber, err := a.Rollup.GetBlockNumber()
if err != nil {
a.Log.WithError(err).Error("failed to get block number")
log.Error().Err(err).Msg("failed to get block number")
w.WriteHeader(http.StatusInternalServerError)
}

subscriptionEnd, err := a.Rollup.GetSubscriptionEnd(commitment)
if err != nil {
a.Log.WithError(err).Error("failed to get subscription end")
log.Error().Err(err).Msg("failed to get subscription end")
w.WriteHeader(http.StatusInternalServerError)
}

searcherAddressParam := searcherAddress.Hex()
a.Log.WithFields(logrus.Fields{"searcher": searcherAddressParam, "block_number": blockNumber, "subscription_end": subscriptionEnd}).
Info("searcher attempting connection")
//(logrus.Fields{"searcher": searcherAddressParam, "block_number": blockNumber, "subscription_end": subscriptionEnd}
log.Info().
Str("searcher", searcherAddressParam).
Uint64("block_number", blockNumber.Uint64()).
Uint64("subscription_end", subscriptionEnd.Uint64()).
Msg("searcher attempting connection")

// Check is subscription is expired
if subscriptionEnd.Cmp(blockNumber) < 0 {
a.Log.WithField("searcher", searcherAddressParam).
Warn("subscription is expired")
log.Warn().Str("searcher", searcherAddressParam).Msg("subscription is expired")
w.WriteHeader(http.StatusForbidden)
return
}
Expand All @@ -234,17 +231,17 @@ func (a *API) ConnectedSearcher(w http.ResponseWriter, r *http.Request) {
_, ok = a.Worker.connectedSearchers[searcherAddressParam]
a.Worker.lock.RUnlock()
if ok {
a.Log.WithFields(logrus.Fields{"searcher": searcherAddressParam}).Error("searcher is already connected")
log.Warn().Str("searcher", searcherAddressParam).Msg("searcher is already connected")
w.WriteHeader(http.StatusForbidden)
w.Write([]byte("searcher is already connected"))
return
}

// Upgrade the HTTP request to a WebSocket connection
conn, err := ws.Upgrade(w, r, nil)
a.Log.Info("searcher upgraded connection")
log.Info().Msg("searcher upgraded connection")
if err != nil {
a.Log.Error(err)
log.Error().Err(err).Msg("")
return
}

Expand All @@ -253,27 +250,27 @@ func (a *API) ConnectedSearcher(w http.ResponseWriter, r *http.Request) {
a.Worker.connectedSearchers[searcherAddressParam] = searcherConsumeChannel
a.Worker.lock.Unlock()

a.Log.Info("searcher connected and ready to consume data")
log.Info().Msg("searcher connected and ready to consume data")

closeSignalChannel := make(chan struct{})
go func(closeChannel chan struct{}, conn *websocket.Conn) {
for {
a.Log.WithFields(logrus.Fields{"searcher": searcherAddressParam}).Info("starting to read from searcher")
log.Info().Str("searcher", searcherAddressParam).Msg("starting to read from searcher")

_, _, err := conn.NextReader()
if err != nil {
a.Log.WithFields(logrus.Fields{"searcher": searcherAddressParam, "err": err}).Error("error reading from searcher")
log.Error().Err(err).Str("searcher", searcherAddressParam).Msg("error reading from searcher")
break
}
}
a.Log.WithFields(logrus.Fields{"searcher": searcherAddressParam}).Info("searcher disconnected")
log.Info().Str("searcher", searcherAddressParam).Msg("searcher disconnected")
closeChannel <- struct{}{}
}(closeSignalChannel, conn)

go func() {
defer func() {
if r := recover(); r != nil {
a.Log.Error("recovered in searcher communication goroutine: closing connection", r)
log.Error().Interface("recovery", r).Stack().Msg("recovered in searcher communication goroutine: closing connection")
a.Worker.lock.Lock()
defer a.Worker.lock.Unlock()
delete(a.Worker.connectedSearchers, searcherAddressParam)
Expand All @@ -292,18 +289,17 @@ func (a *API) ConnectedSearcher(w http.ResponseWriter, r *http.Request) {
data.SenderTimestamp = time.Now().Unix()
json, err := json.Marshal(data)
if err != nil {
a.Log.Error(err)
log.Error().Err(err).Msg("")
panic(err)
}
conn.WriteMessage(websocket.TextMessage, json)
}
}
}()

a.Log.
WithField("searcher_count", len(a.Worker.connectedSearchers)).
WithField("searcher_address", searcherAddressParam).
Info("new searcher connected")
log.Info().Int("searcher_count", len(a.Worker.connectedSearchers)).
Str("searcher_address", searcherAddressParam).
Msg("new searcher connected")
}

// builder related handlers
Expand All @@ -312,7 +308,7 @@ func (a *API) submitBlock(w http.ResponseWriter, r *http.Request) (int, error) {
if err := json.NewDecoder(r.Body).Decode(&br); err != nil {
return http.StatusBadRequest, err
}

log.Info().Timestamp().Str("block_hash", br.ExecutionPayload.BlockHash.String()).Msg("received block")
if err := a.Service.SubmitBlock(r.Context(), &br); err != nil {
return http.StatusBadRequest, err
}
Expand Down