peer_store: Warn only on reputation crossing the ban threshold

[lexnv]

This PR changes the warning behavior of the peer_store component.

We have encountered a large number of warnings coming from peer reputation reports.
Previously, warnings were generated on all reports that were below the threshold.

This behavior also generates warnings for correct behavior (positive) reputation changes, if after adding the reputation change, the reputation is still below the threshold.
In this PR, the warning is printed only when crossing the threshold from being not banned to being banned.

cc @paritytech/networking

[dmitry-markin]

That's strange that we receive to many warnings for banned peers. They should have been disconnected in the first place, aren't they?

[lexnv]

Indeed, it seems that the peer is still kept around after being "banned" and disconnected here:

polkadot-sdk/substrate/client/network/src/protocol_controller.rs

Lines 209 to 213 in bf424fd

	/// Disconnect peer. You should remove the `PeerId` from the `PeerStore` first
	/// to not connect to the peer again during the next slot allocation.
	pub fn disconnect_peer(&self, peer_id: PeerId) {
	let _ = self.actions_tx.unbounded_send(Action::DisconnectPeer(peer_id));
	}

From this comment, it seems like we should remove the peer from the peerstore first.

Although, the ongoing peer candidates are filtered by their reputation here:

polkadot-sdk/substrate/client/network/src/peer_store.rs

Lines 298 to 300 in bf424fd

	.filter_map(|(peer_id, info)| {
	(!info.is_banned() && !ignored.contains(peer_id)).then_some((*peer_id, *info))
	})

Thinking out loud, it may be possible that Action::DisconnectPeer does not disconnect the peers from the protocols entirely

[sandreim]

That's strange that we receive to many warnings for banned peers. They should have been disconnected in the first place, aren't they?

One reason is that there might be multiple messages in the queues of different consumers, which leads to calling report_peer called even after we disconnected the offender.

[dmitry-markin]

Probably makes sense double-checking that we disconnect peers as stated before merging this PR that might hide the issue.

[dmitry-markin]

@lexnv How bad is the situation without this fix? Is it like a hundred of messages is printed once with the same peer id, or they are being printed constantly? (This might clue on the root cause.)

[lexnv]

Coming back to this, I've placed more data in the linked PR:

• the misbehaving client that was causing these logs is misbehaving in intervals of 10 seconds or so (which is in-line with the findings from that PR)
• sometimes we see multiple logs in the same time interval (I think Andrei pointed it out that we might batch multiple calls)

I think we can safely merge this and rely on #4031 to increase the time a peer remains banned (from 10s to around 69secs)

[dmitry-markin]

Coming back to this, I've placed more data in the linked PR:

* the misbehaving client that was causing these logs is misbehaving in intervals of 10 seconds or so (which is in-line with the findings from that PR)

* sometimes we see multiple logs in the same time interval (I think Andrei pointed it out that we might batch multiple calls)

I think we can safely merge this and rely on #4031 to increase the time a peer remains banned (from 10s to around 69secs)

May be merging #4031 is enough then? I worry that the change from this PR can mask some reputation/misbehaving/banning issues if merged.

[lexnv]

Yep that makes sense! I've hit merge on: #4031, I also think it will be sufficient here.

We could still get a few more warnings from batching the reputation propagation, but generally, I think increasing the ban time should reduce the noise.

In the meanwhile, I ll close this PR and re-open if necessary, thanks!