diff --git a/CHANGELOG_PENDING.md b/CHANGELOG_PENDING.md index ad1aeab16..1e136585b 100644 --- a/CHANGELOG_PENDING.md +++ b/CHANGELOG_PENDING.md @@ -19,6 +19,7 @@ ### FEATURES: - [init command] [\#125](https://github.com/line/tendermint/pull/125) Add an option selecting private key type to init, testnet commands +- [consensus] [\#126](https://github.com/line/tendermint/pull/126) Add some metrics measuring duration of each consensus steps ### IMPROVEMENTS: diff --git a/cmd/tendermint/commands/init.go b/cmd/tendermint/commands/init.go index 3acec62a8..35f4c4e02 100644 --- a/cmd/tendermint/commands/init.go +++ b/cmd/tendermint/commands/init.go @@ -27,7 +27,7 @@ func NewInitCmd() *cobra.Command { } func AddInitFlags(cmd *cobra.Command) { - cmd.Flags().String("priv-key-type", config.PrivKeyType, + cmd.Flags().String("priv_key_type", config.PrivKeyType, "Specify validator's private key type (ed25519 | composite)") } diff --git a/cmd/tendermint/commands/testnet.go b/cmd/tendermint/commands/testnet.go index a3c31889e..688d06eda 100644 --- a/cmd/tendermint/commands/testnet.go +++ b/cmd/tendermint/commands/testnet.go @@ -73,7 +73,7 @@ func init() { "P2P Port") TestnetFilesCmd.Flags().BoolVar(&randomMonikers, "random-monikers", false, "Randomize the moniker for each generated node") - TestnetFilesCmd.Flags().StringVar(&privKeyType, "priv-key-type", privval.PrevKeyTypeEd25519, + TestnetFilesCmd.Flags().StringVar(&privKeyType, "priv_key_type", privval.PrevKeyTypeEd25519, "Specify validator's private key type (ed25519 | composite)") } diff --git a/config/config.go b/config/config.go index 0a25ca7dd..b4feb5b25 100644 --- a/config/config.go +++ b/config/config.go @@ -215,7 +215,7 @@ type BaseConfig struct { //nolint: maligned FilterPeers bool `mapstructure:"filter_peers"` // false // Specify validator's private key type - PrivKeyType string `mapstructure:"priv-key-type"` + PrivKeyType string `mapstructure:"priv_key_type"` } // DefaultBaseConfig returns a default base configuration for a Tendermint node diff --git a/consensus/metrics.go b/consensus/metrics.go index e315fd1f7..a448f4559 100644 --- a/consensus/metrics.go +++ b/consensus/metrics.go @@ -63,6 +63,24 @@ type Metrics struct { // Number of blockparts transmitted by peer. BlockParts metrics.Counter + + // 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 } // PrometheusMetrics returns Metrics build using Prometheus client library. @@ -197,6 +215,89 @@ func PrometheusMetrics(namespace string, labelsAndValues ...string) *Metrics { Name: "block_parts", Help: "Number of blockparts transmitted by peer.", }, append(labels, "peer_id")).With(labelsAndValues...), + MissingProposal: prometheus.NewGaugeFrom(stdprometheus.GaugeOpts{ + Namespace: namespace, + Subsystem: MetricsSubsystem, + Name: "missing_proposal", + Help: "Number of blocks we couldn't receive", + }, labels).With(labelsAndValues...), + RoundFailures: prometheus.NewHistogramFrom(stdprometheus.HistogramOpts{ + Namespace: namespace, + Subsystem: MetricsSubsystem, + Name: "round_failures", + Help: "Number of rounds failed on consensus", + Buckets: stdprometheus.LinearBuckets(0, 1, 5), + }, labels).With(labelsAndValues...), + ProposalCreating: prometheus.NewHistogramFrom(stdprometheus.HistogramOpts{ + Namespace: namespace, + Subsystem: MetricsSubsystem, + Name: "duration_proposal_creating", + Help: "Duration of creating proposal and block", + Buckets: stdprometheus.LinearBuckets(100, 100, 10), + }, labels).With(labelsAndValues...), + ProposalWaiting: prometheus.NewHistogramFrom(stdprometheus.HistogramOpts{ + Namespace: namespace, + Subsystem: MetricsSubsystem, + Name: "duration_proposal_waiting", + Help: "Duration between enterNewRound and receiving proposal", + 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{ + Namespace: namespace, + Subsystem: MetricsSubsystem, + Name: "duration_proposal_block_receiving", + Help: "Duration of receiving all proposal block parts", + Buckets: stdprometheus.LinearBuckets(100, 100, 10), + }, labels).With(labelsAndValues...), + PrevoteBlockVerifying: 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", + Buckets: stdprometheus.LinearBuckets(100, 100, 10), + }, labels).With(labelsAndValues...), + PrecommitBlockVerifying: 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", + Buckets: stdprometheus.LinearBuckets(100, 100, 10), + }, labels).With(labelsAndValues...), + CommitBlockVerifying: 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), + }, labels).With(labelsAndValues...), + CommitBlockApplying: prometheus.NewHistogramFrom(stdprometheus.HistogramOpts{ + Namespace: namespace, + Subsystem: MetricsSubsystem, + Name: "duration_commit_block_applying", + Help: "Duration of applying block", + Buckets: stdprometheus.LinearBuckets(100, 100, 10), + }, labels).With(labelsAndValues...), } } @@ -228,5 +329,19 @@ func NopMetrics() *Metrics { CommittedHeight: discard.NewGauge(), FastSyncing: discard.NewGauge(), BlockParts: discard.NewCounter(), + + 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(), } } diff --git a/consensus/state.go b/consensus/state.go index dcb72413d..f7ac2c6c0 100644 --- a/consensus/state.go +++ b/consensus/state.go @@ -9,7 +9,6 @@ import ( "time" "github.com/pkg/errors" - "github.com/tendermint/tendermint/libs/fail" "github.com/tendermint/tendermint/libs/log" tmos "github.com/tendermint/tendermint/libs/os" @@ -68,6 +67,48 @@ type evidencePool interface { AddEvidence(types.Evidence) error } +type StepDuration struct { + started bool + start time.Time + end time.Time +} + +func (sd *StepDuration) GetDuration() float64 { + if !sd.started && sd.end.After(sd.start) { + return float64(sd.end.Sub(sd.start).Microseconds()) / 1000 + } + return 0 +} + +func (sd *StepDuration) SetStart() time.Time { + sd.start = tmtime.Now() + sd.started = true + return sd.start +} + +func (sd *StepDuration) SetEnd() time.Time { + if sd.started { + // update only once at first; it will be reset when Start is re-assigned + sd.end = tmtime.Now() + sd.started = false + } + return sd.end +} + +type StepTimes struct { + ProposalCreatedByMyself bool + ProposalCreating StepDuration + ProposalWaiting StepDuration + ProposalVerifying StepDuration + ProposalBlockReceiving StepDuration + PrevoteBlockVerifying StepDuration + PrevoteReceiving StepDuration + PrecommitBlockVerifying StepDuration + PrecommitReceiving StepDuration + CommitBlockVerifying StepDuration + CommitBlockApplying StepDuration +} + // State handles execution of the consensus algorithm. // It processes votes and proposals, and upon reaching agreement, // commits blocks to the chain and executes them against the application. @@ -134,6 +175,9 @@ type State struct { // for reporting metrics metrics *Metrics + + // times of each step + stepTimes StepTimes } // StateOption sets an optional parameter on the State. @@ -828,7 +872,8 @@ func (cs *State) enterNewRound(height int64, round int) { return } - if now := tmtime.Now(); cs.StartTime.After(now) { + now := cs.stepTimes.ProposalWaiting.SetStart() + if cs.StartTime.After(now) { logger.Info("Need to set a buffer and log message here for sanity.", "startTime", cs.StartTime, "now", now) } @@ -944,13 +989,14 @@ func (cs *State) enterPropose(height int64, round int) { "privValidator", cs.privValidator) cs.decideProposal(height, round) + cs.stepTimes.ProposalCreatedByMyself = true } else { logger.Info("enterPropose: Not our turn to propose", "proposer", cs.Proposer.Address, "privValidator", cs.privValidator) - + cs.stepTimes.ProposalCreatedByMyself = false } if !cs.Voters.HasAddress(address) { @@ -974,8 +1020,10 @@ func (cs *State) defaultDecideProposal(height int64, round int) { block, blockParts = cs.ValidBlock, cs.ValidBlockParts } else { // Create a new proposal block from state/txs from the mempool. + cs.stepTimes.ProposalCreating.SetStart() block, blockParts = cs.createProposalBlock(round) if block == nil { // on error + cs.stepTimes.ProposalCreating.SetEnd() return } cs.Logger.Info("Create Block", "Height", height, "Round", round, @@ -990,7 +1038,7 @@ func (cs *State) defaultDecideProposal(height int64, round int) { propBlockID := types.BlockID{Hash: block.Hash(), PartsHeader: blockParts.Header()} proposal := types.NewProposal(height, round, cs.ValidRound, propBlockID) if err := cs.privValidator.SignProposal(cs.state.ChainID, proposal); err == nil { - + cs.stepTimes.ProposalCreating.SetEnd() // send proposal and block parts on internal msg queue cs.sendInternalMessage(msgInfo{&ProposalMessage{proposal}, ""}) for i := 0; i < blockParts.Total(); i++ { @@ -1000,6 +1048,7 @@ func (cs *State) defaultDecideProposal(height int64, round int) { cs.Logger.Info("Signed proposal", "height", height, "round", round, "proposal", proposal) cs.Logger.Debug(fmt.Sprintf("Signed proposal block: %v", block)) } else if !cs.replayMode { + cs.stepTimes.ProposalCreating.SetEnd() cs.Logger.Error("enterPropose: Error signing proposal", "height", height, "round", round, "err", err) } } @@ -1106,25 +1155,34 @@ func (cs *State) defaultDoPrevote(height int64, round int) { // If ProposalBlock is nil, prevote nil. if cs.ProposalBlock == nil { + // if it already ends or not starts it will be ignored + cs.stepTimes.ProposalWaiting.SetEnd() + cs.stepTimes.ProposalBlockReceiving.SetEnd() logger.Info("enterPrevote: ProposalBlock is nil") cs.signAddVote(types.PrevoteType, nil, types.PartSetHeader{}) + // increase missing proposal by one + cs.metrics.MissingProposal.Add(1) return } + cs.stepTimes.PrevoteBlockVerifying.SetStart() // Validate proposal block err := cs.blockExec.ValidateBlock(cs.state, round, cs.ProposalBlock) if err != nil { // ProposalBlock is invalid, prevote nil. logger.Error("enterPrevote: ProposalBlock is invalid", "err", err) + cs.stepTimes.PrevoteBlockVerifying.SetEnd() cs.signAddVote(types.PrevoteType, nil, types.PartSetHeader{}) return } + cs.stepTimes.PrevoteBlockVerifying.SetEnd() // Prevote cs.ProposalBlock // NOTE: the proposal signature is validated when it is received, // and the proposal block parts are validated as they are received (against the merkle hash in the proposal) logger.Info("enterPrevote: ProposalBlock is valid") cs.signAddVote(types.PrevoteType, cs.ProposalBlock.Hash(), cs.ProposalBlockParts.Header()) + cs.stepTimes.PrevoteReceiving.SetStart() } // Enter: any +2/3 prevotes at next round. @@ -1230,6 +1288,7 @@ func (cs *State) enterPrecommit(height int64, round int) { cs.LockedRound = round cs.eventBus.PublishEventRelock(cs.RoundStateEvent()) cs.signAddVote(types.PrecommitType, blockID.Hash, blockID.PartsHeader) + cs.stepTimes.PrecommitReceiving.SetStart() return } @@ -1237,14 +1296,17 @@ func (cs *State) enterPrecommit(height int64, round int) { if cs.ProposalBlock.HashesTo(blockID.Hash) { logger.Info("enterPrecommit: +2/3 prevoted proposal block. Locking", "hash", blockID.Hash) // Validate the block. + cs.stepTimes.PrecommitBlockVerifying.SetStart() if err := cs.blockExec.ValidateBlock(cs.state, round, cs.ProposalBlock); err != nil { panic(fmt.Sprintf("enterPrecommit: +2/3 prevoted for an invalid block: %v", err)) } + cs.stepTimes.PrecommitBlockVerifying.SetEnd() cs.LockedRound = round cs.LockedBlock = cs.ProposalBlock cs.LockedBlockParts = cs.ProposalBlockParts cs.eventBus.PublishEventLock(cs.RoundStateEvent()) cs.signAddVote(types.PrecommitType, blockID.Hash, blockID.PartsHeader) + cs.stepTimes.PrecommitReceiving.SetStart() return } @@ -1399,6 +1461,7 @@ func (cs *State) finalizeCommit(height int64) { blockID, ok := cs.Votes.Precommits(cs.CommitRound).TwoThirdsMajority() block, blockParts := cs.ProposalBlock, cs.ProposalBlockParts + cs.stepTimes.CommitBlockVerifying.SetStart() if !ok { panic("Cannot finalizeCommit, commit does not have two thirds majority") } @@ -1411,6 +1474,7 @@ func (cs *State) finalizeCommit(height int64) { if err := cs.blockExec.ValidateBlock(cs.state, cs.CommitRound, block); err != nil { panic(fmt.Sprintf("+2/3 committed an invalid block: %v", err)) } + cs.stepTimes.CommitBlockVerifying.SetEnd() cs.Logger.Info("Finalizing commit of block with N txs", "height", block.Height, @@ -1461,6 +1525,7 @@ func (cs *State) finalizeCommit(height int64) { // Execute and commit the block, update and save the state, and update the mempool. // NOTE The block.AppHash wont reflect these txs until the next block. + cs.stepTimes.CommitBlockApplying.SetStart() var err error var retainHeight int64 stateCopy, retainHeight, err = cs.blockExec.ApplyBlock( @@ -1473,6 +1538,7 @@ func (cs *State) finalizeCommit(height int64) { } return } + cs.stepTimes.CommitBlockApplying.SetEnd() fail.Fail() // XXX @@ -1613,6 +1679,20 @@ func (cs *State) recordMetrics(height int64, block *types.Block) { cs.metrics.TotalTxs.Add(float64(len(block.Data.Txs))) cs.metrics.BlockSizeBytes.Set(float64(block.Size())) cs.metrics.CommittedHeight.Set(float64(block.Height)) + + cs.metrics.RoundFailures.Observe(float64(cs.Round)) + if cs.stepTimes.ProposalCreatedByMyself { + cs.metrics.ProposalCreating.Observe(cs.stepTimes.ProposalCreating.GetDuration()) + } + cs.metrics.ProposalWaiting.Observe(cs.stepTimes.ProposalWaiting.GetDuration()) + cs.metrics.ProposalVerifying.Observe(cs.stepTimes.ProposalVerifying.GetDuration()) + cs.metrics.ProposalBlockReceiving.Observe(cs.stepTimes.ProposalBlockReceiving.GetDuration()) + cs.metrics.PrevoteBlockVerifying.Observe(cs.stepTimes.PrevoteBlockVerifying.GetDuration()) + cs.metrics.PrevoteReceiving.Observe(cs.stepTimes.PrevoteReceiving.GetDuration()) + cs.metrics.PrecommitBlockVerifying.Observe(cs.stepTimes.PrecommitBlockVerifying.GetDuration()) + cs.metrics.PrecommitReceiving.Observe(cs.stepTimes.PrecommitReceiving.GetDuration()) + cs.metrics.CommitBlockVerifying.Observe(cs.stepTimes.CommitBlockVerifying.GetDuration()) + cs.metrics.CommitBlockApplying.Observe(cs.stepTimes.CommitBlockApplying.GetDuration()) } //----------------------------------------------------------------------------- @@ -1634,14 +1714,17 @@ func (cs *State) defaultSetProposal(proposal *types.Proposal) error { (proposal.POLRound >= 0 && proposal.POLRound >= proposal.Round) { return ErrInvalidProposalPOLRound } + cs.stepTimes.ProposalWaiting.SetEnd() + cs.stepTimes.ProposalVerifying.SetStart() // If consensus does not enterNewRound yet, cs.Proposer may be nil or prior proposer, so don't use cs.Proposer proposer := cs.Validators.SelectProposer(cs.state.LastProofHash, proposal.Height, proposal.Round) - // Verify signature if !proposer.PubKey.VerifyBytes(proposal.SignBytes(cs.state.ChainID), proposal.Signature) { + cs.stepTimes.ProposalVerifying.SetEnd() return ErrInvalidProposalSignature } + cs.stepTimes.ProposalVerifying.SetEnd() cs.Proposal = proposal // We don't update cs.ProposalBlockParts if it is already set. @@ -1651,6 +1734,8 @@ func (cs *State) defaultSetProposal(proposal *types.Proposal) error { cs.ProposalBlockParts = types.NewPartSetFromHeader(proposal.BlockID.PartsHeader) } cs.Logger.Info("Received proposal", "proposal", proposal) + + cs.stepTimes.ProposalBlockReceiving.SetStart() return nil } @@ -1689,6 +1774,8 @@ func (cs *State) addProposalBlockPart(msg *BlockPartMessage, peerID p2p.ID) (add if err != nil { return added, err } + cs.stepTimes.ProposalBlockReceiving.SetEnd() + // NOTE: it's possible to receive complete proposal blocks for future rounds without having the proposal cs.Logger.Info("Received complete proposal block", "height", cs.ProposalBlock.Height, "hash", cs.ProposalBlock.Hash()) cs.eventBus.PublishEventCompleteProposal(cs.CompleteProposalEvent()) @@ -1839,6 +1926,7 @@ func (cs *State) addVote( // If +2/3 prevotes for a block or nil for *any* round: if blockID, ok := prevotes.TwoThirdsMajority(); ok { + cs.stepTimes.PrevoteReceiving.SetEnd() // There was a polka! // If we're locked but this is a recent polka, unlock. @@ -1908,6 +1996,7 @@ func (cs *State) addVote( blockID, ok := precommits.TwoThirdsMajority() if ok { + cs.stepTimes.PrecommitReceiving.SetEnd() // Executed as TwoThirdsMajority could be from a higher round cs.enterNewRound(height, vote.Round) cs.enterPrecommit(height, vote.Round) @@ -1920,6 +2009,7 @@ func (cs *State) addVote( cs.enterPrecommitWait(height, vote.Round) } } else if cs.Round <= vote.Round && precommits.HasTwoThirdsAny() { + cs.stepTimes.PrecommitReceiving.SetEnd() cs.enterNewRound(height, vote.Round) cs.enterPrecommitWait(height, vote.Round) } diff --git a/state/execution.go b/state/execution.go index db845cdc1..3cc04aa6b 100644 --- a/state/execution.go +++ b/state/execution.go @@ -132,16 +132,19 @@ func (blockExec *BlockExecutor) ApplyBlock( state State, blockID types.BlockID, block *types.Block, ) (State, int64, error) { + startTime := time.Now().UnixNano() // When doing ApplyBlock, we don't need to check whether the block.Round is same to current round, // so we just put block.Round for the current round parameter if err := blockExec.ValidateBlock(state, block.Round, block); err != nil { return state, 0, ErrInvalidBlock(err) } + endTime := time.Now().UnixNano() + blockExec.metrics.BlockVerifyingTime.Observe(float64(endTime-startTime) / 1000000) - startTime := time.Now().UnixNano() + startTime = endTime abciResponses, err := execBlockOnProxyApp(blockExec.logger, blockExec.proxyApp, block, blockExec.db, state.VoterParams) - endTime := time.Now().UnixNano() + endTime = time.Now().UnixNano() blockExec.metrics.BlockProcessingTime.Observe(float64(endTime-startTime) / 1000000) if err != nil { return state, 0, ErrProxyAppConn(err) @@ -174,11 +177,14 @@ func (blockExec *BlockExecutor) ApplyBlock( return state, 0, fmt.Errorf("commit failed for application: %v", err) } + startTime = time.Now().UnixNano() // Lock mempool, commit app state, update mempoool. appHash, retainHeight, err := blockExec.Commit(state, block, abciResponses.DeliverTxs) if err != nil { return state, 0, fmt.Errorf("commit failed for application: %v", err) } + endTime = time.Now().UnixNano() + blockExec.metrics.BlockCommittingTime.Observe(float64(endTime-startTime) / 1000000) // Update evpool with the block and state. blockExec.evpool.Update(block, state) @@ -301,6 +307,7 @@ func execBlockOnProxyApp( return nil, err } + startTime := time.Now() // Run txs of block. for _, tx := range block.Txs { proxyAppConn.DeliverTxAsync(abci.RequestDeliverTx{Tx: tx}) @@ -308,6 +315,8 @@ func execBlockOnProxyApp( return nil, err } } + endTime := time.Now() + execTime := endTime.Sub(startTime) // End block. abciResponses.EndBlock, err = proxyAppConn.EndBlockSync(abci.RequestEndBlock{Height: block.Height}) @@ -316,7 +325,8 @@ func execBlockOnProxyApp( return nil, err } - logger.Info("Executed block", "height", block.Height, "validTxs", validTxs, "invalidTxs", invalidTxs) + logger.Info("Executed block", "height", block.Height, "validTxs", validTxs, + "invalidTxs", invalidTxs, "execTime", execTime) return abciResponses, nil } diff --git a/state/metrics.go b/state/metrics.go index bcd713f5f..7461936d9 100644 --- a/state/metrics.go +++ b/state/metrics.go @@ -15,8 +15,12 @@ const ( // Metrics contains metrics exposed by this package. type Metrics struct { + // Time of ValidBlock + BlockVerifyingTime metrics.Histogram // Time between BeginBlock and EndBlock. BlockProcessingTime metrics.Histogram + // Time of Commit + BlockCommittingTime metrics.Histogram } // PrometheusMetrics returns Metrics build using Prometheus client library. @@ -27,13 +31,31 @@ func PrometheusMetrics(namespace string, labelsAndValues ...string) *Metrics { for i := 0; i < len(labelsAndValues); i += 2 { labels = append(labels, labelsAndValues[i]) } + compositeBuckets := stdprometheus.LinearBuckets(20, 20, 5) + compositeBuckets = append(compositeBuckets, stdprometheus.LinearBuckets(200, 100, 4)...) + compositeBuckets = append(compositeBuckets, stdprometheus.LinearBuckets(1000, 500, 4)...) + return &Metrics{ + BlockVerifyingTime: prometheus.NewHistogramFrom(stdprometheus.HistogramOpts{ + Namespace: namespace, + Subsystem: MetricsSubsystem, + Name: "block_verifying_time", + Help: "Time of ValidBlock in ms.", + Buckets: stdprometheus.LinearBuckets(50, 50, 10), + }, labels).With(labelsAndValues...), BlockProcessingTime: prometheus.NewHistogramFrom(stdprometheus.HistogramOpts{ Namespace: namespace, Subsystem: MetricsSubsystem, Name: "block_processing_time", Help: "Time between BeginBlock and EndBlock in ms.", - Buckets: stdprometheus.LinearBuckets(1, 10, 10), + Buckets: compositeBuckets, + }, labels).With(labelsAndValues...), + BlockCommittingTime: prometheus.NewHistogramFrom(stdprometheus.HistogramOpts{ + Namespace: namespace, + Subsystem: MetricsSubsystem, + Name: "block_committing_time", + Help: "Time of Commit in ms.", + Buckets: stdprometheus.LinearBuckets(20, 20, 10), }, labels).With(labelsAndValues...), } } @@ -41,6 +63,8 @@ func PrometheusMetrics(namespace string, labelsAndValues ...string) *Metrics { // NopMetrics returns no-op Metrics. func NopMetrics() *Metrics { return &Metrics{ + BlockVerifyingTime: discard.NewHistogram(), BlockProcessingTime: discard.NewHistogram(), + BlockCommittingTime: discard.NewHistogram(), } }