add send and receive timings

p2p/metrics.go

@@ -39,8 +39,13 @@ type Metrics struct {
 	NumTxs metrics.Gauge
 	// Number of bytes of each message type received.
 	MessageReceiveBytesTotal metrics.Counter
+
 	// Number of bytes of each message type sent.
 	MessageSendBytesTotal metrics.Counter
+	// Histogram of message receive duration.
+	MessageReceiveTime metrics.Histogram
+	// Histogram of message send duration.
+	MessageSendTime metrics.Histogram
 }
 
 // PrometheusMetrics returns Metrics build using Prometheus client library.
@@ -94,6 +99,22 @@ func PrometheusMetrics(namespace string, labelsAndValues ...string) *Metrics {
 			Name:      "message_send_bytes_total",
 			Help:      "Number of bytes of each message type sent.",
 		}, append(labels, "message_type")).With(labelsAndValues...),
+		MessageReceiveTime: prometheus.NewHistogramFrom(stdprometheus.HistogramOpts{
+			Namespace: namespace,
+			Subsystem: MetricsSubsystem,
+			Name:      "message_receive_time",
+			Help:      "Histogram of message receive duration.",
+
+			Buckets: stdprometheus.ExponentialBucketsRange(0.05, 50, 8),
+		}, labels).With(labelsAndValues...),
+		MessageSendTime: prometheus.NewHistogramFrom(stdprometheus.HistogramOpts{
+			Namespace: namespace,
+			Subsystem: MetricsSubsystem,
+			Name:      "message_send_time",
+			Help:      "Histogram of message send duration.",
+
+			Buckets: stdprometheus.ExponentialBucketsRange(0.05, 50, 8),
+		}, labels).With(labelsAndValues...),
 	}
 }
 
@@ -106,6 +127,8 @@ func NopMetrics() *Metrics {
 		NumTxs:                   discard.NewGauge(),
 		MessageReceiveBytesTotal: discard.NewCounter(),
 		MessageSendBytesTotal:    discard.NewCounter(),
+		MessageReceiveTime:       discard.NewHistogram(),
+		MessageSendTime:          discard.NewHistogram(),
 	}
 }
 

p2p/peer.go

@@ -64,6 +64,12 @@ type EnvelopeSender interface {
 //
 // Deprecated: Will be removed in v0.37.
 func SendEnvelopeShim(p Peer, e Envelope, lg log.Logger) bool {
+	before := time.Now()
+	defer func() {
+		if pp, ok := p.(*peer); ok {
+			pp.metrics.MessageSendTime.Observe(float64(time.Since(before)))
+		}
+	}()
 	/*
 		if es, ok := p.(EnvelopeSender); ok {
 			return es.SendEnvelope(e)
@@ -88,9 +94,17 @@ func SendEnvelopeShim(p Peer, e Envelope, lg log.Logger) bool {
 //
 // Deprecated: Will be removed in v0.37.
 func TrySendEnvelopeShim(p Peer, e Envelope, lg log.Logger) bool {
-	if es, ok := p.(EnvelopeSender); ok {
-		return es.SendEnvelope(e)
-	}
+	before := time.Now()
+	defer func() {
+		if pp, ok := p.(*peer); ok {
+			pp.metrics.MessageSendTime.Observe(float64(time.Since(before)))
+		}
+	}()
+	/*
+		if es, ok := p.(EnvelopeSender); ok {
+			return es.SendEnvelope(e)
+		}
+	*/
 	msg := e.Message
 	if w, ok := msg.(Wrapper); ok {
 		msg = w.Wrap()
@@ -512,6 +526,10 @@ func createMConnection(
 ) *tmconn.MConnection {
 
 	onReceive := func(chID byte, msgBytes []byte) {
+		before := time.Now()
+		defer func() {
+			p.metrics.MessageReceiveTime.Observe(float64(time.Since(before)))
+		}()
 		reactor := reactorsByCh[chID]
 		if reactor == nil {
 			// Note that its ok to panic here as it's caught in the conn._recover,