Grin: Peer ban doesn't work as expected

[garyyu]

A banned peer continue appearing on my peers list, check log and find this:

20181227 17:19:12.838 DEBUG grin_p2p::protocol - handler: consume: peer V4(35.227.48.174:13414) banned, received: GetPeerAddrs, dropping.
20181227 17:19:19.956 DEBUG grin_p2p::peers - clean_peers V4(35.227.48.174:13414), peer banned
20181227 17:19:52.979 DEBUG grin_p2p::peers - Saving newly connected peer 35.227.48.174:13414.
20181227 17:19:52.979 DEBUG grin_p2p::store - save_peer: V4(35.227.48.174:13414) marked Healthy
20181227 17:19:52.982 DEBUG grin_p2p::peers - Saving newly connected peer 35.227.48.174:13414.
20181227 17:19:52.982 DEBUG grin_p2p::store - save_peer: V4(35.227.48.174:13414) marked Healthy

That means when I ban a peer, it works. But after 30 seconds, if this banned peer request connect again, it will connect to my node again!

It will enter an infinite loop here: banned, connected, banned, connected, ...

20181227 17:20:12.843 DEBUG grin_p2p::protocol - handler: consume: peer V4(35.227.48.174:13414) banned, received: GetPeerAddrs, dropping.
20181227 17:20:20.151 DEBUG grin_p2p::peers - clean_peers V4(35.227.48.174:13414), peer banned
20181227 17:20:52.978 DEBUG grin_p2p::peers - Saving newly connected peer 35.227.48.174:13414.
20181227 17:20:52.978 DEBUG grin_p2p::store - save_peer: V4(35.227.48.174:13414) marked Healthy

[garyyu]

It proves that this is caused by a wrong usage.
I called peer.set_banned(); but actually this function call will never write ban state into database. Instead, I should call peers::ban_peer().

Sorry for noise.

[garyyu]

Even after switching to peers::ban_peer(), the banned peer still always can connect.

Finally I find the root cause, it looks like a deep buried bug here which was committed on 2018-03-28 since the is_banned() function was written:

------------------------------- p2p/src/peers.rs -------------------------------
index c09dfb00..0e8ccb9b 100644
@@ -638,4 +638,13 @@ impl NetAdapter for Peers {
            }
        }
    }
+
+   fn is_banned(&self, addr: SocketAddr) -> bool {
+       if let Some(peer) = self.get_connected_peer(&addr) {
+           let mut peer = peer.write().unwrap();
+           peer.is_banned()
+       } else {
+           false
+       }
+   }
 }

For each peer connection request, we will call this is_banned() function to decide whether we can accept it or not,

impl MessageHandler for Protocol {
    fn consume<'a>(...) -> Result<Option<Response<'a>>, Error> {
        ...
        // If we received a msg from a banned peer then log and drop it.
        // If we are getting a lot of these then maybe we are not cleaning
        // banned peers up correctly?
        if adapter.is_banned(self.addr.clone()) {
            debug!(
                "handler: consume: peer {:?} banned, received: {:?}, dropping.",
                self.addr, msg.header.msg_type,
            );
            return Ok(None);
        }

The problem is the get_connected_peer() function only get the current peers which is being connected, what we need here is to check all the peers in the peers database.

Will give a PR to fix this.

[garyyu]

Confirmed the fix seems doesn't work! will investigate.
With the latest master branch code:

20181231 03:20:27.474 DEBUG grin_p2p::peers - Banning peer 2.95.177.91:13414
20181231 03:20:27.474 DEBUG grin_p2p::peer - Sent ban reason FraudHeight to 2.95.177.91:13414
20181231 03:20:27.474 INFO grin_servers::grin::sync::header_sync - sync: ban a fraud peer: 2.95.177.91:13414, claimed height: 13192, total difficulty: 703099211
20181231 03:20:27.477 DEBUG grin_p2p::conn - Connection close with 2.95.177.91:59948 initiated by us
20181231 03:20:44.178 DEBUG grin_p2p::peers - clean_peers V4(2.95.177.91:13414), peer banned
20181231 03:25:05.439 DEBUG grin_p2p::peer - accept: handshaking from Ok(V4(2.95.177.91:60000))
20181231 03:25:05.439 DEBUG grin_p2p::peers - Saving newly connected peer 2.95.177.91:13414.
20181231 03:25:05.439 DEBUG grin_p2p::store - save_peer: V4(2.95.177.91:13414) marked Healthy

And repeating the ban and connect.

[garyyu]

The root cause is clear now:

There're two different address, one is abstracted from the TCP stream (by TcpStream::peer_addr()), another one is abstracted from sender_addr by HandShake protocol:

/// First part of a handshake, sender advertises its version and characteristics.
pub struct Hand {
    ...
    /// network address of the sender
    pub sender_addr: SockAddr,
    ...
}

When we ban a peer, we use this sender_addr. But when we check ban, we're using TcpStream::peer_addr(), that's why a banned peer can always connect again successfully!

            match listener.accept() {
                Ok((stream, peer_addr)) => {
                    if !self.check_banned(&stream) {
                        if let Err(e) = self.handle_new_peer(stream) {
                            warn!("Error accepting peer {}: {:?}", peer_addr.to_string(), e);
                        }
                    }
                }

will write a PR to fix this.