From 6421ab625434cd2e56f4ebef11e23d7f1aa468ac Mon Sep 17 00:00:00 2001 From: forcodedancing Date: Thu, 3 Mar 2022 15:11:56 +0800 Subject: [PATCH] add total time metrics --- core/blockchain.go | 1 - core/state_processor.go | 2 - miner/worker.go | 1 - perf/main_process.go | 102 +++++++++++++++++++++++++++------------- 4 files changed, 70 insertions(+), 36 deletions(-) diff --git a/core/blockchain.go b/core/blockchain.go index cfc1de8118..9708daf752 100644 --- a/core/blockchain.go +++ b/core/blockchain.go @@ -1909,7 +1909,6 @@ func (bc *BlockChain) InsertChain(chain types.Blocks) (int, error) { start := time.Now() n, err := bc.insertChain(chain, true) perf.RecordMPMetrics(perf.MpImportingTotal, start) - perf.RecordMPMetrics(perf.MpImportingTotalAll, start) bc.chainmu.Unlock() bc.wg.Done() diff --git a/core/state_processor.go b/core/state_processor.go index 6618cba4d2..ff5c20c871 100644 --- a/core/state_processor.go +++ b/core/state_processor.go @@ -413,7 +413,6 @@ func (p *StateProcessor) Process(block *types.Block, statedb *state.StateDB, cfg bloomProcessors := NewAsyncReceiptBloomGenerator(txNum) statedb.MarkFullProcessed() - applyStart := time.Now() // usually do have two tx, one for validator set contract, another for system reward contract. systemTxs := make([]*types.Transaction, 0, 2) for i, tx := range block.Transactions() { @@ -439,7 +438,6 @@ func (p *StateProcessor) Process(block *types.Block, statedb *state.StateDB, cfg commonTxs = append(commonTxs, tx) receipts = append(receipts, receipt) } - perf.RecordMPMetrics(perf.MpImportingProcessExecuteApply, applyStart) bloomProcessors.Close() perf.RecordMPMetrics(perf.MpImportingProcessExecute, executeStart) diff --git a/miner/worker.go b/miner/worker.go index d08ff4d3a9..9205fc6208 100644 --- a/miner/worker.go +++ b/miner/worker.go @@ -467,7 +467,6 @@ func (w *worker) mainLoop() { start := time.Now() w.commitNewWork(req.interrupt, req.noempty, req.timestamp) perf.RecordMPMetrics(perf.MpMiningTotal, start) - perf.RecordMPMetrics(perf.MpMiningTotalAll, start) case ev := <-w.chainSideCh: // Short circuit for duplicate side blocks diff --git a/perf/main_process.go b/perf/main_process.go index 0b9a64ad71..8ce797647a 100644 --- a/perf/main_process.go +++ b/perf/main_process.go @@ -9,7 +9,6 @@ import ( type MpMetricsName string const ( - MpMiningTotalAll MpMetricsName = "MP_MINING_TOTAL_ALL" MpMiningTotal MpMetricsName = "MP_MINING_TOTAL" MpMiningPrepare MpMetricsName = "MP_MINING_PREPARE" MpMiningOrder MpMetricsName = "MP_MINING_ORDER" @@ -19,16 +18,14 @@ const ( MpMiningFinalize MpMetricsName = "MP_MINING_FINALIZE" MpMiningWrite MpMetricsName = "MP_MINING_WRITE" - MpImportingTotalAll MpMetricsName = "MP_IMPORTING_TOTAL_ALL" - MpImportingTotal MpMetricsName = "MP_IMPORTING_TOTAL" - MpImportingVerifyHeader MpMetricsName = "MP_IMPORTING_VERIFY_HEADER" - MpImportingVerifyState MpMetricsName = "MP_IMPORTING_VERIFY_STATE" - MpImportingProcess MpMetricsName = "MP_IMPORTING_PROCESS" - MpImportingProcessPreload MpMetricsName = "MP_IMPORTING_PROCESS_PRELOAD" - MpImportingProcessExecute MpMetricsName = "MP_IMPORTING_PROCESS_EXECUTE" - MpImportingProcessExecuteApply MpMetricsName = "MP_IMPORTING_PROCESS_EXECUTE_APPLY" - MpImportingProcessFinalize MpMetricsName = "MP_IMPORTING_PROCESS_FINALIZE" - MpImportingCommit MpMetricsName = "MP_IMPORTING_COMMIT" + MpImportingTotal MpMetricsName = "MP_IMPORTING_TOTAL" + MpImportingVerifyHeader MpMetricsName = "MP_IMPORTING_VERIFY_HEADER" + MpImportingVerifyState MpMetricsName = "MP_IMPORTING_VERIFY_STATE" + MpImportingProcess MpMetricsName = "MP_IMPORTING_PROCESS" + MpImportingProcessPreload MpMetricsName = "MP_IMPORTING_PROCESS_PRELOAD" + MpImportingProcessExecute MpMetricsName = "MP_IMPORTING_PROCESS_EXECUTE" + MpImportingProcessFinalize MpMetricsName = "MP_IMPORTING_PROCESS_FINALIZE" + MpImportingCommit MpMetricsName = "MP_IMPORTING_COMMIT" MpPropagationTotal MpMetricsName = "MP_PROPAGATION_TOTAL" MpPropagationSend MpMetricsName = "MP_PROPAGATION_SEND" @@ -42,27 +39,54 @@ var mpMetricsEnabled, _ = getEnvBool("METRICS_MP_METRICS_ENABLED") var ( //block mining related metrics - miningTotalAllCounter = metrics.NewRegisteredCounter("mp/mining/total/all", nil) - miningTotalTimer = metrics.NewRegisteredTimer("mp/mining/total", nil) - miningPrepareTimer = metrics.NewRegisteredTimer("mp/mining/prepare", nil) - miningOrderTimer = metrics.NewRegisteredTimer("mp/mining/order", nil) + miningTotalAllCounter = metrics.NewRegisteredCounter("mp/mining/total/all", nil) + miningTotalTimer = metrics.NewRegisteredTimer("mp/mining/total", nil) + + miningPrepareAllCounter = metrics.NewRegisteredCounter("mp/mining/prepare/all", nil) + miningPrepareTimer = metrics.NewRegisteredTimer("mp/mining/prepare", nil) + + miningOrderAllCounter = metrics.NewRegisteredCounter("mp/mining/order/all", nil) + miningOrderTimer = metrics.NewRegisteredTimer("mp/mining/order", nil) + + miningCommitTxAllCounter = metrics.NewRegisteredCounter("mp/mining/commit_tx/all", nil) miningCommitTxTimer = metrics.NewRegisteredTimer("mp/mining/commit_tx", nil) - miningCommitDelayTimer = metrics.NewRegisteredTimer("mp/mining/commit/delay", nil) - miningCommitProcessTimer = metrics.NewRegisteredTimer("mp/mining/commit/process", nil) + + miningCommitDelayAllCounter = metrics.NewRegisteredCounter("mp/mining/commit/delay/all", nil) + miningCommitDelayTimer = metrics.NewRegisteredTimer("mp/mining/commit/delay", nil) + + miningCommitProcessAllCounter = metrics.NewRegisteredCounter("mp/mining/commit/process/all", nil) + miningCommitProcessTimer = metrics.NewRegisteredTimer("mp/mining/commit/process", nil) + + miningFinalizeAllCounter = metrics.NewRegisteredCounter("mp/mining/finalize/all", nil) miningFinalizeTimer = metrics.NewRegisteredTimer("mp/mining/finalize", nil) - miningWriteTimer = metrics.NewRegisteredTimer("mp/mining/write", nil) + + miningWriteAllCounter = metrics.NewRegisteredCounter("mp/mining/write/all", nil) + miningWriteTimer = metrics.NewRegisteredTimer("mp/mining/write", nil) //block importing related metrics - importingTotalAllCounter = metrics.NewRegisteredCounter("mp/importing/total/all", nil) - importingTotalTimer = metrics.NewRegisteredTimer("mp/importing/total", nil) - importingVerifyHeaderTimer = metrics.NewRegisteredTimer("mp/importing/verify/header", nil) - importingVerifyStateTimer = metrics.NewRegisteredTimer("mp/importing/verify/state", nil) - importingProcessTimer = metrics.NewRegisteredTimer("mp/importing/process", nil) + importingTotalAllCounter = metrics.NewRegisteredCounter("mp/importing/total/all", nil) + importingTotalTimer = metrics.NewRegisteredTimer("mp/importing/total", nil) + + importingVerifyHeaderAllCounter = metrics.NewRegisteredCounter("mp/importing/verify/header/all", nil) + importingVerifyHeaderTimer = metrics.NewRegisteredTimer("mp/importing/verify/header", nil) + + importingVerifyStateAllCounter = metrics.NewRegisteredCounter("mp/importing/verify/state/all", nil) + importingVerifyStateTimer = metrics.NewRegisteredTimer("mp/importing/verify/state", nil) + + importingProcessAllCounter = metrics.NewRegisteredCounter("mp/importing/process/all", nil) + importingProcessTimer = metrics.NewRegisteredTimer("mp/importing/process", nil) + + importingProcessPreloadAllCounter = metrics.NewRegisteredCounter("mp/importing/process/preload/all", nil) importingProcessPreloadTimer = metrics.NewRegisteredTimer("mp/importing/process/preload", nil) + + importingProcessExecuteAllCounter = metrics.NewRegisteredCounter("mp/importing/process/execute/all", nil) importingProcessExecuteTimer = metrics.NewRegisteredTimer("mp/importing/process/execute", nil) - importingProcessExecuteApplyTimer = metrics.NewRegisteredTimer("mp/importing/process/execute/apply", nil) - importingProcessFinalizeTimer = metrics.NewRegisteredTimer("mp/importing/process/finalize", nil) - importingCommitTimer = metrics.NewRegisteredTimer("mp/importing/commit", nil) + + importingProcessFinalizeAllCounter = metrics.NewRegisteredCounter("mp/importing/process/finalize/all", nil) + importingProcessFinalizeTimer = metrics.NewRegisteredTimer("mp/importing/process/finalize", nil) + + importingCommitAllCounter = metrics.NewRegisteredCounter("mp/importing/commit/all", nil) + importingCommitTimer = metrics.NewRegisteredTimer("mp/importing/commit", nil) //block importing, block mining, p2p overall metrics propagationTotalTimer = metrics.NewRegisteredTimer("mp/propagation/total", nil) @@ -81,45 +105,55 @@ func RecordMPMetrics(metricsName MpMetricsName, start time.Time) { } switch metricsName { - case MpMiningTotalAll: - miningTotalAllCounter.Inc(time.Since(start).Nanoseconds()) case MpMiningTotal: recordTimer(miningTotalTimer, start) + increaseCounter(miningTotalAllCounter, start) case MpMiningPrepare: recordTimer(miningPrepareTimer, start) + increaseCounter(miningPrepareAllCounter, start) case MpMiningOrder: recordTimer(miningOrderTimer, start) + increaseCounter(miningOrderAllCounter, start) case MpMiningCommitTx: recordTimer(miningCommitTxTimer, start) + increaseCounter(miningCommitTxAllCounter, start) case MpMiningCommitDelay: recordTimer(miningCommitDelayTimer, start) + increaseCounter(miningCommitDelayAllCounter, start) case MpMiningCommitProcess: recordTimer(miningCommitProcessTimer, start) + increaseCounter(miningCommitProcessAllCounter, start) case MpMiningFinalize: recordTimer(miningFinalizeTimer, start) + increaseCounter(miningFinalizeAllCounter, start) case MpMiningWrite: recordTimer(miningWriteTimer, start) + increaseCounter(miningWriteAllCounter, start) - case MpImportingTotalAll: - importingTotalAllCounter.Inc(time.Since(start).Nanoseconds()) case MpImportingTotal: recordTimer(importingTotalTimer, start) + increaseCounter(importingTotalAllCounter, start) case MpImportingVerifyHeader: recordTimer(importingVerifyHeaderTimer, start) + increaseCounter(importingVerifyHeaderAllCounter, start) case MpImportingVerifyState: recordTimer(importingVerifyStateTimer, start) + increaseCounter(importingVerifyStateAllCounter, start) case MpImportingProcess: recordTimer(importingProcessTimer, start) + increaseCounter(importingProcessAllCounter, start) case MpImportingProcessPreload: recordTimer(importingProcessPreloadTimer, start) + increaseCounter(importingProcessPreloadAllCounter, start) case MpImportingProcessExecute: recordTimer(importingProcessExecuteTimer, start) - case MpImportingProcessExecuteApply: - recordTimer(importingProcessExecuteApplyTimer, start) + increaseCounter(importingProcessExecuteAllCounter, start) case MpImportingProcessFinalize: recordTimer(importingProcessFinalizeTimer, start) + increaseCounter(importingProcessFinalizeAllCounter, start) case MpImportingCommit: recordTimer(importingCommitTimer, start) + increaseCounter(importingCommitAllCounter, start) case MpPropagationTotal: recordTimer(propagationTotalTimer, start) @@ -151,3 +185,7 @@ func RecordMPLogs(logger log.Logger, msg string, ctx ...interface{}) { func recordTimer(timer metrics.Timer, start time.Time) { timer.Update(time.Since(start)) } + +func increaseCounter(counter metrics.Counter, start time.Time) { + counter.Inc(time.Since(start).Nanoseconds()) +}