From 6d5441b4bbeb1dcc2944c90eade0377063936138 Mon Sep 17 00:00:00 2001
From: Ivan Folgueira Bande <ivansete@status.im>
Date: Tue, 22 Oct 2024 20:06:49 +0200
Subject: [PATCH] temporary logs to analyse filter issue. some can be
 interesting

---
 waku/node/peer_manager/peer_manager.nim |  6 ++++--
 waku/waku_filter_v2/protocol.nim        | 20 +++++++++++++++-----
 2 files changed, 19 insertions(+), 7 deletions(-)

diff --git a/waku/node/peer_manager/peer_manager.nim b/waku/node/peer_manager/peer_manager.nim
index cb728f3ee3..608a74fb86 100644
--- a/waku/node/peer_manager/peer_manager.nim
+++ b/waku/node/peer_manager/peer_manager.nim
@@ -627,7 +627,7 @@ proc onPeerMetadata(pm: PeerManager, peerId: PeerId) {.async.} =
 
     return
 
-  info "disconnecting from peer", peerId = peerId, reason = reason
+  debug "disconnecting from peer", peerId = shortLog(peerId), reason = reason
   asyncSpawn(pm.switch.disconnect(peerId))
   pm.wakuPeerStore.delete(peerId)
 
@@ -673,7 +673,8 @@ proc onPeerEvent(pm: PeerManager, peerId: PeerId, event: PeerEvent) {.async.} =
       # pm.colocationLimit == 0 disables the ip colocation limit
       if pm.colocationLimit != 0 and peersBehindIp.len > pm.colocationLimit:
         for peerId in peersBehindIp[0 ..< (peersBehindIp.len - pm.colocationLimit)]:
-          debug "Pruning connection due to ip colocation", peerId = peerId, ip = ip
+          debug "Pruning connection due to ip colocation",
+            peerId = shortLog(peerId), ip = ip
           asyncSpawn(pm.switch.disconnect(peerId))
           pm.wakuPeerStore.delete(peerId)
   of Left:
@@ -889,6 +890,7 @@ proc prunePeerStore*(pm: PeerManager) =
       peersToPrune.incl(peer)
 
   for peer in peersToPrune:
+    debug "deleting peer", peerId = shortLog(peer)
     pm.wakuPeerStore.delete(peer)
 
   let afterNumPeers = pm.wakuPeerStore[AddressBook].book.len
diff --git a/waku/waku_filter_v2/protocol.nim b/waku/waku_filter_v2/protocol.nim
index 147df70a5b..fd15b1bd7f 100644
--- a/waku/waku_filter_v2/protocol.nim
+++ b/waku/waku_filter_v2/protocol.nim
@@ -30,10 +30,10 @@ type WakuFilter* = ref object of LPProtocol
   peerRequestRateLimiter*: PerPeerRateLimiter
 
 proc pingSubscriber(wf: WakuFilter, peerId: PeerID): FilterSubscribeResult =
-  trace "pinging subscriber", peerId = peerId
+  debug "pinging subscriber", peerId = shortLog(peerId)
 
   if not wf.subscriptions.isSubscribed(peerId):
-    debug "pinging peer has no subscriptions", peerId = peerId
+    debug "pinging peer has no subscriptions", peerId = shortLog(peerId)
     return err(FilterSubscribeError.notFound())
 
   wf.subscriptions.refreshSubscription(peerId)
@@ -125,13 +125,20 @@ proc handleSubscribeRequest*(
     ## Handle subscribe request
     case request.filterSubscribeType
     of FilterSubscribeType.SUBSCRIBER_PING:
+      debug "debugging filter ping", peerId
       subscribeResult = wf.pingSubscriber(peerId)
     of FilterSubscribeType.SUBSCRIBE:
+      debug "debugging filter subscribe",
+        peerId, pubsubTopic = $(request.pubsubTopic), cTopics = $(request.contentTopics)
       subscribeResult = wf.subscribe(peerId, request.pubsubTopic, request.contentTopics)
     of FilterSubscribeType.UNSUBSCRIBE:
+      debug "debugging filter unsibscribe",
+        peerId, pubsubTopic = $(request.pubsubTopic), cTopics = $(request.contentTopics)
       subscribeResult =
         wf.unsubscribe(peerId, request.pubsubTopic, request.contentTopics)
     of FilterSubscribeType.UNSUBSCRIBE_ALL:
+      debug "debugging filter unsubscribe all",
+        peerId, pubsubTopic = $(request.pubsubTopic), cTopics = $(request.contentTopics)
       subscribeResult = wf.unsubscribeAll(peerId)
 
   let
@@ -143,16 +150,18 @@ proc handleSubscribeRequest*(
   )
 
   if subscribeResult.isErr():
+    debug "debugging filter is err", error = $(subscribeResult.error)
     return FilterSubscribeResponse(
       requestId: request.requestId,
       statusCode: subscribeResult.error.kind.uint32,
       statusDesc: some($subscribeResult.error),
     )
   else:
+    debug "debugging filter ok"
     return FilterSubscribeResponse.ok(request.requestId)
 
 proc pushToPeer(wf: WakuFilter, peer: PeerId, buffer: seq[byte]) {.async.} =
-  trace "pushing message to subscribed peer", peer_id = shortLog(peer)
+  debug "pushing message to subscribed peer", peer_id = shortLog(peer)
 
   if not wf.peerManager.wakuPeerStore.hasPeer(peer, WakuFilterPushCodec):
     # Check that peer has not been removed from peer store
@@ -175,6 +184,7 @@ proc pushToPeer(wf: WakuFilter, peer: PeerId, buffer: seq[byte]) {.async.} =
 proc pushToPeers(
     wf: WakuFilter, peers: seq[PeerId], messagePush: MessagePush
 ) {.async.} =
+  debug "debugging filter pushToPeers"
   let targetPeerIds = peers.mapIt(shortLog(it))
   let msgHash =
     messagePush.pubsubTopic.computeMessageHash(messagePush.wakuMessage).to0xHex()
@@ -202,7 +212,7 @@ proc pushToPeers(
     await allFutures(pushFuts)
 
 proc maintainSubscriptions*(wf: WakuFilter) =
-  trace "maintaining subscriptions"
+  debug "maintaining subscriptions"
 
   ## Remove subscriptions for peers that have been removed from peer store
   var peersToRemove: seq[PeerId]
@@ -227,7 +237,7 @@ proc handleMessage*(
 ) {.async.} =
   let msgHash = computeMessageHash(pubsubTopic, message).to0xHex()
 
-  trace "handling message", pubsubTopic = pubsubTopic, msg_hash = msgHash
+  debug "handling message", pubsubTopic = pubsubTopic, msg_hash = msgHash
 
   let handleMessageStartTime = Moment.now()