Merge pull request #1940 from input-output-hk/djo/refactor_common_logging

Enhance `mithril-common` logging

Author: Alenar

Cargo.lock

@@ -1,6 +1,6 @@
 [package]
 name = "mithril-common"
-version = "0.4.53"
+version = "0.4.54"
 description = "Common types, interfaces, and utilities for Mithril nodes."
 authors = { workspace = true }
 edition = { workspace = true }
@@ -84,7 +84,6 @@ pallas-crypto = "0.30.1"
 rand_core = { version = "0.6.4", features = ["getrandom"] }
 reqwest = { version = "0.12.7", features = ["json"] }
 slog-async = "2.8.0"
-slog-scope = "4.4.0"
 slog-term = "2.9.1"
 tokio = { version = "1.40.0", features = ["macros", "rt-multi-thread", "time"] }
 

mithril-common/Cargo.toml

@@ -8,6 +8,7 @@ use crate::cardano_block_scanner::BlockStreamer;
 use crate::cardano_block_scanner::ChainScannedBlocks;
 use crate::chain_reader::{ChainBlockNextAction, ChainBlockReader};
 use crate::entities::{BlockNumber, ChainPoint};
+use crate::logging::LoggerExtensions;
 use crate::StdResult;
 
 /// The action that indicates what to do next with the streamer
