feat: clean up tracing in robust provider

Author: LeoPatOZ

src/robust_provider/provider.rs

@@ -11,7 +11,7 @@ use alloy::{
 use backon::{ExponentialBuilder, Retryable};
 use thiserror::Error;
 use tokio::time::{error as TokioError, timeout};
-use tracing::{error, info};
+use tracing::{error, info, instrument, warn};
 
 use crate::robust_provider::RobustSubscription;
 
@@ -111,20 +111,17 @@ impl<N: Network> RobustProvider<N> {
     /// # Errors
     ///
     /// See [retry errors](#retry-errors).
+    #[instrument(level = "debug", skip(self))]
     pub async fn get_block_by_number(
         &self,
         number: BlockNumberOrTag,
     ) -> Result<N::BlockResponse, Error> {
-        info!("eth_getBlockByNumber called");
         let result = self
             .try_operation_with_failover(
                 move |provider| async move { provider.get_block_by_number(number).await },
                 false,
             )
             .await;
-        if let Err(e) = &result {
-            error!(error = %e, "eth_getByBlockNumber failed");
-        }
 
         result?.ok_or_else(|| Error::BlockNotFound(number.into()))
     }
@@ -136,17 +133,14 @@ impl<N: Network> RobustProvider<N> {
     /// # Errors
     ///
     /// See [retry errors](#retry-errors).
+    #[instrument(level = "debug", skip(self))]
     pub async fn get_block(&self, id: BlockId) -> Result<N::BlockResponse, Error> {
-        info!("eth_getBlock called");
         let result = self
             .try_operation_with_failover(
                 |provider| async move { provider.get_block(id).await },
                 false,
             )
             .await;
-        if let Err(e) = &result {
-            error!(error = %e, "eth_getByBlockNumber failed");
-        }
         result?.ok_or_else(|| Error::BlockNotFound(id))
     }
 
@@ -157,19 +151,14 @@ impl<N: Network> RobustProvider<N> {
     /// # Errors
     ///
     /// See [retry errors](#retry-errors).
+    #[instrument(level = "debug", skip(self))]
     pub async fn get_block_number(&self) -> Result<BlockNumber, Error> {
-        info!("eth_getBlockNumber called");
-        let result = self
-            .try_operation_with_failover(
-                move |provider| async move { provider.get_block_number().await },
-                false,
-            )
-            .await
-            .map_err(Error::from);
-        if let Err(e) = &result {
-            error!(error = %e, "eth_getBlockNumber failed");
-        }
-        result
+        self.try_operation_with_failover(
+            move |provider| async move { provider.get_block_number().await },
+            false,
+        )
+        .await
+        .map_err(Error::from)
     }
 
     /// Get the block number for a given block identifier.
@@ -183,17 +172,14 @@ impl<N: Network> RobustProvider<N> {
     /// # Errors
     ///
     /// See [retry errors](#retry-errors).
+    #[instrument(level = "debug", skip(self))]
     pub async fn get_block_number_by_id(&self, block_id: BlockId) -> Result<BlockNumber, Error> {
-        info!("get_block_number_by_id called");
         let result = self
             .try_operation_with_failover(
                 move |provider| async move { provider.get_block_number_by_id(block_id).await },
                 false,
             )
             .await;
-        if let Err(e) = &result {
-            error!(error = %e, "get_block_number_by_id failed");
-        }
         result?.ok_or_else(|| Error::BlockNotFound(block_id))
     }
 
@@ -210,8 +196,8 @@ impl<N: Network> RobustProvider<N> {
     /// # Errors
     ///
     /// See [retry errors](#retry-errors).
+    #[instrument(level = "debug", skip(self))]
     pub async fn get_latest_confirmed(&self, confirmations: u64) -> Result<u64, Error> {
-        info!("get_latest_confirmed called with confirmations={}", confirmations);
         let latest_block = self.get_block_number().await?;
         let confirmed_block = latest_block.saturating_sub(confirmations);
         Ok(confirmed_block)
@@ -224,17 +210,14 @@ impl<N: Network> RobustProvider<N> {
     /// # Errors
     ///
     /// See [retry errors](#retry-errors).
+    #[instrument(level = "debug", skip(self))]
     pub async fn get_block_by_hash(&self, hash: BlockHash) -> Result<N::BlockResponse, Error> {
-        info!("eth_getBlockByHash called");
         let result = self
             .try_operation_with_failover(
                 move |provider| async move { provider.get_block_by_hash(hash).await },
                 false,
             )
             .await;
-        if let Err(e) = &result {
-            error!(error = %e, "eth_getBlockByHash failed");
-        }
 
         result?.ok_or_else(|| Error::BlockNotFound(hash.into()))
     }
@@ -246,19 +229,14 @@ impl<N: Network> RobustProvider<N> {
     /// # Errors
     ///
     /// See [retry errors](#retry-errors).
+    #[instrument(level = "debug", skip(self, filter))]
     pub async fn get_logs(&self, filter: &Filter) -> Result<Vec<Log>, Error> {
-        info!("eth_getLogs called");
-        let result = self
-            .try_operation_with_failover(
-                move |provider| async move { provider.get_logs(filter).await },
-                false,
-            )
-            .await
-            .map_err(Error::from);
-        if let Err(e) = &result {
-            error!(error = %e, "eth_getLogs failed");
-        }
-        result
+        self.try_operation_with_failover(
+            move |provider| async move { provider.get_logs(filter).await },
+            false,
+        )
+        .await
+        .map_err(Error::from)
     }
 
     /// Subscribe to new block headers with automatic failover and reconnection.
@@ -273,24 +251,18 @@ impl<N: Network> RobustProvider<N> {
     /// # Errors
     ///
     /// see [retry errors](#retry-errors).
+    #[instrument(level = "debug", skip(self))]
     pub async fn subscribe_blocks(&self) -> Result<RobustSubscription<N>, Error> {
-        info!("eth_subscribe called");
         let subscription = self
             .try_operation_with_failover(
                 move |provider| async move {
                     provider.subscribe_blocks().channel_size(MAX_CHANNEL_SIZE).await
                 },
                 true,
             )
-            .await;
+            .await?;
 
-        match subscription {
-            Ok(sub) => Ok(RobustSubscription::new(sub, self.clone())),
-            Err(e) => {
-                error!(error = %e, "eth_subscribe failed");
-                Err(e.into())
-            }
-        }
+        Ok(RobustSubscription::new(subscription, self.clone()))
     }
 
     /// Execute `operation` with exponential backoff and a total timeout.
@@ -361,31 +333,30 @@ impl<N: Network> RobustProvider<N> {
         Fut: Future<Output = Result<T, RpcError<TransportErrorKind>>>,
     {
         let num_fallbacks = self.fallback_providers.len();
-        if num_fallbacks > 0 && start_index == 0 {
-            info!("Primary provider failed, trying fallback provider(s)");
-        }
 
         let fallback_providers = self.fallback_providers.iter().enumerate().skip(start_index);
         for (fallback_idx, provider) in fallback_providers {
             if require_pubsub && !Self::supports_pubsub(provider) {
-                info!("Fallback provider {} doesn't support pubsub, skipping", fallback_idx + 1);
+                warn!(provider_num = fallback_idx + 1, "Fallback provider doesn't support pubsub, skipping");
                 continue;
             }
-            info!("Attempting fallback provider {}/{}", fallback_idx + 1, num_fallbacks);
 
             match self.try_provider_with_timeout(provider, &operation).await {
                 Ok(value) => {
-                    info!(provider_num = fallback_idx + 1, "Fallback provider succeeded");
+                    info!(
+                        provider_num = fallback_idx + 1,
+                        total_fallbacks = num_fallbacks,
+                        "Switched to fallback provider"
+                    );
                     return Ok((value, fallback_idx));
                 }
                 Err(e) => {
-                    error!(provider_num = fallback_idx + 1, err = %e, "Fallback provider failed");
                     last_error = e;
                 }
             }
         }
-        // All fallbacks failed / skipped, return the last error
-        error!("All providers failed or timed out - returning the last providers attempt's error");
+
+        error!("All providers exhausted");
         Err(last_error)
     }
 
@@ -405,12 +376,7 @@ impl<N: Network> RobustProvider<N> {
 
         timeout(
             self.call_timeout,
-            (|| operation(provider.clone()))
-                .retry(retry_strategy)
-                .notify(|err: &RpcError<TransportErrorKind>, dur: Duration| {
-                    info!(error = %err, "RPC error retrying after {:?}", dur);
-                })
-                .sleep(tokio::time::sleep),
+            (|| operation(provider.clone())).retry(retry_strategy).sleep(tokio::time::sleep),
         )
         .await
         .map_err(CoreError::from)?

src/robust_provider/subscription.rs

@@ -15,7 +15,7 @@ use thiserror::Error;
 use tokio::{sync::broadcast::error::RecvError, time::timeout};
 use tokio_stream::Stream;
 use tokio_util::sync::ReusableBoxFuture;
-use tracing::{error, info, warn};
+use tracing::{info, warn};
 
 use crate::robust_provider::{RobustProvider, provider::CoreError};
 
@@ -44,14 +44,8 @@ impl From<CoreError> for Error {
 impl From<RecvError> for Error {
     fn from(err: RecvError) -> Self {
         match err {
-            RecvError::Closed => {
-                error!("Provider closed the subscription channel");
-                Error::Closed
-            }
-            RecvError::Lagged(count) => {
-                error!(skipped = count, "Receiver lagged");
-                Error::Lagged(count)
-            }
+            RecvError::Closed => Error::Closed,
+            RecvError::Lagged(count) => Error::Lagged(count),
         }
     }
 }
@@ -123,17 +117,7 @@ impl<N: Network> RobustSubscription<N> {
                         }
                         return Ok(header);
                     }
-                    Err(recv_error) => {
-                        match recv_error {
-                            RecvError::Closed => {
-                                error!("Provider closed the subscription channel");
-                            }
-                            RecvError::Lagged(count) => {
-                                error!(skipped = count, "Receiver lagged");
-                            }
-                        }
-                        return Err(recv_error.into());
-                    }
+                    Err(recv_error) => return Err(recv_error.into()),
                 },
                 Err(elapsed_err) => {
                     warn!(
@@ -163,28 +147,22 @@ impl<N: Network> RobustSubscription<N> {
             return false;
         }
 
-        info!("Attempting to reconnect to primary provider");
-
         let operation =
             move |provider: RootProvider<N>| async move { provider.subscribe_blocks().await };
 
         let primary = self.robust_provider.primary();
         let subscription =
             self.robust_provider.try_provider_with_timeout(primary, &operation).await;
 
-        match subscription {
-            Ok(sub) => {
-                info!("Successfully reconnected to primary provider");
-                self.subscription = sub;
-                self.current_fallback_index = None;
-                self.last_reconnect_attempt = None;
-                true
-            }
-            Err(e) => {
-                self.last_reconnect_attempt = Some(Instant::now());
-                warn!(error = %e, "Failed to reconnect to primary provider");
-                false
-            }
+        if let Ok(sub) = subscription {
+            info!("Reconnected to primary provider");
+            self.subscription = sub;
+            self.current_fallback_index = None;
+            self.last_reconnect_attempt = None;
+            true
+        } else {
+            self.last_reconnect_attempt = Some(Instant::now());
+            false
         }
     }