Skip to content

Commit

Permalink
fix: make logging less noisy (#3267)
Browse files Browse the repository at this point in the history
Description
---
Remove logging of errors from tracing instrument macros.

Motivation and Context
---
Was reported as making the base node unusable. Hopefully we are not swallowing important information, but probably the right choice

How Has This Been Tested?
---
Manually

> ~~Note: This PR is based on #3266 to enable compilation without SQLite installed~~
  • Loading branch information
stringhandler committed Sep 1, 2021
1 parent 95ac87d commit 4798161
Show file tree
Hide file tree
Showing 9 changed files with 30 additions and 23 deletions.
2 changes: 1 addition & 1 deletion comms/src/connection_manager/dialer.rs
Expand Up @@ -338,7 +338,7 @@ where
}

#[allow(clippy::too_many_arguments)]
#[tracing::instrument(skip(peer_manager, socket, conn_man_notifier, config, cancel_signal), err)]
#[tracing::instrument(skip(peer_manager, socket, conn_man_notifier, config, cancel_signal))]
async fn perform_socket_upgrade_procedure(
peer_manager: Arc<PeerManager>,
node_identity: Arc<NodeIdentity>,
Expand Down
12 changes: 6 additions & 6 deletions comms/src/connection_manager/peer_connection.rs
Expand Up @@ -191,7 +191,7 @@ impl PeerConnection {
self.substream_counter.get()
}

#[tracing::instrument("peer_connection::open_substream", skip(self), err)]
#[tracing::instrument("peer_connection::open_substream", skip(self))]
pub async fn open_substream(
&mut self,
protocol_id: &ProtocolId,
Expand All @@ -209,7 +209,7 @@ impl PeerConnection {
.map_err(|_| PeerConnectionError::InternalReplyCancelled)?
}

#[tracing::instrument("peer_connection::open_framed_substream", skip(self), err)]
#[tracing::instrument("peer_connection::open_framed_substream", skip(self))]
pub async fn open_framed_substream(
&mut self,
protocol_id: &ProtocolId,
Expand All @@ -220,14 +220,14 @@ impl PeerConnection {
}

#[cfg(feature = "rpc")]
#[tracing::instrument("peer_connection::connect_rpc", skip(self), fields(peer_node_id = self.peer_node_id.to_string().as_str()), err)]
#[tracing::instrument("peer_connection::connect_rpc", skip(self), fields(peer_node_id = self.peer_node_id.to_string().as_str()))]
pub async fn connect_rpc<T>(&mut self) -> Result<T, RpcError>
where T: From<RpcClient> + NamedProtocolService {
self.connect_rpc_using_builder(Default::default()).await
}

#[cfg(feature = "rpc")]
#[tracing::instrument("peer_connection::connect_rpc_with_builder", skip(self, builder), err)]
#[tracing::instrument("peer_connection::connect_rpc_with_builder", skip(self, builder))]
pub async fn connect_rpc_using_builder<T>(&mut self, builder: RpcClientBuilder<T>) -> Result<T, RpcError>
where T: From<RpcClient> + NamedProtocolService {
let protocol = ProtocolId::from_static(T::PROTOCOL_NAME);
Expand Down Expand Up @@ -397,7 +397,7 @@ impl PeerConnectionActor {
}
}

#[tracing::instrument(skip(self, stream), err, fields(comms.direction="inbound"))]
#[tracing::instrument(skip(self, stream),fields(comms.direction="inbound"))]
async fn handle_incoming_substream(&mut self, mut stream: Substream) -> Result<(), PeerConnectionError> {
let selected_protocol = ProtocolNegotiation::new(&mut stream)
.negotiate_protocol_inbound(&self.our_supported_protocols)
Expand All @@ -413,7 +413,7 @@ impl PeerConnectionActor {
Ok(())
}

#[tracing::instrument(skip(self), err)]
#[tracing::instrument(skip(self))]
async fn open_negotiated_protocol_stream(
&mut self,
protocol: ProtocolId,
Expand Down
6 changes: 3 additions & 3 deletions comms/src/connection_manager/requester.rs
Expand Up @@ -74,7 +74,7 @@ impl ConnectionManagerRequester {
}

/// Attempt to connect to a remote peer
#[tracing::instrument(skip(self), err)]
#[tracing::instrument(skip(self))]
pub async fn dial_peer(&mut self, node_id: NodeId) -> Result<PeerConnection, ConnectionManagerError> {
let (reply_tx, reply_rx) = oneshot::channel();
self.send_dial_peer(node_id, Some(reply_tx)).await?;
Expand All @@ -93,7 +93,7 @@ impl ConnectionManagerRequester {
}

/// Send instruction to ConnectionManager to dial a peer and return the result on the given oneshot
#[tracing::instrument(skip(self, reply_tx), err)]
#[tracing::instrument(skip(self, reply_tx))]
pub(crate) async fn send_dial_peer(
&mut self,
node_id: NodeId,
Expand All @@ -120,7 +120,7 @@ impl ConnectionManagerRequester {
}

/// Send instruction to ConnectionManager to dial a peer without waiting for a result.
#[tracing::instrument(skip(self), err)]
#[tracing::instrument(skip(self))]
pub(crate) async fn send_dial_peer_no_reply(&mut self, node_id: NodeId) -> Result<(), ConnectionManagerError> {
self.send_dial_peer(node_id, None).await?;
Ok(())
Expand Down
2 changes: 1 addition & 1 deletion comms/src/connectivity/requester.rs
Expand Up @@ -126,7 +126,7 @@ impl ConnectivityRequester {
self.event_tx.clone()
}

#[tracing::instrument(skip(self), err)]
#[tracing::instrument(skip(self))]
pub async fn dial_peer(&mut self, peer: NodeId) -> Result<PeerConnection, ConnectivityError> {
let mut num_cancels = 0;
loop {
Expand Down
2 changes: 1 addition & 1 deletion comms/src/noise/config.rs
Expand Up @@ -60,7 +60,7 @@ impl NoiseConfig {

/// Upgrades the given socket to using the noise protocol. The upgraded socket and the peer's static key
/// is returned.
#[tracing::instrument(name = "noise::upgrade_socket", skip(self, socket), err)]
#[tracing::instrument(name = "noise::upgrade_socket", skip(self, socket))]
pub async fn upgrade_socket<TSocket>(
&self,
socket: TSocket,
Expand Down
2 changes: 1 addition & 1 deletion comms/src/protocol/identity.rs
Expand Up @@ -41,7 +41,7 @@ use tracing;
pub static IDENTITY_PROTOCOL: ProtocolId = ProtocolId::from_static(b"t/identity/1.0");
const LOG_TARGET: &str = "comms::protocol::identity";

#[tracing::instrument(skip(socket, our_supported_protocols), err)]
#[tracing::instrument(skip(socket, our_supported_protocols))]
pub async fn identity_exchange<'p, TSocket, P>(
node_identity: &NodeIdentity,
direction: ConnectionDirection,
Expand Down
19 changes: 13 additions & 6 deletions comms/src/protocol/messaging/outbound.rs
Expand Up @@ -30,13 +30,12 @@ use crate::{
protocol::messaging::protocol::MESSAGING_PROTOCOL,
};
use futures::{future::Either, StreamExt, TryStreamExt};
use log::*;
use std::{
io,
time::{Duration, Instant},
};
use tokio::sync::mpsc as tokiompsc;
use tracing::{event, span, Instrument, Level};
use tracing::{debug, error, event, span, Instrument, Level};

const LOG_TARGET: &str = "comms::protocol::messaging::outbound";
/// The number of times to retry sending a failed message before publishing a SendMessageFailed event.
Expand Down Expand Up @@ -107,9 +106,18 @@ impl OutboundMessaging {
peer_node_id.short_str()
);
},
Err(err) => {
event!(Level::ERROR, "Outbound messaging substream failed:{}", err);
debug!(target: LOG_TARGET, "Outbound messaging substream failed: {}", err);
Err(err) => match err {
MessagingProtocolError::PeerDialFailed => {
debug!(
target: LOG_TARGET,
"Outbound messaging substream failed due to a dial fail. Most likely the peer is offline \
or doesn't exist: {}",
err
);
},
_ => {
error!(target: LOG_TARGET, "Outbound messaging substream failed:{}", err);
},
},
}

Expand All @@ -131,7 +139,6 @@ impl OutboundMessaging {
break substream;
},
Err(err) => {
event!(Level::ERROR, "Error establishing messaging protocol");
if attempts >= MAX_SEND_RETRIES {
debug!(
target: LOG_TARGET,
Expand Down
2 changes: 1 addition & 1 deletion comms/src/protocol/rpc/client.rs
Expand Up @@ -511,7 +511,7 @@ where TSubstream: AsyncRead + AsyncWrite + Unpin + Send
Ok(())
}

#[tracing::instrument(name = "rpc_do_request_response", skip(self, reply), err)]
#[tracing::instrument(name = "rpc_do_request_response", skip(self, reply))]
async fn do_request_response(
&mut self,
request: BaseRequest<Bytes>,
Expand Down
6 changes: 3 additions & 3 deletions comms/src/socks/client.rs
Expand Up @@ -104,15 +104,15 @@ where TSocket: AsyncRead + AsyncWrite + Unpin

/// Connects to a address through a SOCKS5 proxy and returns the 'upgraded' socket. This consumes the
/// `Socks5Client` as once connected, the socks protocol does not recognise any further commands.
#[tracing::instrument(name = "socks::connect", skip(self), err)]
#[tracing::instrument(name = "socks::connect", skip(self))]
pub async fn connect(mut self, address: &Multiaddr) -> Result<(TSocket, Multiaddr)> {
let address = self.execute_command(Command::Connect, address).await?;
Ok((self.protocol.socket, address))
}

/// Requests the tor proxy to resolve a DNS address is resolved into an IP address.
/// This operation only works with the tor SOCKS proxy.
#[tracing::instrument(name = "socks:tor_resolve", skip(self), err)]
#[tracing::instrument(name = "socks:tor_resolve", skip(self))]
pub async fn tor_resolve(&mut self, address: &Multiaddr) -> Result<Multiaddr> {
// Tor resolve does not return the port back
let (dns, rest) = multiaddr_split_first(&address);
Expand All @@ -126,7 +126,7 @@ where TSocket: AsyncRead + AsyncWrite + Unpin

/// Requests the tor proxy to reverse resolve an IP address into a DNS address if it is able.
/// This operation only works with the tor SOCKS proxy.
#[tracing::instrument(name = "socks::tor_resolve_ptr", skip(self), err)]
#[tracing::instrument(name = "socks::tor_resolve_ptr", skip(self))]
pub async fn tor_resolve_ptr(&mut self, address: &Multiaddr) -> Result<Multiaddr> {
self.execute_command(Command::TorResolvePtr, address).await
}
Expand Down

0 comments on commit 4798161

Please sign in to comment.