@@ -31,7 +32,7 @@ pub struct ChainReaderBlockStreamer {
 #[async_trait]
 impl BlockStreamer for ChainReaderBlockStreamer {
     async fn poll_next(&mut self) -> StdResult<Option<ChainScannedBlocks>> {
-        debug!(self.logger, "ChainReaderBlockStreamer polls next");
+        debug!(self.logger, "polls next");
 
         let chain_scanned_blocks: ChainScannedBlocks;
         let mut roll_forwards = vec![];
@@ -111,7 +112,7 @@ impl ChainReaderBlockStreamer {
             from,
             until,
             max_roll_forwards_per_poll,
-            logger,
+            logger: logger.new_with_component_name::<Self>(),
         })
     }
 
@@ -122,14 +123,14 @@ impl ChainReaderBlockStreamer {
                 if parsed_block.block_number > self.until {
                     trace!(
                         self.logger,
-                        "ChainReaderBlockStreamer received a RollForward above threshold block number ({})",
+                        "received a RollForward above threshold block number ({})",
                         parsed_block.block_number
                     );
                     Ok(None)
                 } else {
                     trace!(
                         self.logger,
-                        "ChainReaderBlockStreamer received a RollForward below threshold block number ({})",
+                        "received a RollForward below threshold block number ({})",
                         parsed_block.block_number
                     );
                     Ok(Some(BlockStreamerNextAction::ChainBlockNextAction(
@@ -142,7 +143,7 @@ impl ChainReaderBlockStreamer {
             }) => {
                 trace!(
                     self.logger,
-                    "ChainReaderBlockStreamer received a RollBackward({rollback_slot_number:?})"
+                    "received a RollBackward({rollback_slot_number:?})"
                 );
                 let block_streamer_next_action = if rollback_slot_number == self.from.slot_number {
                     BlockStreamerNextAction::SkipToNextAction
@@ -156,7 +157,7 @@ impl ChainReaderBlockStreamer {
                 Ok(Some(block_streamer_next_action))
             }
             None => {
-                trace!(self.logger, "ChainReaderBlockStreamer received nothing");
+                trace!(self.logger, "received nothing");
                 Ok(None)
             }
         }

mithril-common/src/cardano_block_scanner/chain_reader_block_streamer.rs

@@ -11,6 +11,7 @@ use slog::{debug, info, Logger};
 
 use crate::chain_observer::ChainObserver;
 use crate::entities::{BlockNumber, SignedEntityTypeDiscriminants};
+use crate::logging::LoggerExtensions;
 use crate::signable_builder::TransactionsImporter;
 use crate::signed_entity_type_lock::SignedEntityTypeLock;
 use crate::StdResult;
@@ -71,34 +72,31 @@ impl CardanoTransactionsPreloader {
             importer,
             security_parameter,
             chain_observer,
-            logger,
+            logger: logger.new_with_component_name::<Self>(),
             activation_state,
         }
     }
 
     /// Preload the Cardano Transactions by running the importer up to the current chain block number.
     pub async fn preload(&self) -> StdResult<()> {
         if !self.is_activated().await? {
-            debug!(
-                self.logger,
-                "⟳ Preload Cardano Transactions - Not running, conditions not met"
-            );
+            debug!(self.logger, "Not running, conditions not met");
             return Ok(());
         }
 
-        info!(self.logger, "⟳ Preload Cardano Transactions - Started");
-        debug!(self.logger, "⟳ Locking signed entity type"; "entity_type" => "CardanoTransactions");
+        info!(self.logger, "Started");
+        debug!(self.logger, "Locking signed entity type"; "entity_type" => "CardanoTransactions");
         self.signed_entity_type_lock
             .lock(SignedEntityTypeDiscriminants::CardanoTransactions)
             .await;
 
         let preload_result = self.do_preload().await;
 
-        debug!(self.logger, "⟳ Releasing signed entity type"; "entity_type" => "CardanoTransactions");
+        debug!(self.logger, "Releasing signed entity type"; "entity_type" => "CardanoTransactions");
         self.signed_entity_type_lock
             .release(SignedEntityTypeDiscriminants::CardanoTransactions)
             .await;
-        info!(self.logger, "⟳ Preload Cardano Transactions - Finished");
+        info!(self.logger, "Finished");
 
         preload_result
     }

mithril-common/src/cardano_transactions_preloader.rs

@@ -15,6 +15,7 @@ use crate::crypto_helper::{
 use crate::entities::{
     Certificate, CertificateSignature, ProtocolMessage, ProtocolMessagePartKey, ProtocolParameters,
 };
+use crate::logging::LoggerExtensions;
 use crate::StdResult;
 
 #[cfg(test)]
@@ -122,7 +123,7 @@ impl MithrilCertificateVerifier {
     pub fn new(logger: Logger, certificate_retriever: Arc<dyn CertificateRetriever>) -> Self {
         debug!(logger, "New MithrilCertificateVerifier created");
         Self {
-            logger,
+            logger: logger.new_with_component_name::<Self>(),
             certificate_retriever,
         }
     }
@@ -302,14 +303,13 @@ impl CertificateVerifier for MithrilCertificateVerifier {
 mod tests {
     use async_trait::async_trait;
     use mockall::mock;
-    use slog_scope;
 
     use super::CertificateRetriever;
     use super::*;
 
     use crate::certificate_chain::CertificateRetrieverError;
     use crate::crypto_helper::{tests_setup::*, ProtocolClerk};
-    use crate::test_utils::MithrilFixtureBuilder;
+    use crate::test_utils::{MithrilFixtureBuilder, TestLogger};
 
     mock! {
         pub CertificateRetrieverImpl { }
@@ -348,7 +348,7 @@ mod tests {
             .into();
 
         let verifier = MithrilCertificateVerifier::new(
-            slog_scope::logger(),
+            TestLogger::stdout(),
             Arc::new(MockCertificateRetrieverImpl::new()),
         );
         let message_tampered = message_hash[1..].to_vec();
@@ -387,7 +387,7 @@ mod tests {
             .returning(move |_| Ok(fake_certificate2.clone()))
             .times(1);
         let verifier = MithrilCertificateVerifier::new(
-            slog_scope::logger(),
+            TestLogger::stdout(),
             Arc::new(mock_certificate_retriever),
         );
         let verify = verifier
@@ -410,7 +410,7 @@ mod tests {
             .returning(move |_| Ok(fake_certificate2.clone()))
             .times(1);
         let verifier = MithrilCertificateVerifier::new(
-            slog_scope::logger(),
+            TestLogger::stdout(),
             Arc::new(mock_certificate_retriever),
         );
         let verify = verifier
@@ -435,7 +435,7 @@ mod tests {
             .returning(move |_| Ok(fake_certificate2.clone()))
             .times(1);
         let verifier = MithrilCertificateVerifier::new(
-            slog_scope::logger(),
+            TestLogger::stdout(),
             Arc::new(mock_certificate_retriever),
         );
         let error = verifier
@@ -478,7 +478,7 @@ mod tests {
             .returning(move |_| Ok(fake_certificate2.clone()))
             .times(1);
         let verifier = MithrilCertificateVerifier::new(
-            slog_scope::logger(),
+            TestLogger::stdout(),
             Arc::new(mock_certificate_retriever),
         );
         let error = verifier
@@ -505,7 +505,7 @@ mod tests {
         fake_certificate1.hash = "another-hash".to_string();
         let mock_certificate_retriever = MockCertificateRetrieverImpl::new();
         let verifier = MithrilCertificateVerifier::new(
-            slog_scope::logger(),
+            TestLogger::stdout(),
             Arc::new(mock_certificate_retriever),
         );
         let error = verifier
@@ -537,7 +537,7 @@ mod tests {
                 .times(1);
         }
         let verifier = MithrilCertificateVerifier::new(
-            slog_scope::logger(),
+            TestLogger::stdout(),
             Arc::new(mock_certificate_retriever),
         );
         let verify = verifier
@@ -570,7 +570,7 @@ mod tests {
                 .times(1);
         }
         let verifier = MithrilCertificateVerifier::new(
-            slog_scope::logger(),
+            TestLogger::stdout(),
             Arc::new(mock_certificate_retriever),
         );
         let error = verifier

mithril-common/src/certificate_chain/certificate_verifier.rs

@@ -9,6 +9,7 @@ use pallas_network::{
 use pallas_traverse::MultiEraBlock;
 use slog::{debug, Logger};
 
+use crate::logging::LoggerExtensions;
 use crate::{cardano_block_scanner::ScannedBlock, entities::ChainPoint, CardanoNetwork, StdResult};
 
 use super::{ChainBlockNextAction, ChainBlockReader};
@@ -28,7 +29,7 @@ impl PallasChainReader {
             socket: socket.to_owned(),
             network,
             client: None,
-            logger,
+            logger: logger.new_with_component_name::<Self>(),
         }
     }
 
@@ -45,7 +46,7 @@ impl PallasChainReader {
     async fn get_client(&mut self) -> StdResult<&mut NodeClient> {
         if self.client.is_none() {
             self.client = Some(self.new_client().await?);
-            debug!(self.logger, "PallasChainReader connected to a new client");
+            debug!(self.logger, "connected to a new client");
         }
 
         self.client
@@ -60,12 +61,12 @@ impl PallasChainReader {
         let chainsync = client.chainsync();
 
         if chainsync.has_agency() {
-            debug!(logger, "PallasChainReader has agency, finding intersect point..."; "point" => ?point);
+            debug!(logger, "has agency, finding intersect point..."; "point" => ?point);
             chainsync
                 .find_intersect(vec![point.to_owned().into()])
                 .await?;
         } else {
-            debug!(logger, "PallasChainReader doesn't have agency, no need to find intersect point";);
+            debug!(logger, "doesn't have agency, no need to find intersect point";);
         }
 
         Ok(())

mithril-common/src/chain_reader/pallas_chain_reader.rs

@@ -1,5 +1,6 @@
 use crate::{
     digesters::cache::{ImmutableFileDigestCacheProvider, JsonImmutableFileDigestCacheProvider},
+    logging::LoggerExtensions,
     StdResult,
 };
 use anyhow::Context;
@@ -43,7 +44,7 @@ impl<'a> JsonImmutableFileDigestCacheProviderBuilder<'a> {
 
     /// Set the [Logger] to use.
     pub fn with_logger(&mut self, logger: Logger) -> &mut Self {
-        self.logger = logger;
+        self.logger = logger.new_with_component_name::<Self>();
         self
     }
 

mithril-common/src/digesters/cache/json_provider_builder.rs

@@ -4,6 +4,7 @@ use crate::{
         ImmutableFile,
     },
     entities::{CardanoDbBeacon, HexEncodedDigest, ImmutableFileName},
+    logging::LoggerExtensions,
 };
 use async_trait::async_trait;
 use sha2::{Digest, Sha256};
@@ -32,7 +33,7 @@ impl CardanoImmutableDigester {
     ) -> Self {
         Self {
             cache_provider,
-            logger,
+            logger: logger.new_with_component_name::<Self>(),
         }
     }
 }

mithril-common/src/digesters/cardano_immutable_digester.rs

@@ -57,6 +57,7 @@ pub mod crypto_helper;
 pub mod entities;
 #[macro_use]
 pub mod era;
+pub mod logging;
 pub mod messages;
 pub mod protocol;
 pub mod resource_pool;