From 655b1b7d0c890b10374c4a8d986697b1d0d3409a Mon Sep 17 00:00:00 2001
From: Age Manning <Age@AgeManning.com>
Date: Tue, 8 Dec 2020 05:06:25 +0000
Subject: [PATCH] Downgrades a valid log (#2057)

## Issue Addressed

#2046

## Proposed Changes

The log was originally intended to verify the correct logic and ordering of events when scoring peers. The queued tasks can be structured in such a way that peers can be banned after they are disconnected. Therefore the error log is now downgraded to  debug log.
---
 Cargo.lock                                    |  1 +
 .../eth2_libp2p/src/peer_manager/peerdb.rs    |  5 +--
 beacon_node/network/Cargo.toml                |  1 +
 beacon_node/network/src/service/tests.rs      | 36 ++++++++++---------
 4 files changed, 24 insertions(+), 19 deletions(-)

diff --git a/Cargo.lock b/Cargo.lock
index 65786b26671..8b85792aa2d 100644
--- a/Cargo.lock
+++ b/Cargo.lock
@@ -4373,6 +4373,7 @@ dependencies = [
  "itertools 0.9.0",
  "lazy_static",
  "lighthouse_metrics",
+ "logging",
  "lru_cache",
  "matches",
  "num_cpus",
diff --git a/beacon_node/eth2_libp2p/src/peer_manager/peerdb.rs b/beacon_node/eth2_libp2p/src/peer_manager/peerdb.rs
index 1ab1f2da2d2..5382b178c53 100644
--- a/beacon_node/eth2_libp2p/src/peer_manager/peerdb.rs
+++ b/beacon_node/eth2_libp2p/src/peer_manager/peerdb.rs
@@ -474,8 +474,9 @@ impl<TSpec: EthSpec> PeerDB<TSpec> {
         // Check and verify all the connection states
         match info.connection_status() {
             PeerConnectionStatus::Disconnected { .. } => {
-                // It should not be possible to ban a peer that is already disconnected.
-                error!(log_ref, "Banning a disconnected peer"; "peer_id" => %peer_id);
+                // It is possible to ban a peer that has a disconnected score, if there are many
+                // events that score it poorly and are processed after it has disconnected.
+                debug!(log_ref, "Banning a disconnected peer"; "peer_id" => %peer_id);
                 self.disconnected_peers = self.disconnected_peers.saturating_sub(1);
                 info.ban();
                 self.banned_peers_count
diff --git a/beacon_node/network/Cargo.toml b/beacon_node/network/Cargo.toml
index 725fc937fee..fabac5c97e0 100644
--- a/beacon_node/network/Cargo.toml
+++ b/beacon_node/network/Cargo.toml
@@ -13,6 +13,7 @@ tempfile = "3.1.0"
 exit-future = "0.2.0"
 slog-term = "2.6.0"
 slog-async = "2.5.0"
+logging = { path = "../../common/logging" }
 
 [dependencies]
 beacon_chain =  { path = "../beacon_chain" }
diff --git a/beacon_node/network/src/service/tests.rs b/beacon_node/network/src/service/tests.rs
index b9b9e3e3afb..b425e1c64b7 100644
--- a/beacon_node/network/src/service/tests.rs
+++ b/beacon_node/network/src/service/tests.rs
@@ -5,8 +5,7 @@ mod tests {
     use crate::{NetworkConfig, NetworkService};
     use beacon_chain::test_utils::BeaconChainHarness;
     use eth2_libp2p::Enr;
-    //use slog::{o, Drain, Level, Logger};
-    use slog::Logger;
+    use slog::{o, Drain, Level, Logger};
     use sloggers::{null::NullLoggerBuilder, Build};
     use std::str::FromStr;
     use std::sync::Arc;
@@ -14,26 +13,27 @@ mod tests {
     use tokio::runtime::Runtime;
     use types::{test_utils::generate_deterministic_keypairs, MinimalEthSpec};
 
-    fn get_logger() -> Logger {
-        /* For emitting logs during the tests
-        let drain = {
-            let decorator = slog_term::TermDecorator::new().build();
-            let decorator =
-                logging::AlignedTermDecorator::new(decorator, logging::MAX_MESSAGE_WIDTH);
-            let drain = slog_term::FullFormat::new(decorator).build().fuse();
-            let drain = slog_async::Async::new(drain).chan_size(2048).build();
-            drain.filter_level(Level::Debug)
-        };
+    fn get_logger(actual_log: bool) -> Logger {
+        if actual_log {
+            let drain = {
+                let decorator = slog_term::TermDecorator::new().build();
+                let decorator =
+                    logging::AlignedTermDecorator::new(decorator, logging::MAX_MESSAGE_WIDTH);
+                let drain = slog_term::FullFormat::new(decorator).build().fuse();
+                let drain = slog_async::Async::new(drain).chan_size(2048).build();
+                drain.filter_level(Level::Debug)
+            };
 
-        Logger::root(drain.fuse(), o!())
-        */
-        let builder = NullLoggerBuilder;
-        builder.build().expect("should build logger")
+            Logger::root(drain.fuse(), o!())
+        } else {
+            let builder = NullLoggerBuilder;
+            builder.build().expect("should build logger")
+        }
     }
 
     #[test]
     fn test_dht_persistence() {
-        let log = get_logger();
+        let log = get_logger(false);
 
         let beacon_chain = Arc::new(
             BeaconChainHarness::new_with_store_config(
@@ -73,6 +73,8 @@ mod tests {
             let _ = NetworkService::start(beacon_chain.clone(), &config, executor)
                 .await
                 .unwrap();
+            // Allow the network task to spawn on the executor before shutting down.
+            tokio::time::sleep(std::time::Duration::from_secs(1)).await;
             drop(signal);
         });