Further enrich logs for v1.5.1

CHANGELOG.md

@@ -12,12 +12,13 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
 
 - Added support for the experimental multidapp claimer.
 - Added the `DAPP_CONTRACT_ADDRESS` environment variable to the `authority-claimer`. If let unset, the service instantiates the MultidappClaimer, that reads dapp addresses from Redis.
+- Added `READER_MODE_ENABLED` environment variable to control whether the node generate claims or not.
 
 ### Changed
 
 - Redacted the contents of `CARTESI_EXPERIMENTAL_SUNODO_VALIDATOR_REDIS_ENDPOINT`.
-- server-manager tainted session errors logged on inspect-server.
-- Improved dispatcher logs.
+- Logged server-manager tainted session errors on advance-runner and inspect-server.
+- Adjusted dispatcher, advance-runner and authority-claimer logs.
 
 ## [1.5.0] 2024-07-22
 

offchain/advance-runner/src/runner.rs

@@ -127,14 +127,14 @@ impl Runner {
                     .context(ProduceOutputsSnafu)?;
                 tracing::trace!("produced outputs in broker stream");
 
-                let dapp_address = rollups_claim.dapp_address.clone();
+                let claim = rollups_claim.clone();
                 self.broker
                     .produce_rollups_claim(rollups_claim)
                     .await
                     .context(ProduceClaimSnafu)?;
                 tracing::info!(
-                    "produced epoch claim in broker stream for dapp address {:?}",
-                    dapp_address
+                    "produced epoch claim in broker stream: {:?}",
+                    claim
                 );
             }
             Err(source) => {

offchain/advance-runner/src/server_manager/facade.rs

@@ -180,7 +180,7 @@ impl ServerManagerFacade {
     ) -> Result<Vec<RollupsOutput>> {
         tracing::trace!("sending advance-state input to server-manager");
 
-        grpc_call!(self, advance_state, {
+        let response = grpc_call!(self, advance_state, {
             let input_metadata = InputMetadata {
                 msg_sender: Some(Address {
                     data: (*input_metadata.msg_sender.inner()).into(),
@@ -197,7 +197,9 @@ impl ServerManagerFacade {
                 input_metadata: Some(input_metadata),
                 input_payload: input_payload.clone(),
             }
-        })?;
+        });
+
+        self.handle_advance_state_error(response).await?;
 
         tracing::trace!("waiting until the input is processed");
 
@@ -271,6 +273,77 @@ impl ServerManagerFacade {
         Ok(outputs)
     }
 
+    /// Handle response to advance-state request
+    #[tracing::instrument(level = "trace", skip_all)]
+    async fn handle_advance_state_error(
+        &mut self,
+        response: Result<grpc_interfaces::cartesi_machine::Void>,
+    ) -> Result<()> {
+        if response.is_ok() {
+            return Ok(());
+        }
+
+        // Capture server-manager error for advance-state request
+        // to try to get the reason for a possible tainted session error.
+        let err = response.unwrap_err();
+
+        let err: ServerManagerError = match err {
+            ServerManagerError::MethodCallError {
+                method,
+                request_id,
+                source,
+            } => {
+                // Original error message to be reported by default.
+                let mut message = source.message().to_string();
+                // The server-manager signals with code Dataloss when the session has been previously tainted.
+                if source.code() == tonic::Code::DataLoss {
+                    // Recover the tainted session reason from the session's status.
+                    let status_response = grpc_call!(
+                        self,
+                        get_session_status,
+                        GetSessionStatusRequest {
+                            session_id: self.config.session_id.clone(),
+                        }
+                    );
+
+                    if status_response.is_err() {
+                        match status_response.unwrap_err() {
+                            ServerManagerError::MethodCallError {
+                                method: _,
+                                request_id: _,
+                                source,
+                            } => {
+                                tracing::error!(
+                                    "get-session-status error: {:?}",
+                                    source.message()
+                                );
+                            }
+                            _ => (),
+                        }
+                    } else {
+                        let status_response = status_response.unwrap();
+                        let taint_status = status_response.taint_status.clone();
+                        if let Some(taint_status) = taint_status {
+                            message = format!(
+                                "Server manager session was tainted: {} ({})",
+                                taint_status.error_code,
+                                taint_status.error_message
+                            );
+                            tracing::error!(message);
+                        }
+                    }
+                }
+                ServerManagerError::MethodCallError {
+                    method,
+                    request_id,
+                    source: tonic::Status::new(source.code(), message),
+                }
+            }
+            _ => err,
+        };
+        Err(err)
+    }
+
     /// Send a finish-epoch request to the server-manager
     /// Return the epoch claim and the proofs
     #[tracing::instrument(level = "trace", skip_all)]
@@ -369,3 +442,15 @@ impl ServerManagerFacade {
         Err(ServerManagerError::PendingInputsExceededError {})
     }
 }
+
+#[tracing::instrument(level = "trace", skip_all)]
+fn get_advance_state_error_message(err: &ServerManagerError) -> Option<String> {
+    match err {
+        ServerManagerError::MethodCallError {
+            method: _,
+            request_id: _,
+            source,
+        } => Some(source.message().to_string()),
+        _ => None,
+    }
+}

offchain/authority-claimer/src/claimer.rs

@@ -96,7 +96,7 @@ where
                 .listen()
                 .await
                 .context(BrokerListenerSnafu)?;
-            debug!("Got a claim from the broker: {:?}", rollups_claim);
+            info!("Received claim from the broker: {:?}", rollups_claim);
 
             let is_duplicated_rollups_claim = self
                 .duplicate_checker
@@ -108,7 +108,7 @@ where
                 continue;
             }
 
-            info!("Sending a new rollups claim");
+            info!("Sending a new rollups claim transaction");
             self.transaction_sender = self
                 .transaction_sender
                 .send_rollups_claim_transaction(rollups_claim)

offchain/authority-claimer/src/listener.rs

@@ -7,7 +7,7 @@ use rollups_events::{
     RollupsClaimsStream, INITIAL_ID,
 };
 use snafu::ResultExt;
-use std::{collections::HashMap, fmt::Debug};
+use std::{collections::HashMap, collections::HashSet, fmt::Debug};
 
 /// The `BrokerListener` listens for new claims from the broker.
 #[async_trait]
@@ -41,7 +41,7 @@ impl DefaultBrokerListener {
         chain_id: u64,
         dapp_address: Address,
     ) -> Result<Self, BrokerError> {
-        tracing::trace!("Connecting to the broker ({:?})", broker_config);
+        tracing::info!("Connecting to the broker ({:?})", broker_config);
         let broker = Broker::new(broker_config).await?;
         let dapp_metadata = DAppMetadata {
             chain_id,
@@ -94,7 +94,7 @@ impl MultidappBrokerListener {
         broker_config: BrokerConfig,
         chain_id: u64,
     ) -> Result<Self, BrokerError> {
-        tracing::trace!(
+        tracing::info!(
             "Connecting to the broker ({:?}) on multidapp mode",
             broker_config
         );
@@ -119,11 +119,22 @@ impl MultidappBrokerListener {
         // Gets the dapps from the broker.
         let dapps = self.broker.get_dapps().await.context(BrokerSnafu)?;
         assert!(!dapps.is_empty());
-        tracing::info!(
-            "Got the following dapps from key \"{}\": {:?}",
-            rollups_events::DAPPS_KEY,
-            dapps
-        );
+        {
+            // Logging if the dapps changed.
+            let old_dapps: HashSet<Address> = self
+                .streams
+                .iter()
+                .map(|(stream, _)| stream.dapp_address.clone())
+                .collect();
+            let new_dapps = HashSet::from_iter(dapps.clone());
+            if old_dapps != new_dapps {
+                tracing::info!(
+                    "Updated list of dapp addresses from key \"{}\": {:?}",
+                    rollups_events::DAPPS_KEY,
+                    new_dapps
+                );
+            }
+        }
 
         // Converts dapps to streams.
         let streams: Vec<_> = dapps

offchain/authority-claimer/src/sender.rs

@@ -260,7 +260,7 @@ impl TransactionSender for DefaultTransactionSender {
                 dapp_address,
             })
             .inc();
-        trace!("Claim transaction confirmed: `{:?}`", receipt);
+        info!("Claim transaction confirmed: `{:?}`", receipt);
 
         Ok(Self { tx_manager, ..self })
     }

offchain/dispatcher/src/dispatcher.rs

@@ -6,7 +6,7 @@ use eth_state_fold_types::{Block, BlockStreamItem};
 use rollups_events::DAppMetadata;
 use std::sync::Arc;
 use tokio_stream::StreamExt;
-use tracing::{error, info, instrument, trace, warn};
+use tracing::{error, instrument, trace, warn};
 use types::foldables::{InputBox, InputBoxInitialState};
 
 use crate::{
@@ -87,13 +87,16 @@ pub async fn start(
     )
     .await?;
 
-    trace!("Starting dispatcher...");
     loop {
         match block_subscription.next().await {
             Some(Ok(BlockStreamItem::NewBlock(b))) => {
                 // Normal operation, react on newest block.
-                info!("Received block number {}", b.number);
-                trace!("Block hash {:?}, parent: {:?}", b.hash, b.parent_hash);
+                trace!(
+                    "Received block number {} and hash {:?}, parent: {:?}",
+                    b.number,
+                    b.hash,
+                    b.parent_hash
+                );
                 process_block(
                     &b,
                     &state_server,

offchain/dispatcher/src/drivers/context.rs

@@ -7,6 +7,7 @@ use crate::{
 };
 
 use rollups_events::DAppMetadata;
+use tracing::info;
 use types::foldables::Input;
 
 #[derive(Debug)]
@@ -146,6 +147,10 @@ impl Context {
             .inc();
 
         self.last_finished_epoch = self.last_input_epoch;
+        info!(
+            "sent finish_epoch event for epoch {:?}",
+            self.last_finished_epoch
+        );
         Ok(())
     }
 }

offchain/dispatcher/src/drivers/machine.rs

@@ -37,7 +37,7 @@ impl MachineDriver {
         };
 
         let block_number = block.number.as_u64();
-        tracing::debug!("reacting to standalone block {}", block_number);
+        tracing::info!("received block {}", block_number);
         context.finish_epoch_if_needed(block_number, broker).await?;
 
         Ok(())

offchain/inspect-server/src/inspect.rs

@@ -70,7 +70,7 @@ fn respond(
     }
 }
 
-/// Loop that answers requests comming from inspect_rx.
+/// Loop that answers requests coming from inspect_rx.
 async fn handle_inspect(
     address: String,
     session_id: String,
@@ -148,7 +148,7 @@ async fn handle_inspect_error(
 ) -> String {
     let mut message = status.message().to_string();
 
-    // If the session was previously tainted, the server-manager replies if with code DataLoss.
+    // If the session was previously tainted, the server-manager replies it with code DataLoss.
     // Trying to recover the reason for the session tainted from the session's status.
     // If not available, we return the original status error message.
     if status.code() == Code::DataLoss {

offchain/rollups-events/src/broker/mod.rs

@@ -376,12 +376,24 @@ impl Broker {
             let mut dapp_addresses: Vec<Address> = vec![];
             for value in reply {
                 let normalized = value.to_lowercase();
-                let dapp_address = Address::from_str(&normalized).unwrap();
-                if dapp_addresses.contains(&dapp_address) {
-                    let _: () =
-                        self.connection.clone().srem(DAPPS_KEY, value).await?;
-                } else {
-                    dapp_addresses.push(dapp_address);
+                let dapp_address = Address::from_str(&normalized);
+                match dapp_address {
+                    Ok(dapp_address) => {
+                        if dapp_addresses.contains(&dapp_address) {
+                            let _: () = self
+                                .connection
+                                .clone()
+                                .srem(DAPPS_KEY, value)
+                                .await?;
+                        } else {
+                            dapp_addresses.push(dapp_address);
+                        }
+                    }
+                    Err(message) => tracing::info!(
+                        "Error while parsing DApp address {:?}: {}",
+                        normalized,
+                        message,
+                    ),
                 }
             }