Skip to content
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.

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

Add more profiling logging in submit block #596

Merged
merged 1 commit into from
Apr 4, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
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: 1 addition & 0 deletions common/common.go
Original file line number Diff line number Diff line change
Expand Up @@ -42,6 +42,7 @@ type BuilderStatus struct {
// field corresponds to the number of microseconds in each stage. The `Total`
// field is the number of microseconds taken for entire flow.
type Profile struct {
PayloadLoad uint64
Decode uint64
Prechecks uint64
Simulation uint64
Expand Down
27 changes: 17 additions & 10 deletions services/api/service.go
Original file line number Diff line number Diff line change
Expand Up @@ -1880,6 +1880,10 @@ func (api *RelayAPI) handleSubmitNewBlock(w http.ResponseWriter, req *http.Reque
return
}

nextTime = time.Now().UTC()
pf.PayloadLoad = uint64(nextTime.Sub(prevTime).Microseconds())
prevTime = nextTime

payload := new(common.VersionedSubmitBlockRequest)

// Check for SSZ encoding
Expand Down Expand Up @@ -1952,10 +1956,7 @@ func (api *RelayAPI) handleSubmitNewBlock(w http.ResponseWriter, req *http.Reque
return
}

log = log.WithFields(logrus.Fields{
"builderIsHighPrio": builderEntry.status.IsHighPrio,
"timestampAfterChecks1": time.Now().UTC().UnixMilli(),
})
log = log.WithField("builderIsHighPrio", builderEntry.status.IsHighPrio)

gasLimit, ok := api.checkSubmissionFeeRecipient(w, log, submission.BidTrace)
if !ok {
Expand All @@ -1977,8 +1978,6 @@ func (api *RelayAPI) handleSubmitNewBlock(w http.ResponseWriter, req *http.Reque
return
}

log = log.WithField("timestampBeforeAttributesCheck", time.Now().UTC().UnixMilli())

attrs, ok := api.checkSubmissionPayloadAttrs(w, log, submission)
if !ok {
return
Expand All @@ -1999,6 +1998,8 @@ func (api *RelayAPI) handleSubmitNewBlock(w http.ResponseWriter, req *http.Reque
return
}

log = log.WithField("timestampBeforeCheckingFloorBid", time.Now().UTC().UnixMilli())

// Create the redis pipeline tx
tx := api.redis.NewTxPipeline()

Expand Down Expand Up @@ -2026,6 +2027,8 @@ func (api *RelayAPI) handleSubmitNewBlock(w http.ResponseWriter, req *http.Reque
return
}

log = log.WithField("timestampAfterCheckingFloorBid", time.Now().UTC().UnixMilli())

// Deferred saving of the builder submission to database (whenever this function ends)
defer func() {
savePayloadToDatabase := !api.ffDisablePayloadDBStorage
Expand Down Expand Up @@ -2053,6 +2056,8 @@ func (api *RelayAPI) handleSubmitNewBlock(w http.ResponseWriter, req *http.Reque
// THE BID WILL BE SIMULATED SHORTLY
// ---------------------------------

log = log.WithField("timestampBeforeCheckingTopBid", time.Now().UTC().UnixMilli())

// Get the latest top bid value from Redis
bidIsTopBid := false
topBidValue, err := api.redis.GetTopBidValue(context.Background(), tx, submission.BidTrace.Slot, submission.BidTrace.ParentHash.String(), submission.BidTrace.ProposerPubkey.String())
Expand All @@ -2066,6 +2071,12 @@ func (api *RelayAPI) handleSubmitNewBlock(w http.ResponseWriter, req *http.Reque
})
}

log = log.WithField("timestampAfterCheckingTopBid", time.Now().UTC().UnixMilli())

nextTime = time.Now().UTC()
pf.Prechecks = uint64(nextTime.Sub(prevTime).Microseconds())
prevTime = nextTime

// Simulate the block submission and save to db
fastTrackValidation := builderEntry.status.IsHighPrio && bidIsTopBid && !isLargeRequest
timeBeforeValidation := time.Now().UTC()
Expand All @@ -2075,10 +2086,6 @@ func (api *RelayAPI) handleSubmitNewBlock(w http.ResponseWriter, req *http.Reque
"fastTrackValidation": fastTrackValidation,
})

nextTime = time.Now().UTC()
pf.Prechecks = uint64(nextTime.Sub(prevTime).Microseconds())
prevTime = nextTime

// Construct simulation request
opts := blockSimOptions{
isHighPrio: builderEntry.status.IsHighPrio,
Expand Down
Loading