feat: revise metric for measuring performance

blockchain/v0/reactor.go

@@ -398,7 +398,7 @@ FOR_LOOP:
 				// TODO: same thing for app - but we would need a way to
 				// get the hash without persisting the state
 				var err error
-				state, _, err = bcR.blockExec.ApplyBlock(state, firstID, first)
+				state, _, err = bcR.blockExec.ApplyBlock(state, firstID, first, nil)
 				if err != nil {
 					// TODO This is bad, are we zombie?
 					panic(fmt.Sprintf("Failed to process committed block (%d:%X): %v", first.Height, first.Hash(), err))

blockchain/v0/reactor_test.go

@@ -118,7 +118,7 @@ func newBlockchainReactor(
 		thisParts := thisBlock.MakePartSet(types.BlockPartSizeBytes)
 		blockID := types.BlockID{Hash: thisBlock.Hash(), PartSetHeader: thisParts.Header()}
 
-		state, _, err = blockExec.ApplyBlock(state, blockID, thisBlock)
+		state, _, err = blockExec.ApplyBlock(state, blockID, thisBlock, nil)
 		if err != nil {
 			panic(fmt.Errorf("error apply block: %w", err))
 		}

blockchain/v1/reactor.go

@@ -484,7 +484,7 @@ func (bcR *BlockchainReactor) processBlock() error {
 
 	bcR.store.SaveBlock(first, firstParts, second.LastCommit)
 
-	bcR.state, _, err = bcR.blockExec.ApplyBlock(bcR.state, firstID, first)
+	bcR.state, _, err = bcR.blockExec.ApplyBlock(bcR.state, firstID, first, nil)
 	if err != nil {
 		panic(fmt.Sprintf("failed to process committed block (%d:%X): %v", first.Height, first.Hash(), err))
 	}

blockchain/v1/reactor_test.go

@@ -137,7 +137,7 @@ func newBlockchainReactor(
 		thisParts := thisBlock.MakePartSet(types.BlockPartSizeBytes)
 		blockID := types.BlockID{Hash: thisBlock.Hash(), PartSetHeader: thisParts.Header()}
 
-		state, _, err = blockExec.ApplyBlock(state, blockID, thisBlock)
+		state, _, err = blockExec.ApplyBlock(state, blockID, thisBlock, nil)
 		if err != nil {
 			panic(fmt.Errorf("error apply block: %w", err))
 		}

blockchain/v2/processor_context.go

@@ -30,7 +30,7 @@ func newProcessorContext(st blockStore, ex blockApplier, s state.State) *pContex
 }
 
 func (pc *pContext) applyBlock(blockID types.BlockID, block *types.Block) error {
-	newState, _, err := pc.applier.ApplyBlock(pc.state, blockID, block)
+	newState, _, err := pc.applier.ApplyBlock(pc.state, blockID, block, nil)
 	pc.state = newState
 	return err
 }

blockchain/v2/reactor.go

@@ -53,7 +53,7 @@ type blockVerifier interface {
 }
 
 type blockApplier interface {
-	ApplyBlock(state state.State, blockID types.BlockID, block *types.Block) (state.State, int64, error)
+	ApplyBlock(state state.State, blockID types.BlockID, block *types.Block, times *state.CommitStepTimes) (state.State, int64, error)
 }
 
 // XXX: unify naming in this package around tmState

blockchain/v2/reactor_test.go

@@ -82,7 +82,7 @@ type mockBlockApplier struct {
 
 // XXX: Add whitelist/blacklist?
 func (mba *mockBlockApplier) ApplyBlock(
-	state sm.State, blockID types.BlockID, block *types.Block,
+	state sm.State, blockID types.BlockID, block *types.Block, times *sm.CommitStepTimes,
 ) (sm.State, int64, error) {
 	state.LastBlockHeight++
 	return state, 0, nil
@@ -544,7 +544,7 @@ func newReactorStore(
 		thisParts := thisBlock.MakePartSet(types.BlockPartSizeBytes)
 		blockID := types.BlockID{Hash: thisBlock.Hash(), PartSetHeader: thisParts.Header()}
 
-		state, _, err = blockExec.ApplyBlock(state, blockID, thisBlock)
+		state, _, err = blockExec.ApplyBlock(state, blockID, thisBlock, nil)
 		if err != nil {
 			panic(fmt.Errorf("error apply block: %w", err))
 		}

consensus/metrics.go

@@ -66,23 +66,24 @@ type Metrics struct {
 	// Number of blockparts transmitted by peer.
 	BlockParts metrics.Counter
 
+	// ////////////////////////////////////
+	// Metrics for measuring performance
+	// ////////////////////////////////////
+
 	// Number of blocks that are we couldn't receive
 	MissingProposal metrics.Gauge
 
 	// Number of rounds turned over.
 	RoundFailures metrics.Histogram
 
 	// Execution time profiling of each step
-	ProposalCreating        metrics.Histogram
-	ProposalWaiting         metrics.Histogram
-	ProposalVerifying       metrics.Histogram
-	ProposalBlockReceiving  metrics.Histogram
-	PrevoteBlockVerifying   metrics.Histogram
-	PrevoteReceiving        metrics.Histogram
-	PrecommitBlockVerifying metrics.Histogram
-	PrecommitReceiving      metrics.Histogram
-	CommitBlockVerifying    metrics.Histogram
-	CommitBlockApplying     metrics.Histogram
+	DurationProposal           metrics.Histogram
+	DurationPrevote            metrics.Histogram
+	DurationPrecommit          metrics.Histogram
+	DurationCommitExecuting    metrics.Histogram
+	DurationCommitCommitting   metrics.Histogram
+	DurationCommitRechecking   metrics.Histogram
+	DurationWaitingForNewRound metrics.Histogram
 }
 
 // PrometheusMetrics returns Metrics build using Prometheus client library.
@@ -234,74 +235,53 @@ func PrometheusMetrics(namespace string, labelsAndValues ...string) *Metrics {
 			Help:      "Number of rounds failed on consensus",
 			Buckets:   stdprometheus.LinearBuckets(0, 1, 5),
 		}, labels).With(labelsAndValues...),
-		ProposalCreating: prometheus.NewHistogramFrom(stdprometheus.HistogramOpts{
+		DurationProposal: prometheus.NewHistogramFrom(stdprometheus.HistogramOpts{
 			Namespace: namespace,
 			Subsystem: MetricsSubsystem,
-			Name:      "duration_proposal_creating",
-			Help:      "Duration of creating proposal and block",
+			Name:      "duration_proposal",
+			Help:      "Duration of proposal step",
 			Buckets:   stdprometheus.LinearBuckets(100, 100, 10),
 		}, labels).With(labelsAndValues...),
-		ProposalWaiting: prometheus.NewHistogramFrom(stdprometheus.HistogramOpts{
+		DurationPrevote: prometheus.NewHistogramFrom(stdprometheus.HistogramOpts{
 			Namespace: namespace,
 			Subsystem: MetricsSubsystem,
-			Name:      "duration_proposal_waiting",
-			Help:      "Duration between enterNewRound and receiving proposal",
+			Name:      "duration_prevote",
+			Help:      "Duration of prevote step",
 			Buckets:   stdprometheus.LinearBuckets(100, 100, 10),
 		}, labels).With(labelsAndValues...),
-		ProposalVerifying: prometheus.NewHistogramFrom(stdprometheus.HistogramOpts{
-			Namespace: namespace,
-			Subsystem: MetricsSubsystem,
-			Name:      "duration_proposal_verifying",
-			Help:      "Duration of ValidBlock",
-			Buckets:   stdprometheus.LinearBuckets(50, 50, 10),
-		}, labels).With(labelsAndValues...),
-		ProposalBlockReceiving: prometheus.NewHistogramFrom(stdprometheus.HistogramOpts{
+		DurationPrecommit: prometheus.NewHistogramFrom(stdprometheus.HistogramOpts{
 			Namespace: namespace,
 			Subsystem: MetricsSubsystem,
-			Name:      "duration_proposal_block_receiving",
-			Help:      "Duration of receiving all proposal block parts",
+			Name:      "duration_precommit",
+			Help:      "Duration of precommit step",
 			Buckets:   stdprometheus.LinearBuckets(100, 100, 10),
 		}, labels).With(labelsAndValues...),
-		PrevoteBlockVerifying: prometheus.NewHistogramFrom(stdprometheus.HistogramOpts{
+		DurationCommitExecuting: prometheus.NewHistogramFrom(stdprometheus.HistogramOpts{
 			Namespace: namespace,
 			Subsystem: MetricsSubsystem,
-			Name:      "duration_prevote_block_verifying",
-			Help:      "Duration of ValidBlock in prevote",
-			Buckets:   stdprometheus.LinearBuckets(50, 50, 10),
-		}, labels).With(labelsAndValues...),
-		PrevoteReceiving: prometheus.NewHistogramFrom(stdprometheus.HistogramOpts{
-			Namespace: namespace,
-			Subsystem: MetricsSubsystem,
-			Name:      "duration_prevote_receiving",
-			Help:      "Duration of receiving 2/3+ prevotes",
+			Name:      "duration_commit_executing",
+			Help:      "Duration of executing block txs",
 			Buckets:   stdprometheus.LinearBuckets(100, 100, 10),
 		}, labels).With(labelsAndValues...),
-		PrecommitBlockVerifying: prometheus.NewHistogramFrom(stdprometheus.HistogramOpts{
+		DurationCommitCommitting: prometheus.NewHistogramFrom(stdprometheus.HistogramOpts{
 			Namespace: namespace,
 			Subsystem: MetricsSubsystem,
-			Name:      "duration_precommit_block_verifying",
-			Help:      "Duration of ValidBlock in precommit",
-			Buckets:   stdprometheus.LinearBuckets(50, 50, 10),
-		}, labels).With(labelsAndValues...),
-		PrecommitReceiving: prometheus.NewHistogramFrom(stdprometheus.HistogramOpts{
-			Namespace: namespace,
-			Subsystem: MetricsSubsystem,
-			Name:      "duration_precommit_receiving",
-			Help:      "Duration of receiving 2/3+ precommits",
+			Name:      "duration_commit_committing",
+			Help:      "Duration of committing updated state",
 			Buckets:   stdprometheus.LinearBuckets(100, 100, 10),
 		}, labels).With(labelsAndValues...),
-		CommitBlockVerifying: prometheus.NewHistogramFrom(stdprometheus.HistogramOpts{
+		DurationCommitRechecking: prometheus.NewHistogramFrom(stdprometheus.HistogramOpts{
 			Namespace: namespace,
 			Subsystem: MetricsSubsystem,
-			Name:      "duration_commit_block_verifying",
-			Help:      "Duration of ValidBlock in commit",
-			Buckets:   stdprometheus.LinearBuckets(50, 50, 10),
+			Name:      "duration_commit_rechecking",
+			Help:      "Duration of rechecking mempool txs",
+			Buckets:   stdprometheus.LinearBuckets(100, 100, 10),
 		}, labels).With(labelsAndValues...),
-		CommitBlockApplying: prometheus.NewHistogramFrom(stdprometheus.HistogramOpts{
+		DurationWaitingForNewRound: prometheus.NewHistogramFrom(stdprometheus.HistogramOpts{
 			Namespace: namespace,
 			Subsystem: MetricsSubsystem,
-			Name:      "duration_commit_block_applying",
-			Help:      "Duration of applying block",
+			Name:      "duration_waiting_for_new_round",
+			Help:      "Duration of waiting for next new round",
 			Buckets:   stdprometheus.LinearBuckets(100, 100, 10),
 		}, labels).With(labelsAndValues...),
 	}
@@ -340,15 +320,12 @@ func NopMetrics() *Metrics {
 		MissingProposal: discard.NewGauge(),
 		RoundFailures:   discard.NewHistogram(),
 
-		ProposalCreating:        discard.NewHistogram(),
-		ProposalWaiting:         discard.NewHistogram(),
-		ProposalVerifying:       discard.NewHistogram(),
-		ProposalBlockReceiving:  discard.NewHistogram(),
-		PrevoteBlockVerifying:   discard.NewHistogram(),
-		PrevoteReceiving:        discard.NewHistogram(),
-		PrecommitBlockVerifying: discard.NewHistogram(),
-		PrecommitReceiving:      discard.NewHistogram(),
-		CommitBlockVerifying:    discard.NewHistogram(),
-		CommitBlockApplying:     discard.NewHistogram(),
+		DurationProposal:           discard.NewHistogram(),
+		DurationPrevote:            discard.NewHistogram(),
+		DurationPrecommit:          discard.NewHistogram(),
+		DurationCommitExecuting:    discard.NewHistogram(),
+		DurationCommitCommitting:   discard.NewHistogram(),
+		DurationCommitRechecking:   discard.NewHistogram(),
+		DurationWaitingForNewRound: discard.NewHistogram(),
 	}
 }

consensus/replay.go

@@ -502,7 +502,7 @@ func (h *Handshaker) replayBlock(state sm.State, height int64, proxyApp proxy.Ap
 	blockExec.SetEventBus(h.eventBus)
 
 	var err error
-	state, _, err = blockExec.ApplyBlock(state, meta.BlockID, block)
+	state, _, err = blockExec.ApplyBlock(state, meta.BlockID, block, nil)
 	if err != nil {
 		return sm.State{}, err
 	}

consensus/replay_test.go

@@ -808,7 +808,7 @@ func applyBlock(stateStore sm.Store, st sm.State, blk *types.Block, proxyApp pro
 	blockExec := sm.NewBlockExecutor(stateStore, log.TestingLogger(), proxyApp.Consensus(), mempool, evpool)
 
 	blkID := types.BlockID{Hash: blk.Hash(), PartSetHeader: blk.MakePartSet(testPartSize).Header()}
-	newState, _, err := blockExec.ApplyBlock(st, blkID, blk)
+	newState, _, err := blockExec.ApplyBlock(st, blkID, blk, nil)
 	if err != nil {
 		panic(err)
 	}