From d4f26f7d61c3930550d732c50466e1f721ee4aa9 Mon Sep 17 00:00:00 2001 From: "mergify[bot]" <37929162+mergify[bot]@users.noreply.github.com> Date: Tue, 18 Jan 2022 20:21:12 -0500 Subject: [PATCH] consensus: calculate prevote message delay metric (backport #7551) (#7618) * consensus: calculate prevote message delay metric (#7551) ## What does this pull request do? This pull requests adds two metrics intended for use in calculating an experimental value for `MessageDelay`. The metrics are as follows: ``` # HELP tendermint_consensus_complete_prevote_message_delay Difference in seconds between the proposal timestamp and the timestamp of the prevote that achieved 100% of the voting power in the prevote step. # TYPE tendermint_consensus_complete_prevote_message_delay gauge tendermint_consensus_complete_prevote_message_delay{chain_id="test-chain-aZbwF1"} 0.013025505 # HELP tendermint_consensus_quorum_prevote_message_delay Difference in seconds between the proposal timestamp and the timestamp of the prevote that achieved a quorum in the prevote step. # TYPE tendermint_consensus_quorum_prevote_message_delay gauge tendermint_consensus_quorum_prevote_message_delay{chain_id="test-chain-aZbwF1"} 0.013025505 ``` ## Why this change? For more information on what these metrics are calculating, see #7202. The aim is to merge to backport these metrics to v0.34 and run nodes on a few popular chains with these metrics to determine the experimental values for `MessageDelay` on these popular chains and use these to select our default `SynchronyParams.MessageDelay` value. ## Why Gauges for the metrics? Gauges allow us to overwrite the metric on each successive observation. We can then capture these metrics over time to track the highest and lowest observed value. (cherry picked from commit 0c82ceaa5f7964c13247af9b64d72477af9dc973) # Conflicts: # internal/consensus/state.go * fix merge conflicts Co-authored-by: William Banfield <4561443+williambanfield@users.noreply.github.com> Co-authored-by: William Banfield --- internal/consensus/metrics.go | 46 +++++++++++++++++++++++++++++------ internal/consensus/state.go | 23 ++++++++++++++++++ types/vote_set.go | 17 +++++++++++++ 3 files changed, 79 insertions(+), 7 deletions(-) diff --git a/internal/consensus/metrics.go b/internal/consensus/metrics.go index a75f1505c..dbefb9a5b 100644 --- a/internal/consensus/metrics.go +++ b/internal/consensus/metrics.go @@ -64,6 +64,22 @@ type Metrics struct { // Histogram of time taken per step annotated with reason that the step proceeded. StepTime metrics.Histogram + + // QuroumPrevoteMessageDelay is the interval in seconds between the proposal + // timestamp and the timestamp of the earliest prevote that achieved a quorum + // during the prevote step. + // + // To compute it, sum the voting power over each prevote received, in increasing + // order of timestamp. The timestamp of the first prevote to increase the sum to + // be above 2/3 of the total voting power of the network defines the endpoint + // the endpoint of the interval. Subtract the proposal timestamp from this endpoint + // to obtain the quorum delay. + QuorumPrevoteMessageDelay metrics.Gauge + + // FullPrevoteMessageDelay is the interval in seconds between the proposal + // timestamp and the timestamp of the latest prevote in a round where 100% + // of the voting power on the network issued prevotes. + FullPrevoteMessageDelay metrics.Gauge } // PrometheusMetrics returns Metrics build using Prometheus client library. @@ -196,6 +212,20 @@ func PrometheusMetrics(namespace string, labelsAndValues ...string) *Metrics { Name: "step_time", Help: "Time spent per step.", }, append(labels, "step", "reason")).With(labelsAndValues...), + QuorumPrevoteMessageDelay: prometheus.NewGaugeFrom(stdprometheus.GaugeOpts{ + Namespace: namespace, + Subsystem: MetricsSubsystem, + Name: "quorum_prevote_message_delay", + Help: "Difference in seconds between the proposal timestamp and the timestamp " + + "of the latest prevote that achieved a quorum in the prevote step.", + }, labels).With(labelsAndValues...), + FullPrevoteMessageDelay: prometheus.NewGaugeFrom(stdprometheus.GaugeOpts{ + Namespace: namespace, + Subsystem: MetricsSubsystem, + Name: "full_prevote_message_delay", + Help: "Difference in seconds between the proposal timestamp and the timestamp " + + "of the latest prevote that achieved 100% of the voting power in the prevote step.", + }, labels).With(labelsAndValues...), } } @@ -219,13 +249,15 @@ func NopMetrics() *Metrics { BlockIntervalSeconds: discard.NewHistogram(), - NumTxs: discard.NewGauge(), - BlockSizeBytes: discard.NewHistogram(), - TotalTxs: discard.NewGauge(), - CommittedHeight: discard.NewGauge(), - BlockSyncing: discard.NewGauge(), - StateSyncing: discard.NewGauge(), - BlockParts: discard.NewCounter(), + NumTxs: discard.NewGauge(), + BlockSizeBytes: discard.NewHistogram(), + TotalTxs: discard.NewGauge(), + CommittedHeight: discard.NewGauge(), + BlockSyncing: discard.NewGauge(), + StateSyncing: discard.NewGauge(), + BlockParts: discard.NewCounter(), + QuorumPrevoteMessageDelay: discard.NewGauge(), + FullPrevoteMessageDelay: discard.NewGauge(), } } diff --git a/internal/consensus/state.go b/internal/consensus/state.go index 837174356..f87455bb9 100644 --- a/internal/consensus/state.go +++ b/internal/consensus/state.go @@ -8,6 +8,7 @@ import ( "io/ioutil" "os" "runtime/debug" + "sort" "time" "github.com/gogo/protobuf/proto" @@ -1623,6 +1624,8 @@ func (cs *State) finalizeCommit(height int64) { return } + cs.calculatePrevoteMessageDelayMetrics() + blockID, ok := cs.Votes.Precommits(cs.CommitRound).TwoThirdsMajority() block, blockParts := cs.ProposalBlock, cs.ProposalBlockParts @@ -2347,6 +2350,26 @@ func (cs *State) checkDoubleSigningRisk(height int64) error { return nil } +func (cs *State) calculatePrevoteMessageDelayMetrics() { + ps := cs.Votes.Prevotes(cs.Round) + pl := ps.List() + sort.Slice(pl, func(i, j int) bool { + return pl[i].Timestamp.Before(pl[j].Timestamp) + }) + var votingPowerSeen int64 + for _, v := range pl { + _, val := cs.Validators.GetByAddress(v.ValidatorAddress) + votingPowerSeen += val.VotingPower + if votingPowerSeen >= cs.Validators.TotalVotingPower()*2/3+1 { + cs.metrics.QuorumPrevoteMessageDelay.Set(v.Timestamp.Sub(cs.Proposal.Timestamp).Seconds()) + break + } + } + if ps.HasAll() { + cs.metrics.FullPrevoteMessageDelay.Set(pl[len(pl)-1].Timestamp.Sub(cs.Proposal.Timestamp).Seconds()) + } +} + //--------------------------------------------------------- func CompareHRS(h1 int64, r1 int32, s1 cstypes.RoundStepType, h2 int64, r2 int32, s2 cstypes.RoundStepType) int { diff --git a/types/vote_set.go b/types/vote_set.go index e014ae7bb..259857e40 100644 --- a/types/vote_set.go +++ b/types/vote_set.go @@ -378,6 +378,20 @@ func (voteSet *VoteSet) GetByIndex(valIndex int32) *Vote { return voteSet.votes[valIndex] } +// List returns a copy of the list of votes stored by the VoteSet. +func (voteSet *VoteSet) List() []Vote { + if voteSet == nil || voteSet.votes == nil { + return nil + } + votes := make([]Vote, 0, len(voteSet.votes)) + for i := range voteSet.votes { + if voteSet.votes[i] != nil { + votes = append(votes, *voteSet.votes[i]) + } + } + return votes +} + func (voteSet *VoteSet) GetByAddress(address []byte) *Vote { if voteSet == nil { return nil @@ -423,6 +437,9 @@ func (voteSet *VoteSet) HasTwoThirdsAny() bool { } func (voteSet *VoteSet) HasAll() bool { + if voteSet == nil { + return false + } voteSet.mtx.Lock() defer voteSet.mtx.Unlock() return voteSet.sum == voteSet.valSet.TotalVotingPower()