refactor: reduce log level of some messages (#3804)

Co-authored-by: Byron Hambly <bizzle@tari.com>
tari-project · Feb 7, 2022 · 0754ac5 · 0754ac5
1 parent e6f6423
commit 0754ac5
Show file tree

Hide file tree

Showing 8 changed files with 21 additions and 39 deletions.
diff --git a/base_layer/wallet/src/output_manager_service/tasks/txo_validation_task.rs b/base_layer/wallet/src/output_manager_service/tasks/txo_validation_task.rs
@@ -84,7 +84,7 @@ where
             .ok_or(OutputManagerError::Shutdown)
             .for_protocol(self.operation_id)?;
 
-        info!(
+        debug!(
             target: LOG_TARGET,
             "Starting TXO validation protocol (Id: {})", self.operation_id,
         );
@@ -96,7 +96,7 @@ where
         self.update_spent_outputs(&mut base_node_client, last_mined_header)
             .await?;
         self.publish_event(OutputManagerEvent::TxoValidationSuccess(self.operation_id));
-        info!(
+        debug!(
             target: LOG_TARGET,
             "Finished TXO validation protocol (Id: {})", self.operation_id,
         );
@@ -227,7 +227,7 @@ where
             .for_protocol(self.operation_id)?;
 
         for batch in unconfirmed_outputs.chunks(self.config.tx_validator_batch_size) {
-            info!(
+            debug!(
                 target: LOG_TARGET,
                 "Asking base node for location of {} unconfirmed outputs by hash (Operation ID: {})",
                 batch.len(),
@@ -268,7 +268,7 @@ where
         client: &mut BaseNodeWalletRpcClient,
     ) -> Result<Option<BlockHash>, OutputManagerProtocolError> {
         let mut last_mined_header_hash = None;
-        info!(
+        debug!(
             target: LOG_TARGET,
             "Checking last mined TXO to see if the base node has re-orged (Operation ID: {})", self.operation_id
         );
@@ -306,7 +306,7 @@ where
                     .await
                     .for_protocol(self.operation_id)?;
             } else {
-                info!(
+                debug!(
                     target: LOG_TARGET,
                     "Last mined transaction is still in the block chain according to base node. (Operation ID: {})",
                     self.operation_id
@@ -344,7 +344,7 @@ where
                     .await
                     .for_protocol(self.operation_id)?;
             } else {
-                info!(
+                debug!(
                     target: LOG_TARGET,
                     "Last mined transaction is still in the block chain according to base node (Operation ID: {}).",
                     self.operation_id
@@ -366,7 +366,7 @@ where
         let result = match client.get_header_by_height(height).await {
             Ok(r) => r,
             Err(rpc_error) => {
-                info!(
+                warn!(
                     target: LOG_TARGET,
                     "Error asking base node for header:{} (Operation ID: {})", rpc_error, self.operation_id
                 );

diff --git a/base_layer/wallet/src/transaction_service/protocols/transaction_validation_protocol.rs b/base_layer/wallet/src/transaction_service/protocols/transaction_validation_protocol.rs
@@ -104,7 +104,7 @@ where
             .for_protocol(self.operation_id.as_u64())?;
 
         self.check_for_reorgs(&mut *base_node_wallet_client).await?;
-        info!(
+        debug!(
             target: LOG_TARGET,
             "Checking if transactions have been mined since last we checked (Operation ID: {})", self.operation_id
         );
@@ -122,15 +122,15 @@ where
                 .query_base_node_for_transactions(batch, &mut *base_node_wallet_client)
                 .await
                 .for_protocol(self.operation_id.as_u64())?;
-            info!(
+            debug!(
                 target: LOG_TARGET,
                 "Base node returned {} as mined and {} as unmined (Operation ID: {})",
                 mined.len(),
                 unmined.len(),
                 self.operation_id
             );
             for (mined_tx, mined_height, mined_in_block, num_confirmations) in &mined {
-                info!(
+                debug!(
                     target: LOG_TARGET,
                     "Updating transaction {} as mined and confirmed '{}' (Operation ID: {})",
                     mined_tx.tx_id,
@@ -152,7 +152,7 @@ where
                     // Treat coinbases separately
                     if unmined_tx.is_coinbase() {
                         if unmined_tx.coinbase_block_height.unwrap_or_default() <= tip_height {
-                            info!(
+                            debug!(
                                 target: LOG_TARGET,
                                 "Updated coinbase {} as abandoned (Operation ID: {})",
                                 unmined_tx.tx_id,
@@ -167,7 +167,7 @@ where
                             .await?;
                             state_changed = true;
                         } else {
-                            info!(
+                            debug!(
                                 target: LOG_TARGET,
                                 "Coinbase not found, but it is for a block that is not yet in the chain. Coinbase \
                                  height: {}, tip height:{} (Operation ID: {})",
@@ -177,7 +177,7 @@ where
                             );
                         }
                     } else {
-                        info!(
+                        debug!(
                             target: LOG_TARGET,
                             "Updated transaction {} as unmined (Operation ID: {})", unmined_tx.tx_id, self.operation_id
                         );
@@ -208,7 +208,7 @@ where
         &mut self,
         client: &mut BaseNodeWalletRpcClient,
     ) -> Result<(), TransactionServiceProtocolError> {
-        info!(
+        debug!(
             target: LOG_TARGET,
             "Checking last mined transactions to see if the base node has re-orged (Operation ID: {})",
             self.operation_id
@@ -259,7 +259,7 @@ where
                     .await?;
                 self.publish_event(TransactionEvent::TransactionValidationStateChanged(op_id));
             } else {
-                info!(
+                debug!(
                     target: LOG_TARGET,
                     "Last mined transaction is still in the block chain according to base node (Operation ID: {}).",
                     self.operation_id
@@ -294,7 +294,7 @@ where
         }
 
         if batch_signatures.is_empty() {
-            info!(
+            debug!(
                 target: LOG_TARGET,
                 "No transactions needed to query with the base node (Operation ID: {})", self.operation_id
             );

diff --git a/comms/src/connection_manager/common.rs b/comms/src/connection_manager/common.rs
@@ -25,7 +25,6 @@ use std::{convert::TryFrom, net::Ipv6Addr};
 use log::*;
 use tokio::io::{AsyncRead, AsyncWrite};
 
-use super::types::ConnectionDirection;
 use crate::{
     connection_manager::error::ConnectionManagerError,
     multiaddr::{Multiaddr, Protocol},
@@ -50,17 +49,11 @@ pub async fn perform_identity_exchange<
 >(
     socket: &mut TSocket,
     node_identity: &NodeIdentity,
-    direction: ConnectionDirection,
     our_supported_protocols: P,
     network_info: NodeNetworkInfo,
 ) -> Result<PeerIdentityMsg, ConnectionManagerError> {
-    debug!(
-        target: LOG_TARGET,
-        "{} socket opened to peer. Performing identity exchange.", direction
-    );
-
     let peer_identity =
-        protocol::identity_exchange(node_identity, direction, our_supported_protocols, network_info, socket).await?;
+        protocol::identity_exchange(node_identity, our_supported_protocols, network_info, socket).await?;
 
     Ok(peer_identity)
 }

diff --git a/comms/src/connection_manager/dialer.rs b/comms/src/connection_manager/dialer.rs
@@ -389,7 +389,6 @@ where
         let peer_identity = common::perform_identity_exchange(
             &mut socket,
             &node_identity,
-            CONNECTION_DIRECTION,
             &our_supported_protocols,
             config.network_info.clone(),
         )

diff --git a/comms/src/connection_manager/listener.rs b/comms/src/connection_manager/listener.rs
@@ -381,7 +381,6 @@ where
         let peer_identity = common::perform_identity_exchange(
             &mut noise_socket,
             &node_identity,
-            CONNECTION_DIRECTION,
             &our_supported_protocols,
             config.network_info.clone(),
         )

diff --git a/comms/src/protocol/identity.rs b/comms/src/protocol/identity.rs
@@ -29,10 +29,8 @@ use tokio::{
     io::{AsyncRead, AsyncReadExt, AsyncWrite, AsyncWriteExt},
     time,
 };
-use tracing;
 
 use crate::{
-    connection_manager::ConnectionDirection,
     message::MessageExt,
     peer_manager::NodeIdentity,
     proto::identity::PeerIdentityMsg,
@@ -43,10 +41,8 @@ const LOG_TARGET: &str = "comms::protocol::identity";
 
 const MAX_IDENTITY_PROTOCOL_MSG_SIZE: u16 = 1024;
 
-#[tracing::instrument(skip(socket, our_supported_protocols))]
 pub async fn identity_exchange<'p, TSocket, P>(
     node_identity: &NodeIdentity,
-    direction: ConnectionDirection,
     our_supported_protocols: P,
     network_info: NodeNetworkInfo,
     socket: &mut TSocket,
@@ -186,7 +182,6 @@ mod test {
     use futures::{future, StreamExt};
 
     use crate::{
-        connection_manager::ConnectionDirection,
         peer_manager::PeerFeatures,
         protocol::{IdentityProtocolError, NodeNetworkInfo},
         runtime,
@@ -211,7 +206,6 @@ mod test {
         let (result1, result2) = future::join(
             super::identity_exchange(
                 &node_identity1,
-                ConnectionDirection::Inbound,
                 &[],
                 NodeNetworkInfo {
                     minor_version: 1,
@@ -221,7 +215,6 @@ mod test {
             ),
             super::identity_exchange(
                 &node_identity2,
-                ConnectionDirection::Outbound,
                 &[],
                 NodeNetworkInfo {
                     minor_version: 2,
@@ -260,7 +253,6 @@ mod test {
         let (result1, result2) = future::join(
             super::identity_exchange(
                 &node_identity1,
-                ConnectionDirection::Inbound,
                 &[],
                 NodeNetworkInfo {
                     major_version: 0,
@@ -270,7 +262,6 @@ mod test {
             ),
             super::identity_exchange(
                 &node_identity2,
-                ConnectionDirection::Outbound,
                 &[],
                 NodeNetworkInfo {
                     major_version: 1,

diff --git a/comms/src/protocol/rpc/client/mod.rs b/comms/src/protocol/rpc/client/mod.rs
@@ -440,7 +440,7 @@ where TSubstream: AsyncRead + AsyncWrite + Unpin + Send + StreamId
         self.framed.stream_id()
     }
 
-    #[tracing::instrument(name = "rpc_client_worker run", skip(self), fields(next_request_id = self.next_request_id))]
+    #[tracing::instrument(level="trace", name = "rpc_client_worker run", skip(self), fields(next_request_id = self.next_request_id))]
     async fn run(mut self) {
         debug!(
             target: LOG_TARGET,
@@ -590,7 +590,7 @@ where TSubstream: AsyncRead + AsyncWrite + Unpin + Send + StreamId
         Ok(())
     }
 
-    #[tracing::instrument(name = "rpc_do_request_response", skip(self, reply, request), fields(request_method = ?request.method, request_body_size = request.message.len()))]
+    #[tracing::instrument(level="trace", name = "rpc_do_request_response", skip(self, reply, request), fields(request_method = ?request.method, request_body_size = request.message.len()))]
     async fn do_request_response(
         &mut self,
         request: BaseRequest<Bytes>,

diff --git a/comms/src/protocol/rpc/handshake.rs b/comms/src/protocol/rpc/handshake.rs
@@ -78,7 +78,7 @@ where T: AsyncRead + AsyncWrite + Unpin
     }
 
     /// Server-side handshake protocol
-    #[tracing::instrument(name = "rpc::server::perform_server_handshake", skip(self), err, fields(comms.direction="inbound"))]
+    #[tracing::instrument(level="trace", name = "rpc::server::perform_server_handshake", skip(self), err, fields(comms.direction="inbound"))]
     pub async fn perform_server_handshake(&mut self) -> Result<u32, RpcHandshakeError> {
         match self.recv_next_frame().await {
             Ok(Some(Ok(msg))) => {
@@ -88,7 +88,7 @@ where T: AsyncRead + AsyncWrite + Unpin
                     .iter()
                     .find(|v| msg.supported_versions.contains(v));
                 if let Some(version) = version {
-                    event!(Level::INFO, version = version, "Server accepted version");
+                    event!(Level::DEBUG, version = version, "Server accepted version");
                     debug!(target: LOG_TARGET, "Server accepted version: {}", version);
                     let reply = proto::rpc::RpcSessionReply {
                         session_result: Some(proto::rpc::rpc_session_reply::SessionResult::AcceptedVersion(*version)),