From f71345c1ec0ee4b30cd702bb605927f788ff9f36 Mon Sep 17 00:00:00 2001
From: Pavel Zbitskiy <65323360+algorandskiy@users.noreply.github.com>
Date: Wed, 25 Sep 2024 02:33:35 -0400
Subject: [PATCH] Do not format expensive debug messages in non-debug levels in
 doDropRPC (#580)

In high load scenarios when consumer is slow, `doDropRPC` is called
often and makes extra unnecessary allocations formatting `log.Debug`
message.

Fixed by checking log level before running expensive formatting.

Before:
```
BenchmarkAllocDoDropRPC-10    	13684732	        76.28 ns/op	     144 B/op	       3 allocs/op
```

After:
```
BenchmarkAllocDoDropRPC-10    	28140273	        42.88 ns/op	     112 B/op	       1 allocs/op
```
---
 go.mod            | 2 +-
 gossipsub.go      | 6 +++++-
 gossipsub_test.go | 8 ++++++++
 3 files changed, 14 insertions(+), 2 deletions(-)

diff --git a/go.mod b/go.mod
index 3faa411..f1358e7 100644
--- a/go.mod
+++ b/go.mod
@@ -12,6 +12,7 @@ require (
 	github.com/libp2p/go-msgio v0.3.0
 	github.com/multiformats/go-multiaddr v0.13.0
 	github.com/multiformats/go-varint v0.0.7
+	go.uber.org/zap v1.27.0
 )
 
 require (
@@ -98,7 +99,6 @@ require (
 	go.uber.org/fx v1.22.2 // indirect
 	go.uber.org/mock v0.4.0 // indirect
 	go.uber.org/multierr v1.11.0 // indirect
-	go.uber.org/zap v1.27.0 // indirect
 	golang.org/x/crypto v0.26.0 // indirect
 	golang.org/x/exp v0.0.0-20240808152545-0cdaa3abc0fa // indirect
 	golang.org/x/mod v0.20.0 // indirect
diff --git a/gossipsub.go b/gossipsub.go
index 117b585..dcc5d19 100644
--- a/gossipsub.go
+++ b/gossipsub.go
@@ -19,6 +19,8 @@ import (
 	"github.com/libp2p/go-libp2p/core/protocol"
 	"github.com/libp2p/go-libp2p/core/record"
 	"github.com/libp2p/go-libp2p/p2p/host/peerstore/pstoremem"
+
+	"go.uber.org/zap/zapcore"
 )
 
 const (
@@ -1334,7 +1336,9 @@ func (gs *GossipSubRouter) sendRPC(p peer.ID, out *RPC, urgent bool) {
 }
 
 func (gs *GossipSubRouter) doDropRPC(rpc *RPC, p peer.ID, reason string) {
-	log.Debugf("dropping message to peer %s: %s", p, reason)
+	if log.Level() <= zapcore.DebugLevel {
+		log.Debugf("dropping message to peer %s: %s", p, reason)
+	}
 	gs.tracer.DropRPC(rpc, p)
 	// push control messages that need to be retried
 	ctl := rpc.GetControl()
diff --git a/gossipsub_test.go b/gossipsub_test.go
index 3b45557..d515654 100644
--- a/gossipsub_test.go
+++ b/gossipsub_test.go
@@ -3175,3 +3175,11 @@ func TestGossipsubIdontwantClear(t *testing.T) {
 
 	<-ctx.Done()
 }
+
+func BenchmarkAllocDoDropRPC(b *testing.B) {
+	gs := GossipSubRouter{tracer: &pubsubTracer{}}
+
+	for i := 0; i < b.N; i++ {
+		gs.doDropRPC(&RPC{}, "peerID", "reason")
+	}
+}