peerstore: Clarify peer report warnings (#5407)

This PR aims to make the logging from the peer store a bit more clear.

In the past, we aggressively produced warning logs from the peer store
component, even in cases where the reputation change was not malicious.
This has led to an extensive number of logs, as well to node operator
confusion.

In this PR, we produce a warning message if:
- The peer crosses the banned threshold for the first time. This is the
actual reason of a ban
- The peer misbehaves again while being banned. This may happen during a
batch peer report

cc @paritytech/networking 

Part of: #5379.

---------

Signed-off-by: Alexandru Vasile <alexandru.vasile@parity.io>
Co-authored-by: Dmitry Markin <dmitry@markin.tech>

prdoc/pr_5407.prdoc

@@ -0,0 +1,17 @@
+title: Prepare PVFs if node is a validator in the next session
+
+doc:
+  - audience: [Node Operator, Node Dev]
+    description: |
+      This PR aims to remove the noise caused by the peer store's reputation system.
+      A warning was emitted each time a reputation was reported for a banned peer,
+      regardless of the reputation being positive. This has led in the past to
+      situations where it was hard to identify the actual reason of the ban and
+      caused noise for node operators.
+
+      The `Banned, disconnecting.` warning is logged only when the peer is banned.
+      Other misbehaves are logged as `Misbehaved during the ban threshold`.
+
+crates:
+  - name: sc-network
+    bump: patch

substrate/client/network/src/litep2p/peerstore.rs

@@ -192,38 +192,63 @@ impl PeerStoreProvider for PeerstoreHandle {
 	}
 
 	/// Adjust peer reputation.
-	fn report_peer(&self, peer: PeerId, reputation_change: ReputationChange) {
+	fn report_peer(&self, peer_id: PeerId, change: ReputationChange) {
 		let mut lock = self.0.lock();
+		let peer_info = lock.peers.entry(peer_id).or_default();
+		let was_banned = peer_info.is_banned();
+		peer_info.add_reputation(change.value);
+		let peer_reputation = peer_info.reputation;
+
+		log::trace!(
+			target: LOG_TARGET,
+			"Report {}: {:+} to {}. Reason: {}.",
+			peer_id,
+			change.value,
+			peer_reputation,
+			change.reason,
+		);
 
-		log::trace!(target: LOG_TARGET, "report peer {reputation_change:?}");
-
-		match lock.peers.get_mut(&peer) {
-			Some(info) => {
-				info.add_reputation(reputation_change.value);
-			},
-			None => {
-				lock.peers.insert(
-					peer,
-					PeerInfo {
-						reputation: reputation_change.value,
-						last_updated: Instant::now(),
-						role: None,
-					},
+		if !peer_info.is_banned() {
+			if was_banned {
+				log::info!(
+					target: LOG_TARGET,
+					"Peer {} is now unbanned: {:+} to {}. Reason: {}.",
+					peer_id,
+					change.value,
+					peer_reputation,
+					change.reason,
 				);
-			},
+			}
+			return;
 		}
 
-		if lock
-			.peers
-			.get(&peer)
-			.expect("peer exist since it was just modified; qed")
-			.is_banned()
-		{
-			log::warn!(target: LOG_TARGET, "{peer:?} banned, disconnecting, reason: {}", reputation_change.reason);
-
-			for sender in &lock.protocols {
-				sender.disconnect_peer(peer);
-			}
+		// Peer is currently banned, disconnect it from all protocols.
+		lock.protocols.iter().for_each(|handle| handle.disconnect_peer(peer_id.into()));
+
+		// The peer is banned for the first time.
+		if !was_banned {
+			log::warn!(
+				target: LOG_TARGET,
+				"Report {}: {:+} to {}. Reason: {}. Banned, disconnecting.",
+				peer_id,
+				change.value,
+				peer_reputation,
+				change.reason,
+			);
+			return;
+		}
+
+		// The peer was already banned and it got another negative report.
+		// This may happen during a batch report.
+		if change.value < 0 {
+			log::debug!(
+				target: LOG_TARGET,
+				"Report {}: {:+} to {}. Reason: {}. Misbehaved during the ban threshold.",
+				peer_id,
+				change.value,
+				peer_reputation,
+				change.reason,
+			);
 		}
 	}
 

substrate/client/network/src/peer_store.rs

@@ -260,11 +260,37 @@ impl PeerStoreInner {
 
 	fn report_peer(&mut self, peer_id: PeerId, change: ReputationChange) {
 		let peer_info = self.peers.entry(peer_id).or_default();
+		let was_banned = peer_info.is_banned();
 		peer_info.add_reputation(change.value);
 
-		if peer_info.is_banned() {
-			self.protocols.iter().for_each(|handle| handle.disconnect_peer(peer_id.into()));
+		log::trace!(
+			target: LOG_TARGET,
+			"Report {}: {:+} to {}. Reason: {}.",
+			peer_id,
+			change.value,
+			peer_info.reputation,
+			change.reason,
+		);
+
+		if !peer_info.is_banned() {
+			if was_banned {
+				log::info!(
+					target: LOG_TARGET,
+					"Peer {} is now unbanned: {:+} to {}. Reason: {}.",
+					peer_id,
+					change.value,
+					peer_info.reputation,
+					change.reason,
+				);
+			}
+			return;
+		}
+
+		// Peer is currently banned, disconnect it from all protocols.
+		self.protocols.iter().for_each(|handle| handle.disconnect_peer(peer_id.into()));
 
+		// The peer is banned for the first time.
+		if !was_banned {
 			log::warn!(
 				target: LOG_TARGET,
 				"Report {}: {:+} to {}. Reason: {}. Banned, disconnecting.",
@@ -273,10 +299,15 @@ impl PeerStoreInner {
 				peer_info.reputation,
 				change.reason,
 			);
-		} else {
-			log::trace!(
+			return;
+		}
+
+		// The peer was already banned and it got another negative report.
+		// This may happen during a batch report.
+		if change.value < 0 {
+			log::debug!(
 				target: LOG_TARGET,
-				"Report {}: {:+} to {}. Reason: {}.",
+				"Report {}: {:+} to {}. Reason: {}. Misbehaved during the ban threshold.",
 				peer_id,
 				change.value,
 				peer_info.reputation,