From 3fcee2bd00d2c6106461bc7d536d4e0da56f11a9 Mon Sep 17 00:00:00 2001 From: ckoopmann Date: Sat, 9 Dec 2023 16:15:43 +0800 Subject: [PATCH] Log out performance measurements in microseconds for consistency with reth logging --- core/blockchain.go | 42 ++++++++++++++++++------------------- eth/block-validation/api.go | 10 ++++----- 2 files changed, 26 insertions(+), 26 deletions(-) diff --git a/core/blockchain.go b/core/blockchain.go index 2dc578056..31962b412 100644 --- a/core/blockchain.go +++ b/core/blockchain.go @@ -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() } } @@ -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 @@ -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 @@ -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. @@ -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 diff --git a/eth/block-validation/api.go b/eth/block-validation/api.go index 7295ee671..4288b529d 100644 --- a/eth/block-validation/api.go +++ b/eth/block-validation/api.go @@ -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 @@ -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[:]) @@ -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 }