From 5bceb2dcf1bb99bdad8692157dadb445a967c74b Mon Sep 17 00:00:00 2001 From: Michael Neuder Date: Fri, 15 Sep 2023 12:29:37 -0400 Subject: [PATCH 1/9] optimistic v2 slowpath --- services/api/optimistic_test.go | 81 ++++++++++++++++++++ services/api/service.go | 128 +++++++++++++++++++++++++++----- 2 files changed, 190 insertions(+), 19 deletions(-) diff --git a/services/api/optimistic_test.go b/services/api/optimistic_test.go index 6635b753..283d7fb0 100644 --- a/services/api/optimistic_test.go +++ b/services/api/optimistic_test.go @@ -1,8 +1,10 @@ package api import ( + "bytes" "context" "encoding/json" + "errors" "fmt" "math/big" "net/http" @@ -12,6 +14,7 @@ import ( "time" "github.com/alicebob/miniredis/v2" + "github.com/attestantio/go-builder-client/api/capella" v1 "github.com/attestantio/go-builder-client/api/v1" "github.com/attestantio/go-eth2-client/spec/bellatrix" consensuscapella "github.com/attestantio/go-eth2-client/spec/capella" @@ -640,3 +643,81 @@ func TestBuilderApiSubmitNewBlockOptimisticV2_full(t *testing.T) { }) } } + +func TestBuilderApiOptimisticV2SlowPath_fail_ssz_decode_header(t *testing.T) { + pubkey, _ := generateKeyPair(t) + backend := startTestBackend(t, pubkey) + outBytes := make([]byte, 944) // 944 bytes is min required to try ssz decoding. + outBytes[0] = 0xaa + + r := bytes.NewReader(outBytes) + + backend.relay.optimisticV2SlowPath(r, v2SlowPathOpts{ + payload: &common.BuilderSubmitBlockRequest{ + Capella: &capella.SubmitBlockRequest{ + Message: &v1.BidTrace{ + BuilderPubkey: *pubkey, + }, + }, + }, + }) + + // Check that demotion occurred. + mockDB, ok := backend.relay.db.(*database.MockDB) + require.True(t, ok) + require.Equal(t, mockDB.Demotions[pubkey.String()], true) +} + +func TestBuilderApiOptimisticV2SlowPath(t *testing.T) { + pubkey, secretkey := generateKeyPair(t) + + testReq := common.TestBuilderSubmitBlockRequestV2(secretkey, getTestBidTrace(*pubkey, 10)) + testPayload := &common.BuilderSubmitBlockRequest{ + Capella: &capella.SubmitBlockRequest{ + Message: &v1.BidTrace{ + BuilderPubkey: *pubkey, + }, + ExecutionPayload: &consensuscapella.ExecutionPayload{}, + }, + } + + testCases := []struct { + description string + simError error + expectDemotion bool + }{ + { + description: "success", + }, + { + description: "failure_empty_payload", + simError: errors.New("test err"), + expectDemotion: true, + }, + } + + for _, tc := range testCases { + t.Run(tc.description, func(t *testing.T) { + backend := startTestBackend(t, pubkey) + backend.relay.blockSimRateLimiter = &MockBlockSimulationRateLimiter{ + simulationError: tc.simError, + } + + submissionBytes, err := testReq.MarshalSSZ() + require.NoError(t, err) + + r := bytes.NewReader(submissionBytes) + + opts := v2SlowPathOpts{ + payload: testPayload, + entry: &blockBuilderCacheEntry{}, + } + backend.relay.optimisticV2SlowPath(r, opts) + + // Check demotion status. + mockDB, ok := backend.relay.db.(*database.MockDB) + require.True(t, ok) + require.Equal(t, mockDB.Demotions[pubkey.String()], tc.expectDemotion) + }) + } +} diff --git a/services/api/service.go b/services/api/service.go index 428d8a0d..14af4800 100644 --- a/services/api/service.go +++ b/services/api/service.go @@ -2311,15 +2311,12 @@ func (api *RelayAPI) handleSubmitNewBlockV2(w http.ResponseWriter, req *http.Req remainderReader := bytes.NewReader(remainder) slowPathOpts := v2SlowPathOpts{ - header: &header, - payload: payload, - receivedAt: receivedAt, - eligibleAt: eligibleAt, - pf: pf, - isCancellationEnabled: isCancellationEnabled, - entry: builderEntry, - gasLimit: gasLimit, - pipeliner: tx, + payload: payload, + receivedAt: receivedAt, + eligibleAt: eligibleAt, + pf: pf, + entry: builderEntry, + gasLimit: gasLimit, } // Join the header bytes with the remaining bytes. @@ -2333,21 +2330,114 @@ func (api *RelayAPI) handleSubmitNewBlockV2(w http.ResponseWriter, req *http.Req } type v2SlowPathOpts struct { - header *common.SubmitBlockRequestV2Optimistic - payload *common.BuilderSubmitBlockRequest - receivedAt time.Time - eligibleAt time.Time - pf common.Profile - isCancellationEnabled bool - entry *blockBuilderCacheEntry - gasLimit uint64 - pipeliner redis.Pipeliner + payload *common.BuilderSubmitBlockRequest + receivedAt time.Time + eligibleAt time.Time + pf common.Profile + entry *blockBuilderCacheEntry + gasLimit uint64 } func (api *RelayAPI) optimisticV2SlowPath(r io.Reader, v2Opts v2SlowPathOpts) { log := api.log.WithFields(logrus.Fields{"method": "optimisticV2SlowPath"}) - // TODO(mikeneuder): slow path + payload := v2Opts.payload + msg, err := io.ReadAll(r) + if err != nil { + demotionErr := fmt.Errorf("%w: could not read full message", err) + api.demoteBuilder(payload.BuilderPubkey().String(), payload, demotionErr) + log.WithError(err).Warn("could not read full message") + return + } + + // Unmarshall full request. + var req common.SubmitBlockRequestV2Optimistic + err = req.UnmarshalSSZ(msg) + if err != nil { + demotionErr := fmt.Errorf("%w: could not unmarshall full request", err) + api.demoteBuilder(payload.BuilderPubkey().String(), payload, demotionErr) + log.WithError(err).Warn("could not unmarshall full request") + return + } + + // Fill in txns and withdrawals. + payload.Capella.ExecutionPayload.Transactions = req.Transactions + payload.Capella.ExecutionPayload.Withdrawals = req.Withdrawals + + getPayloadResponse, err := common.BuildGetPayloadResponse(payload) + if err != nil { + demotionErr := fmt.Errorf("%w: could not construct getPayloadResponse", err) + api.demoteBuilder(payload.BuilderPubkey().String(), payload, demotionErr) + log.WithError(err).Warn("could not construct getPayloadResponse") + return + } + + // Create the redis pipeline tx + tx := api.redis.NewTxPipeline() + + // Save payload. + err = api.redis.SaveExecutionPayloadCapella(context.Background(), tx, payload.Slot(), payload.ProposerPubkey(), payload.BlockHash(), getPayloadResponse.Capella.Capella) + if err != nil { + demotionErr := fmt.Errorf("%w: could not save execution payload", err) + api.demoteBuilder(payload.BuilderPubkey().String(), payload, demotionErr) + log.WithError(err).Warn("could not save execution payload") + return + } + + currentTime := time.Now().UTC() + log.WithFields(logrus.Fields{ + "timeStampExecutionPayloadSaved": currentTime.UnixMilli(), + "timeSinceReceivedAt": v2Opts.receivedAt.Sub(currentTime).Milliseconds(), + "timeSinceEligibleAt": v2Opts.eligibleAt.Sub(currentTime).Milliseconds(), + }).Info("v2 execution payload saved") + + // Used to communicate simulation result to the deferred function. + simResultC := make(chan *blockSimResult, 1) + + // Deferred saving of the builder submission to database (whenever this function ends) + defer func() { + savePayloadToDatabase := !api.ffDisablePayloadDBStorage + var simResult *blockSimResult + select { + case simResult = <-simResultC: + case <-time.After(10 * time.Second): + log.Warn("timed out waiting for simulation result") + simResult = &blockSimResult{false, false, nil, nil} + } + + submissionEntry, err := api.db.SaveBuilderBlockSubmission(payload, simResult.requestErr, simResult.validationErr, v2Opts.receivedAt, v2Opts.eligibleAt, simResult.wasSimulated, savePayloadToDatabase, v2Opts.pf, simResult.optimisticSubmission) + if err != nil { + log.WithError(err).WithField("payload", payload).Error("saving builder block submission to database failed") + return + } + + err = api.db.UpsertBlockBuilderEntryAfterSubmission(submissionEntry, simResult.validationErr != nil) + if err != nil { + log.WithError(err).Error("failed to upsert block-builder-entry") + } + }() + + // Simulate the block submission and save to db + timeBeforeValidation := time.Now().UTC() + + log = log.WithFields(logrus.Fields{ + "timestampBeforeValidation": timeBeforeValidation.UTC().UnixMilli(), + }) + + // Construct simulation request. + opts := blockSimOptions{ + isHighPrio: v2Opts.entry.status.IsHighPrio, + log: log, + builder: v2Opts.entry, + req: &common.BuilderBlockValidationRequest{ + BuilderSubmitBlockRequest: *payload, + RegisteredGasLimit: v2Opts.gasLimit, + }, + } + go api.processOptimisticBlock(opts, simResultC) + + nextTime := time.Now().UTC() + v2Opts.pf.Simulation = uint64(nextTime.Sub(v2Opts.eligibleAt).Microseconds()) // All done log.Info("received v2 block from builder") From 24e0f84ae607785dea80dbf6ba8fa795094dd883 Mon Sep 17 00:00:00 2001 From: Michael Neuder Date: Fri, 15 Sep 2023 12:35:50 -0400 Subject: [PATCH 2/9] fix lint --- services/api/optimistic_test.go | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/services/api/optimistic_test.go b/services/api/optimistic_test.go index 283d7fb0..39e7e1ec 100644 --- a/services/api/optimistic_test.go +++ b/services/api/optimistic_test.go @@ -4,7 +4,6 @@ import ( "bytes" "context" "encoding/json" - "errors" "fmt" "math/big" "net/http" @@ -691,7 +690,7 @@ func TestBuilderApiOptimisticV2SlowPath(t *testing.T) { }, { description: "failure_empty_payload", - simError: errors.New("test err"), + simError: errFake, expectDemotion: true, }, } From 19901824379551210aacd504c0be3a0584a5ee6e Mon Sep 17 00:00:00 2001 From: Michael Neuder Date: Fri, 15 Sep 2023 12:38:33 -0400 Subject: [PATCH 3/9] remove race --- services/api/service.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/services/api/service.go b/services/api/service.go index 14af4800..c9147385 100644 --- a/services/api/service.go +++ b/services/api/service.go @@ -2434,7 +2434,7 @@ func (api *RelayAPI) optimisticV2SlowPath(r io.Reader, v2Opts v2SlowPathOpts) { RegisteredGasLimit: v2Opts.gasLimit, }, } - go api.processOptimisticBlock(opts, simResultC) + api.processOptimisticBlock(opts, simResultC) nextTime := time.Now().UTC() v2Opts.pf.Simulation = uint64(nextTime.Sub(v2Opts.eligibleAt).Microseconds()) From b75d6b76d941ce5b7062bf1fe904f7d21ace6a0e Mon Sep 17 00:00:00 2001 From: Michael Neuder Date: Thu, 21 Sep 2023 09:14:55 -0400 Subject: [PATCH 4/9] move signature below other checks --- services/api/optimistic_test.go | 5 ++++- services/api/service.go | 30 +++++++++++++++--------------- 2 files changed, 19 insertions(+), 16 deletions(-) diff --git a/services/api/optimistic_test.go b/services/api/optimistic_test.go index 39e7e1ec..833bf3b2 100644 --- a/services/api/optimistic_test.go +++ b/services/api/optimistic_test.go @@ -509,7 +509,10 @@ func TestBuilderApiSubmitNewBlockOptimisticV2_full(t *testing.T) { badSigReq := common.TestBuilderSubmitBlockRequestV2(secretkey, getTestBidTrace(*pubkey, 10)) badSigReq.Signature[0] = 0xaa invalidSigReq := common.TestBuilderSubmitBlockRequestV2(secretkey, getTestBidTrace(*pubkey, 10)) - invalidSigReq.Message.Slot += 1 + // Sign over a message with a different value. + diffSig, err := boostTypes.SignMessage(getTestBidTrace(*pubkey, 11), boostTypes.DomainBuilder, secretkey) + require.Nil(t, err) + invalidSigReq.Signature = phase0.BLSSignature(diffSig) badTimestampReq := common.TestBuilderSubmitBlockRequestV2(secretkey, getTestBidTrace(*pubkey, 10)) badTimestampReq.ExecutionPayloadHeader.Timestamp -= 1 badWithdrawalsRootReq := common.TestBuilderSubmitBlockRequestV2(secretkey, getTestBidTrace(*pubkey, 10)) diff --git a/services/api/service.go b/services/api/service.go index c9147385..ed080f63 100644 --- a/services/api/service.go +++ b/services/api/service.go @@ -2149,25 +2149,11 @@ func (api *RelayAPI) handleSubmitNewBlockV2(w http.ResponseWriter, req *http.Req "value": bid.Value.String(), }) - // Verify the signature - log = log.WithField("timestampBeforeSignatureCheck", time.Now().UTC().UnixMilli()) - ok, err := boostTypes.VerifySignature(bid, api.opts.EthNetDetails.DomainBuilder, bid.BuilderPubkey[:], sig[:]) - log = log.WithField("timestampAfterSignatureCheck", time.Now().UTC().UnixMilli()) - if err != nil { - log.WithError(err).Warn("failed verifying builder signature") - api.RespondError(w, http.StatusBadRequest, "failed verifying builder signature") - return - } else if !ok { - log.Warn("invalid builder signature") - api.RespondError(w, http.StatusBadRequest, "invalid signature") - return - } - log.WithFields(logrus.Fields{ "bid": bid, "signature": sig, "decode_time": pf.Decode, - }).Info("optimistically parsed bid and verified signature") + }).Info("optimistically parsed bid") // Check optimistic eligibility. builderPubkey := bid.BuilderPubkey @@ -2242,6 +2228,20 @@ func (api *RelayAPI) handleSubmitNewBlockV2(w http.ResponseWriter, req *http.Req return } + // Verify the signature + log = log.WithField("timestampBeforeSignatureCheck", time.Now().UTC().UnixMilli()) + ok, err = boostTypes.VerifySignature(bid, api.opts.EthNetDetails.DomainBuilder, bid.BuilderPubkey[:], sig[:]) + log = log.WithField("timestampAfterSignatureCheck", time.Now().UTC().UnixMilli()) + if err != nil { + log.WithError(err).Warn("failed verifying builder signature") + api.RespondError(w, http.StatusBadRequest, "failed verifying builder signature") + return + } else if !ok { + log.Warn("invalid builder signature") + api.RespondError(w, http.StatusBadRequest, "invalid signature") + return + } + // Create the redis pipeline tx tx := api.redis.NewTxPipeline() From 7db71a52cb7f6820af99ee8d038107960a297fc2 Mon Sep 17 00:00:00 2001 From: Michael Neuder Date: Thu, 21 Sep 2023 09:16:13 -0400 Subject: [PATCH 5/9] Revert "remove race" This reverts commit 19901824379551210aacd504c0be3a0584a5ee6e. --- services/api/service.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/services/api/service.go b/services/api/service.go index ed080f63..933f0b9b 100644 --- a/services/api/service.go +++ b/services/api/service.go @@ -2434,7 +2434,7 @@ func (api *RelayAPI) optimisticV2SlowPath(r io.Reader, v2Opts v2SlowPathOpts) { RegisteredGasLimit: v2Opts.gasLimit, }, } - api.processOptimisticBlock(opts, simResultC) + go api.processOptimisticBlock(opts, simResultC) nextTime := time.Now().UTC() v2Opts.pf.Simulation = uint64(nextTime.Sub(v2Opts.eligibleAt).Microseconds()) From 00d259400560926978aee789f8ed996e4d28e6ee Mon Sep 17 00:00:00 2001 From: Michael Neuder Date: Thu, 21 Sep 2023 09:17:27 -0400 Subject: [PATCH 6/9] fix race --- services/api/service.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/services/api/service.go b/services/api/service.go index 933f0b9b..ed080f63 100644 --- a/services/api/service.go +++ b/services/api/service.go @@ -2434,7 +2434,7 @@ func (api *RelayAPI) optimisticV2SlowPath(r io.Reader, v2Opts v2SlowPathOpts) { RegisteredGasLimit: v2Opts.gasLimit, }, } - go api.processOptimisticBlock(opts, simResultC) + api.processOptimisticBlock(opts, simResultC) nextTime := time.Now().UTC() v2Opts.pf.Simulation = uint64(nextTime.Sub(v2Opts.eligibleAt).Microseconds()) From 303183fc5161322d9a3cbf63c3ea3a41f1585c92 Mon Sep 17 00:00:00 2001 From: Michael Neuder Date: Thu, 21 Sep 2023 09:18:01 -0400 Subject: [PATCH 7/9] Revert "fix race" This reverts commit 00d259400560926978aee789f8ed996e4d28e6ee. --- services/api/service.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/services/api/service.go b/services/api/service.go index ed080f63..933f0b9b 100644 --- a/services/api/service.go +++ b/services/api/service.go @@ -2434,7 +2434,7 @@ func (api *RelayAPI) optimisticV2SlowPath(r io.Reader, v2Opts v2SlowPathOpts) { RegisteredGasLimit: v2Opts.gasLimit, }, } - api.processOptimisticBlock(opts, simResultC) + go api.processOptimisticBlock(opts, simResultC) nextTime := time.Now().UTC() v2Opts.pf.Simulation = uint64(nextTime.Sub(v2Opts.eligibleAt).Microseconds()) From 355ae7634d40ba38e65e0d98f1260344b119f91d Mon Sep 17 00:00:00 2001 From: Michael Neuder Date: Thu, 21 Sep 2023 09:18:20 -0400 Subject: [PATCH 8/9] Revert "Revert "remove race"" This reverts commit 7db71a52cb7f6820af99ee8d038107960a297fc2. --- services/api/service.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/services/api/service.go b/services/api/service.go index 933f0b9b..ed080f63 100644 --- a/services/api/service.go +++ b/services/api/service.go @@ -2434,7 +2434,7 @@ func (api *RelayAPI) optimisticV2SlowPath(r io.Reader, v2Opts v2SlowPathOpts) { RegisteredGasLimit: v2Opts.gasLimit, }, } - go api.processOptimisticBlock(opts, simResultC) + api.processOptimisticBlock(opts, simResultC) nextTime := time.Now().UTC() v2Opts.pf.Simulation = uint64(nextTime.Sub(v2Opts.eligibleAt).Microseconds()) From 997bcb20167f72ef1a488473e7d5e2dbce53dd15 Mon Sep 17 00:00:00 2001 From: Michael Neuder Date: Thu, 21 Sep 2023 09:20:22 -0400 Subject: [PATCH 9/9] fix race --- services/api/optimistic_test.go | 5 +---- services/api/service.go | 30 +++++++++++++++--------------- 2 files changed, 16 insertions(+), 19 deletions(-) diff --git a/services/api/optimistic_test.go b/services/api/optimistic_test.go index 833bf3b2..39e7e1ec 100644 --- a/services/api/optimistic_test.go +++ b/services/api/optimistic_test.go @@ -509,10 +509,7 @@ func TestBuilderApiSubmitNewBlockOptimisticV2_full(t *testing.T) { badSigReq := common.TestBuilderSubmitBlockRequestV2(secretkey, getTestBidTrace(*pubkey, 10)) badSigReq.Signature[0] = 0xaa invalidSigReq := common.TestBuilderSubmitBlockRequestV2(secretkey, getTestBidTrace(*pubkey, 10)) - // Sign over a message with a different value. - diffSig, err := boostTypes.SignMessage(getTestBidTrace(*pubkey, 11), boostTypes.DomainBuilder, secretkey) - require.Nil(t, err) - invalidSigReq.Signature = phase0.BLSSignature(diffSig) + invalidSigReq.Message.Slot += 1 badTimestampReq := common.TestBuilderSubmitBlockRequestV2(secretkey, getTestBidTrace(*pubkey, 10)) badTimestampReq.ExecutionPayloadHeader.Timestamp -= 1 badWithdrawalsRootReq := common.TestBuilderSubmitBlockRequestV2(secretkey, getTestBidTrace(*pubkey, 10)) diff --git a/services/api/service.go b/services/api/service.go index ed080f63..c9147385 100644 --- a/services/api/service.go +++ b/services/api/service.go @@ -2149,11 +2149,25 @@ func (api *RelayAPI) handleSubmitNewBlockV2(w http.ResponseWriter, req *http.Req "value": bid.Value.String(), }) + // Verify the signature + log = log.WithField("timestampBeforeSignatureCheck", time.Now().UTC().UnixMilli()) + ok, err := boostTypes.VerifySignature(bid, api.opts.EthNetDetails.DomainBuilder, bid.BuilderPubkey[:], sig[:]) + log = log.WithField("timestampAfterSignatureCheck", time.Now().UTC().UnixMilli()) + if err != nil { + log.WithError(err).Warn("failed verifying builder signature") + api.RespondError(w, http.StatusBadRequest, "failed verifying builder signature") + return + } else if !ok { + log.Warn("invalid builder signature") + api.RespondError(w, http.StatusBadRequest, "invalid signature") + return + } + log.WithFields(logrus.Fields{ "bid": bid, "signature": sig, "decode_time": pf.Decode, - }).Info("optimistically parsed bid") + }).Info("optimistically parsed bid and verified signature") // Check optimistic eligibility. builderPubkey := bid.BuilderPubkey @@ -2228,20 +2242,6 @@ func (api *RelayAPI) handleSubmitNewBlockV2(w http.ResponseWriter, req *http.Req return } - // Verify the signature - log = log.WithField("timestampBeforeSignatureCheck", time.Now().UTC().UnixMilli()) - ok, err = boostTypes.VerifySignature(bid, api.opts.EthNetDetails.DomainBuilder, bid.BuilderPubkey[:], sig[:]) - log = log.WithField("timestampAfterSignatureCheck", time.Now().UTC().UnixMilli()) - if err != nil { - log.WithError(err).Warn("failed verifying builder signature") - api.RespondError(w, http.StatusBadRequest, "failed verifying builder signature") - return - } else if !ok { - log.Warn("invalid builder signature") - api.RespondError(w, http.StatusBadRequest, "invalid signature") - return - } - // Create the redis pipeline tx tx := api.redis.NewTxPipeline()