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.

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

Jump to bottom

Output performance measurements in microseconds for easier log processing / evaluation #5

Merged
merged 1 commit into from
Dec 10, 2023
Merged

Output performance measurements in microseconds for easier log processing / evaluation #5

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
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
42 changes: 21 additions & 21 deletions core/blockchain.go
View file
Open in desktop
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
Open in desktop
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
}
Loading