diff --git a/consensus/metrics.go b/consensus/metrics.go index d268454fc..a92c949ef 100644 --- a/consensus/metrics.go +++ b/consensus/metrics.go @@ -76,6 +76,11 @@ type Metrics struct { // 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 + + // ProposalTimestampDifference is the difference between the timestamp in + // the proposal message and the local time of the validator at the time + // that the validator received the message. + ProposalTimestampDifference metrics.Histogram } // PrometheusMetrics returns Metrics build using Prometheus client library. @@ -216,6 +221,15 @@ func PrometheusMetrics(namespace string, labelsAndValues ...string) *Metrics { 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.", }, append(labels, "height")).With(labelsAndValues...), + ProposalTimestampDifference: prometheus.NewHistogramFrom(stdprometheus.HistogramOpts{ + Namespace: namespace, + Subsystem: MetricsSubsystem, + Name: "proposal_timestamp_difference", + Help: "Difference in seconds between the timestamp in the proposal " + + "message and the local time when the message was received. " + + "Only calculated when a new block is proposed.", + Buckets: []float64{-10, -.5, -.025, 0, .1, .5, 1, 1.5, 2, 10}, + }, append(labels, "is_timely")).With(labelsAndValues...), } } @@ -239,14 +253,15 @@ func NopMetrics() *Metrics { BlockIntervalSeconds: discard.NewHistogram(), - NumTxs: discard.NewGauge(), - BlockSizeBytes: discard.NewGauge(), - TotalTxs: discard.NewGauge(), - CommittedHeight: discard.NewGauge(), - FastSyncing: discard.NewGauge(), - StateSyncing: discard.NewGauge(), - BlockParts: discard.NewCounter(), - QuorumPrevoteMessageDelay: discard.NewGauge(), - FullPrevoteMessageDelay: discard.NewGauge(), + NumTxs: discard.NewGauge(), + BlockSizeBytes: discard.NewGauge(), + TotalTxs: discard.NewGauge(), + CommittedHeight: discard.NewGauge(), + FastSyncing: discard.NewGauge(), + StateSyncing: discard.NewGauge(), + BlockParts: discard.NewCounter(), + QuorumPrevoteMessageDelay: discard.NewGauge(), + FullPrevoteMessageDelay: discard.NewGauge(), + ProposalTimestampDifference: discard.NewHistogram(), } } diff --git a/consensus/state.go b/consensus/state.go index b2e1f52a1..358e78606 100644 --- a/consensus/state.go +++ b/consensus/state.go @@ -1817,6 +1817,8 @@ func (cs *State) defaultSetProposal(proposal *types.Proposal) error { proposal.Signature = p.Signature cs.Proposal = proposal + cs.ProposalReceiveTime = recvTime + cs.calculateProposalTimestampDifferenceMetric() // We don't update cs.ProposalBlockParts if it is already set. // This happens if we're already in cstypes.RoundStepCommit or if there is a valid block in the current round. // TODO: We can check if Proposal is for a different block as this is a sign of misbehavior! @@ -2369,3 +2371,16 @@ func repairWalFile(src, dst string) error { return nil } + +func (cs *State) calculateProposalTimestampDifferenceMetric() { + if cs.Proposal != nil && cs.Proposal.POLRound == -1 { + tp := types.SynchronyParams{ + Precision: cs.state.ConsensusParams.Synchrony.Precision, + MessageDelay: cs.state.ConsensusParams.Synchrony.MessageDelay, + } + + isTimely := cs.Proposal.IsTimely(cs.ProposalReceiveTime, tp, cs.state.InitialHeight) + cs.metrics.ProposalTimestampDifference.With("is_timely", fmt.Sprintf("%t", isTimely)). + Observe(cs.ProposalReceiveTime.Sub(cs.Proposal.Timestamp).Seconds()) + } +}