Skip to content

Commit

Permalink
Merge pull request #5 from ultrasoundmoney/relayer-performance-measur…
Browse files Browse the repository at this point in the history 
…ing-in-microseconds

Output performance measurements in microseconds for easier log processing / evaluation
  • Loading branch information
@ckoopmann
ckoopmann authored Dec 10, 2023
2 parents d5e4a63 + 3fcee2b commit 84e9721
Show file tree
Hide file tree
Showing 2 changed files with 26 additions and 26 deletions.
42 changes: 21 additions & 21 deletions core/blockchain.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -875,7 +875,7 @@ func (bc *BlockChain) ExportN(w io.Writer, first uint64, last uint64) error {
return err
}
if time.Since(reported) >= statsReportLimit {
log.Info("Exporting blocks", "exported", block.NumberU64()-first, "elapsed", common.PrettyDuration(time.Since(start)))
log.Info("Exporting blocks", "exported", block.NumberU64()-first, "elapsed", common.PrettyDuration(time.Since(start).Microseconds()))
reported = time.Now()
}
}
Expand Down Expand Up @@ -2498,43 +2498,43 @@ func (bc *BlockChain) SetBlockValidatorAndProcessorForTesting(v Validator, p Pro
func (bc *BlockChain) ValidatePayload(block *types.Block, feeRecipient common.Address, expectedProfit *big.Int, registeredGasLimit uint64, vmConfig vm.Config, start time.Time, requestId uuid.UUID) error {
header := block.Header()
if err := bc.engine.VerifyHeader(bc, header, true); err != nil {
log.Debug("VerifyHeader failed", "time_elapsed", time.Since(start), "error", err, "requestId", requestId)
log.Debug("VerifyHeader failed", "time_elapsed", time.Since(start).Microseconds(), "error", err, "requestId", requestId)
return err
} else {
log.Debug("VerifyHeader succeeded", "time_elapsed", time.Since(start), "requestId", requestId)
log.Debug("VerifyHeader succeeded", "time_elapsed", time.Since(start).Microseconds(), "requestId", requestId)
}

current := bc.CurrentBlock()
reorg, err := bc.forker.ReorgNeeded(current, header)
if err == nil && reorg {
log.Debug("ReorgNeeded failed", "time_elapsed", time.Since(start), "error", err, "requestId", requestId)
log.Debug("ReorgNeeded failed", "time_elapsed", time.Since(start).Microseconds(), "error", err, "requestId", requestId)
return errors.New("block requires a reorg")
} else {
log.Debug("ReorgNeeded succeeded", "time_elapsed", time.Since(start), "requestId", requestId)
log.Debug("ReorgNeeded succeeded", "time_elapsed", time.Since(start).Microseconds(), "requestId", requestId)
}

parent := bc.GetHeader(block.ParentHash(), block.NumberU64()-1)
if parent == nil {
log.Debug("GetHeader(Parent) failed", "time_elapsed", time.Since(start), "error", err, "requestId", requestId)
log.Debug("GetHeader(Parent) failed", "time_elapsed", time.Since(start).Microseconds(), "error", err, "requestId", requestId)
return errors.New("parent not found")
} else {
log.Debug("GetHeader(Parent) succeeded", "time_elapsed", time.Since(start), "requestId", requestId)
log.Debug("GetHeader(Parent) succeeded", "time_elapsed", time.Since(start).Microseconds(), "requestId", requestId)
}

err = CheckGasLimit(parent.GasLimit, registeredGasLimit, header.GasLimit)
if err != nil {
log.Debug("CheckGasLimit failed", "time_elapsed", time.Since(start), "error", err)
log.Debug("CheckGasLimit failed", "time_elapsed", time.Since(start).Microseconds(), "error", err)
return err
} else {
log.Debug("CheckGasLimit succeeded", "time_elapsed", time.Since(start))
log.Debug("CheckGasLimit succeeded", "time_elapsed", time.Since(start).Microseconds())
}

statedb, err := bc.StateAt(parent.Root)
if err != nil {
log.Debug("StateAt(parent.Root) failed", "time_elapsed", time.Since(start), "error", err, "requestId", requestId)
log.Debug("StateAt(parent.Root) failed", "time_elapsed", time.Since(start).Microseconds(), "error", err, "requestId", requestId)
return err
} else {
log.Debug("StateAt(parent.Root) succeeded", "time_elapsed", time.Since(start), "requestId", requestId)
log.Debug("StateAt(parent.Root) succeeded", "time_elapsed", time.Since(start).Microseconds(), "requestId", requestId)
}

// The chain importer is starting and stopping trie prefetchers. If a bad
Expand All @@ -2547,10 +2547,10 @@ func (bc *BlockChain) ValidatePayload(block *types.Block, feeRecipient common.Ad

receipts, _, usedGas, err := bc.processor.Process(block, statedb, vmConfig)
if err != nil {
log.Debug("Execute transactions failed", "time_elapsed", time.Since(start), "error", err, "requestId", requestId)
log.Debug("Execute transactions failed", "time_elapsed", time.Since(start).Microseconds(), "error", err, "requestId", requestId)
return err
} else {
log.Debug("Execute transactions succeeded", "time_elapsed", time.Since(start), "requestId", requestId)
log.Debug("Execute transactions succeeded", "time_elapsed", time.Since(start).Microseconds(), "requestId", requestId)
}

err = nil
Expand All @@ -2568,24 +2568,24 @@ func (bc *BlockChain) ValidatePayload(block *types.Block, feeRecipient common.Ad
}
}
if err != nil {
log.Debug("Check Withdrawal hash failed", "time_elapsed", time.Since(start), "error", err, "requestId", requestId)
log.Debug("Check Withdrawal hash failed", "time_elapsed", time.Since(start).Microseconds(), "error", err, "requestId", requestId)
return err
} else {
log.Debug("Check Withdrawal hash succeeded", "time_elapsed", time.Since(start), "requestId", requestId)
log.Debug("Check Withdrawal hash succeeded", "time_elapsed", time.Since(start).Microseconds(), "requestId", requestId)
}

if err := bc.validator.ValidateBody(block); err != nil {
log.Debug("ValidateBody failed", "time_elapsed", time.Since(start), "error", err, "requestId", requestId)
log.Debug("ValidateBody failed", "time_elapsed", time.Since(start).Microseconds(), "error", err, "requestId", requestId)
return err
} else {
log.Debug("ValidateBody succeeded", "time_elapsed", time.Since(start), "requestId", requestId)
log.Debug("ValidateBody succeeded", "time_elapsed", time.Since(start).Microseconds(), "requestId", requestId)
}

if err := bc.validator.ValidateState(block, statedb, receipts, usedGas); err != nil {
log.Debug("ValidateState failed", "time_elapsed", time.Since(start), "error", err, "requestId", requestId)
log.Debug("ValidateState failed", "time_elapsed", time.Since(start).Microseconds(), "error", err, "requestId", requestId)
return err
} else {
log.Debug("ValidateState succeeded", "time_elapsed", time.Since(start), "requestId", requestId)
log.Debug("ValidateState succeeded", "time_elapsed", time.Since(start).Microseconds(), "requestId", requestId)
}

// First just check the balance delta to see if it matches.
Expand All @@ -2594,10 +2594,10 @@ func (bc *BlockChain) ValidatePayload(block *types.Block, feeRecipient common.Ad

err = CheckProposerPayment(expectedProfit, feeRecipient, feeRecipientDiff, receipts, block)
if err != nil {
log.Debug("CheckProposerPayment failed", "time_elapsed", time.Since(start), "error", err, "requestId", requestId)
log.Debug("CheckProposerPayment failed", "time_elapsed", time.Since(start).Microseconds(), "error", err, "requestId", requestId)
return err
} else {
log.Debug("CheckProposerPayment succeeded", "time_elapsed", time.Since(start), "requestId", requestId)
log.Debug("CheckProposerPayment succeeded", "time_elapsed", time.Since(start).Microseconds(), "requestId", requestId)
}

return nil
Expand Down
10 changes: 5 additions & 5 deletions eth/block-validation/api.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -152,10 +152,10 @@ func (api *BlockValidationAPI) ValidateBuilderSubmissionV2(params *BuilderBlockV
payload := params.ExecutionPayload
block, err := engine.ExecutionPayloadV2ToBlock(payload)
if err != nil {
log.Debug("Block parsing failed", "time_elapsed", time.Since(start), "requestId", requestId)
log.Debug("Block parsing failed", "time_elapsed", time.Since(start).Microseconds(), "requestId", requestId)
return err
} else {
log.Debug("Block parsing succeeded", "time_elapsed", time.Since(start), "requestId", requestId)
log.Debug("Block parsing succeeded", "time_elapsed", time.Since(start).Microseconds(), "requestId", requestId)
}

// validated at the relay
Expand All @@ -166,10 +166,10 @@ func (api *BlockValidationAPI) ValidateBuilderSubmissionV2(params *BuilderBlockV

err = CompareMessageAndBlock(params, block)
if err != nil {
log.Debug("Message / Payload comparison failed", "time_elapsed", time.Since(start), "requestId", requestId)
log.Debug("Message / Payload comparison failed", "time_elapsed", time.Since(start).Microseconds(), "requestId", requestId)
return err
} else {
log.Debug("Message / Payload comparison succeeded", "time_elapsed", time.Since(start), "requestId", requestId)
log.Debug("Message / Payload comparison succeeded", "time_elapsed", time.Since(start).Microseconds(), "requestId", requestId)
}

feeRecipient := common.BytesToAddress(params.Message.ProposerFeeRecipient[:])
Expand All @@ -181,6 +181,6 @@ func (api *BlockValidationAPI) ValidateBuilderSubmissionV2(params *BuilderBlockV
return err
}

log.Info("validated block", "hash", block.Hash(), "number", block.NumberU64(), "parentHash", block.ParentHash(), "time_elapsed", time.Since(start), "requestId", requestId)
log.Info("validated block", "hash", block.Hash(), "number", block.NumberU64(), "parentHash", block.ParentHash(), "time_elapsed", time.Since(start).Microseconds(), "requestId", requestId)
return nil
}

0 comments on commit 84e9721

Please sign in to comment.